Node stops working after updating

Node Operators troubleshooting
,
1

Hello,

my Node tried to do an auto Update but ended in an infinite loop where it only shows following lines in the logs:

2022-11-30T12:46:03.415Z        INFO    Downloading versions.   {"Process": "storagenode-updater", "Server Address": "https://version.storj.io"}
2022-11-30T12:46:03.817Z        INFO    Current binary version  {"Process": "storagenode-updater", "Service": "storagenode", "Version": "v1.67.3"}
2022-11-30T12:46:03.817Z        INFO    Version is up to date   {"Process": "storagenode-updater", "Service": "storagenode"}
2022-11-30T12:46:03.821Z        INFO    Current binary version  {"Process": "storagenode-updater", "Service": "storagenode-updater", "Version": "v1.67.3"}
2022-11-30T12:46:03.821Z        INFO    Version is up to date   {"Process": "storagenode-updater", "Service": "storagenode-updater"}

Restarting the Node / Server does not fix the problem. After some minutes the same things happens again. I also tried to remove the docker container and add it again, with no success.

Does anyone have an idea what could be the problem?

Thanks in advance

2

How long did you allow it to run before restarting? These logs are from the storagenode-updater and it shows it is working fine. Can you provide at least the last 20 lines of the log?

3

I left it running for multiple hours. How long is a update supposed to take?
Here are some more logs:

2022-11-30T13:59:35.470Z        INFO    piecestore      uploaded        {"Process": "storagenode", "Piece ID": "KV6PV555VJX7KOWZUZJCZPUWTWZFH4WVYSJZJ7U3MR37BWIWJFOA", "Satellite ID": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S", "Action": "PUT", "Size": 199680}
2022-11-30T13:59:36.396Z        INFO    piecestore      upload started  {"Process": "storagenode", "Piece ID": "5HQ4CQH5HYZ6CVCB3Z4U22NDYVDSSD6QA3BMH3BIYYKPEX3KADRQ", "Satellite ID": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S", "Action": "PUT", "Available Space": 5393729039744}
2022-11-30T13:59:37.742Z        INFO    piecestore      uploaded        {"Process": "storagenode", "Piece ID": "5HQ4CQH5HYZ6CVCB3Z4U22NDYVDSSD6QA3BMH3BIYYKPEX3KADRQ", "Satellite ID": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S", "Action": "PUT", "Size": 168704}
2022-11-30T13:59:38.308Z        INFO    piecestore      upload started  {"Process": "storagenode", "Piece ID": "HIOZ7RNGLTU4KXDCJYDZNSCV2MHSMBXWM2LEYJDO3CSYF4DFACBA", "Satellite ID": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S", "Action": "PUT", "Available Space": 5393728870528}
2022-11-30T13:59:38.490Z        INFO    piecestore      uploaded        {"Process": "storagenode", "Piece ID": "KOUJ42XL2Z37T7BMBZZD262PURP62N5JBDQUM4MSZ2RGVRKEQ6GA", "Satellite ID": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S", "Action": "PUT", "Size": 100864}
2022-11-30T14:00:33.709Z        INFO    piecestore      download started        {"Process": "storagenode", "Piece ID": "CBJHT4Y7KGICVAQ3CXNC4Y65LU7OKFO5VZZOAFHWPSO4MFSXAEQA", "Satellite ID": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S", "Action": "GET"}
2022-11-30T14:03:07.439Z        INFO    piecestore      download started        {"Process": "storagenode", "Piece ID": "HA747GK7KOCIA6IGADMJGE7223NDUXYT3OYOWSBBWDOG3DRC3LSQ", "Satellite ID": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S", "Action": "GET"}
2022-11-30T14:03:16.793Z        INFO    piecestore      download started        {"Process": "storagenode", "Piece ID": "HA747GK7KOCIA6IGADMJGE7223NDUXYT3OYOWSBBWDOG3DRC3LSQ", "Satellite ID": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S", "Action": "GET"}
2022-11-30T14:03:29.192Z        INFO    piecestore      download started        {"Process": "storagenode", "Piece ID": "HA747GK7KOCIA6IGADMJGE7223NDUXYT3OYOWSBBWDOG3DRC3LSQ", "Satellite ID": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S", "Action": "GET"}
2022-11-30T14:03:36.494Z        INFO    piecestore      download started        {"Process": "storagenode", "Piece ID": "LY65JEO352MHP46C2WIUIST5O5Z634VDTVW4NQBK6APHAKKKQ6JA", "Satellite ID": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S", "Action": "GET"}
2022-11-30T14:03:49.834Z        INFO    piecestore      download started        {"Process": "storagenode", "Piece ID": "LY65JEO352MHP46C2WIUIST5O5Z634VDTVW4NQBK6APHAKKKQ6JA", "Satellite ID": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S", "Action": "GET"}
2022-11-30T14:03:51.696Z        INFO    piecestore      download started        {"Process": "storagenode", "Piece ID": "HA747GK7KOCIA6IGADMJGE7223NDUXYT3OYOWSBBWDOG3DRC3LSQ", "Satellite ID": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S", "Action": "GET"}
2022-11-30T14:04:00.244Z        INFO    piecestore      download started        {"Process": "storagenode", "Piece ID": "HA747GK7KOCIA6IGADMJGE7223NDUXYT3OYOWSBBWDOG3DRC3LSQ", "Satellite ID": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S", "Action": "GET"}
2022-11-30T14:05:20.363Z        INFO    piecestore      download started        {"Process": "storagenode", "Piece ID": "QH35M7Q3C2WCGRD6HWNR7Y5KKD4OULXTCW44KW6S6ZT67UUO7QFQ", "Satellite ID": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S", "Action": "GET"}
2022-11-30T14:07:20.431Z        INFO    piecestore      download started        {"Process": "storagenode", "Piece ID": "HA747GK7KOCIA6IGADMJGE7223NDUXYT3OYOWSBBWDOG3DRC3LSQ", "Satellite ID": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S", "Action": "GET"}
2022-11-30T14:07:39.915Z        INFO    piecestore      download started        {"Process": "storagenode", "Piece ID": "LY65JEO352MHP46C2WIUIST5O5Z634VDTVW4NQBK6APHAKKKQ6JA", "Satellite ID": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S", "Action": "GET"}
2022-11-30T14:08:18.599Z        INFO    Downloading versions.   {"Process": "storagenode-updater", "Server Address": "https://version.storj.io"}
2022-11-30T14:08:19.000Z        INFO    Current binary version  {"Process": "storagenode-updater", "Service": "storagenode", "Version": "v1.67.3"}
2022-11-30T14:08:19.000Z        INFO    Version is up to date   {"Process": "storagenode-updater", "Service": "storagenode"}
2022-11-30T14:08:19.005Z        INFO    Current binary version  {"Process": "storagenode-updater", "Service": "storagenode-updater", "Version": "v1.67.3"}
2022-11-30T14:08:19.005Z        INFO    Version is up to date   {"Process": "storagenode-updater", "Service": "storagenode-updater"}
2022-11-30T14:08:34.713Z        INFO    piecestore      download started        {"Process": "storagenode", "Piece ID": "HA747GK7KOCIA6IGADMJGE7223NDUXYT3OYOWSBBWDOG3DRC3LSQ", "Satellite ID": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S", "Action": "GET"}
2022-11-30T14:15:21.841Z        INFO    piecestore      download started        {"Process": "storagenode", "Piece ID": "PQKLD5RIZDMG3TH3FYE7FZ3MTT3X45MKHVMJVLLQWIB2ATYZ5XZQ", "Satellite ID": "12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs", "Action": "GET"}
2022-11-30T14:21:22.410Z        INFO    piecestore      download started        {"Process": "storagenode", "Piece ID": "IVOCZJVFSFFARQVQTPYWBB6X5YMN2RHFVR2DSG6LYVC7HUUS53WA", "Satellite ID": "12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs", "Action": "GET"}
2022-11-30T14:22:09.761Z        INFO    piecestore      download started        {"Process": "storagenode", "Piece ID": "IVOCZJVFSFFARQVQTPYWBB6X5YMN2RHFVR2DSG6LYVC7HUUS53WA", "Satellite ID": "12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs", "Action": "GET"}
2022-11-30T14:23:18.590Z        INFO    Downloading versions.   {"Process": "storagenode-updater", "Server Address": "https://version.storj.io"}
2022-11-30T14:23:18.988Z        INFO    Current binary version  {"Process": "storagenode-updater", "Service": "storagenode", "Version": "v1.67.3"}
2022-11-30T14:23:18.988Z        INFO    Version is up to date   {"Process": "storagenode-updater", "Service": "storagenode"}
2022-11-30T14:23:18.992Z        INFO    Current binary version  {"Process": "storagenode-updater", "Service": "storagenode-updater", "Version": "v1.67.3"}
2022-11-30T14:23:18.992Z        INFO    Version is up to date   {"Process": "storagenode-updater", "Service": "storagenode-updater"}
2022-11-30T14:23:20.871Z        INFO    bandwidth       Performing bandwidth usage rollups      {"Process": "storagenode"}
4

Thats what it looks like on a different node with the same problem:

2022-11-30T12:37:34.098Z        INFO    piecestore      download started        {"Process": "storagenode", "Piece ID": "KAM7PWV2ZFBX35AVVA45FSJRJPJLTULTDYTOVXVS75U6KOPM53IA", "Satellite ID": "12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs", "Action": "GET"}
2022-11-30T12:37:34.505Z        INFO    piecestore      download started        {"Process": "storagenode", "Piece ID": "WDKMI5E6YQ5HZYXE62JX44RFZIZHACJ7W2AAPDE53HEPYZNK4YPA", "Satellite ID": "121RTSDpyNZVcEU84Ticf2L1ntiuUimbWgfATz21tuvgk3vzoA6", "Action": "GET"}
2022-11-30T12:37:46.564Z        INFO    piecestore      download started        {"Process": "storagenode", "Piece ID": "TQTBWVX77HBHGYKWJZA3T2RTOIYPBX6K6BOADQL272AHZ6G74I4Q", "Satellite ID": "12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs", "Action": "GET"}
2022-11-30T12:37:50.184Z        INFO    piecestore      download started        {"Process": "storagenode", "Piece ID": "KWN26KM2GHBVS2GFU6UUCLOEDR6UPYZDZ4FR37TEUM6EYZRH3NQA", "Satellite ID": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S", "Action": "GET"}
2022-11-30T12:37:59.973Z        INFO    piecestore      download started        {"Process": "storagenode", "Piece ID": "LGKHLIWCQNYSGAL43YPCYVIBZQAFXDK5MOCPARAA2PW7MK6ZOGJQ", "Satellite ID": "12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs", "Action": "GET"}
2022-11-30T12:38:09.104Z        INFO    piecestore      download started        {"Process": "storagenode", "Piece ID": "4UFUB7ZV6JS7SMCI2BCEZJRCDHSW4475UHDFN6PY4ORQKCYTW2HQ", "Satellite ID": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S", "Action": "GET"}
2022-11-30T12:46:03.415Z        INFO    Downloading versions.   {"Process": "storagenode-updater", "Server Address": "https://version.storj.io"}
2022-11-30T12:46:03.817Z        INFO    Current binary version  {"Process": "storagenode-updater", "Service": "storagenode", "Version": "v1.67.3"}
2022-11-30T12:46:03.817Z        INFO    Version is up to date   {"Process": "storagenode-updater", "Service": "storagenode"}
2022-11-30T12:46:03.821Z        INFO    Current binary version  {"Process": "storagenode-updater", "Service": "storagenode-updater", "Version": "v1.67.3"}
2022-11-30T12:46:03.821Z        INFO    Version is up to date   {"Process": "storagenode-updater", "Service": "storagenode-updater"}
2022-11-30T13:01:03.415Z        INFO    Downloading versions.   {"Process": "storagenode-updater", "Server Address": "https://version.storj.io"}
2022-11-30T13:01:03.794Z        INFO    Current binary version  {"Process": "storagenode-updater", "Service": "storagenode", "Version": "v1.67.3"}
2022-11-30T13:01:03.794Z        INFO    Version is up to date   {"Process": "storagenode-updater", "Service": "storagenode"}
2022-11-30T13:01:03.799Z        INFO    Current binary version  {"Process": "storagenode-updater", "Service": "storagenode-updater", "Version": "v1.67.3"}
2022-11-30T13:01:03.799Z        INFO    Version is up to date   {"Process": "storagenode-updater", "Service": "storagenode-updater"}
2022-11-30T13:16:03.425Z        INFO    Downloading versions.   {"Process": "storagenode-updater", "Server Address": "https://version.storj.io"}
2022-11-30T13:16:03.827Z        INFO    Current binary version  {"Process": "storagenode-updater", "Service": "storagenode", "Version": "v1.67.3"}
2022-11-30T13:16:03.827Z        INFO    Version is up to date   {"Process": "storagenode-updater", "Service": "storagenode"}
2022-11-30T13:16:03.831Z        INFO    Current binary version  {"Process": "storagenode-updater", "Service": "storagenode-updater", "Version": "v1.67.3"}
2022-11-30T13:16:03.831Z        INFO    Version is up to date   {"Process": "storagenode-updater", "Service": "storagenode-updater"}
2022-11-30T13:31:03.416Z        INFO    Downloading versions.   {"Process": "storagenode-updater", "Server Address": "https://version.storj.io"}
2022-11-30T13:31:03.834Z        INFO    Current binary version  {"Process": "storagenode-updater", "Service": "storagenode", "Version": "v1.67.3"}
2022-11-30T13:31:03.834Z        INFO    Version is up to date   {"Process": "storagenode-updater", "Service": "storagenode"}
2022-11-30T13:31:03.839Z        INFO    Current binary version  {"Process": "storagenode-updater", "Service": "storagenode-updater", "Version": "v1.67.3"}
2022-11-30T13:31:03.839Z        INFO    Version is up to date   {"Process": "storagenode-updater", "Service": "storagenode-updater"}
2022-11-30T13:46:03.425Z        INFO    Downloading versions.   {"Process": "storagenode-updater", "Server Address": "https://version.storj.io"}
2022-11-30T13:46:03.883Z        INFO    Current binary version  {"Process": "storagenode-updater", "Service": "storagenode", "Version": "v1.67.3"}
2022-11-30T13:46:03.883Z        INFO    Version is up to date   {"Process": "storagenode-updater", "Service": "storagenode"}
2022-11-30T13:46:03.887Z        INFO    Current binary version  {"Process": "storagenode-updater", "Service": "storagenode-updater", "Version": "v1.67.3"}
2022-11-30T13:46:03.887Z        INFO    Version is up to date   {"Process": "storagenode-updater", "Service": "storagenode-updater"}
2022-11-30T14:01:03.424Z        INFO    Downloading versions.   {"Process": "storagenode-updater", "Server Address": "https://version.storj.io"}
2022-11-30T14:01:03.816Z        INFO    Current binary version  {"Process": "storagenode-updater", "Service": "storagenode", "Version": "v1.67.3"}
2022-11-30T14:01:03.816Z        INFO    Version is up to date   {"Process": "storagenode-updater", "Service": "storagenode"}
2022-11-30T14:01:03.821Z        INFO    Current binary version  {"Process": "storagenode-updater", "Service": "storagenode-updater", "Version": "v1.67.3"}
2022-11-30T14:01:03.821Z        INFO    Version is up to date   {"Process": "storagenode-updater", "Service": "storagenode-updater"}
2022-11-30T14:16:03.423Z        INFO    Downloading versions.   {"Process": "storagenode-updater", "Server Address": "https://version.storj.io"}
2022-11-30T14:16:03.826Z        INFO    Current binary version  {"Process": "storagenode-updater", "Service": "storagenode", "Version": "v1.67.3"}
2022-11-30T14:16:03.826Z        INFO    Version is up to date   {"Process": "storagenode-updater", "Service": "storagenode"}
2022-11-30T14:16:03.830Z        INFO    Current binary version  {"Process": "storagenode-updater", "Service": "storagenode-updater", "Version": "v1.67.3"}
2022-11-30T14:16:03.830Z        INFO    Version is up to date   {"Process": "storagenode-updater", "Service": "storagenode-updater"}
2022-11-30T14:31:03.425Z        INFO    Downloading versions.   {"Process": "storagenode-updater", "Server Address": "https://version.storj.io"}
2022-11-30T14:31:03.813Z        INFO    Current binary version  {"Process": "storagenode-updater", "Service": "storagenode", "Version": "v1.67.3"}
2022-11-30T14:31:03.813Z        INFO    Version is up to date   {"Process": "storagenode-updater", "Service": "storagenode"}
2022-11-30T14:31:03.818Z        INFO    Current binary version  {"Process": "storagenode-updater", "Service": "storagenode-updater", "Version": "v1.67.3"}
2022-11-30T14:31:03.818Z        INFO    Version is up to date   {"Process": "storagenode-updater", "Service": "storagenode-updater"}
2022-11-30T14:46:03.415Z        INFO    Downloading versions.   {"Process": "storagenode-updater", "Server Address": "https://version.storj.io"}
2022-11-30T14:46:03.800Z        INFO    Current binary version  {"Process": "storagenode-updater", "Service": "storagenode", "Version": "v1.67.3"}
2022-11-30T14:46:03.800Z        INFO    Version is up to date   {"Process": "storagenode-updater", "Service": "storagenode"}
2022-11-30T14:46:03.806Z        INFO    Current binary version  {"Process": "storagenode-updater", "Service": "storagenode-updater", "Version": "v1.67.3"}
2022-11-30T14:46:03.806Z        INFO    Version is up to date   {"Process": "storagenode-updater", "Service": "storagenode-updater"}
2022-11-30T15:01:03.418Z        INFO    Downloading versions.   {"Process": "storagenode-updater", "Server Address": "https://version.storj.io"}
2022-11-30T15:01:03.810Z        INFO    Current binary version  {"Process": "storagenode-updater", "Service": "storagenode", "Version": "v1.67.3"}
2022-11-30T15:01:03.810Z        INFO    Version is up to date   {"Process": "storagenode-updater", "Service": "storagenode"}
2022-11-30T15:01:03.816Z        INFO    Current binary version  {"Process": "storagenode-updater", "Service": "storagenode-updater", "Version": "v1.67.3"}
2022-11-30T15:01:03.816Z        INFO    Version is up to date   {"Process": "storagenode-updater", "Service": "storagenode-updater"}
5

The node is working fine. I don’t see any issue from the logs. The INFO level logs from the updater is just showing the updater doing its work (i.e. regularly checking for newer storagenode version and update the node if needed).

6

But is the node still Up and Downloading files during this process? Even if there are no logs? Also the node Dashboard 127.0.0.X:14002 is not available during when these messages appear

7

Note that the updater is also running as a separate process in the docker container together with the storagenode process. So you will see these logs from the updater while the node is still running.

8

Yes. See Node stops working after updating - #7 by clement

9

Hmm okay. I also just noticed that the ram is filling up. 25GB of Ram Usage on a System with 2 Nodes seems to be a bit high.
How long is the update process supposed to take?

10

Looking at the docker stats the container has 0,01% CPU utilization. I don’t think that the node is running properly

11

The updater will run in an endless loop. It will check for a new version every 15 minutes. That is what you are seeing in the logs. The updater is working just fine.

I would agree. I see a lot of download started but no finish messages. Doesn’t look healthy to me. Your node might get suspended or disqualified after some time.

12

Do you have any recommendations on how to fix this? I am running out of ideas…
I recently switched from Docker on Windows to an Ubuntu Proxmox VM. Could this have something to do with it?

13

Maybe you redirected logs to the file for the node without upload/download lines?

Also please check

docker ps -a