ERROR Error updating service

clearing · July 25, 2024, 3:17pm

i keep getting this error during bootup. how do i fix this?

2024-07-25T15:14:38Z	ERROR	failure during run	{"Process": "storagenode", "error": "Error checking version for storagenode database: validate db version mismatch: expected 26, but current version is 60\n\tstorj.io/storj/private/migrate.(*Migration).ValidateVersions:141\n\tstorj.io/storj/storagenode/storagenodedb.(*DB).CheckVersion:671\n\tmain.cmdRun:103\n\tmain.newRunCmd.func1:33\n\tstorj.io/common/process.cleanup.func1.4:393\n\tstorj.io/common/process.cleanup.func1:411\n\tgithub.com/spf13/cobra.(*Command).execute:983\n\tgithub.com/spf13/cobra.(*Command).ExecuteC:1115\n\tgithub.com/spf13/cobra.(*Command).Execute:1039\n\tstorj.io/common/process.ExecWithCustomOptions:112\n\tmain.main:34\n\truntime.main:267", "errorVerbose": "Error checking version for storagenode database: validate db version mismatch: expected 26, but current version is 60\n\tstorj.io/storj/private/migrate.(*Migration).ValidateVersions:141\n\tstorj.io/storj/storagenode/storagenodedb.(*DB).CheckVersion:671\n\tmain.cmdRun:103\n\tmain.newRunCmd.func1:33\n\tstorj.io/common/process.cleanup.func1.4:393\n\tstorj.io/common/process.cleanup.func1:411\n\tgithub.com/spf13/cobra.(*Command).execute:983\n\tgithub.com/spf13/cobra.(*Command).ExecuteC:1115\n\tgithub.com/spf13/cobra.(*Command).Execute:1039\n\tstorj.io/common/process.ExecWithCustomOptions:112\n\tmain.main:34\n\truntime.main:267\n\tmain.cmdRun:105\n\tmain.newRunCmd.func1:33\n\tstorj.io/common/process.cleanup.func1.4:393\n\tstorj.io/common/process.cleanup.func1:411\n\tgithub.com/spf13/cobra.(*Command).execute:983\n\tgithub.com/spf13/cobra.(*Command).ExecuteC:1115\n\tgithub.com/spf13/cobra.(*Command).Execute:1039\n\tstorj.io/common/process.ExecWithCustomOptions:112\n\tmain.main:34\n\truntime.main:267"}
2024-07-25T15:14:38Z	FATAL	Unrecoverable error	{"Process": "storagenode", "error": "Error checking version for storagenode database: validate db version mismatch: expected 26, but current version is 60\n\tstorj.io/storj/private/migrate.(*Migration).ValidateVersions:141\n\tstorj.io/storj/storagenode/storagenodedb.(*DB).CheckVersion:671\n\tmain.cmdRun:103\n\tmain.newRunCmd.func1:33\n\tstorj.io/common/process.cleanup.func1.4:393\n\tstorj.io/common/process.cleanup.func1:411\n\tgithub.com/spf13/cobra.(*Command).execute:983\n\tgithub.com/spf13/cobra.(*Command).ExecuteC:1115\n\tgithub.com/spf13/cobra.(*Command).Execute:1039\n\tstorj.io/common/process.ExecWithCustomOptions:112\n\tmain.main:34\n\truntime.main:267", "errorVerbose": "Error checking version for storagenode database: validate db version mismatch: expected 26, but current version is 60\n\tstorj.io/storj/private/migrate.(*Migration).ValidateVersions:141\n\tstorj.io/storj/storagenode/storagenodedb.(*DB).CheckVersion:671\n\tmain.cmdRun:103\n\tmain.newRunCmd.func1:33\n\tstorj.io/common/process.cleanup.func1.4:393\n\tstorj.io/common/process.cleanup.func1:411\n\tgithub.com/spf13/cobra.(*Command).execute:983\n\tgithub.com/spf13/cobra.(*Command).ExecuteC:1115\n\tgithub.com/spf13/cobra.(*Command).Execute:1039\n\tstorj.io/common/process.ExecWithCustomOptions:112\n\tmain.main:34\n\truntime.main:267\n\tmain.cmdRun:105\n\tmain.newRunCmd.func1:33\n\tstorj.io/common/process.cleanup.func1.4:393\n\tstorj.io/common/process.cleanup.func1:411\n\tgithub.com/spf13/cobra.(*Command).execute:983\n\tgithub.com/spf13/cobra.(*Command).ExecuteC:1115\n\tgithub.com/spf13/cobra.(*Command).Execute:1039\n\tstorj.io/common/process.ExecWithCustomOptions:112\n\tmain.main:34\n\truntime.main:267"}

Ambifacient · July 25, 2024, 3:31pm

Looks like your node software version was rolled back. Might need to manually upgrade to latest. v1.108 had database migrations.

clearing · July 25, 2024, 3:34pm

im also seing this in the log
2024-07-25T15:31:56Z WARN retain encountered error(s) while loading cache {“Process”: “storagenode”, “cachePath”: “config/retain”, “error”: “invalid filename: pmw6tvzmf2jv6giyybmmvl4o2ahqlaldsaeha4yx74n5aaaaaaaa-1721671199999668000.pb; strconv.ParseInt: parsing "1721671199999668000.pb": invalid syntax; invalid filename: ukfu6bhbboxilvt7jrwlqk7y2tapb5d2r2tsmj2sjxvw5qaaaaaa-1721584799999920000.pb; strconv.ParseInt: parsing "1721584799999920000.pb": invalid syntax; invalid filename: v4weeab67sbgvnbwd5z7tweqsqqun7qox2agpbxy44mqqaaaaaaa-1721671199882581000.pb; strconv.ParseInt: parsing "1721671199882581000.pb": invalid syntax”, “errorVerbose”: “group:\n— invalid filename: pmw6tvzmf2jv6giyybmmvl4o2ahqlaldsaeha4yx74n5aaaaaaaa-1721671199999668000.pb; strconv.ParseInt: parsing "1721671199999668000.pb": invalid syntax\n\tstorj.io/storj/storagenode/retain.NewRequestStore:73\n\tstorj.io/storj/storagenode/retain.NewService:136\n\tstorj.io/storj/storagenode.New:574\n\tmain.cmdRun:82\n\tmain.newRunCmd.func1:33\n\tstorj.io/common/process.cleanup.func1.4:393\n\tstorj.io/common/process.cleanup.func1:411\n\tgithub.com/spf13/cobra.(*Command).execute:983\n\tgithub.com/spf13/cobra.(*Command).ExecuteC:1115\n\tgithub.com/spf13/cobra.(*Command).Execute:1039\n\tstorj.io/common/process.ExecWithCustomOptions:112\n\tmain.main:34\n\truntime.main:267\n— invalid filename: ukfu6bhbboxilvt7jrwlqk7y2tapb5d2r2tsmj2sjxvw5qaaaaaa-1721584799999920000.pb; strconv.ParseInt: parsing "1721584799999920000.pb": invalid syntax\n\tstorj.io/storj/storagenode/retain.NewRequestStore:73\n\tstorj.io/storj/storagenode/retain.NewService:136\n\tstorj.io/storj/storagenode.New:574\n\tmain.cmdRun:82\n\tmain.newRunCmd.func1:33\n\tstorj.io/common/process.cleanup.func1.4:393\n\tstorj.io/common/process.cleanup.func1:411\n\tgithub.com/spf13/cobra.(*Command).execute:983\n\tgithub.com/spf13/cobra.(*Command).ExecuteC:1115\n\tgithub.com/spf13/cobra.(*Command).Execute:1039\n\tstorj.io/common/process.ExecWithCustomOptions:112\n\tmain.main:34\n\truntime.main:267\n— invalid filename: v4weeab67sbgvnbwd5z7tweqsqqun7qox2agpbxy44mqqaaaaaaa-1721671199882581000.pb; strconv.ParseInt: parsing "1721671199882581000.pb": invalid syntax\n\tstorj.io/storj/storagenode/retain.NewRequestStore:73\n\tstorj.io/storj/storagenode/retain.NewService:136\n\tstorj.io/storj/storagenode.New:574\n\tmain.cmdRun:82\n\tmain.newRunCmd.func1:33\n\tstorj.io/common/process.cleanup.func1.4:393\n\tstorj.io/common/process.cleanup.func1:411\n\tgithub.com/spf13/cobra.(*Command).execute:983\n\tgithub.com/spf13/cobra.(*Command).ExecuteC:1115\n\tgithub.com/spf13/cobra.(*Command).Execute:1039\n\tstorj.io/common/process.ExecWithCustomOptions:112\n\tmain.main:34\n\truntime.main:267”}

clearing · July 25, 2024, 3:42pm

how to manually update? im running sn in docker

nerdatwork · July 25, 2024, 4:18pm

Did you rename the file? You should remove the .pb from the file name.

What is the current version of your node ? It seems you may have encountered database issues during migration.

clearing · July 25, 2024, 4:41pm

no, i didnt rename anything. but i tried earlier moving the database (*.db) to a backup directory, but it didnt fix the issue, so i moved it back.
i have this files under retain directory.

should i remove the .pb?

version of the sn:

Ambifacient · July 25, 2024, 5:12pm

You can run something like this on the host. Change the variables to match.

#!/bin/bash
VERSION=v1.104.1
CONTAINER=storagenode

ARCH=$(docker exec $CONTAINER printenv GOARCH)

cat <<EOF | docker exec -i $CONTAINER bash
wget https://github.com/storj/storj/releases/download/$VERSION/storagenode_linux_$ARCH.zip
unzip -o storagenode_linux_$ARCH.zip && rm storagenode_linux_$ARCH.zip
chmod +x storagenode
EOF

docker container restart $CONTAINER

Alexey · July 26, 2024, 4:44am

This is a new format for these files used in 1.108.x, and they are incompatible with a previous version. This node cannot be downgraded to any previous version.

they shouldn’t touch anything in the storage location. They need to upgrade back to 1.108.x

no, you shouldn’t. Please do not touch anything in the data location.

They need to replace to

VERSION=v1.108.3

However, this node shouldn’t downgrade, if it was upgraded. So need more details.
@clearing What you did to have this situation?

Could you please provide logs since the start of the container? Especially where the updater should update the node.
Sure, it would download the 1.105.4 version first, but then it should update it to the 1.108.3 version.

clearing · July 26, 2024, 3:48pm

there was a power interruption yesterday, and after that, the nodes keeps restarting. i didnt done anything for version related. but i tried removing all *.db files but didnt work so i remove the newly create dbs and i put back the old *.db, heres the log

docker logs 1sn -f
downloading storagenode-updater
--2024-07-26 15:45:27--  https://version.storj.io/processes/storagenode-updater/minimum/url?os=linux&arch=arm64
Resolving version.storj.io (version.storj.io)... 34.173.164.90
Connecting to version.storj.io (version.storj.io)|34.173.164.90|:443... connected.
HTTP request sent, awaiting response... 200 OK
Length: 93 [text/plain]
Saving to: 'STDOUT'

     0K                                                       100% 33.7M=0s

2024-07-26 15:45:29 (33.7 MB/s) - written to stdout [93/93]

--2024-07-26 15:45:29--  https://github.com/storj/storj/releases/download/v1.105.4/storagenode-updater_linux_arm64.zip
Resolving github.com (github.com)... 20.205.243.166
Connecting to github.com (github.com)|20.205.243.166|:443... connected.
HTTP request sent, awaiting response... 302 Found
Location: https://objects.githubusercontent.com/github-production-release-asset-2e65be/128089774/6c96ddc8-fe5a-46cf-a6fd-044d252626d0?X-Amz-Algorithm=AWS4-HMAC-SHA256&X-Amz-Credential=releaseassetproduction%2F20240726%2Fus-east-1%2Fs3%2Faws4_request&X-Amz-Date=20240726T154529Z&X-Amz-Expires=300&X-Amz-Signature=23217ac4418ec16a55c822e593bbd321a1b00fcf7cd5625379668bc13ddad64e&X-Amz-SignedHeaders=host&actor_id=0&key_id=0&repo_id=128089774&response-content-disposition=attachment%3B%20filename%3Dstoragenode-updater_linux_arm64.zip&response-content-type=application%2Foctet-stream [following]
--2024-07-26 15:45:29--  https://objects.githubusercontent.com/github-production-release-asset-2e65be/128089774/6c96ddc8-fe5a-46cf-a6fd-044d252626d0?X-Amz-Algorithm=AWS4-HMAC-SHA256&X-Amz-Credential=releaseassetproduction%2F20240726%2Fus-east-1%2Fs3%2Faws4_request&X-Amz-Date=20240726T154529Z&X-Amz-Expires=300&X-Amz-Signature=23217ac4418ec16a55c822e593bbd321a1b00fcf7cd5625379668bc13ddad64e&X-Amz-SignedHeaders=host&actor_id=0&key_id=0&repo_id=128089774&response-content-disposition=attachment%3B%20filename%3Dstoragenode-updater_linux_arm64.zip&response-content-type=application%2Foctet-stream
Resolving objects.githubusercontent.com (objects.githubusercontent.com)... 185.199.111.133, 185.199.109.133, 185.199.110.133, ...
Connecting to objects.githubusercontent.com (objects.githubusercontent.com)|185.199.111.133|:443... connected.
HTTP request sent, awaiting response... 200 OK
Length: 9618394 (9.2M) [application/octet-stream]
Saving to: '/tmp/storagenode-updater.zip'
 9300K .......... .......... .......... .......... .......... 99% 8.44M 0s
  9350K .......... .......... .......... .......... ..        100% 20.4M=1.7s

2024-07-26 15:45:32 (5.52 MB/s) - '/tmp/storagenode-updater.zip' saved [9618394/9618394]

downloading storagenode
--2024-07-26 15:45:33--  https://version.storj.io/processes/storagenode/minimum/url?os=linux&arch=arm64
Resolving version.storj.io (version.storj.io)... 34.173.164.90
Connecting to version.storj.io (version.storj.io)|34.173.164.90|:443... connected.
HTTP request sent, awaiting response... 200 OK
Length: 85 [text/plain]
Saving to: 'STDOUT'

     0K                                                       100% 70.6M=0s

2024-07-26 15:45:34 (70.6 MB/s) - written to stdout [85/85]

--2024-07-26 15:45:34--  https://github.com/storj/storj/releases/download/v1.105.4/storagenode_linux_arm64.zip
Resolving github.com (github.com)... 20.205.243.166
Connecting to github.com (github.com)|20.205.243.166|:443... connected.
HTTP request sent, awaiting response... 302 Found
Location: https://objects.githubusercontent.com/github-production-release-asset-2e65be/128089774/c2482a80-bbc8-4950-b85d-4cb71022a0cb?X-Amz-Algorithm=AWS4-HMAC-SHA256&X-Amz-Credential=releaseassetproduction%2F20240726%2Fus-east-1%2Fs3%2Faws4_request&X-Amz-Date=20240726T154534Z&X-Amz-Expires=300&X-Amz-Signature=f56818de6853f868467762e000e83228bf3268f4683cdf950313a1dca3d9d23e&X-Amz-SignedHeaders=host&actor_id=0&key_id=0&repo_id=128089774&response-content-disposition=attachment%3B%20filename%3Dstoragenode_linux_arm64.zip&response-content-type=application%2Foctet-stream [following]
--2024-07-26 15:45:34--  https://objects.githubusercontent.com/github-production-release-asset-2e65be/128089774/c2482a80-bbc8-4950-b85d-4cb71022a0cb?X-Amz-Algorithm=AWS4-HMAC-SHA256&X-Amz-Credential=releaseassetproduction%2F20240726%2Fus-east-1%2Fs3%2Faws4_request&X-Amz-Date=20240726T154534Z&X-Amz-Expires=300&X-Amz-Signature=f56818de6853f868467762e000e83228bf3268f4683cdf950313a1dca3d9d23e&X-Amz-SignedHeaders=host&actor_id=0&key_id=0&repo_id=128089774&response-content-disposition=attachment%3B%20filename%3Dstoragenode_linux_arm64.zip&response-content-type=application%2Foctet-stream
Resolving objects.githubusercontent.com (objects.githubusercontent.com)... 185.199.111.133, 185.199.109.133, 185.199.110.133, ...
Connecting to objects.githubusercontent.com (objects.githubusercontent.com)|185.199.111.133|:443... connected.
HTTP request sent, awaiting response... 200 OK
Length: 17586623 (17M) [application/octet-stream]
Saving to: '/tmp/storagenode.zip'

 17000K .......... .......... .......... .......... .......... 99% 11.6M 0s
 17050K .......... .......... .......... .......... .......... 99% 11.6M 0s
 17100K .......... .......... .......... .......... .......... 99% 9.05M 0s
 17150K .......... .......... ....                            100% 25.7M=1.7s

2024-07-26 15:45:37 (9.77 MB/s) - '/tmp/storagenode.zip' saved [17586623/17586623]

2024-07-26 15:45:49,287 INFO RPC interface 'supervisor' initialized
2024-07-26 15:45:49,288 INFO supervisord started with pid 1
2024-07-26 15:45:50,293 INFO spawned: 'processes-exit-eventlistener' with pid 42
2024-07-26 15:45:50,299 INFO spawned: 'storagenode' with pid 43
2024-07-26 15:45:50,304 INFO spawned: 'storagenode-updater' with pid 44
2024-07-26T15:45:50Z	INFO	Configuration loaded	{"Process": "storagenode-updater", "Location": "/app/config/config.yaml"}
2024-07-26T15:45:50Z	INFO	Invalid configuration file key	{"Process": "storagenode-updater", "Key": "storage.path"}
2024-07-26T15:45:50Z	INFO	Invalid configuration file key	{"Process": "storagenode-updater", "Key": "operator.email"}
2024-07-26T15:45:50Z	INFO	Invalid configuration file key	{"Process": "storagenode-updater", "Key": "healthcheck.enabled"}
2024-07-26T15:45:50Z	INFO	Invalid configuration file key	{"Process": "storagenode-updater", "Key": "server.address"}
2024-07-26T15:45:50Z	INFO	Invalid configuration file key	{"Process": "storagenode-updater", "Key": "storage2.database-dir"}
2024-07-26T15:45:50Z	INFO	Invalid configuration file key	{"Process": "storagenode-updater", "Key": "server.private-address"}
2024-07-26T15:45:50Z	INFO	Invalid configuration file key	{"Process": "storagenode-updater", "Key": "contact.external-address"}
2024-07-26T15:45:50Z	INFO	Invalid configuration file key	{"Process": "storagenode-updater", "Key": "healthcheck.details"}
2024-07-26T15:45:50Z	INFO	Invalid configuration file key	{"Process": "storagenode-updater", "Key": "storage.allocated-disk-space"}
2024-07-26T15:45:50Z	INFO	Invalid configuration file key	{"Process": "storagenode-updater", "Key": "operator.wallet-features.0"}
2024-07-26T15:45:50Z	INFO	Invalid configuration file key	{"Process": "storagenode-updater", "Key": "operator.wallet"}
2024-07-26T15:45:50Z	INFO	Invalid configuration file key	{"Process": "storagenode-updater", "Key": "console.address"}
2024-07-26T15:45:50Z	INFO	Anonymized tracing enabled	{"Process": "storagenode-updater"}
2024-07-26T15:45:50Z	INFO	Running on version	{"Process": "storagenode-updater", "Service": "storagenode-updater", "Version": "v1.105.4"}
2024-07-26T15:45:50Z	INFO	Downloading versions.	{"Process": "storagenode-updater", "Server Address": "https://version.storj.io"}
2024-07-26T15:45:51Z	INFO	Current binary version	{"Process": "storagenode-updater", "Service": "storagenode", "Version": "v1.105.4"}
2024-07-26T15:45:51Z	INFO	Download started.	{"Process": "storagenode-updater", "From": "https://github.com/storj/storj/releases/download/v1.108.3/storagenode_linux_arm64.zip", "To": "/tmp/storagenode_linux_arm64.1835671993.zip"}
2024-07-26 15:45:51,416 INFO success: processes-exit-eventlistener entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2024-07-26 15:45:51,417 INFO success: storagenode entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2024-07-26 15:45:51,417 INFO success: storagenode-updater entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2024-07-26 15:45:51,418 INFO exited: storagenode (exit status 1; not expected)
2024-07-26 15:45:52,427 INFO spawned: 'storagenode' with pid 67
2024-07-26 15:45:52,430 WARN received SIGQUIT indicating exit request
2024-07-26 15:45:52,432 INFO waiting for storagenode, processes-exit-eventlistener, storagenode-updater to die
2024-07-26T15:45:52Z	INFO	Got a signal from the OS: "terminated"	{"Process": "storagenode-updater"}
2024-07-26T15:45:52Z	ERROR	Error updating service.	{"Process": "storagenode-updater", "Service": "storagenode", "error": "Get \"https://objects.githubusercontent.com/github-production-release-asset-2e65be/128089774/0d18588a-6ef3-4a04-81d7-6c733dba25a5?X-Amz-Algorithm=AWS4-HMAC-SHA256&X-Amz-Credential=releaseassetproduction%2F20240726%2Fus-east-1%2Fs3%2Faws4_request&X-Amz-Date=20240726T154551Z&X-Amz-Expires=300&X-Amz-Signature=a1b454c3d5ebb6a2efa24358c9ea8569f37af56cb82d4638d3cbf0e85c5d2c38&X-Amz-SignedHeaders=host&actor_id=0&key_id=0&repo_id=128089774&response-content-disposition=attachment%3B%20filename%3Dstoragenode_linux_arm64.zip&response-content-type=application%2Foctet-stream\": context canceled", "errorVerbose": "Get \"https://objects.githubusercontent.com/github-production-release-asset-2e65be/128089774/0d18588a-6ef3-4a04-81d7-6c733dba25a5?X-Amz-Algorithm=AWS4-HMAC-SHA256&X-Amz-Credential=releaseassetproduction%2F20240726%2Fus-east-1%2Fs3%2Faws4_request&X-Amz-Date=20240726T154551Z&X-Amz-Expires=300&X-Amz-Signature=a1b454c3d5ebb6a2efa24358c9ea8569f37af56cb82d4638d3cbf0e85c5d2c38&X-Amz-SignedHeaders=host&actor_id=0&key_id=0&repo_id=128089774&response-content-disposition=attachment%3B%20filename%3Dstoragenode_linux_arm64.zip&response-content-type=application%2Foctet-stream\": context canceled\n\tmain.downloadBinary:58\n\tmain.update:39\n\tmain.loopFunc:26\n\tstorj.io/common/sync2.(*Cycle).Run:99\n\tmain.cmdRun:136\n\tstorj.io/common/process.cleanup.func1.4:393\n\tstorj.io/common/process.cleanup.func1:411\n\tgithub.com/spf13/cobra.(*Command).execute:983\n\tgithub.com/spf13/cobra.(*Command).ExecuteC:1115\n\tgithub.com/spf13/cobra.(*Command).Execute:1039\n\tstorj.io/common/process.ExecWithCustomOptions:112\n\tstorj.io/common/process.ExecWithCustomConfigAndLogger:77\n\tmain.main:22\n\truntime.main:267"}
2024-07-26T15:45:52Z	INFO	Current binary version	{"Process": "storagenode-updater", "Service": "storagenode-updater", "Version": "v1.105.4"}
2024-07-26T15:45:52Z	INFO	Download started.	{"Process": "storagenode-updater", "From": "https://github.com/storj/storj/releases/download/v1.108.3/storagenode-updater_linux_arm64.zip", "To": "/tmp/storagenode-updater_linux_arm64.174341145.zip"}
2024-07-26T15:45:52Z	ERROR	Error updating service.	{"Process": "storagenode-updater", "Service": "storagenode-updater", "error": "Get \"https://github.com/storj/storj/releases/download/v1.108.3/storagenode-updater_linux_arm64.zip\": context canceled", "errorVerbose": "Get \"https://github.com/storj/storj/releases/download/v1.108.3/storagenode-updater_linux_arm64.zip\": context canceled\n\tmain.downloadBinary:58\n\tmain.update:39\n\tmain.loopFunc:31\n\tstorj.io/common/sync2.(*Cycle).Run:99\n\tmain.cmdRun:136\n\tstorj.io/common/process.cleanup.func1.4:393\n\tstorj.io/common/process.cleanup.func1:411\n\tgithub.com/spf13/cobra.(*Command).execute:983\n\tgithub.com/spf13/cobra.(*Command).ExecuteC:1115\n\tgithub.com/spf13/cobra.(*Command).Execute:1039\n\tstorj.io/common/process.ExecWithCustomOptions:112\n\tstorj.io/common/process.ExecWithCustomConfigAndLogger:77\n\tmain.main:22\n\truntime.main:267"}
2024-07-26 15:45:52,479 INFO stopped: storagenode-updater (exit status 0)
2024-07-26 15:45:52,486 INFO stopped: storagenode (terminated by SIGTERM)
2024-07-26 15:45:52,489 INFO stopped: processes-exit-eventlistener (terminated by SIGTERM)
2024-07-26 15:45:54,360 INFO RPC interface 'supervisor' initialized
2024-07-26 15:45:54,362 INFO supervisord started with pid 1
2024-07-26 15:45:55,366 INFO spawned: 'processes-exit-eventlistener' with pid 12
2024-07-26 15:45:55,372 INFO spawned: 'storagenode' with pid 13
2024-07-26 15:45:55,378 INFO spawned: 'storagenode-updater' with pid 14
2024-07-26T15:45:55Z	INFO	Configuration loaded	{"Process": "storagenode-updater", "Location": "/app/config/config.yaml"}
2024-07-26T15:45:55Z	INFO	Invalid configuration file key	{"Process": "storagenode-updater", "Key": "storage.allocated-disk-space"}
2024-07-26T15:45:55Z	INFO	Invalid configuration file key	{"Process": "storagenode-updater", "Key": "operator.wallet"}
2024-07-26T15:45:55Z	INFO	Invalid configuration file key	{"Process": "storagenode-updater", "Key": "server.address"}
2024-07-26T15:45:55Z	INFO	Invalid configuration file key	{"Process": "storagenode-updater", "Key": "console.address"}
2024-07-26T15:45:55Z	INFO	Invalid configuration file key	{"Process": "storagenode-updater", "Key": "healthcheck.enabled"}
2024-07-26T15:45:55Z	INFO	Invalid configuration file key	{"Process": "storagenode-updater", "Key": "storage2.database-dir"}
2024-07-26T15:45:55Z	INFO	Invalid configuration file key	{"Process": "storagenode-updater", "Key": "contact.external-address"}
2024-07-26T15:45:55Z	INFO	Invalid configuration file key	{"Process": "storagenode-updater", "Key": "server.private-address"}
2024-07-26T15:45:55Z	INFO	Invalid configuration file key	{"Process": "storagenode-updater", "Key": "healthcheck.details"}
2024-07-26T15:45:55Z	INFO	Invalid configuration file key	{"Process": "storagenode-updater", "Key": "operator.wallet-features.0"}
2024-07-26T15:45:55Z	INFO	Invalid configuration file key	{"Process": "storagenode-updater", "Key": "operator.email"}
2024-07-26T15:45:55Z	INFO	Invalid configuration file key	{"Process": "storagenode-updater", "Key": "storage.path"}
2024-07-26T15:45:55Z	INFO	Anonymized tracing enabled	{"Process": "storagenode-updater"}
2024-07-26T15:45:55Z	INFO	Running on version	{"Process": "storagenode-updater", "Service": "storagenode-updater", "Version": "v1.105.4"}
2024-07-26T15:45:55Z	INFO	Downloading versions.	{"Process": "storagenode-updater", "Server Address": "https://version.storj.io"}
2024-07-26T15:45:56Z	INFO	Current binary version	{"Process": "storagenode-updater", "Service": "storagenode", "Version": "v1.105.4"}
2024-07-26T15:45:56Z	INFO	Download started.	{"Process": "storagenode-updater", "From": "https://github.com/storj/storj/releases/download/v1.108.3/storagenode_linux_arm64.zip", "To": "/tmp/storagenode_linux_arm64.459485078.zip"}
2024-07-26 15:45:56,481 INFO success: processes-exit-eventlistener entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2024-07-26 15:45:56,481 INFO success: storagenode entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2024-07-26 15:45:56,481 INFO success: storagenode-updater entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2024-07-26 15:45:56,482 INFO exited: storagenode (exit status 1; not expected)
2024-07-26 15:45:57,487 INFO spawned: 'storagenode' with pid 39
2024-07-26 15:45:57,488 WARN received SIGQUIT indicating exit request
2024-07-26 15:45:57,489 INFO waiting for storagenode, processes-exit-eventlistener, storagenode-updater to die
2024-07-26T15:45:57Z	INFO	Got a signal from the OS: "terminated"	{"Process": "storagenode-updater"}
2024-07-26T15:45:57Z	ERROR	Error updating service.	{"Process": "storagenode-updater", "Service": "storagenode", "error": "context canceled", "errorVerbose": "context canceled\n\tmain.downloadBinary:58\n\tmain.update:39\n\tmain.loopFunc:26\n\tstorj.io/common/sync2.(*Cycle).Run:99\n\tmain.cmdRun:136\n\tstorj.io/common/process.cleanup.func1.4:393\n\tstorj.io/common/process.cleanup.func1:411\n\tgithub.com/spf13/cobra.(*Command).execute:983\n\tgithub.com/spf13/cobra.(*Command).ExecuteC:1115\n\tgithub.com/spf13/cobra.(*Command).Execute:1039\n\tstorj.io/common/process.ExecWithCustomOptions:112\n\tstorj.io/common/process.ExecWithCustomConfigAndLogger:77\n\tmain.main:22\n\truntime.main:267"}
2024-07-26T15:45:57Z	INFO	Current binary version	{"Process": "storagenode-updater", "Service": "storagenode-updater", "Version": "v1.105.4"}
2024-07-26T15:45:57Z	INFO	Download started.	{"Process": "storagenode-updater", "From": "https://github.com/storj/storj/releases/download/v1.108.3/storagenode-updater_linux_arm64.zip", "To": "/tmp/storagenode-updater_linux_arm64.4042740877.zip"}
2024-07-26T15:45:57Z	ERROR	Error updating service.	{"Process": "storagenode-updater", "Service": "storagenode-updater", "error": "Get \"https://github.com/storj/storj/releases/download/v1.108.3/storagenode-updater_linux_arm64.zip\": context canceled", "errorVerbose": "Get \"https://github.com/storj/storj/releases/download/v1.108.3/storagenode-updater_linux_arm64.zip\": context canceled\n\tmain.downloadBinary:58\n\tmain.update:39\n\tmain.loopFunc:31\n\tstorj.io/common/sync2.(*Cycle).Run:99\n\tmain.cmdRun:136\n\tstorj.io/common/process.cleanup.func1.4:393\n\tstorj.io/common/process.cleanup.func1:411\n\tgithub.com/spf13/cobra.(*Command).execute:983\n\tgithub.com/spf13/cobra.(*Command).ExecuteC:1115\n\tgithub.com/spf13/cobra.(*Command).Execute:1039\n\tstorj.io/common/process.ExecWithCustomOptions:112\n\tstorj.io/common/process.ExecWithCustomConfigAndLogger:77\n\tmain.main:22\n\truntime.main:267"}
2024-07-26 15:45:58,556 INFO success: storagenode entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2024-07-26 15:45:58,557 INFO stopped: storagenode-updater (exit status 0)
2024-07-26 15:45:58,625 INFO stopped: storagenode (exit status 1)
2024-07-26 15:45:58,626 INFO stopped: processes-exit-eventlistener (terminated by SIGTERM)
2024-07-26 15:46:03,211 INFO RPC interface 'supervisor' initialized
2024-07-26 15:46:03,212 INFO supervisord started with pid 1
2024-07-26 15:46:04,216 INFO spawned: 'processes-exit-eventlistener' with pid 12
2024-07-26 15:46:04,222 INFO spawned: 'storagenode' with pid 13
2024-07-26 15:46:04,228 INFO spawned: 'storagenode-updater' with pid 14
2024-07-26T15:46:04Z	INFO	Configuration loaded	{"Process": "storagenode-updater", "Location": "/app/config/config.yaml"}
2024-07-26T15:46:04Z	INFO	Invalid configuration file key	{"Process": "storagenode-updater", "Key": "operator.email"}
2024-07-26T15:46:04Z	INFO	Invalid configuration file key	{"Process": "storagenode-updater", "Key": "operator.wallet-features.0"}
2024-07-26T15:46:04Z	INFO	Invalid configuration file key	{"Process": "storagenode-updater", "Key": "storage.allocated-disk-space"}
2024-07-26T15:46:04Z	INFO	Invalid configuration file key	{"Process": "storagenode-updater", "Key": "healthcheck.details"}
2024-07-26T15:46:04Z	INFO	Invalid configuration file key	{"Process": "storagenode-updater", "Key": "storage.path"}
2024-07-26T15:46:04Z	INFO	Invalid configuration file key	{"Process": "storagenode-updater", "Key": "contact.external-address"}
2024-07-26T15:46:04Z	INFO	Invalid configuration file key	{"Process": "storagenode-updater", "Key": "healthcheck.enabled"}
2024-07-26T15:46:04Z	INFO	Invalid configuration file key	{"Process": "storagenode-updater", "Key": "console.address"}
2024-07-26T15:46:04Z	INFO	Invalid configuration file key	{"Process": "storagenode-updater", "Key": "operator.wallet"}
2024-07-26T15:46:04Z	INFO	Invalid configuration file key	{"Process": "storagenode-updater", "Key": "server.private-address"}
2024-07-26T15:46:04Z	INFO	Invalid configuration file key	{"Process": "storagenode-updater", "Key": "server.address"}
2024-07-26T15:46:04Z	INFO	Invalid configuration file key	{"Process": "storagenode-updater", "Key": "storage2.database-dir"}
2024-07-26T15:46:04Z	INFO	Anonymized tracing enabled	{"Process": "storagenode-updater"}
2024-07-26T15:46:04Z	INFO	Running on version	{"Process": "storagenode-updater", "Service": "storagenode-updater", "Version": "v1.105.4"}
2024-07-26T15:46:04Z	INFO	Downloading versions.	{"Process": "storagenode-updater", "Server Address": "https://version.storj.io"}
2024-07-26T15:46:04Z	INFO	Current binary version	{"Process": "storagenode-updater", "Service": "storagenode", "Version": "v1.105.4"}
2024-07-26T15:46:04Z	INFO	Download started.	{"Process": "storagenode-updater", "From": "https://github.com/storj/storj/releases/download/v1.108.3/storagenode_linux_arm64.zip", "To": "/tmp/storagenode_linux_arm64.1734750044.zip"}
2024-07-26 15:46:05,424 INFO success: processes-exit-eventlistener entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2024-07-26 15:46:05,424 INFO success: storagenode entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2024-07-26 15:46:05,424 INFO success: storagenode-updater entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2024-07-26 15:46:05,425 INFO exited: storagenode (exit status 1; not expected)
2024-07-26 15:46:06,431 INFO spawned: 'storagenode' with pid 39
2024-07-26 15:46:06,433 WARN received SIGQUIT indicating exit request
2024-07-26 15:46:06,434 INFO waiting for storagenode, processes-exit-eventlistener, storagenode-updater to die
2024-07-26T15:46:06Z	INFO	Got a signal from the OS: "terminated"	{"Process": "storagenode-updater"}
2024-07-26T15:46:06Z	ERROR	Error updating service.	{"Process": "storagenode-updater", "Service": "storagenode", "error": "context canceled", "errorVerbose": "context canceled\n\tmain.downloadBinary:58\n\tmain.update:39\n\tmain.loopFunc:26\n\tstorj.io/common/sync2.(*Cycle).Run:99\n\tmain.cmdRun:136\n\tstorj.io/common/process.cleanup.func1.4:393\n\tstorj.io/common/process.cleanup.func1:411\n\tgithub.com/spf13/cobra.(*Command).execute:983\n\tgithub.com/spf13/cobra.(*Command).ExecuteC:1115\n\tgithub.com/spf13/cobra.(*Command).Execute:1039\n\tstorj.io/common/process.ExecWithCustomOptions:112\n\tstorj.io/common/process.ExecWithCustomConfigAndLogger:77\n\tmain.main:22\n\truntime.main:267"}
2024-07-26T15:46:06Z	INFO	Current binary version	{"Process": "storagenode-updater", "Service": "storagenode-updater", "Version": "v1.105.4"}
2024-07-26T15:46:06Z	INFO	Download started.	{"Process": "storagenode-updater", "From": "https://github.com/storj/storj/releases/download/v1.108.3/storagenode-updater_linux_arm64.zip", "To": "/tmp/storagenode-updater_linux_arm64.973490243.zip"}
2024-07-26T15:46:06Z	ERROR	Error updating service.	{"Process": "storagenode-updater", "Service": "storagenode-updater", "error": "Get \"https://github.com/storj/storj/releases/download/v1.108.3/storagenode-updater_linux_arm64.zip\": context canceled", "errorVerbose": "Get \"https://github.com/storj/storj/releases/download/v1.108.3/storagenode-updater_linux_arm64.zip\": context canceled\n\tmain.downloadBinary:58\n\tmain.update:39\n\tmain.loopFunc:31\n\tstorj.io/common/sync2.(*Cycle).Run:99\n\tmain.cmdRun:136\n\tstorj.io/common/process.cleanup.func1.4:393\n\tstorj.io/common/process.cleanup.func1:411\n\tgithub.com/spf13/cobra.(*Command).execute:983\n\tgithub.com/spf13/cobra.(*Command).ExecuteC:1115\n\tgithub.com/spf13/cobra.(*Command).Execute:1039\n\tstorj.io/common/process.ExecWithCustomOptions:112\n\tstorj.io/common/process.ExecWithCustomConfigAndLogger:77\n\tmain.main:22\n\truntime.main:267"}
2024-07-26 15:46:06,504 INFO stopped: storagenode-updater (exit status 0)
2024-07-26 15:46:06,509 INFO stopped: storagenode (terminated by SIGTERM)
2024-07-26 15:46:06,511 INFO stopped: processes-exit-eventlistener (terminated by SIGTERM)

clearing · July 26, 2024, 3:54pm

the sn is running now. but im seeing alot of

2024-07-26T15:53:01Z WARN collector unable to delete piece {“Process”: “storagenode”, “Satellite ID”:

is this expected?

clearing · July 26, 2024, 4:00pm

this is weird. i haven’t changed anything today, yet both my SNs are now running again. was it related to the version? did i just got rolled back yesterday?

nerdatwork · July 26, 2024, 4:36pm

Alexey · July 30, 2024, 3:31am

github.com/storj/storj

Race condition in the update process in docker (when the new version is incompatible with the old one)

opened 03:25AM - 30 Jul 24 UTC

AlexeyALeonov

Bug

**Description** https://forum.storj.io/t/error-error-updating-service/27262/9?u=alexey We have an issue in the update process inside the container. Since the new version is rolling out, the node is updated to the rolled version, but it's not minimum yet (e.g. 1.108.3), this new version has a database migration, which is incompatible with the current minimum version (e.g. 1.105.4). If the container would be re-created, it will download an old version of storagenode-updater, and the old version of storagenode and start them with a supervisor, but the old version of storagenode will fail due to incompatibility of the database versions, not allowing storagenode-updater to update the node to the current new version, which was before. **Steps to reproduce the issue:** 1. The new version is rolling out, the node is updated to the rolled version, but it's not minimum yet (e.g. 1.108.3) 2. The new version has a database migration, which is incompatible with the current minimum version (e.g. 1.105.4) 3. If the container would be re-created, it will download a minimum (old) version of storagenode-updater, and a minimum (old) version of storagenode and start them with a supervisor 4. storagenode-updater would download a new version of itself and start it, the new version of storagenode-updater may try to download a new version of storagenode, but if there is a delay (slow download for example), it will not finish it because the old version of storagenode already failed (see below) 5. However, meanwhile the old storagenode version is failing due to incompatible version of the database 6. supervisor notices that the node is failed and exiting, killing also a new version of storagenode-updater and itself 7. docker will restart the failed container and the loop would repeat from p.3 **Describe the results you expected:** 1. container downloads storagenode-updater and start it, it may download storagenode too, but shouldn't start it 2. storagenode-updater updates itself and downloads a new allowed version of storagenode, then starts both with a supervisor **Describe the results you received:** 1. container downloads storagenode-updater, storagenode and start them both with a supervisor. 2. If the current minimum version of storagenode is incompatible with the migrated databases, the storagenode process will fail and this will kill the container **Possible Fix** storagenode should not be started before the new allowed version of storagenode is downloaded. The Community used this script to bypass the issue: ``` #!/bin/bash VERSION=v1.108.3 CONTAINER=storagenode ARCH=$(docker exec $CONTAINER printenv GOARCH) cat <<EOF | docker exec -i $CONTAINER bash wget https://github.com/storj/storj/releases/download/$VERSION/storagenode_linux_$ARCH.zip unzip -o storagenode_linux_$ARCH.zip && rm storagenode_linux_$ARCH.zip chmod +x storagenode EOF docker container restart $CONTAINER ``` **Additional information you deem important (e.g. issue happens only occasionally):** The issue may happen, if the download of a new versions is longer than the time, until the node would check the database migrations. Since the node would exit with error code 1, the supervisor would try to restart it. However, it could be not enough time for storagenode-updater to download a new version before the last crash, then the supervisor will kill a container and the loop would repeat. See https://forum.storj.io/t/error-error-updating-service/27262/9?u=alexey **Logs:** ``` 2024-07-25T15:14:38Z ERROR failure during run {"Process": "storagenode", "error": "Error checking version for storagenode database: validate db version mismatch: expected 26, but current version is 60\n\tstorj.io/storj/private/migrate.(*Migration).ValidateVersions:141\n\tstorj.io/storj/storagenode/storagenodedb.(*DB).CheckVersion:671\n\tmain.cmdRun:103\n\tmain.newRunCmd.func1:33\n\tstorj.io/common/process.cleanup.func1.4:393\n\tstorj.io/common/process.cleanup.func1:411\n\tgithub.com/spf13/cobra.(*Command).execute:983\n\tgithub.com/spf13/cobra.(*Command).ExecuteC:1115\n\tgithub.com/spf13/cobra.(*Command).Execute:1039\n\tstorj.io/common/process.ExecWithCustomOptions:112\n\tmain.main:34\n\truntime.main:267", "errorVerbose": "Error checking version for storagenode database: validate db version mismatch: expected 26, but current version is 60\n\tstorj.io/storj/private/migrate.(*Migration).ValidateVersions:141\n\tstorj.io/storj/storagenode/storagenodedb.(*DB).CheckVersion:671\n\tmain.cmdRun:103\n\tmain.newRunCmd.func1:33\n\tstorj.io/common/process.cleanup.func1.4:393\n\tstorj.io/common/process.cleanup.func1:411\n\tgithub.com/spf13/cobra.(*Command).execute:983\n\tgithub.com/spf13/cobra.(*Command).ExecuteC:1115\n\tgithub.com/spf13/cobra.(*Command).Execute:1039\n\tstorj.io/common/process.ExecWithCustomOptions:112\n\tmain.main:34\n\truntime.main:267\n\tmain.cmdRun:105\n\tmain.newRunCmd.func1:33\n\tstorj.io/common/process.cleanup.func1.4:393\n\tstorj.io/common/process.cleanup.func1:411\n\tgithub.com/spf13/cobra.(*Command).execute:983\n\tgithub.com/spf13/cobra.(*Command).ExecuteC:1115\n\tgithub.com/spf13/cobra.(*Command).Execute:1039\n\tstorj.io/common/process.ExecWithCustomOptions:112\n\tmain.main:34\n\truntime.main:267"} 2024-07-25T15:14:38Z FATAL Unrecoverable error {"Process": "storagenode", "error": "Error checking version for storagenode database: validate db version mismatch: expected 26, but current version is 60\n\tstorj.io/storj/private/migrate.(*Migration).ValidateVersions:141\n\tstorj.io/storj/storagenode/storagenodedb.(*DB).CheckVersion:671\n\tmain.cmdRun:103\n\tmain.newRunCmd.func1:33\n\tstorj.io/common/process.cleanup.func1.4:393\n\tstorj.io/common/process.cleanup.func1:411\n\tgithub.com/spf13/cobra.(*Command).execute:983\n\tgithub.com/spf13/cobra.(*Command).ExecuteC:1115\n\tgithub.com/spf13/cobra.(*Command).Execute:1039\n\tstorj.io/common/process.ExecWithCustomOptions:112\n\tmain.main:34\n\truntime.main:267", "errorVerbose": "Error checking version for storagenode database: validate db version mismatch: expected 26, but current version is 60\n\tstorj.io/storj/private/migrate.(*Migration).ValidateVersions:141\n\tstorj.io/storj/storagenode/storagenodedb.(*DB).CheckVersion:671\n\tmain.cmdRun:103\n\tmain.newRunCmd.func1:33\n\tstorj.io/common/process.cleanup.func1.4:393\n\tstorj.io/common/process.cleanup.func1:411\n\tgithub.com/spf13/cobra.(*Command).execute:983\n\tgithub.com/spf13/cobra.(*Command).ExecuteC:1115\n\tgithub.com/spf13/cobra.(*Command).Execute:1039\n\tstorj.io/common/process.ExecWithCustomOptions:112\n\tmain.main:34\n\truntime.main:267\n\tmain.cmdRun:105\n\tmain.newRunCmd.func1:33\n\tstorj.io/common/process.cleanup.func1.4:393\n\tstorj.io/common/process.cleanup.func1:411\n\tgithub.com/spf13/cobra.(*Command).execute:983\n\tgithub.com/spf13/cobra.(*Command).ExecuteC:1115\n\tgithub.com/spf13/cobra.(*Command).Execute:1039\n\tstorj.io/common/process.ExecWithCustomOptions:112\n\tmain.main:34\n\truntime.main:267"} ``` More logs in the forum post above. **Your environment** - Operating system and version: - Additional environment details (Raspberry PI, Docker, VMWare, etc.):

clearing · October 9, 2024, 6:02am

its happening again.

2024-10-09T05:59:10Z	FATAL	Unrecoverable error	{"Process": "storagenode", "error": "Error checking version for storagenode database: validate db version mismatch: expected 56, but current version is 62\n\tstorj.io/storj/private/migrate.(*Migration).ValidateVersions:141\n\tstorj.io/storj/storagenode/storagenodedb.(*DB).CheckVersion:719\n\tmain.cmdRun:105\n\tmain.newRunCmd.func1:33\n\tstorj.io/common/process.cleanup.func1.4:392\n\tstorj.io/common/process.cleanup.func1:410\n\tgithub.com/spf13/cobra.(*Command).execute:983\n\tgithub.com/spf13/cobra.(*Command).ExecuteC:1115\n\tgithub.com/spf13/cobra.(*Command).Execute:1039\n\tstorj.io/common/process.ExecWithCustomOptions:112\n\tmain.main:34\n\truntime.main:271", "errorVerbose": "Error checking version for storagenode database: validate db version mismatch: expected 56, but current version is 62\n\tstorj.io/storj/private/migrate.(*Migration).ValidateVersions:141\n\tstorj.io/storj/storagenode/storagenodedb.(*DB).CheckVersion:719\n\tmain.cmdRun:105\n\tmain.newRunCmd.func1:33\n\tstorj.io/common/process.cleanup.func1.4:392\n\tstorj.io/common/process.cleanup.func1:410\n\tgithub.com/spf13/cobra.(*Command).execute:983\n\tgithub.com/spf13/cobra.(*Command).ExecuteC:1115\n\tgithub.com/spf13/cobra.(*Command).Execute:1039\n\tstorj.io/common/process.ExecWithCustomOptions:112\n\tmain.main:34\n\truntime.main:271\n\tmain.cmdRun:107\n\tmain.newRunCmd.func1:33\n\tstorj.io/common/process.cleanup.func1.4:392\n\tstorj.io/common/process.cleanup.func1:410\n\tgithub.com/spf13/cobra.(*Command).execute:983\n\tgithub.com/spf13/cobra.(*Command).ExecuteC:1115\n\tgithub.com/spf13/cobra.(*Command).Execute:1039\n\tstorj.io/common/process.ExecWithCustomOptions:112\n\tmain.main:34\n\truntime.main:271"}

2024-10-09T05:59:41Z	INFO	Download started.	{"Process": "storagenode-updater", "From": "https://github.com/storj/storj/releases/download/v1.114.6/storagenode-updater_linux_arm64.zip", "To": "/tmp/storagenode-updater_linux_arm64.184240375.zip"}
2024-10-09T05:59:41Z	ERROR	Error updating service.	{"Process": "storagenode-updater", "Service": "storagenode-updater", "error": "Get \"https://github.com/storj/storj/releases/download/v1.114.6/storagenode-updater_linux_arm64.zip\": context canceled", "errorVerbose": "Get \"https://github.com/storj/storj/releases/download/v1.114.6/storagenode-updater_linux_arm64.zip\": context canceled\n\tmain.downloadBinary:58\n\tmain.update:40\n\tmain.loopFunc:31\n\tstorj.io/common/sync2.(*Cycle).Run:99\n\tmain.cmdRun:138\n\tstorj.io/common/process.cleanup.func1.4:392\n\tstorj.io/common/process.cleanup.func1:410\n\tgithub.com/spf13/cobra.(*Command).execute:983\n\tgithub.com/spf13/cobra.(*Command).ExecuteC:1115\n\tgithub.com/spf13/cobra.(*Command).Execute:1039\n\tstorj.io/common/process.ExecWithCustomOptions:112\n\tstorj.io/common/process.ExecWithCustomConfigAndLogger:77\n\tmain.main:22\n\truntime.main:271"}

for additional context, my setup is that I am creating a new docker container for my old storagenode. could this be causing the issue?

Alexey · October 9, 2024, 7:08am

Yes, because you need to download a version, which has this database migration. I may guess, but it should be the same which was running before. Please search in the logs, which one you have used before. It should print that to the logs when it’s checking for a new version.
By the way, why do you not use an official image?

clearing · October 9, 2024, 11:37am

Hi, i am using the official image of storagenode.

the version is v1.113.2

2024-10-09T11:35:47Z	INFO	Anonymized tracing enabled	{"Process": "storagenode-updater"}
2024-10-09T11:35:47Z	INFO	Running on version	{"Process": "storagenode-updater", "Service": "storagenode-updater", "Version": "v1.113.2"}
2024-10-09T11:35:47Z	INFO	Downloading versions.	{"Process": "storagenode-updater", "Server Address": "https://version.storj.io"}
2024-10-09T11:35:48Z	INFO	Current binary version	{"Process": "storagenode-updater", "Service": "storagenode", "Version": "v1.113.2"}
2024-10-09T11:35:48Z	INFO	Download started.	{"Process": "storagenode-updater", "From": "https://github.com/storj/storj/releases/download/v1.114.6/storagenode_linux_arm64.zip", "To": "/tmp/storagenode_linux_arm64.634857301.zip"}
2024-10-09 11:35:48,659 INFO success: processes-exit-eventlistener entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2024-10-09 11:35:48,660 INFO success: storagenode entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2024-10-09 11:35:48,661 INFO success: storagenode-updater entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2024-10-09 11:35:48,661 WARN exited: storagenode (exit status 1; not expected)
2024-10-09 11:35:48,667 INFO spawned: 'storagenode' with pid 62
2024-10-09 11:35:48,669 WARN received SIGQUIT indicating exit request
2024-10-09 11:35:48,670 INFO waiting for processes-exit-eventlistener, storagenode, storagenode-updater to die
2024-10-09T11:35:48Z	INFO	Got a signal from the OS: "terminated"	{"Process": "storagenode-updater"}
2024-10-09T11:35:48Z	ERROR	Error updating service.	{"Process": "storagenode-updater", "Service": "storagenode", "error": "Get \"https://objects.githubusercontent.com/github-production-release-asset-2e65be/128089774/f04b907b-1027-40e9-8a96-66b7e33b1a23?X-Amz-Algorithm=AWS4-HMAC-SHA256&X-Amz-Credential=releaseassetproduction%2F20241009%2Fus-east-1%2Fs3%2Faws4_request&X-Amz-Date=20241009T113534Z&X-Amz-Expires=300&X-Amz-Signature=a12ecb8e56b473716a6336da0f21ec55555ce0c2cb2063b4cc777b73a7a8eee4&X-Amz-SignedHeaders=host&response-content-disposition=attachment%3B%20filename%3Dstoragenode_linux_arm64.zip&response-content-type=application%2Foctet-stream\": context canceled", "errorVerbose": "Get \"https://objects.githubusercontent.com/github-production-release-asset-2e65be/128089774/f04b907b-1027-40e9-8a96-66b7e33b1a23?X-Amz-Algorithm=AWS4-HMAC-SHA256&X-Amz-Credential=releaseassetproduction%2F20241009%2Fus-east-1%2Fs3%2Faws4_request&X-Amz-Date=20241009T113534Z&X-Amz-Expires=300&X-Amz-Signature=a12ecb8e56b473716a6336da0f21ec55555ce0c2cb2063b4cc777b73a7a8eee4&X-Amz-SignedHeaders=host&response-content-disposition=attachment%3B%20filename%3Dstoragenode_linux_arm64.zip&response-content-type=application%2Foctet-stream\": context canceled\n\tmain.downloadBinary:58\n\tmain.update:40\n\tmain.loopFunc:26\n\tstorj.io/common/sync2.(*Cycle).Run:99\n\tmain.cmdRun:138\n\tstorj.io/common/process.cleanup.func1.4:392\n\tstorj.io/common/process.cleanup.func1:410\n\tgithub.com/spf13/cobra.(*Command).execute:983\n\tgithub.com/spf13/cobra.(*Command).ExecuteC:1115\n\tgithub.com/spf13/cobra.(*Command).Execute:1039\n\tstorj.io/common/process.ExecWithCustomOptions:112\n\tstorj.io/common/process.ExecWithCustomConfigAndLogger:77\n\tmain.main:22\n\truntime.main:271"}
2024-10-09T11:35:48Z	INFO	Current binary version	{"Process": "storagenode-updater", "Service": "storagenode-updater", "Version": "v1.113.2"}
2024-10-09T11:35:48Z	INFO	Download started.	{"Process": "storagenode-updater", "From": "https://github.com/storj/storj/releases/download/v1.114.6/storagenode-updater_linux_arm64.zip", "To": "/tmp/storagenode-updater_linux_arm64.2090648873.zip"}
2024-10-09T11:35:48Z	ERROR	Error updating service.	{"Process": "storagenode-updater", "Service": "storagenode-updater", "error": "Get \"https://github.com/storj/storj/releases/download/v1.114.6/storagenode-updater_linux_arm64.zip\": context canceled", "errorVerbose": "Get \"https://github.com/storj/storj/releases/download/v1.114.6/storagenode-updater_linux_arm64.zip\": context canceled\n\tmain.downloadBinary:58\n\tmain.update:40\n\tmain.loopFunc:31\n\tstorj.io/common/sync2.(*Cycle).Run:99\n\tmain.cmdRun:138\n\tstorj.io/common/process.cleanup.func1.4:392\n\tstorj.io/common/process.cleanup.func1:410\n\tgithub.com/spf13/cobra.(*Command).execute:983\n\tgithub.com/spf13/cobra.(*Command).ExecuteC:1115\n\tgithub.com/spf13/cobra.(*Command).Execute:1039\n\tstorj.io/common/process.ExecWithCustomOptions:112\n\tstorj.io/common/process.ExecWithCustomConfigAndLogger:77\n\tmain.main:22\n\truntime.main:271"}
2024-10-09 11:35:49,729 INFO success: storagenode entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2024-10-09 11:35:49,730 INFO stopped: storagenode-updater (exit status 0)
2024-10-09 11:35:49,747 WARN stopped: storagenode (exit status 1)
2024-10-09 11:35:49,751 WARN stopped: processes-exit-eventlistener (terminated by SIGTERM)

Alexey · October 10, 2024, 5:33am

Do you have a watchtower? If not, please update the image by

docker pull storjlabs/storagenode:latest

and re-create the container:

docker stop -t 300 storagenode
docker rm storagenode

then run your full docker run command (without SETUP flag!).

clearing · October 10, 2024, 10:12am

yes i am also using watch tower.
the container image i have is the latest one.

docker pull storjlabs/storagenode:latest
latest: Pulling from storjlabs/storagenode
Digest: sha256:21ca0ac819d1d66240830d28097eeb693923e51383aa3bb07bf823f9fad1f6e9
Status: Image is up to date for storjlabs/storagenode:latest
docker.io/storjlabs/storagenode:latest

clearing · October 10, 2024, 5:01pm

when will there be a container image that contains v1.114.6 as the initial storagenode?

Alexey · October 11, 2024, 7:41am

when your NodeID would be eligible.
How is it happened that your node have been upgraded to a not fully released version?

Ok, right now you can download a new v1.114.6 binaries for your platform and extract them to the bin subfolder in your data location, then restart the container.