Input/Output Error on my Disk

Node Operators troubleshooting
,
1

Greetings everyone!
I was transitioning to fiber internet from my VDSL connection a couple of days ago. A couple of times I turned off my Raspberry Pi without a soft turn-off (stop the storj-node and then shut down the Raspberry from the terminal).

Right now, I’m getting an Input/output error when I execute the ls command from the terminal.

abc@raspberrypi:/mnt/storj $ ls -la
ls: cannot access ‘storagenode’: Input/output error
total 24
drwxr-xr-x 4 pi pi 4096 Dec 5 2021 .
drwxr-xr-x 3 root root 4096 Nov 18 2021 …
drwx------ 2 pi pi 16384 Nov 18 2021 lost+found
d??? ? ? ? ? ? storagenode
abc@raspberrypi:/mnt/storj $ ls -a
ls: cannot access ‘storagenode’: Input/output error
. … lost+found storagenode

Here is the docker logs output:

docker logs --tail 30 storagenode
--- stat config/storage/temp: no such file or directory
--- stat config/storage/garbage: no such file or directory
--- stat config/storage/trash: no such file or directory
2023-04-12 12:54:38,764 INFO exited: storagenode (exit status 1; not expected)
2023-04-12 12:54:40,782 INFO spawned: 'storagenode' with pid 54
2023-04-12T12:54:41.116Z        INFO    Anonymized tracing enabled      {"Process": "storagenode"}
2023-04-12T12:54:41.173Z        INFO    Operator email  {"Process": "storagenode", "Address": "abcdef@gmail.com"}
2023-04-12T12:54:41.174Z        INFO    Operator wallet {"Process": "storagenode", "Address": "0xaaaaaabbbbbbbbbb"}
Error: Error starting master database on storagenode: group:
--- stat config/storage/blobs: no such file or directory
--- stat config/storage/temp: no such file or directory
--- stat config/storage/garbage: no such file or directory
--- stat config/storage/trash: no such file or directory
2023-04-12 12:54:41,181 INFO exited: storagenode (exit status 1; not expected)
2023-04-12 12:54:44,202 INFO spawned: 'storagenode' with pid 62
2023-04-12T12:54:44.542Z        INFO    Anonymized tracing enabled      {"Process": "storagenode"}
2023-04-12T12:54:44.599Z        INFO    Operator email  {"Process": "storagenode", "Address": "abcdef@gmail.com"}
2023-04-12T12:54:44.599Z        INFO    Operator wallet {"Process": "storagenode", "Address": "0xaaaaaaaaaaabbbbbbbbbbbbbccccccccccccccc"}
Error: Error starting master database on storagenode: group:
--- stat config/storage/blobs: no such file or directory
--- stat config/storage/temp: no such file or directory
--- stat config/storage/garbage: no such file or directory
--- stat config/storage/trash: no such file or directory
2023-04-12 12:54:44,606 INFO exited: storagenode (exit status 1; not expected)
2023-04-12 12:54:45,608 INFO gave up: storagenode entered FATAL state, too many start retries too quickly
2023-04-12 12:54:46,613 WARN received SIGQUIT indicating exit request
2023-04-12 12:54:46,615 INFO waiting for processes-exit-eventlistener, storagenode-updater to die
2023-04-12T12:54:46.615Z        INFO    Got a signal from the OS: "terminated"  {"Process": "storagenode-updater"}
2023-04-12 12:54:46,627 INFO stopped: storagenode-updater (exit status 0)
2023-04-12 12:54:47,633 INFO stopped: processes-exit-eventlistener (terminated by SIGTERM)

e2fsck command output as below:

abc@raspberrypi:~ $ sudo e2fsck -p /dev/sdb1 
/dev/sdb1: recovering journal
/dev/sdb1 contains a file system with errors, check forced.
/dev/sdb1: Inode 48722798 ref count is 1, should be 2.  FIXED.
/dev/sdb1: Inode 49285578 ref count is 1, should be 2.  FIXED.
/dev/sdb1: Inode 49286370 ref count is 1, should be 2.  FIXED.
/dev/sdb1: Inode 49286404 ref count is 1, should be 2.  FIXED.
/dev/sdb1: Inode 49286409 ref count is 1, should be 2.  FIXED.
/dev/sdb1: Inode 49286490 ref count is 1, should be 2.  FIXED.
/dev/sdb1: Inode 49286494 ref count is 1, should be 2.  FIXED.
/dev/sdb1: Inode 49286502 ref count is 1, should be 2.  FIXED.
/dev/sdb1: Inode 49286649 ref count is 1, should be 2.  FIXED.
/dev/sdb1: Inode 49286651 ref count is 1, should be 2.  FIXED.
Error reading block 86507525 (Input/output error) while reading inode and block bitmaps.  

/dev/sdb1: UNEXPECTED INCONSISTENCY; RUN fsck MANUALLY.
        (i.e., without -a or -p options)

After e2fsck command, I do not get any input/output error but my docker log output as below:

abc@raspberrypi:~ $ docker logs --tail 30 storagenode
2023-04-12T13:56:51.506Z        INFO    Invalid configuration file key  {"Process": "storagenode-updater", "Key": "storage.allocated-disk-space"}
2023-04-12T13:56:51.506Z        INFO    Invalid configuration file key  {"Process": "storagenode-updater", "Key": "contact.external-address"}
2023-04-12T13:56:51.506Z        INFO    Invalid configuration file key  {"Process": "storagenode-updater", "Key": "server.address"}
2023-04-12T13:56:51.506Z        INFO    Invalid configuration file key  {"Process": "storagenode-updater", "Key": "server.private-address"}
2023-04-12T13:56:51.506Z        INFO    Invalid configuration file value for key        {"Process": "storagenode-updater", "Key": "log.output"}
2023-04-12T13:56:51.535Z        INFO    Anonymized tracing enabled      {"Process": "storagenode-updater"}
2023-04-12T13:56:51.617Z        INFO    Running on version      {"Process": "storagenode-updater", "Service": "storagenode-updater", "Version": "v1.76.2"}
2023-04-12T13:56:51.618Z        INFO    Downloading versions.   {"Process": "storagenode-updater", "Server Address": "https://version.storj.io"}
2023-04-12T13:56:52.006Z        INFO    Configuration loaded    {"Process": "storagenode", "Location": "/app/config/config.yaml"}
2023-04-12T13:56:52.009Z        INFO    Anonymized tracing enabled      {"Process": "storagenode"}
2023-04-12T13:56:52.072Z        INFO    Operator email  {"Process": "storagenode", "Address": "abcdef90@gmail.com"}
2023-04-12T13:56:52.072Z        INFO    Operator wallet {"Process": "storagenode", "Address": "0xaaaaaaaaaaabbbbbbbbbbbbccccccccccccccccccc"}
2023-04-12T13:56:52.865Z        INFO    Current binary version  {"Process": "storagenode-updater", "Service": "storagenode", "Version": "v1.76.2"}
2023-04-12T13:56:52.865Z        INFO    Version is up to date   {"Process": "storagenode-updater", "Service": "storagenode"}
2023-04-12T13:56:52.902Z        INFO    Current binary version  {"Process": "storagenode-updater", "Service": "storagenode-updater", "Version": "v1.76.2"}
2023-04-12T13:56:52.902Z        INFO    Version is up to date   {"Process": "storagenode-updater", "Service": "storagenode-updater"}
2023-04-12T13:57:34.885Z        INFO    server  kernel support for server-side tcp fast open remains disabled.  {"Process": "storagenode"}
2023-04-12T13:57:34.887Z        INFO    server  enable with: sysctl -w net.ipv4.tcp_fastopen=3  {"Process": "storagenode"}
Error: trust: open config/trust-cache.json: permission denied
2023-04-12 13:58:10,869 INFO exited: storagenode (exit status 1; not expected)
2023-04-12 13:58:11,887 INFO spawned: 'storagenode' with pid 46
2023-04-12 13:58:11,890 WARN received SIGQUIT indicating exit request
2023-04-12 13:58:11,893 INFO waiting for storagenode, processes-exit-eventlistener, storagenode-updater to die
2023-04-12T13:58:11.893Z        INFO    Got a signal from the OS: "terminated"  {"Process": "storagenode-updater"}
2023-04-12 13:58:11,908 INFO stopped: storagenode-updater (exit status 0)
2023-04-12T13:58:12.221Z        INFO    Configuration loaded    {"Process": "storagenode", "Location": "/app/config/config.yaml"}
2023-04-12T13:58:12.222Z        INFO    Anonymized tracing enabled      {"Process": "storagenode"}
2023-04-12T13:58:12.279Z        INFO    Operator email  {"Process": "storagenode", "Address": "abcdef@gmail.com"}
2023-04-12T13:58:12.279Z        INFO    Operator wallet {"Process": "storagenode", "Address": "0xaaaaaaaaaaaaaabbbbbbbbbbbbccccccccccccccc"}
2023-04-12 13:58:15,287 INFO waiting for storagenode, processes-exit-eventlistener to die

A couple of minutes later, logs output from storagenode as below, and now my node is getting restarted within 12 seconds:

abc@raspberrypi:~ $ docker logs --tail 60 storagenode
2023-04-12 14:03:13,944 INFO exited: storagenode (exit status 1; not expected)
2023-04-12 14:03:14,946 INFO gave up: storagenode entered FATAL state, too many start retries too quickly
2023-04-12 14:03:14,948 WARN received SIGQUIT indicating exit request
2023-04-12 14:03:14,950 INFO waiting for processes-exit-eventlistener to die
2023-04-12 14:03:16,956 INFO stopped: processes-exit-eventlistener (terminated by SIGTERM)
2023-04-12 14:03:19,960 INFO RPC interface 'supervisor' initialized
2023-04-12 14:03:19,961 INFO supervisord started with pid 1
2023-04-12 14:03:20,971 INFO spawned: 'processes-exit-eventlistener' with pid 12
2023-04-12 14:03:20,989 INFO spawned: 'storagenode' with pid 13
2023-04-12 14:03:21,005 INFO spawned: 'storagenode-updater' with pid 14
2023/04/12 14:03:21 failed to check for file existence: stat config/config.yaml: input/output error
2023-04-12 14:03:21,097 INFO exited: storagenode-updater (exit status 1; not expected)
2023/04/12 14:03:21 failed to check for file existence: stat config/config.yaml: input/output error
2023-04-12 14:03:21,128 INFO exited: storagenode (exit status 1; not expected)
2023-04-12 14:03:22,130 INFO success: processes-exit-eventlistener entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2023-04-12 14:03:22,145 INFO spawned: 'storagenode' with pid 29
2023-04-12 14:03:22,161 INFO spawned: 'storagenode-updater' with pid 30
2023/04/12 14:03:22 failed to check for file existence: stat config/config.yaml: input/output error
2023-04-12 14:03:22,250 INFO exited: storagenode-updater (exit status 1; not expected)
2023/04/12 14:03:22 failed to check for file existence: stat config/config.yaml: input/output error
2023-04-12 14:03:22,289 INFO exited: storagenode (exit status 1; not expected)
2023-04-12 14:03:24,308 INFO spawned: 'storagenode' with pid 44
2023-04-12 14:03:24,322 INFO spawned: 'storagenode-updater' with pid 45
2023/04/12 14:03:24 failed to check for file existence: stat config/config.yaml: input/output error
2023-04-12 14:03:24,417 INFO exited: storagenode-updater (exit status 1; not expected)
2023/04/12 14:03:24 failed to check for file existence: stat config/config.yaml: input/output error
2023-04-12 14:03:24,444 INFO exited: storagenode (exit status 1; not expected)
2023-04-12 14:03:27,465 INFO spawned: 'storagenode' with pid 60
2023-04-12 14:03:27,480 INFO spawned: 'storagenode-updater' with pid 61
2023/04/12 14:03:27 failed to check for file existence: stat config/config.yaml: input/output error
2023-04-12 14:03:27,570 INFO exited: storagenode-updater (exit status 1; not expected)
2023/04/12 14:03:27 failed to check for file existence: stat config/config.yaml: input/output error
2023-04-12 14:03:27,601 INFO gave up: storagenode-updater entered FATAL state, too many start retries too quickly
2023-04-12 14:03:27,607 INFO exited: storagenode (exit status 1; not expected)
2023-04-12 14:03:28,610 INFO gave up: storagenode entered FATAL state, too many start retries too quickly
2023-04-12 14:03:28,610 WARN received SIGQUIT indicating exit request
2023-04-12 14:03:28,612 INFO waiting for processes-exit-eventlistener to die
2023-04-12 14:03:30,618 INFO stopped: processes-exit-eventlistener (terminated by SIGTERM)
2023-04-12 14:03:34,985 INFO RPC interface 'supervisor' initialized
2023-04-12 14:03:34,986 INFO supervisord started with pid 1
2023-04-12 14:03:35,996 INFO spawned: 'processes-exit-eventlistener' with pid 12
2023-04-12 14:03:36,015 INFO spawned: 'storagenode' with pid 13
2023-04-12 14:03:36,032 INFO spawned: 'storagenode-updater' with pid 14
2023/04/12 14:03:36 failed to check for file existence: stat config/config.yaml: input/output error
2023-04-12 14:03:36,130 INFO exited: storagenode-updater (exit status 1; not expected)
2023/04/12 14:03:36 failed to check for file existence: stat config/config.yaml: input/output error
2023-04-12 14:03:36,163 INFO exited: storagenode (exit status 1; not expected)
2023-04-12 14:03:37,166 INFO success: processes-exit-eventlistener entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2023-04-12 14:03:37,174 INFO spawned: 'storagenode' with pid 30
2023-04-12 14:03:37,182 INFO spawned: 'storagenode-updater' with pid 31
2023/04/12 14:03:37 failed to check for file existence: stat config/config.yaml: input/output error
2023-04-12 14:03:37,245 INFO exited: storagenode-updater (exit status 1; not expected)
2023/04/12 14:03:37 failed to check for file existence: stat config/config.yaml: input/output error
2023-04-12 14:03:37,268 INFO exited: storagenode (exit status 1; not expected)
2023-04-12 14:03:39,286 INFO spawned: 'storagenode' with pid 46
2023-04-12 14:03:39,301 INFO spawned: 'storagenode-updater' with pid 47
2023/04/12 14:03:39 failed to check for file existence: stat config/config.yaml: input/output error
2023-04-12 14:03:39,383 INFO exited: storagenode-updater (exit status 1; not expected)
2023/04/12 14:03:39 failed to check for file existence: stat config/config.yaml: input/output error
2023-04-12 14:03:39,410 INFO exited: storagenode (exit status 1; not expected)

Looks like I need to set up my node from scratch, Any suggestions?
Thank you

2

Looks like your drive is dead, starting a new node isnt gonna fix this… Unless you also have a bad mount or bad external hardware. All is possible. Ive seen this a few times on my rpi4 but it was a drive that was on the way out.

3

You should run sudo fsck /dev/sdb1 several times, until it will not throw any errors before continue.

But @deathlessdd is likely right - your disk could start dying.

4

After some work, I’ve fixed the disk issues… Some of the folder owners changed from my username to root and I fixed them manually.

Here is the last 50 logs output currently I get from the storagenode.

2023-04-17T15:23:59.587Z        INFO    piecestore      downloaded      {"Process": "storagenode", "Piece ID": "J6UJKFVMRCKPJCGO23XGX6HHXNAFV3T7WKUZCYC45MXSO5XEQIOA", "Satellite ID": "12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs", "Action": "GET", "Offset": 847104, "Size": 2560, "Remote Address": "162.55.184.55:53208"}
2023-04-17T15:23:59.759Z        INFO    piecestore      upload started  {"Process": "storagenode", "Piece ID": "76AHKSCAMLQMKKY2TJG632DOXK2TXOLNZIWCAKZWUSWLGLZROFKA", "Satellite ID": "12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs", "Action": "PUT_REPAIR", "Available Space": 3413155017901, "Remote Address": "23.88.105.177:42572"}
2023-04-17T15:23:59.902Z        INFO    piecestore      uploaded        {"Process": "storagenode", "Piece ID": "OXXDUTAU7QP7XSPBCZUVDUK3P4TI7KW5AVX2PQJHUPYAMCFUR6WQ", "Satellite ID": "12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs", "Action": "PUT", "Size": 580096, "Remote Address": "149.6.140.107:44610"}
2023-04-17T15:23:59.962Z        INFO    piecestore      upload started  {"Process": "storagenode", "Piece ID": "CH6QVBOHPDUO6LL5YVYJCJWNQF2HBWMSCOACHPFOMMSUNTJUEJVQ", "Satellite ID": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S", "Action": "PUT", "Available Space": 3413155014829, "Remote Address": "5.161.178.166:36376"}
2023-04-17T15:23:59.971Z        INFO    piecestore      upload started  {"Process": "storagenode", "Piece ID": "WCTUDKNQDXSTIAJXMDUIW4LZWUUJGYOHQVKASX6L7T7L3IIJILLQ", "Satellite ID": "12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs", "Action": "PUT", "Available Space": 3413155014829, "Remote Address": "128.140.5.217:56886"}
2023-04-17T15:23:59.978Z        INFO    piecestore      uploaded        {"Process": "storagenode", "Piece ID": "76AHKSCAMLQMKKY2TJG632DOXK2TXOLNZIWCAKZWUSWLGLZROFKA", "Satellite ID": "12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs", "Action": "PUT_REPAIR", "Size": 2560, "Remote Address": "23.88.105.177:42572"}
2023-04-17T15:23:59.973Z        INFO    piecestore      download started        {"Process": "storagenode", "Piece ID": "UUAOUPZSLCH3MWVTXPZHPNMHHTEMIH3VAVLPSIBEMJXQYPKC6TIA", "Satellite ID": "12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs", "Action": "GET", "Offset": 1158656, "Size": 2560, "Remote Address": "149.6.140.107:44610"}
2023-04-17T15:24:00.056Z        INFO    piecestore      uploaded        {"Process": "storagenode", "Piece ID": "YIEFYODXOXNHNYA7JV6WWW7PFHNEIXULO2XTWX2BVND5TTFEYQNQ", "Satellite ID": "12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs", "Action": "PUT", "Size": 580096, "Remote Address": "128.140.6.18:37216"}
2023-04-17T15:24:00.068Z        INFO    piecestore      upload started  {"Process": "storagenode", "Piece ID": "QQOQ76HKF53WNQKRHLIQK35VFSNKH67VVFYOFM3LKGYLIZEKJ2RQ", "Satellite ID": "12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs", "Action": "PUT", "Available Space": 3413155011245, "Remote Address": "128.140.5.255:23038"}
2023-04-17T15:24:00.090Z        INFO    piecestore      upload started  {"Process": "storagenode", "Piece ID": "QEMXCJGQNBSMXYU2W747TSP27EVOBXD2EM34W2NKSDW3PLKCQN2Q", "Satellite ID": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S", "Action": "PUT", "Available Space": 3413155011245, "Remote Address": "5.161.96.135:25242"}
2023-04-17T15:24:00.175Z        INFO    piecestore      download started        {"Process": "storagenode", "Piece ID": "PXL3WYQLPF6IJCXBR6SF2R7QBOBEM7HQNBQQTXY3RQ272J4YQ4UA", "Satellite ID": "12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs", "Action": "GET", "Offset": 1144064, "Size": 2560, "Remote Address": "188.239.191.33:47984"}
2023-04-17T15:24:00.322Z        ERROR   piecestore      upload failed   {"Process": "storagenode", "Piece ID": "CH6QVBOHPDUO6LL5YVYJCJWNQF2HBWMSCOACHPFOMMSUNTJUEJVQ", "Satellite ID": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S", "Action": "PUT", "error": "write tcp 172.17.0.3:28967->5.161.178.166:36376: write: connection reset by peer", "errorVerbose": "write tcp 172.17.0.3:28967->5.161.178.166:36376: write: connection reset by peer\n\tstorj.io/drpc/drpcstream.(*Stream).rawFlushLocked:401\n\tstorj.io/drpc/drpcstream.(*Stream).MsgSend:462\n\tstorj.io/common/pb.(*drpcPiecestore_UploadStream).SendAndClose:320\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).Upload.func5.1:490\n\tstorj.io/common/rpc/rpctimeout.Run.func1:22", "Size": 3072, "Remote Address": "5.161.178.166:36376"}
2023-04-17T15:24:00.385Z        INFO    piecestore      download canceled       {"Process": "storagenode", "Piece ID": "UUAOUPZSLCH3MWVTXPZHPNMHHTEMIH3VAVLPSIBEMJXQYPKC6TIA", "Satellite ID": "12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs", "Action": "GET", "Offset": 1158656, "Size": 0, "Remote Address": "149.6.140.107:44610"}
2023-04-17T15:24:00.463Z        INFO    piecestore      uploaded        {"Process": "storagenode", "Piece ID": "QEMXCJGQNBSMXYU2W747TSP27EVOBXD2EM34W2NKSDW3PLKCQN2Q", "Satellite ID": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S", "Action": "PUT", "Size": 1536, "Remote Address": "5.161.96.135:25242"}
2023-04-17T15:24:00.513Z        INFO    piecestore      downloaded      {"Process": "storagenode", "Piece ID": "PXL3WYQLPF6IJCXBR6SF2R7QBOBEM7HQNBQQTXY3RQ272J4YQ4UA", "Satellite ID": "12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs", "Action": "GET", "Offset": 1144064, "Size": 2560, "Remote Address": "188.239.191.33:47984"}
2023-04-17T15:24:00.605Z        INFO    piecestore      uploaded        {"Process": "storagenode", "Piece ID": "WCTUDKNQDXSTIAJXMDUIW4LZWUUJGYOHQVKASX6L7T7L3IIJILLQ", "Satellite ID": "12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs", "Action": "PUT", "Size": 580096, "Remote Address": "128.140.5.217:56886"}
2023-04-17T15:24:00.823Z        INFO    piecestore      upload started  {"Process": "storagenode", "Piece ID": "WZ3C5WKWKYKGBQ46VE6GTH6WTON2P3FG6YF6ZSKXGMOI5YXMFP6Q", "Satellite ID": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S", "Action": "PUT", "Available Space": 3413154428589, "Remote Address": "5.161.201.17:18302"}
2023-04-17T15:24:01.196Z        INFO    piecestore      download started        {"Process": "storagenode", "Piece ID": "HZXZ5XOVGVCPTUIDDXZU6CSBH6VUAG3RY3YCG2QMXDLFKX7RMBBA", "Satellite ID": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S", "Action": "GET", "Offset": 0, "Size": 11776, "Remote Address": "38.88.241.43:50196"}
2023-04-17T15:24:01.283Z        INFO    piecestore      upload started  {"Process": "storagenode", "Piece ID": "SLRALLXCAB3ZANE45ONNF55LKZH3UIGRTGA2JQAXPYIPE5PSQTCA", "Satellite ID": "121RTSDpyNZVcEU84Ticf2L1ntiuUimbWgfATz21tuvgk3vzoA6", "Action": "PUT_REPAIR", "Available Space": 3413154428589, "Remote Address": "167.235.19.43:38088"}
2023-04-17T15:24:01.369Z        INFO    piecestore      downloaded      {"Process": "storagenode", "Piece ID": "U2MXEFKLFTJZOUFSNA5RACRSREIVJHQGDZMATVFRLZ2LXY6IG52Q", "Satellite ID": "12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs", "Action": "GET", "Offset": 378112, "Size": 2560, "Remote Address": "188.239.191.33:47968"}
2023-04-17T15:24:01.398Z        INFO    piecestore      downloaded      {"Process": "storagenode", "Piece ID": "HZXZ5XOVGVCPTUIDDXZU6CSBH6VUAG3RY3YCG2QMXDLFKX7RMBBA", "Satellite ID": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S", "Action": "GET", "Offset": 0, "Size": 11776, "Remote Address": "38.88.241.43:50196"}
2023-04-17T15:24:01.585Z        INFO    piecestore      upload started  {"Process": "storagenode", "Piece ID": "ZZWUOQLWNEO5XT6IYTOK57ZPAXUH5P2V2P4P6PTIIMCETKK6H2IQ", "Satellite ID": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S", "Action": "PUT", "Available Space": 3413154273965, "Remote Address": "5.161.178.166:49386"}
2023-04-17T15:24:01.617Z        INFO    piecestore      uploaded        {"Process": "storagenode", "Piece ID": "SLRALLXCAB3ZANE45ONNF55LKZH3UIGRTGA2JQAXPYIPE5PSQTCA", "Satellite ID": "121RTSDpyNZVcEU84Ticf2L1ntiuUimbWgfATz21tuvgk3vzoA6", "Action": "PUT_REPAIR", "Size": 154112, "Remote Address": "167.235.19.43:38088"}
2023-04-17T15:24:01.686Z        INFO    piecestore      upload started  {"Process": "storagenode", "Piece ID": "B6ZHOLLGM3YPC3RXKNQR3CFR3UKJMGVIWJGY4MG7W6OEQPTZSEOA", "Satellite ID": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S", "Action": "PUT", "Available Space": 3413154267821, "Remote Address": "38.104.84.242:21312"}
2023-04-17T15:24:01.843Z        INFO    piecestore      uploaded        {"Process": "storagenode", "Piece ID": "ZZWUOQLWNEO5XT6IYTOK57ZPAXUH5P2V2P4P6PTIIMCETKK6H2IQ", "Satellite ID": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S", "Action": "PUT", "Size": 5632, "Remote Address": "5.161.178.166:49386"}
2023-04-17T15:24:01.978Z        INFO    piecestore      download started        {"Process": "storagenode", "Piece ID": "EPJ5L2QIB6WGK2M3VSKV6L7TJEVBTBSTWKS4O37XWF732MB5IG6A", "Satellite ID": "12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs", "Action": "GET", "Offset": 226304, "Size": 353536, "Remote Address": "149.6.140.106:33716"}
2023-04-17T15:24:01.995Z        INFO    piecestore      upload started  {"Process": "storagenode", "Piece ID": "RNY3KVXGNRCQTBBJWXXS3OIQISMSQWCKEJZJ4JA2C3L2ZF55N6DA", "Satellite ID": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S", "Action": "PUT", "Available Space": 3413152948653, "Remote Address": "5.161.178.166:51244"}
2023-04-17T15:24:02.007Z        INFO    piecestore      uploaded        {"Process": "storagenode", "Piece ID": "B6ZHOLLGM3YPC3RXKNQR3CFR3UKJMGVIWJGY4MG7W6OEQPTZSEOA", "Satellite ID": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S", "Action": "PUT", "Size": 13312, "Remote Address": "38.104.84.242:21312"}
2023-04-17T15:24:02.316Z        INFO    piecedeleter    delete piece sent to trash      {"Process": "storagenode", "Satellite ID": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S", "Piece ID": "YEUVXDLLVOLLNDR4MD2B2ZRMRM53G22G3WYVQSZBMTLNTEAZYM3A"}
2023-04-17T15:24:02.348Z        ERROR   piecestore      upload failed   {"Process": "storagenode", "Piece ID": "RNY3KVXGNRCQTBBJWXXS3OIQISMSQWCKEJZJ4JA2C3L2ZF55N6DA", "Satellite ID": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S", "Action": "PUT", "error": "context canceled", "errorVerbose": "context canceled\n\tstorj.io/common/rpc/rpcstatus.Wrap:75\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).Upload.func5:498\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).Upload:529\n\tstorj.io/common/pb.DRPCPiecestoreDescription.Method.func1:243\n\tstorj.io/drpc/drpcmux.(*Mux).HandleRPC:33\n\tstorj.io/common/rpc/rpctracing.(*Handler).HandleRPC:61\n\tstorj.io/common/experiment.(*Handler).HandleRPC:42\n\tstorj.io/drpc/drpcserver.(*Server).handleRPC:124\n\tstorj.io/drpc/drpcserver.(*Server).ServeOne:66\n\tstorj.io/drpc/drpcserver.(*Server).Serve.func2:114\n\tstorj.io/drpc/drpcctx.(*Tracker).track:35", "Size": 5120, "Remote Address": "5.161.178.166:51244"}
2023-04-17T15:24:02.374Z        ERROR   piecestore      upload failed   {"Process": "storagenode", "Piece ID": "3AWP6FTPS6GMHTVOKE3TZFWR2WBAHYCUZZ2Z3MTLFSLT4EQMZAPQ", "Satellite ID": "12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs", "Action": "PUT", "error": "context canceled", "errorVerbose": "context canceled\n\tstorj.io/common/rpc/rpcstatus.Wrap:75\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).Upload.func5:498\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).Upload:529\n\tstorj.io/common/pb.DRPCPiecestoreDescription.Method.func1:243\n\tstorj.io/drpc/drpcmux.(*Mux).HandleRPC:33\n\tstorj.io/common/rpc/rpctracing.(*Handler).HandleRPC:61\n\tstorj.io/common/experiment.(*Handler).HandleRPC:42\n\tstorj.io/drpc/drpcserver.(*Server).handleRPC:124\n\tstorj.io/drpc/drpcserver.(*Server).ServeOne:66\n\tstorj.io/drpc/drpcserver.(*Server).Serve.func2:114\n\tstorj.io/drpc/drpcctx.(*Tracker).track:35", "Size": 1304832, "Remote Address": "159.69.110.216:46548"}
2023-04-17T15:24:02.571Z        INFO    piecestore      download started        {"Process": "storagenode", "Piece ID": "TWG5UFQ2JYEHUVFB3RURDGSRJVVNQNPEYCTBIFHAVDNYAA4Q5T7A", "Satellite ID": "12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs", "Action": "GET", "Offset": 1310976, "Size": 1008128, "Remote Address": "162.55.58.180:54886"}
2023-04-17T15:24:02.772Z        INFO    piecestore      download canceled       {"Process": "storagenode", "Piece ID": "EPJ5L2QIB6WGK2M3VSKV6L7TJEVBTBSTWKS4O37XWF732MB5IG6A", "Satellite ID": "12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs", "Action": "GET", "Offset": 226304, "Size": 353536, "Remote Address": "149.6.140.106:33716"}
2023-04-17T15:24:02.903Z        INFO    piecestore      upload started  {"Process": "storagenode", "Piece ID": "ASLJS4NAURH6C753Z66VQ4Y5X24ALKISTZJZ2MAMVJHHUDBX33CQ", "Satellite ID": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S", "Action": "PUT", "Available Space": 3413152943021, "Remote Address": "5.161.96.135:47292"}
2023-04-17T15:24:02.964Z        INFO    piecestore      download started        {"Process": "storagenode", "Piece ID": "HYY7WVELMF36TWJ7NCROYPUZ52HFYSILARLZ3KRPFFGHYWD6FJBQ", "Satellite ID": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S", "Action": "GET", "Offset": 500480, "Size": 2304, "Remote Address": "38.88.241.42:48318"}
2023-04-17T15:24:03.187Z        INFO    piecestore      uploaded        {"Process": "storagenode", "Piece ID": "ASLJS4NAURH6C753Z66VQ4Y5X24ALKISTZJZ2MAMVJHHUDBX33CQ", "Satellite ID": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S", "Action": "PUT", "Size": 48640, "Remote Address": "5.161.96.135:47292"}
2023-04-17T15:24:03.211Z        INFO    piecestore      download started        {"Process": "storagenode", "Piece ID": "UBJ6TQ2U2JFC45XMI5H2MYVBTUH6HTWE5F6CNPXBEHNDVV5N5UQQ", "Satellite ID": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S", "Action": "GET", "Offset": 0, "Size": 8192, "Remote Address": "5.161.111.220:55280"}
2023-04-17T15:24:03.285Z        INFO    piecestore      download started        {"Process": "storagenode", "Piece ID": "F5XNRTRIRAGWH4U2LSTD5DAYTU2K22IAJPFF47D24S46VAVO6NGA", "Satellite ID": "12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs", "Action": "GET", "Offset": 1119744, "Size": 2304, "Remote Address": "188.239.191.33:57560"}
2023-04-17T15:24:03.302Z        INFO    piecestore      downloaded      {"Process": "storagenode", "Piece ID": "HYY7WVELMF36TWJ7NCROYPUZ52HFYSILARLZ3KRPFFGHYWD6FJBQ", "Satellite ID": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S", "Action": "GET", "Offset": 500480, "Size": 2304, "Remote Address": "38.88.241.42:48318"}
2023-04-17T15:24:03.305Z        INFO    piecestore      download started        {"Process": "storagenode", "Piece ID": "LLMESS5CCRDTCGUTGOLFB7XLM3TME24SYZORL4TU4NI3U64IBNGQ", "Satellite ID": "12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs", "Action": "GET", "Offset": 1307904, "Size": 2560, "Remote Address": "128.140.5.251:58502"}
2023-04-17T15:24:03.376Z        INFO    piecestore      download started        {"Process": "storagenode", "Piece ID": "HYY7WVELMF36TWJ7NCROYPUZ52HFYSILARLZ3KRPFFGHYWD6FJBQ", "Satellite ID": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S", "Action": "GET", "Offset": 502528, "Size": 2560, "Remote Address": "38.88.241.42:48318"}
2023-04-17T15:24:03.512Z        INFO    piecestore      download canceled       {"Process": "storagenode", "Piece ID": "UBJ6TQ2U2JFC45XMI5H2MYVBTUH6HTWE5F6CNPXBEHNDVV5N5UQQ", "Satellite ID": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S", "Action": "GET", "Offset": 0, "Size": 0, "Remote Address": "5.161.111.220:55280"}
2023-04-17T15:24:03.577Z        INFO    piecestore      downloaded      {"Process": "storagenode", "Piece ID": "LLMESS5CCRDTCGUTGOLFB7XLM3TME24SYZORL4TU4NI3U64IBNGQ", "Satellite ID": "12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs", "Action": "GET", "Offset": 1307904, "Size": 2560, "Remote Address": "128.140.5.251:58502"}
2023-04-17T15:24:03.660Z        INFO    piecestore      downloaded      {"Process": "storagenode", "Piece ID": "HYY7WVELMF36TWJ7NCROYPUZ52HFYSILARLZ3KRPFFGHYWD6FJBQ", "Satellite ID": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S", "Action": "GET", "Offset": 502528, "Size": 2560, "Remote Address": "38.88.241.42:48318"}
2023-04-17T15:24:03.707Z        INFO    piecestore      download started        {"Process": "storagenode", "Piece ID": "LLMESS5CCRDTCGUTGOLFB7XLM3TME24SYZORL4TU4NI3U64IBNGQ", "Satellite ID": "12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs", "Action": "GET", "Offset": 1310208, "Size": 4864, "Remote Address": "128.140.5.251:58502"}
2023-04-17T15:24:03.735Z        INFO    piecestore      download canceled       {"Process": "storagenode", "Piece ID": "TWG5UFQ2JYEHUVFB3RURDGSRJVVNQNPEYCTBIFHAVDNYAA4Q5T7A", "Satellite ID": "12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs", "Action": "GET", "Offset": 1310976, "Size": 655360, "Remote Address": "162.55.58.180:54886"}
2023-04-17T15:24:03.902Z        INFO    piecestore      upload started  {"Process": "storagenode", "Piece ID": "ZPGPBVLFXLVWMN47VZ4HSPS3U45N35CGM5HGID5XIULLH5QDZ33A", "Satellite ID": "12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs", "Action": "PUT", "Available Space": 3413152893869, "Remote Address": "162.55.184.55:53208"}
2023-04-17T15:24:03.914Z        INFO    piecestore      downloaded      {"Process": "storagenode", "Piece ID": "LLMESS5CCRDTCGUTGOLFB7XLM3TME24SYZORL4TU4NI3U64IBNGQ", "Satellite ID": "12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs", "Action": "GET", "Offset": 1310208, "Size": 4864, "Remote Address": "128.140.5.251:58502"}
2023-04-17T15:24:04.112Z        INFO    piecestore      uploaded        {"Process": "storagenode", "Piece ID": "ZPGPBVLFXLVWMN47VZ4HSPS3U45N35CGM5HGID5XIULLH5QDZ33A", "Satellite ID": "12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs", "Action": "PUT", "Size": 4864, "Remote Address": "162.55.184.55:53208"}
2023-04-17T15:24:04.431Z        INFO    piecestore      download started        {"Process": "storagenode", "Piece ID": "LRRXEQMKAXWCZMXIFHYQ25Q2PDQJHVQQBFNFYTRKDMGI7CVEHGNA", "Satellite ID": "12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs", "Action": "GET", "Offset": 402944, "Size": 2304, "Remote Address": "38.104.84.242:33252"}

As you see there are some ERRORS, is it normal or shall I track the node logs for a while? If I keep receiving ERRORS in the log output shall I execute Graceful exit and then with cleaning the disk shall I create a new node?

I saw “bandwidth usage error” in the logs 2 times yesterday. There is an expression like “database is locked”, does it mean there is some write-read issue because of the disk?

2023-04-17T10:07:52.045Z        ERROR   piecestore      failed to add bandwidth usage   {"Process": "storagenode", "error": "bandwidthdb: database is locked", "errorVerbose": "bandwidthdb: database is locked\n\tstorj.io/storj/storagenode/storagenodedb.(*bandwidthDB).Add:60\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).beginSaveOrder.func1:852\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).Upload:530\n\tstorj.io/common/pb.DRPCPiecestoreDescription.Method.func1:243\n\tstorj.io/drpc/drpcmux.(*Mux).HandleRPC:33\n\tstorj.io/common/rpc/rpctracing.(*Handler).HandleRPC:61\n\tstorj.io/common/experiment.(*Handler).HandleRPC:42\n\tstorj.io/drpc/drpcserver.(*Server).handleRPC:124\n\tstorj.io/drpc/drpcserver.(*Server).ServeOne:66\n\tstorj.io/drpc/drpcserver.(*Server).Serve.func2:114\n\tstorj.io/drpc/drpcctx.(*Tracker).track:35"}
2023-04-17T10:07:45.290Z        ERROR   piecestore      failed to add bandwidth usage   {"Process": "storagenode", "error": "bandwidthdb: database is locked", "errorVerbose": "bandwidthdb: database is locked\n\tstorj.io/storj/storagenode/storagenodedb.(*bandwidthDB).Add:60\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).beginSaveOrder.func1:852\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).Upload:530\n\tstorj.io/common/pb.DRPCPiecestoreDescription.Method.func1:243\n\tstorj.io/drpc/drpcmux.(*Mux).HandleRPC:33\n\tstorj.io/common/rpc/rpctracing.(*Handler).HandleRPC:61\n\tstorj.io/common/experiment.(*Handler).HandleRPC:42\n\tstorj.io/drpc/drpcserver.(*Server).handleRPC:124\n\tstorj.io/drpc/drpcserver.(*Server).ServeOne:66\n\tstorj.io/drpc/drpcserver.(*Server).Serve.func2:114\n\tstorj.io/drpc/drpcctx.(*Tracker).track:35"}

Thank you for your help :slight_smile:

5

these ones

are usual when the customer cancel the upload or download.

But errors, related to databases points to the slow disk/filesystem. It also happening for the network filesystems like NFS or CIFS/SMB etc., or using NTFS under Linux.

If S.M.A.R.T. doesn’t show problems with this disk, you may follow the general recommendation for such case: move databases to the SSD, if you have it: How to move DB’s to SSD on Docker

1 Like