Two nodes down - Error during preflight check for storagenode databases: storage node preflight database error: reputation: expected schema does not match actual

Hi,
I am running two nodes on a raspberry pi4 4GB. Beside the nodes I am running nothing else on that Pi. Today I had to restart the pi and after the restart I was not able to start the nodes again. For both I get the same error, that the database schema does not match. I used the exact same start command that I always used, the drive is correctly mounted, so I don’t understand what happened.

STORJ-Node versions: 1.26.3

Start command:

sudo docker run -d --restart unless-stopped --stop-timeout 300 -p 28909:28967 -p 192.168.178.133:14009:14002 -e WALLET=“###” -e EMAIL="maximilian_brell@icloud.com" -e ADDRESS=“####:28909” -e STORAGE=“5000GB” --memory=2500m --log-opt max-size=50m --log-opt max-file=10 --mount type=bind,source=/identity-path,destination=/app/identity --mount type=bind,source=/storagenode-path,destination=/app/config --name storagenode storjlabs/storagenode:latest

Log when I try to start:

2021-04-21T07:50:28.477Z INFO Configuration loaded {“Location”: “/app/config/config.yaml”}
2021-04-21T07:50:28.484Z INFO Operator email {“Address”: “email@domain.com”}
2021-04-21T07:50:28.484Z INFO Operator wallet {“Address”: “#########”}
2021-04-21T07:50:28.847Z INFO Telemetry enabled
2021-04-21T07:50:28.893Z INFO db.migration Database Version {“version”: 42}
Error: Error during preflight check for storagenode databases: storage node preflight database error: reputation: expected schema does not match actual: &dbschema.Schema{
Tables: *dbschema.Table{
&{
Name: “reputation”,
Columns: *dbschema.Column{

  •   		s"Name: audit_history\nType: BLOB\nNullable: true\nDefault: \"\"\nReference: nil",
      		&{Name: "audit_reputation_alpha", Type: "REAL"},
      		&{Name: "audit_reputation_beta", Type: "REAL"},
      		... // 4 identical elements
      		&{Name: "audit_unknown_reputation_beta", Type: "REAL"},
      		&{Name: "audit_unknown_reputation_score", Type: "REAL"},
      		&{
    
  •   			Name:       "disqualified",
    
  •   			Name:       "disqualified_at",
      			Type:       "TIMESTAMP",
      			IsNullable: true,
      			... // 2 identical fields
      		},
      		&{Name: "joined_at", Type: "TIMESTAMP"},
      		&{
    
  •   			Name:       "satellite_id",
    
  •   			Name:       "offline_suspended_at",
    
  •   			Type:       "BLOB",
    
  •   			Type:       "TIMESTAMP",
    
  •   			IsNullable: false,
    
  •   			IsNullable: true,
      			Default:    "",
      			Reference:  nil,
      		},
      		&{
    
  •   			Name:       "suspended",
    
  •   			Name:       "offline_under_review_at",
      			Type:       "TIMESTAMP",
      			IsNullable: true,
      			... // 2 identical fields
      		},
    
  •   		s"Name: online_score\nType: REAL\nNullable: false\nDefault: \"\"\nReference: nil",
    
  •   		s"Name: satellite_id\nType: BLOB\nNullable: false\nDefault: \"\"\nReference: nil",
    
  •   		s"Name: suspended_at\nType: TIMESTAMP\nNullable: true\nDefault: \"\"\nReference: nil",
      		&{Name: "updated_at", Type: "TIMESTAMP"},
    

The same issue is present for both nodes. Do you have an idea how to fix this?
Thanks

I tried to start a few more times and it seems like other DB’s are also affected. Sometimes I get the same error but for heldamount DB for example.

Can I safely use these commands or did the DB Schemas change since this comment was created?

Please, do

  1. Stop the storagenode
  2. Remove the reputation.db
  3. Move all remained databases to a backup folder
  4. Start the storagenode
    It should create an empty databases
  5. Stop the storagenode
  6. Move databases back from the backup folder
  7. Start storagenode
  8. Check your logs

Thanks, I did that and got the same error, but this time with heldamound.db. So I repeated the steps with this database and now the node dashboard says it’s online, but the logs only show this in the first 15 minutes after start:

2021-04-21T20:46:48.615Z INFO Configuration loaded {“Location”: “/app/config/config.yaml”}

2021-04-21T20:46:48.616Z INFO Invalid configuration file key {“Key”: “operator.wallet-features”}

2021-04-21T20:46:48.619Z INFO Operator email {“Address”: "XXXX“}

2021-04-21T20:46:48.619Z INFO Operator wallet {“Address”: "}

2021-04-21T20:46:48.992Z INFO Telemetry enabled

2021-04-21T20:46:49.035Z INFO db.migration.32 Create paystubs table and payments table

2021-04-21T20:46:49.039Z INFO db.migration.33 Remove time zone from created_at in paystubs and payments

2021-04-21T20:46:49.045Z INFO db.migration.37 Drop payments table as unused

2021-04-21T20:46:49.049Z INFO db.migration Database Version {“version”: 42}

2021-04-21T20:46:49.491Z WARN trust Failed to fetch URLs from source; used cache {“source”: “https://tardigrade.io/trusted-satellites”, “error”: “HTTP source: Get https://tardigrade.io/trusted-satellites: x509: certificate signed by unknown authority”, “errorVerbose”: “HTTP source: Get https://tardigrade.io/trusted-satellites: x509: certificate signed by unknown authority\n\tstorj.io/storj/storagenode/trust.(*HTTPSource).FetchEntries:63\n\tstorj.io/storj/storagenode/trust.(*List).fetchEntries:90\n\tstorj.io/storj/storagenode/trust.(*List).FetchURLs:49\n\tstorj.io/storj/storagenode/trust.(*Pool).fetchURLs:240\n\tstorj.io/storj/storagenode/trust.(*Pool).Refresh:177\n\tstorj.io/storj/storagenode.(*Peer).Run:688\n\tmain.cmdRun:200\n\tstorj.io/private/process.cleanup.func1.4:359\n\tstorj.io/private/process.cleanup.func1:377\n\tgithub.com/spf13/cobra.(*Command).execute:840\n\tgithub.com/spf13/cobra.(*Command).ExecuteC:945\n\tgithub.com/spf13/cobra.(*Command).Execute:885\n\tstorj.io/private/process.ExecWithCustomConfig:88\n\tstorj.io/private/process.ExecCustomDebug:70\n\tmain.main:320\n\truntime.main:203”}

2021-04-21T20:46:49.503Z INFO preflight:localtime start checking local system clock with trusted satellites’ system clock.

2021-04-21T20:46:50.281Z INFO preflight:localtime local system clock is in sync with trusted satellites’ system clock.

2021-04-21T20:46:50.282Z INFO Node 12MZFRDyJ99CNQUVAqiJbYYF6BqViarU9YrdHHN3GS9nKW9LWgj started

2021-04-21T20:46:50.282Z INFO Public server started on [::]:28967

2021-04-21T20:46:50.283Z INFO bandwidth Performing bandwidth usage rollups

2021-04-21T20:46:50.283Z INFO Private server started on 127.0.0.1:7778

2021-04-21T20:46:50.284Z INFO trust Scheduling next refresh {“after”: “5h7m40.976245063s”}

2021-04-21T20:46:50.318Z INFO collector delete expired {“Satellite ID”: “12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs”, “Piece ID”: “POMGM4PCUEFYZOZAFPZ5E32CQHBU3HP47CFRKOHVASJNGNG7B5GQ”}

2021-04-21T20:46:50.345Z INFO collector delete expired {“Satellite ID”: “12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs”, “Piece ID”: “GFZIT2WB5RW5GSVA7LZIYA3NRSQ2PAOMYN3CB4PRBBOSXZTFQS7A”}

2021-04-21T20:46:50.364Z INFO collector delete expired {“Satellite ID”: “12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs”, “Piece ID”: “FYR6E6ANIW37KZZ4RCHW7VABRXO5TMXASD2574SYK4QZ6MZGQU4Q”}

2021-04-21T20:46:50.376Z INFO collector collect {“count”: 3}

2021-04-21T20:51:34.678Z INFO piecestore download started {“Piece ID”: “LJ3MGC3IPWK55QG2BQVRZAAERA5BYVKFU4X3NDB4EZFVGPCUWB5Q”, “Satellite ID”: “12tRQrMTWUWwzwGh18i7Fqs67kmdhH9t6aToeiwbo5mfS2rUmo”, “Action”: “GET_AUDIT”}

2021-04-21T20:51:35.023Z ERROR piecestore download failed {“Piece ID”: “LJ3MGC3IPWK55QG2BQVRZAAERA5BYVKFU4X3NDB4EZFVGPCUWB5Q”, “Satellite ID”: “12tRQrMTWUWwzwGh18i7Fqs67kmdhH9t6aToeiwbo5mfS2rUmo”, “Action”: “GET_AUDIT”, “error”: “untrusted: invalid order limit signature: signature verification error: signature is not valid”, “errorVerbose”: “untrusted: invalid order limit signature: signature verification error: signature is not valid\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).VerifyOrderLimitSignature:145\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).verifyOrderLimit:62\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).Download:467\n\tstorj.io/common/pb.DRPCPiecestoreDescription.Method.func2:1004\n\tstorj.io/drpc/drpcmux.(*Mux).HandleRPC:107\n\tstorj.io/common/rpc/rpctracing.(*Handler).HandleRPC:56\n\tstorj.io/drpc/drpcserver.(*Server).handleRPC:111\n\tstorj.io/drpc/drpcserver.(*Server).ServeOne:62\n\tstorj.io/drpc/drpcserver.(*Server).Serve.func2:99\n\tstorj.io/drpc/drpcctx.(*Tracker).track:51”}

2021-04-21T20:55:31.816Z INFO piecestore download started {“Piece ID”: “CBVPUBLCGXL7G2B6I2TOGZBBPNVEEJGHLXKMUNW4KBL7M5KF6Q6A”, “Satellite ID”: “1wFTAgs9DP5RSnCqKV1eLf6N9wtk4EAtmN5DpSxcs8EjT69tGE”, “Action”: “GET”}

2021-04-21T20:55:32.224Z ERROR piecestore download failed {“Piece ID”: “CBVPUBLCGXL7G2B6I2TOGZBBPNVEEJGHLXKMUNW4KBL7M5KF6Q6A”, “Satellite ID”: “1wFTAgs9DP5RSnCqKV1eLf6N9wtk4EAtmN5DpSxcs8EjT69tGE”, “Action”: “GET”, “error”: “untrusted: invalid order limit signature: signature verification error: signature is not valid”, “errorVerbose”: “untrusted: invalid order limit signature: signature verification error: signature is not valid\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).VerifyOrderLimitSignature:145\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).verifyOrderLimit:62\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).Download:467\n\tstorj.io/common/pb.DRPCPiecestoreDescription.Method.func2:1004\n\tstorj.io/drpc/drpcmux.(*Mux).HandleRPC:107\n\tstorj.io/common/rpc/rpctracing.(*Handler).HandleRPC:56\n\tstorj.io/drpc/drpcserver.(*Server).handleRPC:111\n\tstorj.io/drpc/drpcserver.(*Server).ServeOne:62\n\tstorj.io/drpc/drpcserver.(*Server).Serve.func2:99\n\tstorj.io/drpc/drpcctx.(*Tracker).track:51”}

Please, update your storagenode: Software Updates - Node Operator
Then configure automatic updates: Software Updates - Node Operator

I have 1.26.3. Isn’t that the latest version? I was always running Watchtower.

It’s a latest version.
Please, stop and remove the container:

docker stop -t 300 storagenode
docker rm storagenode
docker image rm storjlabs/storagenode

Then run it back with all your parameters, then check your logs.

Removing the image locally seems to work. Now the node is receiving data again and the logs look normal. On the second node it’s also working even without doing anything with the databases. So somehow my local image got corrupted…

Thanks a lot for your fast support :slight_smile:

2 Likes