wallet: Reset BerkeleyDB handle after connection fails #13161

real-or-random · 2018-05-03T17:21:40Z

According to the BerkeleyDB docs, the DbEnv handle may not be accessed
after close() has been called. This change ensures that we create a new
handle after close() is called. This avoids a segfault when the first
connection attempt fails and then a second connection attempt tries to
call open() on the already closed DbEnv handle.

Without the patch, bitcoindd reliably crashes in the second call to set_lg_dir() after close() if
there is an issue with the database:

2018-05-03T13:27:21Z Bitcoin Core version v0.16.99.0-a024a1841-dirty (debug build)
[...]
2018-05-03T13:27:21Z Using wallet directory /home/tim/.bitcoin
2018-05-03T13:27:21Z init message: Verifying wallet(s)...
2018-05-03T13:27:21Z Using BerkeleyDB version Berkeley DB 4.8.30: (April  9, 2010)
2018-05-03T13:27:21Z Using wallet wallet.dat
2018-05-03T13:27:21Z BerkeleyEnvironment::Open: LogDir=/home/tim/.bitcoin/database 
2018-05-03T13:27:21Z BerkeleyEnvironment::Open: Error -30974 opening database environment: DB_RUNRECOVERY: Fatal error, run database recovery
2018-05-03T13:27:21Z Moved old /home/tim/.bitcoin/database to /home/tim/.bitcoin/database.1525354041.bak. Retrying.
2018-05-03T13:27:21Z BerkeleyEnvironment::Open: LogDir=/home/tim/.bitcoin/database ErrorFile=/home/tim/.bitcoin/db.log
[1]    14533 segmentation fault (core dumped)  ./src/bitcoind

After the fix:

2018-05-03T17:19:32Z Bitcoin Core version v0.16.99.0-cc09e3bd0-dirty (release build)
[...]
2018-05-03T17:19:32Z Using wallet directory /home/tim/.bitcoin
2018-05-03T17:19:32Z init message: Verifying wallet(s)...
2018-05-03T17:19:32Z Using BerkeleyDB version Berkeley DB 4.8.30: (April  9, 2010)
2018-05-03T17:19:32Z Using wallet wallet.dat
2018-05-03T17:19:32Z BerkeleyEnvironment::Open: LogDir=/home/tim/.bitcoin/database ErrorFile=/home/tim/.bitcoin/db.log
2018-05-03T17:19:32Z scheduler thread start
2018-05-03T17:19:32Z BerkeleyEnvironment::Open: Error -30974 opening database environment: DB_RUNRECOVERY: Fatal error, run database recovery
2018-05-03T17:19:32Z Moved old /home/tim/.bitcoin/database to /home/tim/.bitcoin/database.1525367972.bak. Retrying.
2018-05-03T17:19:32Z BerkeleyEnvironment::Open: LogDir=/home/tim/.bitcoin/database ErrorFile=/home/tim/.bitcoin/db.log
2018-05-03T17:19:32Z Cache configuration:
2018-05-03T17:19:32Z * Using 2.0MiB for block index database
2018-05-03T17:19:32Z * Using 8.0MiB for chain state database
2018-05-03T17:19:32Z * Using 440.0MiB for in-memory UTXO set (plus up to 286.1MiB of unused mempool space)
2018-05-03T17:19:32Z init message: Loading block index..
[...]

According to the BerkeleyDB docs, the DbEnv handle may not be accessed after close() has been called. This change ensures that we create a new handle after close() is called. This avoids a segfault when the first connection attempt fails and then a second connection attempt tries to call open() on the already closed DbEnv handle.

jamesob · 2018-05-03T18:38:35Z

utACK 264c643

Nice first contribution.

fanquake · 2018-05-04T03:30:38Z

Concept ACK.
@real-or-random What are you doing to simulate an issue with the database?

real-or-random · 2018-05-05T10:43:40Z

Oh it was not simulated, the error was real. The log file says

Unacceptable log file /home/tim/.bitcoin/database/log.0000000001: unsupported log version 19
Invalid log file: log.0000000001: Invalid argument
PANIC: Invalid argument
process-private: unable to find environment

(I guess the last line appeared only later after bitcoind moved away the database directory.)
Any idea what could be the reason for this? (I'm not claiming that this was due to normal usage, I was playing around.)

For testing, I can reliable reproduce the database issue by moving the old database directory back in place.

real-or-random · 2018-05-07T12:38:44Z

Not really related but I think I know what caused the database error: The wallet was initially created with the official Arch Linux version, which is configured --with-incompatible-bdb (I didn't know that), and then I tried to open the wallet with a version built against bdb 4.8.

ryanofsky · 2018-05-08T15:18:53Z

Would a simpler fix just be to drop the dbenv->close(0); line? Adding more initialization steps and resetting fDbEnvInit and fMockDb members would seem to make the retry code a little more convoluted than it needs to be. It also doesn't seem good that the close return value isn't checked and nothing is logged if it failed (also true before this PR).

I also wonder if we could add a unit test or functional test to exercise this code. One way could be to create a dummy pathIn / "database" file and checking to make sure it gets renamed to database.{time}.bak and the wallet still gets loaded successfully.

real-or-random · 2018-05-09T11:36:52Z

The documentation says we need the close():

If DbEnv::open() fails, the DbEnv::close() method must be called to discard the DbEnv handle.
(see https://docs.oracle.com/cd/E17275_01/html/api_reference/CXX/envopen.html)

I've added proper logging if the close() fails.

I'm not sure if a test is that helpful but I can certainly add one if people think it's a good idea.

ryanofsky

utACK b6f0b4d. Thanks for the fix!

sipa · 2018-05-09T17:20:59Z

Concept ACK

laanwj · 2018-05-14T13:06:28Z

utACK b6f0b4d

b6f0b4d wallet: Improve logging when BerkeleyDB environment fails to close (Tim Ruffing) 264c643 wallet: Reset BerkeleyDB handle after connection fails (Tim Ruffing) Pull request description: According to the BerkeleyDB docs, the DbEnv handle may not be accessed after close() has been called. This change ensures that we create a new handle after close() is called. This avoids a segfault when the first connection attempt fails and then a second connection attempt tries to call open() on the already closed DbEnv handle. Without the patch, bitcoindd reliably crashes in the second call to `set_lg_dir()` after `close()` if there is an issue with the database: ``` 2018-05-03T13:27:21Z Bitcoin Core version v0.16.99.0-a024a1841-dirty (debug build) [...] 2018-05-03T13:27:21Z Using wallet directory /home/tim/.bitcoin 2018-05-03T13:27:21Z init message: Verifying wallet(s)... 2018-05-03T13:27:21Z Using BerkeleyDB version Berkeley DB 4.8.30: (April 9, 2010) 2018-05-03T13:27:21Z Using wallet wallet.dat 2018-05-03T13:27:21Z BerkeleyEnvironment::Open: LogDir=/home/tim/.bitcoin/database 2018-05-03T13:27:21Z BerkeleyEnvironment::Open: Error -30974 opening database environment: DB_RUNRECOVERY: Fatal error, run database recovery 2018-05-03T13:27:21Z Moved old /home/tim/.bitcoin/database to /home/tim/.bitcoin/database.1525354041.bak. Retrying. 2018-05-03T13:27:21Z BerkeleyEnvironment::Open: LogDir=/home/tim/.bitcoin/database ErrorFile=/home/tim/.bitcoin/db.log [1] 14533 segmentation fault (core dumped) ./src/bitcoind ``` After the fix: ``` 2018-05-03T17:19:32Z Bitcoin Core version v0.16.99.0-cc09e3bd0-dirty (release build) [...] 2018-05-03T17:19:32Z Using wallet directory /home/tim/.bitcoin 2018-05-03T17:19:32Z init message: Verifying wallet(s)... 2018-05-03T17:19:32Z Using BerkeleyDB version Berkeley DB 4.8.30: (April 9, 2010) 2018-05-03T17:19:32Z Using wallet wallet.dat 2018-05-03T17:19:32Z BerkeleyEnvironment::Open: LogDir=/home/tim/.bitcoin/database ErrorFile=/home/tim/.bitcoin/db.log 2018-05-03T17:19:32Z scheduler thread start 2018-05-03T17:19:32Z BerkeleyEnvironment::Open: Error -30974 opening database environment: DB_RUNRECOVERY: Fatal error, run database recovery 2018-05-03T17:19:32Z Moved old /home/tim/.bitcoin/database to /home/tim/.bitcoin/database.1525367972.bak. Retrying. 2018-05-03T17:19:32Z BerkeleyEnvironment::Open: LogDir=/home/tim/.bitcoin/database ErrorFile=/home/tim/.bitcoin/db.log 2018-05-03T17:19:32Z Cache configuration: 2018-05-03T17:19:32Z * Using 2.0MiB for block index database 2018-05-03T17:19:32Z * Using 8.0MiB for chain state database 2018-05-03T17:19:32Z * Using 440.0MiB for in-memory UTXO set (plus up to 286.1MiB of unused mempool space) 2018-05-03T17:19:32Z init message: Loading block index.. [...] ``` Tree-SHA512: b809b318e5014ec47d023dc3dc40826b9706bfb211fa08bc2d29f36971b96caa10ad48d9a3f96c03933be46fa4ff7e00e952ac77bfffb6563767fb08aa4f23d6

hbxia · 2018-05-25T03:53:19Z

Hi Tim, I still meet the similar issue with the latest code (already has your fix):

2018-05-25T02:14:01Z HTTP: creating work queue of depth 16
2018-05-25T02:14:01Z No rpcpassword set - using random cookie authentication
2018-05-25T02:14:01Z Generated RPC authentication cookie /root/.bitcoin/.cookie
2018-05-25T02:14:01Z HTTP: starting 4 worker threads
2018-05-25T02:14:01Z Using wallet directory /root/.bitcoin/wallets
2018-05-25T02:14:01Z init message: Verifying wallet(s)...
2018-05-25T02:14:01Z Using BerkeleyDB version Berkeley DB 4.8.30: (April 9, 2010)
2018-05-25T02:14:01Z Using wallet wallet.dat
2018-05-25T02:14:01Z BerkeleyEnvironment::Open: LogDir=/root/.bitcoin/wallets/database ErrorFile=/root/.bitcoin/wallets/db.log
Segmentation fault

My server info:
Linux iZbp18y166co7d3pw5qf79Z 4.4.0-98-generic #121-Ubuntu SMP Tue Oct 10 14:24:03 UTC 2017 x86_64 x86_64 x86_64 GNU/Linux

BTW, official downloaded BIN bitcoind has no issue on my server, but manually build bitcoind.

Do you have any idea? or any build parameter needed?

Thanks

real-or-random · 2018-05-25T07:27:29Z

Hm, your problem should not be related to this pull request.

These are the build instructions:
https://github.com/bitcoin/bitcoin/blob/master/doc/build-unix.md#linux-distribution-specific-instructions
If you still encounter the problem, I'd recommend you to open a new issue and paste the contents of the ErrorFile as mentioned in the log.

hbxia · 2018-05-25T08:33:28Z

Tim, thanks for your info. My current work around is to disable wallet "./configure --disable-wallet", because I do not need it so far.

Summary: There was a bug discovered by the addition of D4255 affecting ASAN builds. See core issue: bitcoin/bitcoin#14163. The exact solution for this bug is unclear, but will likely require the backporting of at least the following PRs and their dependencies from Core: bitcoin/bitcoin#13161 bitcoin/bitcoin#12493 bitcoin/bitcoin#14320 bitcoin/bitcoin#14552 bitcoin/bitcoin#14760 bitcoin/bitcoin#11911 Suppression of the error is a temporary fix until the above backports are complete. This is the same approach that Core took. See https://github.com/bitcoin/bitcoin/pull/14794/files#diff-354f30a63fb0907d4ad57269548329e3R111 for the initial suppression and https://github.com/bitcoin/bitcoin/pull/15303/files#diff-354f30a63fb0907d4ad57269548329e3L128 for its removal. Test Plan: From the `build` dir: export ABC_BUILD_NAME=build-asan ../contrib/teamcity/build-configurations.sh ASAN build through TeamCity Reviewers: deadalnix, Fabien, jasonbcox, O1 Bitcoin ABC, #bitcoin_abc Reviewed By: Fabien, jasonbcox, O1 Bitcoin ABC, #bitcoin_abc Differential Revision: https://reviews.bitcoinabc.org/D4281

… fails b6f0b4d wallet: Improve logging when BerkeleyDB environment fails to close (Tim Ruffing) 264c643 wallet: Reset BerkeleyDB handle after connection fails (Tim Ruffing) Pull request description: According to the BerkeleyDB docs, the DbEnv handle may not be accessed after close() has been called. This change ensures that we create a new handle after close() is called. This avoids a segfault when the first connection attempt fails and then a second connection attempt tries to call open() on the already closed DbEnv handle. Without the patch, bitcoindd reliably crashes in the second call to `set_lg_dir()` after `close()` if there is an issue with the database: ``` 2018-05-03T13:27:21Z Bitcoin Core version v0.16.99.0-a024a1841-dirty (debug build) [...] 2018-05-03T13:27:21Z Using wallet directory /home/tim/.bitcoin 2018-05-03T13:27:21Z init message: Verifying wallet(s)... 2018-05-03T13:27:21Z Using BerkeleyDB version Berkeley DB 4.8.30: (April 9, 2010) 2018-05-03T13:27:21Z Using wallet wallet.dat 2018-05-03T13:27:21Z BerkeleyEnvironment::Open: LogDir=/home/tim/.bitcoin/database 2018-05-03T13:27:21Z BerkeleyEnvironment::Open: Error -30974 opening database environment: DB_RUNRECOVERY: Fatal error, run database recovery 2018-05-03T13:27:21Z Moved old /home/tim/.bitcoin/database to /home/tim/.bitcoin/database.1525354041.bak. Retrying. 2018-05-03T13:27:21Z BerkeleyEnvironment::Open: LogDir=/home/tim/.bitcoin/database ErrorFile=/home/tim/.bitcoin/db.log [1] 14533 segmentation fault (core dumped) ./src/bitcoind ``` After the fix: ``` 2018-05-03T17:19:32Z Bitcoin Core version v0.16.99.0-cc09e3bd0-dirty (release build) [...] 2018-05-03T17:19:32Z Using wallet directory /home/tim/.bitcoin 2018-05-03T17:19:32Z init message: Verifying wallet(s)... 2018-05-03T17:19:32Z Using BerkeleyDB version Berkeley DB 4.8.30: (April 9, 2010) 2018-05-03T17:19:32Z Using wallet wallet.dat 2018-05-03T17:19:32Z BerkeleyEnvironment::Open: LogDir=/home/tim/.bitcoin/database ErrorFile=/home/tim/.bitcoin/db.log 2018-05-03T17:19:32Z scheduler thread start 2018-05-03T17:19:32Z BerkeleyEnvironment::Open: Error -30974 opening database environment: DB_RUNRECOVERY: Fatal error, run database recovery 2018-05-03T17:19:32Z Moved old /home/tim/.bitcoin/database to /home/tim/.bitcoin/database.1525367972.bak. Retrying. 2018-05-03T17:19:32Z BerkeleyEnvironment::Open: LogDir=/home/tim/.bitcoin/database ErrorFile=/home/tim/.bitcoin/db.log 2018-05-03T17:19:32Z Cache configuration: 2018-05-03T17:19:32Z * Using 2.0MiB for block index database 2018-05-03T17:19:32Z * Using 8.0MiB for chain state database 2018-05-03T17:19:32Z * Using 440.0MiB for in-memory UTXO set (plus up to 286.1MiB of unused mempool space) 2018-05-03T17:19:32Z init message: Loading block index.. [...] ``` Tree-SHA512: b809b318e5014ec47d023dc3dc40826b9706bfb211fa08bc2d29f36971b96caa10ad48d9a3f96c03933be46fa4ff7e00e952ac77bfffb6563767fb08aa4f23d6

laanwj added the Wallet label May 3, 2018

wallet: Improve logging when BerkeleyDB environment fails to close

b6f0b4d

real-or-random force-pushed the bdb-reset branch from aec1c5f to b6f0b4d Compare May 9, 2018 13:23

ryanofsky reviewed May 9, 2018

View reviewed changes

laanwj merged commit b6f0b4d into bitcoin:master May 14, 2018

Bushstar mentioned this pull request May 16, 2018

commits from bitcoin/master FeatherCoin/Feathercoin#332

Merged

bitcoin locked as resolved and limited conversation to collaborators Sep 8, 2021

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Uh oh!

wallet: Reset BerkeleyDB handle after connection fails #13161

wallet: Reset BerkeleyDB handle after connection fails #13161

Uh oh!

real-or-random commented May 3, 2018

Uh oh!

jamesob commented May 3, 2018

Uh oh!

fanquake commented May 4, 2018

Uh oh!

real-or-random commented May 5, 2018 •

edited

Loading

Uh oh!

real-or-random commented May 7, 2018

Uh oh!

ryanofsky commented May 8, 2018

Uh oh!

real-or-random commented May 9, 2018

Uh oh!

ryanofsky left a comment

Uh oh!

sipa commented May 9, 2018

Uh oh!

laanwj commented May 14, 2018

Uh oh!

hbxia commented May 25, 2018 •

edited

Loading

Uh oh!

real-or-random commented May 25, 2018

Uh oh!

hbxia commented May 25, 2018

Uh oh!

Uh oh!

wallet: Reset BerkeleyDB handle after connection fails #13161

wallet: Reset BerkeleyDB handle after connection fails #13161

Uh oh!

Conversation

real-or-random commented May 3, 2018

Uh oh!

jamesob commented May 3, 2018

Uh oh!

fanquake commented May 4, 2018

Uh oh!

real-or-random commented May 5, 2018 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

real-or-random commented May 7, 2018

Uh oh!

ryanofsky commented May 8, 2018

Uh oh!

real-or-random commented May 9, 2018

Uh oh!

ryanofsky left a comment

Choose a reason for hiding this comment

Uh oh!

sipa commented May 9, 2018

Uh oh!

laanwj commented May 14, 2018

Uh oh!

hbxia commented May 25, 2018 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

real-or-random commented May 25, 2018

Uh oh!

hbxia commented May 25, 2018

Uh oh!

Uh oh!

real-or-random commented May 5, 2018 •

edited

Loading

hbxia commented May 25, 2018 •

edited

Loading