Error starting master database on storagenode: stoage node database error: file is not a database

Windows GUI
So, the storagenode service wasn’t running when I woke up this morning. When I currently start it, it outputs the following error:
FATAL Unrecoverable error {“error”: “Error starting master database on storagenode: storage node database error: file is not a database\n\tstorj.io/storj/storagenode/storagenodedb.(*DB).openDatabase:272\n\tstorj.io/storj/storagenode/storagenodedb.(*DB).openDatabases:197\n\tstorj.io/storj/storagenode/storagenodedb.New:174\n\tmain.cmdRun:150\n\tstorj.io/private/process.cleanup.func1.4:353\n\tstorj.io/private/process.cleanup.func1:371\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.Exec:65\n\tmain.(*service).Execute.func1:66\n\tgolang.org/x/sync/errgroup.(*Group).Go.func1:57”, “errorVerbose”: “Error starting master database on storagenode: storage node database error: file is not a database\n\tstorj.io/storj/storagenode/storagenodedb.(*DB).openDatabase:272\n\tstorj.io/storj/storagenode/storagenodedb.(*DB).openDatabases:197\n\tstorj.io/storj/storagenode/storagenodedb.New:174\n\tmain.cmdRun:150\n\tstorj.io/private/process.cleanup.func1.4:353\n\tstorj.io/private/process.cleanup.func1:371\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.Exec:65\n\tmain.(*service).Execute.func1:66\n\tgolang.org/x/sync/errgroup.(*Group).Go.func1:57\n\tmain.cmdRun:152\n\tstorj.io/private/process.cleanup.func1.4:353\n\tstorj.io/private/process.cleanup.func1:371\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.Exec:65\n\tmain.(*service).Execute.func1:66\n\tgolang.org/x/sync/errgroup.(*Group).Go.func1:57”}

I did some basic searching throughout the forums and eventually found the support document regarding malformed database files, but the problem is that when I scan the .db files in a row, it outputs the following

bandwidth.db ok
heldamount.db ok
info.db ok
notifications.db ok
Error: file is not a database
orders.db
pieceinfo.db ok
piece_expiration.db ok
piece_spaced_used.db ok
pricing.db ok
reputation.db ok
satellites.db ok
storage_usage.db ok
used_serial.db ok

and when I scan them individually it outputs the following

PS G:\Storj\storage> sqlite3 /bandwidth.db “PRAGMA integrity_check;”
ok
PS G:\Storj\storage> sqlite3 /heldamount.db “PRAGMA integrity_check;”
ok
PS G:\Storj\storage> sqlite3 /info.db “PRAGMA integrity_check;”
ok
PS G:\Storj\storage> sqlite3 /notifications.db “PRAGMA integrity_check;”
ok
PS G:\Storj\storage> sqlite3 /orders.db “PRAGMA integrity_check;”
ok
PS G:\Storj\storage> sqlite3 /pieceinfo.db “PRAGMA integrity_check;”
ok
PS G:\Storj\storage> sqlite3 /piece_expiration.db “PRAGMA integrity_check;”
ok
PS G:\Storj\storage> sqlite3 /piece_spaced_used.db “PRAGMA integrity_check;”
ok
PS G:\Storj\storage> sqlite3 /pricing.db “PRAGMA integrity_check;”
ok
PS G:\Storj\storage> sqlite3 /reputation.db “PRAGMA integrity_check;”
ok
PS G:\Storj\storage> sqlite3 /satellites.db “PRAGMA integrity_check;”
ok
PS G:\Storj\storage> sqlite3 /storage_used.db “PRAGMA integrity_check;”
ok
PS G:\Storj\storage> sqlite3 /used_serial.db “PRAGMA integrity_check;”
ok

Either there’s a hidden database file I’m not finding, or something’s very screwy with sqlite3. Any assistance anyone can give would be greatly appreciated.

P.S. Already ran a chkdsk, came back clean. Although I will state upfront that I did have a problem with the disk yesterday that was since resolved (orphaned file, returned to original database)

Please, check them without /. The sqlite3 could create an empty database with such name and it will be ok of course, since it’s empty

Please, show the result of the command (PowerShell):

ls G:\Storj\storage\
ls G:\Storj\

Also, when you check databases, the storagenode must be stopped

Thank you for reminding me that sqlite3 was written for cmd not powershell (forgot to remove the /). I’m now able to identify that the issue is with the orders.db file. I’ll be doing further investigation regarding how to repair that.

Just in case this helps further, here’s the output you asked for.

PS G:\Storj> ls

Directory: G:\Storj

Mode LastWriteTime Length Name


d----- 7/14/2020 10:11 AM blobs
d----- 7/14/2020 10:11 AM garbage
d----- 7/31/2020 1:48 PM storage
d----- 1/21/2020 6:50 PM storagenode
d----- 7/14/2020 10:11 AM temp
d----- 7/14/2020 10:11 AM trash
-a---- 7/14/2020 10:28 AM 32768 bandwidth.db
-a---- 6/26/2020 5:37 PM 6932 config.yaml
-a---- 1/21/2020 6:54 PM 6934 config_old.yaml
-a---- 7/14/2020 10:28 AM 24576 heldamount.db
-a---- 7/14/2020 10:28 AM 16384 info.db
-a---- 10/3/2019 4:57 PM 131072 kademlia
-a---- 7/14/2020 10:28 AM 24576 notifications.db
-a---- 7/14/2020 10:28 AM 32768 orders.db
-a---- 7/14/2020 10:28 AM 24576 pieceinfo.db
-a---- 7/14/2020 10:28 AM 36864 piece_expiration.db
-a---- 7/14/2020 10:28 AM 24576 piece_spaced_used.db
-a---- 7/14/2020 10:28 AM 24576 pricing.db
-a---- 7/14/2020 10:28 AM 24576 reputation.db
-a---- 7/14/2020 8:02 AM 32768 revocations.db
-a---- 7/14/2020 10:28 AM 32768 satellites.db
-a---- 7/14/2020 10:28 AM 20480 storage_usage.db
-a---- 7/14/2020 8:02 AM 1430 trust-cache.json
-a---- 7/14/2020 10:28 AM 20480 used_serial.db

PS G:\Storj\storage> ls

Directory: G:\Storj\storage

Mode LastWriteTime Length Name


d----- 4/27/2020 8:30 PM blobs
d----- 7/31/2020 9:51 AM db_backups
d----- 7/31/2020 9:38 AM garbage
d----- 7/31/2020 9:38 AM temp
d----- 5/11/2020 4:27 PM trash
-a---- 7/31/2020 1:49 AM 16089088 bandwidth.db
-a---- 7/31/2020 9:53 AM 53248 heldamount.db
-a---- 7/31/2020 9:38 AM 16384 info.db
-a---- 7/31/2020 9:53 AM 24576 notifications.db
-a---- 7/31/2020 7:53 AM 529207296 orders.db
-a---- 7/31/2020 9:53 AM 24576 pieceinfo.db
-a---- 7/31/2020 9:53 AM 147456 piece_expiration.db
-a---- 7/31/2020 9:53 AM 24576 piece_spaced_used.db
-a---- 7/31/2020 9:53 AM 24576 pricing.db
-a---- 7/31/2020 9:53 AM 24576 reputation.db
-a---- 7/31/2020 9:53 AM 32768 satellites.db
-a---- 7/31/2020 9:53 AM 286720 storage_usage.db
-a---- 7/31/2020 9:53 AM 50450432 used_serial.db

You have two collections of storagenode’s data. If you migrated recently, you could be disqualified as soon as you bring it online.
G:\Storj\ looks like a Windows GUI path, the G:\Storj\storage looks like a docker path.
What is your current version?

Hm maybe even three version. I see the G:\Storj\storagenode too

Please, show the result of the PowerShell command:

ls G:\Storj\storagenode

PS G:\Storj\storage> ls G:\Storj\storagenode

Directory: G:\Storj\storagenode

Mode LastWriteTime Length Name


-a---- 9/19/2019 11:28 PM 546 ca.1568953704.cert
-a---- 9/19/2019 11:28 PM 1072 ca.cert
-a---- 9/19/2019 11:25 PM 241 ca.key
-a---- 9/19/2019 11:28 PM 1084 identity.1568953704.cert
-a---- 9/19/2019 11:28 PM 1610 identity.cert
-a---- 9/19/2019 11:25 PM 241 identity.key

I did the migration from docker to GUI quite a bit ago, although I recently had to reset my machine due to bluescreens so everything might not be in the right place.

Okay, as an update, I was able to follow the directions within the support document for malformed database files, sqlite3 basically results in the same error that the storagenode was running into, when attempting to dump it just says it’s not a database file. Is there anything I can do to rebuild this file?

Missed that the first time I read it. I’m running version v1.9.5

First of all: please, give me the result of the command (PowerShell):

sls "storage.path:" 'C:\Program Files\Storj\Storage Node\config.yaml'

We will fix the database later, but first we need to fix a probably wrong path.
Do you run the same identity as for a docker node?
What was your docker run command?

PS G:\Storj\storage> sls “storage.path:” ‘C:\Program Files\Storj\Storage Node\config.yaml’

C:\Program Files\Storj\Storage Node\config.yaml:158:storage.path: G:\Storj\storage\

docker run -d --restart unless-stopped -p 28967:28967 -p 127.0.0.1:14002:14002 -e WALLET=“censor” -e EMAIL=“censor” -e ADDRESS=“censor:28967” -e BANDWIDTH=“2TB” -e STORAGE=“500GB” --mount type=bind,source=“C:\Users\censor\AppData\Roaming\Storj\Identity\storagenode”,destination=/app/identity --mount type=bind,source=“g:\storj”,destination=/app/config --name storagenode storjlabs/storagenode:beta

The bandwidth and storage have since increased since I last used the docker version (around June 2019 I think is when I transitioned to Windows GUI).

Also, sorry for the delay, was asleep.

Ok, but from where is G:\Storj\blobs and database files in the G:\Storj\?

To fix the orders.db:

  1. Stop the storagenode
  2. Remove the G:\Storj\storage\orders.db
  3. Execute
sqlite3 G:\Storj\storage\orders.db
CREATE TABLE unsent_order (
                                                satellite_id  BLOB NOT NULL,
                                                serial_number BLOB NOT NULL,
                                                order_limit_serialized BLOB      NOT NULL, -- serialized pb.OrderLimit
                                                order_serialized       BLOB      NOT NULL, -- serialized pb.Order
                                                order_limit_expiration TIMESTAMP NOT NULL, -- when is the deadline for sending it
                                                uplink_cert_id INTEGER NOT NULL,
                                                FOREIGN KEY(uplink_cert_id) REFERENCES certificate(cert_id)
                                        );
CREATE TABLE order_archive_ (
                                                satellite_id  BLOB NOT NULL,
                                                serial_number BLOB NOT NULL,
                                                order_limit_serialized BLOB NOT NULL,
                                                order_serialized       BLOB NOT NULL,
                                                uplink_cert_id INTEGER NOT NULL,
                                                status      INTEGER   NOT NULL,
                                                archived_at TIMESTAMP NOT NULL,
                                                FOREIGN KEY(uplink_cert_id) REFERENCES certificate(cert_id)
                                        );
CREATE UNIQUE INDEX idx_orders ON unsent_order(satellite_id, serial_number);
CREATE TABLE versions (version int, commited_at text);
.exit
  1. Start the storagenode
  2. Check your logs

I checked Storj/blobs and it looks like that folder is empty currently while storj/storage/blobs has 6 folders.
I ran what you typed in and it encountered errors at order_serialized BLOB NOT NULL, – serialized pb.Order during unsent_order:

At line:4 char:91
+ ...                    order_limit_serialized BLOB      NOT NULL, -- seri ...
+                                                                  ~
Missing expression after ',' in pipeline element.
At line:4 char:119
+ ... rder_limit_serialized BLOB      NOT NULL, -- serialized pb.OrderLimit
+                                                                          ~
Missing closing ')' in expression.
At line:5 char:91
+ ...                    order_serialized       BLOB      NOT NULL, -- seri ...
+                                                                  ~
Missing expression after ',' in pipeline element.
    + CategoryInfo          : ParserError: (:) [], ParentContainsErrorRecordException
    + FullyQualifiedErrorId : MissingExpression

Should I start the node anyway?

Looks like a copy-paste issue.
Please, run the

sqlite3 G:\Storj\storage\orders.db

first.
When you see a sqlite> prompt, copy the remained part (started from CREATE)

Seems to be running fine now after doing that, here’s the output from the log.

2020-08-01T13:22:57.379-0500	INFO	Telemetry enabled
2020-08-01T13:22:57.386-0500	INFO	db.migration.27	Add index archived_at to ordersDB
2020-08-01T13:22:57.424-0500	INFO	db.migration	Database Version	{"version": 43}
2020-08-01T13:22:58.386-0500	INFO	preflight:localtime	start checking local system clock with trusted satellites' system clock.
2020-08-01T13:22:59.255-0500	INFO	preflight:localtime	local system clock is in sync with trusted satellites' system clock.
2020-08-01T13:22:59.256-0500	INFO	bandwidth	Performing bandwidth usage rollups
2020-08-01T13:22:59.257-0500	INFO	Node 12CMjYzRsLfx6GAjMTPg9JQ8sJWwpTuDNmVUEMR1Kavd77pgMpv started
2020-08-01T13:22:59.257-0500	INFO	Public server started on [::]:28967
2020-08-01T13:22:59.257-0500	INFO	Private server started on 127.0.0.1:7778
2020-08-01T13:22:59.259-0500	INFO	trust	Scheduling next refresh	{"after": "3h40m56.956315756s"}

Based on the total disk space module on the dashboard, it seems to be successfully grabbing everything correctly.

1 Like

5 posts were split to a new topic: Error starting master database on storagenode: storage node database error: unable to open database file: operation not permitted

same here. just happen. I am on docker too. Windows 10

hm, i tried but still do not start.
I removed storagenode
add it back with docker run -d --privileged --restart unless-stopped…

storagenode is reastaring

Please, show 20 last lines from the log

storj.io/private/process.ExecCustomDebug:70
main.main:323
runtime.main:203
2020-08-05T08:24:42.300Z INFO Configuration loaded {“Location”: “/app/config/config.yaml”}
2020-08-05T08:24:42.314Z INFO Operator email {“Address”: “0000@hotmail.com”}
2020-08-05T08:24:42.314Z INFO Operator wallet {“Address”: “0x000000000000000000000000”}
Error: Error starting master database on storagenode: storage node database error: file is not a database
storj.io/storj/storagenode/storagenodedb.(*DB).openDatabase:272
storj.io/storj/storagenode/storagenodedb.(*DB).openDatabases:212
storj.io/storj/storagenode/storagenodedb.New:174
main.cmdRun:150
storj.io/private/process.cleanup.func1.4:353
storj.io/private/process.cleanup.func1:371
github.com/spf13/cobra.(*Command).execute:840
github.com/spf13/cobra.(*Command).ExecuteC:945
github.com/spf13/cobra.(*Command).Execute:885
storj.io/private/process.ExecWithCustomConfig:88
storj.io/private/process.ExecCustomDebug:70
main.main:323
runtime.main:203

This is completely different issue. You have a write cache enabled on your disk and storagenode was abruptly stopped without clear shutdown for some reason.
Perhaps you even did not update the docker run command to the latest one: https://documentation.storj.io/setup/cli/storage-node#running-the-storage-node
And the watchtower command: https://documentation.storj.io/setup/cli/software-updates#automatic-updates

Regarding how to fix this issue:

  1. Stop and remove the storagenode container
docker stop -t 300 storagenode
docker rm storagenode
  1. Revert back the Docker desktop to 2.1.0.5
  2. Disable write cache on the disk with data
  3. Check all databases to figure out which one is unrecoverable corrupted:

5. Post here, what database should be created from scratch

I am gonna try, but write cash is disabled on this drive. Could this with update?
2. docker is already 2.1.0.5
3. write cash already disabled.

  1. :face_with_monocle: