raspiblitz: 1.11.0RC5 BTCpayserver won't start after updating (or uninstall/install)

Describe the bug Something is going wrong in the file permissions upon starting BTCpayserver, the installation goes fine with 0 issues.

To Reproduce Install 1.11.0RC5 on Pi5

sudo systemctl restart btcpayserver See error

Debug file

Mar 23 17:19:13 raspberrypi systemd[1]: Started btcpayserver.service - BtcPayServer daemon.
Mar 23 17:19:14 raspberrypi dotnet[2355527]: info: Configuration:  Data Directory: /home/btcpay/.btcpayserver/Main
Mar 23 17:19:14 raspberrypi dotnet[2355527]: info: Configuration:  Configuration File: /home/btcpay/.btcpayserver/Main/settings.config
Mar 23 17:19:14 raspberrypi dotnet[2355527]: info: BTCPayServer.Plugins.PluginManager: Loading plugins from /home/btcpay/.btcpayserver/Plugins
Mar 23 17:19:15 raspberrypi dotnet[2355527]: info: BTCPayServer.Plugins.PluginManager: Adding and executing plugin BTCPayServer - 1.12.5.0
Mar 23 17:19:15 raspberrypi dotnet[2355527]: info: BTCPayServer.Plugins.PluginManager: Adding and executing plugin BTCPayServer.Plugins.Shopify - 1.12.5.0
Mar 23 17:19:15 raspberrypi dotnet[2355527]: info: BTCPayServer.Plugins.PluginManager: Adding and executing plugin BTCPayServer.Plugins.PointOfSale - 1.12.5.0
Mar 23 17:19:15 raspberrypi dotnet[2355527]: info: BTCPayServer.Plugins.PluginManager: Adding and executing plugin BTCPayServer.Plugins.PayButton - 1.12.5.0
Mar 23 17:19:15 raspberrypi dotnet[2355527]: info: BTCPayServer.Plugins.PluginManager: Adding and executing plugin BTCPayServer.Plugins.NFC - 1.12.5.0
Mar 23 17:19:15 raspberrypi dotnet[2355527]: info: BTCPayServer.Plugins.PluginManager: Adding and executing plugin BTCPayServer.Plugins.Crowdfund - 1.12.5.0
Mar 23 17:19:15 raspberrypi dotnet[2355527]: info: BTCPayServer.Plugins.PluginManager: Adding and executing plugin BTCPayServer.Plugins.Bitcoin - 1.12.5.0
Mar 23 17:19:15 raspberrypi dotnet[2355527]: info: Configuration:  Supported chains: BTC
Mar 23 17:19:16 raspberrypi dotnet[2355527]: info: Configuration:  BTC: Explorer url is http://127.0.0.1:24444/
Mar 23 17:19:16 raspberrypi dotnet[2355527]: info: Configuration:  BTC: Cookie file is /home/btcpay/.nbxplorer/Main/.cookie
Mar 23 17:19:16 raspberrypi dotnet[2355527]: info: Configuration:  Network: Mainnet
Mar 23 17:19:26 raspberrypi dotnet[2355527]: fail: BTCPayServer.Hosting.MigrationStartupTask: Error on the MigrationStartupTask
Mar 23 17:19:26 raspberrypi dotnet[2355527]: Npgsql.PostgresException (0x80004005): 42501: permission denied for schema public
Mar 23 17:19:26 raspberrypi dotnet[2355527]: POSITION: 14
Mar 23 17:19:26 raspberrypi dotnet[2355527]:    at Npgsql.Internal.NpgsqlConnector.ReadMessageLong(Boolean async, DataRowLoadingMode dataRowLoadingMode, Boolean readingNotifications, Boolean isReadingPrependedMessage)
Mar 23 17:19:26 raspberrypi dotnet[2355527]:    at System.Runtime.CompilerServices.PoolingAsyncValueTaskMethodBuilder`1.StateMachineBox`1.System.Threading.Tasks.Sources.IValueTaskSource<TResult>.GetResult(Int16 token)
Mar 23 17:19:26 raspberrypi dotnet[2355527]:    at Npgsql.NpgsqlDataReader.NextResult(Boolean async, Boolean isConsuming, CancellationToken cancellationToken)
Mar 23 17:19:26 raspberrypi dotnet[2355527]:    at Npgsql.NpgsqlDataReader.NextResult(Boolean async, Boolean isConsuming, CancellationToken cancellationToken)
Mar 23 17:19:26 raspberrypi dotnet[2355527]:    at Npgsql.NpgsqlCommand.ExecuteReader(Boolean async, CommandBehavior behavior, CancellationToken cancellationToken)
Mar 23 17:19:26 raspberrypi dotnet[2355527]:    at Npgsql.NpgsqlCommand.ExecuteReader(Boolean async, CommandBehavior behavior, CancellationToken cancellationToken)
Mar 23 17:19:26 raspberrypi dotnet[2355527]:    at Npgsql.NpgsqlCommand.ExecuteNonQuery(Boolean async, CancellationToken cancellationToken)
Mar 23 17:19:26 raspberrypi dotnet[2355527]:    at Microsoft.EntityFrameworkCore.Storage.RelationalCommand.ExecuteNonQueryAsync(RelationalCommandParameterObject parameterObject, CancellationToken cancellationToken)
Mar 23 17:19:26 raspberrypi dotnet[2355527]:    at Microsoft.EntityFrameworkCore.Storage.RelationalCommand.ExecuteNonQueryAsync(RelationalCommandParameterObject parameterObject, CancellationToken cancellationToken)
Mar 23 17:19:26 raspberrypi dotnet[2355527]:    at Microsoft.EntityFrameworkCore.Storage.RelationalCommand.ExecuteNonQueryAsync(RelationalCommandParameterObject parameterObject, CancellationToken cancellationToken)
Mar 23 17:19:26 raspberrypi dotnet[2355527]:    at Microsoft.EntityFrameworkCore.Migrations.Internal.Migrator.MigrateAsync(String targetMigration, CancellationToken cancellationToken)
Mar 23 17:19:26 raspberrypi dotnet[2355527]:    at Npgsql.EntityFrameworkCore.PostgreSQL.Migrations.Internal.NpgsqlMigrator.MigrateAsync(String targetMigration, CancellationToken cancellationToken)
Mar 23 17:19:26 raspberrypi dotnet[2355527]:    at BTCPayServer.Hosting.MigrationStartupTask.Migrate(CancellationToken cancellationToken) in /home/btcpay/btcpayserver/BTCPayServer/Hosting/MigrationStartupTask.cs:line 859
Mar 23 17:19:26 raspberrypi dotnet[2355527]:    at BTCPayServer.Hosting.MigrationStartupTask.ExecuteAsync(CancellationToken cancellationToken) in /home/btcpay/btcpayserver/BTCPayServer/Hosting/MigrationStartupTask.cs:line 85
Mar 23 17:19:26 raspberrypi dotnet[2355527]:   Exception data:
Mar 23 17:19:26 raspberrypi dotnet[2355527]:     Severity: ERROR
Mar 23 17:19:26 raspberrypi dotnet[2355527]:     SqlState: 42501
Mar 23 17:19:26 raspberrypi dotnet[2355527]:     MessageText: permission denied for schema public
Mar 23 17:19:26 raspberrypi dotnet[2355527]:     Position: 14
Mar 23 17:19:26 raspberrypi dotnet[2355527]:     File: aclchk.c
Mar 23 17:19:26 raspberrypi dotnet[2355527]:     Line: 3650
Mar 23 17:19:26 raspberrypi dotnet[2355527]:     Routine: aclcheck_error
Mar 23 17:19:26 raspberrypi dotnet[2355527]: Unhandled exception. Npgsql.PostgresException (0x80004005): 42501: permission denied for schema public
Mar 23 17:19:26 raspberrypi dotnet[2355527]: POSITION: 14
Mar 23 17:19:26 raspberrypi dotnet[2355527]:    at Npgsql.Internal.NpgsqlConnector.ReadMessageLong(Boolean async, DataRowLoadingMode dataRowLoadingMode, Boolean readingNotifications, Boolean isReadingPrependedMessage)
Mar 23 17:19:26 raspberrypi dotnet[2355527]:    at System.Runtime.CompilerServices.PoolingAsyncValueTaskMethodBuilder`1.StateMachineBox`1.System.Threading.Tasks.Sources.IValueTaskSource<TResult>.GetResult(Int16 token)
Mar 23 17:19:26 raspberrypi dotnet[2355527]:    at Npgsql.NpgsqlDataReader.NextResult(Boolean async, Boolean isConsuming, CancellationToken cancellationToken)
Mar 23 17:19:26 raspberrypi dotnet[2355527]:    at Npgsql.NpgsqlDataReader.NextResult(Boolean async, Boolean isConsuming, CancellationToken cancellationToken)
Mar 23 17:19:26 raspberrypi dotnet[2355527]:    at Npgsql.NpgsqlCommand.ExecuteReader(Boolean async, CommandBehavior behavior, CancellationToken cancellationToken)
Mar 23 17:19:26 raspberrypi dotnet[2355527]:    at Npgsql.NpgsqlCommand.ExecuteReader(Boolean async, CommandBehavior behavior, CancellationToken cancellationToken)
Mar 23 17:19:26 raspberrypi dotnet[2355527]:    at Npgsql.NpgsqlCommand.ExecuteNonQuery(Boolean async, CancellationToken cancellationToken)
Mar 23 17:19:26 raspberrypi dotnet[2355527]:    at Microsoft.EntityFrameworkCore.Storage.RelationalCommand.ExecuteNonQueryAsync(RelationalCommandParameterObject parameterObject, CancellationToken cancellationToken)
Mar 23 17:19:26 raspberrypi dotnet[2355527]:    at Microsoft.EntityFrameworkCore.Storage.RelationalCommand.ExecuteNonQueryAsync(RelationalCommandParameterObject parameterObject, CancellationToken cancellationToken)
Mar 23 17:19:26 raspberrypi dotnet[2355527]:    at Microsoft.EntityFrameworkCore.Storage.RelationalCommand.ExecuteNonQueryAsync(RelationalCommandParameterObject parameterObject, CancellationToken cancellationToken)
Mar 23 17:19:26 raspberrypi dotnet[2355527]:    at Microsoft.EntityFrameworkCore.Migrations.Internal.Migrator.MigrateAsync(String targetMigration, CancellationToken cancellationToken)
Mar 23 17:19:26 raspberrypi dotnet[2355527]:    at Npgsql.EntityFrameworkCore.PostgreSQL.Migrations.Internal.NpgsqlMigrator.MigrateAsync(String targetMigration, CancellationToken cancellationToken)
Mar 23 17:19:26 raspberrypi dotnet[2355527]:    at BTCPayServer.Hosting.MigrationStartupTask.Migrate(CancellationToken cancellationToken) in /home/btcpay/btcpayserver/BTCPayServer/Hosting/MigrationStartupTask.cs:line 859
Mar 23 17:19:26 raspberrypi dotnet[2355527]:    at BTCPayServer.Hosting.MigrationStartupTask.ExecuteAsync(CancellationToken cancellationToken) in /home/btcpay/btcpayserver/BTCPayServer/Hosting/MigrationStartupTask.cs:line 85
Mar 23 17:19:26 raspberrypi dotnet[2355527]:    at Microsoft.AspNetCore.Hosting.WebHostExtensions.StartWithTasksAsync(IWebHost webHost, CancellationToken cancellationToken) in /home/btcpay/btcpayserver/BTCPayServer/Extensions/WebHostExtensions.cs:line 19
Mar 23 17:19:26 raspberrypi dotnet[2355527]:    at BTCPayServer.Program.Main(String[] args) in /home/btcpay/btcpayserver/BTCPayServer/Program.cs:line 76
Mar 23 17:19:26 raspberrypi dotnet[2355527]:    at BTCPayServer.Program.Main(String[] args) in /home/btcpay/btcpayserver/BTCPayServer/Program.cs:line 103
Mar 23 17:19:26 raspberrypi dotnet[2355527]:    at BTCPayServer.Program.<Main>(String[] args)
Mar 23 17:19:26 raspberrypi dotnet[2355527]:   Exception data:
Mar 23 17:19:26 raspberrypi dotnet[2355527]:     Severity: ERROR
Mar 23 17:19:26 raspberrypi dotnet[2355527]:     SqlState: 42501
Mar 23 17:19:26 raspberrypi dotnet[2355527]:     MessageText: permission denied for schema public
Mar 23 17:19:26 raspberrypi dotnet[2355527]:     Position: 14
Mar 23 17:19:26 raspberrypi dotnet[2355527]:     File: aclchk.c
Mar 23 17:19:26 raspberrypi dotnet[2355527]:     Line: 3650
Mar 23 17:19:26 raspberrypi dotnet[2355527]:     Routine: aclcheck_error
Mar 23 17:19:26 raspberrypi systemd[1]: btcpayserver.service: Main process exited, code=exited, status=134/n/a
Mar 23 17:19:26 raspberrypi systemd[1]: btcpayserver.service: Failed with result 'exit-code'.
Mar 23 17:19:26 raspberrypi systemd[1]: btcpayserver.service: Consumed 10.086s CPU time.

About this issue

Original URL
State: open
Created 3 months ago
Comments: 32

Most upvoted comments

The underlying problem was that postgres was installed and ran as an optional CLN dependency which created a new postgres cluster.

Reinstalling BTCPay ran the bonus.postgresql.sh on which restored the old cluster from the disk which now appeared corrupt.

Removing the corrupt cluster and reinstalling postgres with only the script solved the issue.

If you still have a copy of the /mnt/hdd/app-data/postgres dir (in a MIGRATION file for example) could copy it in in place on the disk and should be able to recover from that using the final v0.11.0 release image (expected tomorrow).

If have no old copy of the data might need to move the corrupt postgres directory away anyway to be able to start clean with the next refresh.

To move the old dir just run:

sudo systemctl stop postgresql
sudo mv /mnt/hdd/app-data/postgres `/mnt/hdd/app-data/postgres.backup

and reflash with the final image.

openoms on Mar 29, 2024

Not sure if wifi plays a role, might have a role in the corruption.

Unfortunately only nuking the whole postgres data have fixed the problem for me. Hope @kravens you did not have anything irreplaceable in btcpay as that database looks corrupted and probably needs a lot of effort to recover.

If you have LNbits or anything else using postgres make MIGRATION file backup and try the individual LNbits postgres backup from the menu (taht might not work as postgres is not running).

If you ok with starting a new one could test the fixed script from the PR:

# download
wget -O ~/config.scripts/bonus.postgresql.sh  ~/config.scripts/bonuhttps://raw.githubusercontent.com/raspiblitz/raspiblitz/b1c2e95ff54c094b2faaad2da8c8cdf1c29537fc/home.admin/config.scripts/bonus.postgresql.sh 

~/config.scripts/bonus.postgresql.sh off

take extra care and only use this on a test machine with no valuable data in postgres !!!This deletes all postgres databases, not just btcpayserver (remove the # from front)

# sudo pg_dropcluster 15 main

# install postgres again
~/config.scripts/bonus.postgresql.sh on

Now can reinstall btcpayserver to start clean.

openoms on Mar 28, 2024

I believe this node only used cable in the last 2 years. In very early configuration 2 hardware migrations before I might have used wifi with it that was later disabled in config file.

# Disable WiFi and Bluetooth
dtoverlay=disable-wifi
dtoverlay=disable-bt

kravens on Mar 28, 2024

@openoms I’m using only ethernet cable, I thought that I had wifi and bt disabled in the /boot/config.txt… but now I’m checking it turns out that file is not used and in /boot/firmware/config.txt I’m not explicitly disabling wifi or bluetooth! I’ll disable them and do a reboot to check what is going on then.

kravens on Mar 27, 2024

@kravens got this reproduced.

Comparing the databases between my rc4 update to RC5:

sudo -u postgres psql -d btcpaymainnet -l
                                                     List of databases
       Name       |  Owner   | Encoding |   Collate   |    Ctype    | ICU Locale | Locale Provider |   Access privileges   
------------------+----------+----------+-------------+-------------+------------+-----------------+-----------------------
 btcpaymainnet    | postgres | UTF8     | C           | C           |            | libc            | 
 lnbits_db        | postgres | UTF8     | en_GB.UTF-8 | en_GB.UTF-8 |            | libc            | 
 nbxplorermainnet | postgres | UTF8     | C           | C           |            | libc            | 
 postgres         | postgres | UTF8     | en_GB.UTF-8 | en_GB.UTF-8 |            | libc            | 
 template0        | postgres | UTF8     | en_GB.UTF-8 | en_GB.UTF-8 |            | libc            | =c/postgres          +
                  |          |          |             |             |            |                 | postgres=CTc/postgres
 template1        | postgres | UTF8     | en_GB.UTF-8 | en_GB.UTF-8 |            | libc            | =c/postgres          +
                  |          |          |             |             |            |                 | postgres=CTc/postgres
(6 rows)

vs a working instance:

       Name       |  Owner   | Encoding |   Collate   |    Ctype    | ICU Locale | Locale Provider |    Access privileges     
------------------+----------+----------+-------------+-------------+------------+-----------------+--------------------------
 btcpaymainnet    | postgres | UTF8     | en_US.UTF-8 | en_US.UTF-8 |            | libc            | =Tc/postgres            +
                  |          |          |             |             |            |                 | postgres=CTc/postgres   +
                  |          |          |             |             |            |                 | btcpay=CTc/postgres
 lnbits_db        | postgres | UTF8     | en_US.UTF-8 | en_US.UTF-8 |            | libc            | =Tc/postgres            +
                  |          |          |             |             |            |                 | postgres=CTc/postgres   +
                  |          |          |             |             |            |                 | lnbits_user=CTc/postgres
 nbxplorermainnet | postgres | UTF8     | C           | C           |            | libc            | =Tc/postgres            +
                  |          |          |             |             |            |                 | postgres=CTc/postgres   +
                  |          |          |             |             |            |                 | nbxplorer=CTc/postgres
 postgres         | postgres | UTF8     | en_US.UTF-8 | en_US.UTF-8 |            | libc            | 
 template0        | postgres | UTF8     | en_US.UTF-8 | en_US.UTF-8 |            | libc            | =c/postgres             +
                  |          |          |             |             |            |                 | postgres=CTc/postgres
 template1        | postgres | UTF8     | en_US.UTF-8 | en_US.UTF-8 |            | libc            | =c/postgres             +
                  |          |          |             |             |            |                 | postgres=CTc/postgres
(6 rows)

openoms on Mar 27, 2024