Skip to content

wallet: Reset BerkeleyDB handle after connection fails#13161

Merged
laanwj merged 2 commits intobitcoin:masterfrom
real-or-random:bdb-reset
May 14, 2018
Merged

wallet: Reset BerkeleyDB handle after connection fails#13161
laanwj merged 2 commits intobitcoin:masterfrom
real-or-random:bdb-reset

Conversation

@real-or-random
Copy link
Contributor

@real-or-random real-or-random commented May 3, 2018

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..
[...]

@real-or-random
wallet: Reset BerkeleyDB handle after connection fails
264c643 
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
Copy link
Contributor

jamesob commented May 3, 2018

utACK 264c643

Nice first contribution.

@laanwj laanwj added the Wallet label May 3, 2018
@fanquake
Copy link
Member

fanquake commented May 4, 2018

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

@real-or-random
Copy link
Contributor Author

real-or-random commented May 5, 2018 •
edited
Loading

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
Copy link
Contributor Author

real-or-random commented May 7, 2018

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
Copy link
Contributor

ryanofsky commented May 8, 2018

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
Copy link
Contributor Author

real-or-random commented May 9, 2018

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
ryanofsky reviewed May 9, 2018
View reviewed changes
Copy link
Contributor

@ryanofsky ryanofsky left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

utACK b6f0b4d. Thanks for the fix!

@sipa
Copy link
Member

sipa commented May 9, 2018

Concept ACK

@laanwj
Copy link
Member

laanwj commented May 14, 2018

utACK b6f0b4d

@laanwj laanwj merged commit b6f0b4d into bitcoin:master May 14, 2018
laanwj added a commit that referenced this pull request May 14, 2018
@laanwj
Merge #13161: wallet: Reset BerkeleyDB handle after connection fails
7cc1bd3 
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
@Bushstar Bushstar mentioned this pull request May 16, 2018
Merged
@hbxia
Copy link

hbxia commented May 25, 2018 •
edited
Loading

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
Copy link
Contributor Author

real-or-random commented May 25, 2018

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
Copy link

hbxia commented May 25, 2018

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

jasonbcox pushed a commit to Bitcoin-ABC/bitcoin-abc that referenced this pull request Oct 25, 2019
Add test_runner flag to suppress ASAN errors from wallet_multiwallet.py
8915b2f 
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
PastaPastaPasta pushed a commit to PastaPastaPasta/dash that referenced this pull request Jun 29, 2020
@laanwj @PastaPastaPasta
Merge bitcoin#13161: wallet: Reset BerkeleyDB handle after connection…
5b873eb 
… 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
@bitcoin bitcoin locked as resolved and limited conversation to collaborators Sep 8, 2021
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.

Reviewers

@ryanofsky ryanofsky ryanofsky left review comments

Assignees

No one assigned

Labels

Wallet

Projects

None yet

Milestone

No milestone

Development

Successfully merging this pull request may close these issues.

7 participants

@real-or-random @jamesob @fanquake @ryanofsky @sipa @laanwj @hbxia