Crash with loading wallet async via RPC #14572

Describe the issue

Multiple RPC commands to loadwallet crashes daemon without any trace/log. In my implementation, a wallet is dynamically loaded and then released/unloaded at the end of request, the problem arises when 2 or more async requests are sent which calls loadwallet via RPC but daemon is crashed possibly because wallet is in process of being loaded and in meanwhile it receives another request to loadwallet again.

(RPC specifically because when working in stateless environments i.e. web based apps, users are able to send multiple requests without having to wait for previous requests to finish)

note: I have tested and attempted to debug using few methods to find whether crash occurs when requesting to load same wallet too quickly OR multiple wallets too quickly, and so far I merely think daemon crashes on same wallet but this information may not be reliable enough

Here are logs of successful op, loading wallets alternatively:

2018-10-25T14:37:50Z Using BerkeleyDB version Berkeley DB 4.8.30: (April 9, 2010) 2018-10-25T14:37:50Z Using wallet wallet.dat 2018-10-25T14:37:50Z init message: Loading wallet... 2018-10-25T14:37:50Z [wallet1] nFileVersion = 179900 2018-10-25T14:37:50Z [wallet1] Keys: 0 plaintext, 4035 encrypted, 4035 w/ metadata, 4035 total. Unknown wallet records: 1 2018-10-25T14:37:50Z [wallet1] Wallet completed loading in 45ms 2018-10-25T14:37:50Z [wallet1] setKeyPool.size() = 1999 2018-10-25T14:37:50Z [wallet1] mapWallet.size() = 15 2018-10-25T14:37:50Z [wallet1] mapAddressBook.size() = 34 2018-10-25T14:37:50Z [wallet1] Releasing wallet 2018-10-25T14:37:50Z Using BerkeleyDB version Berkeley DB 4.8.30: (April 9, 2010) 2018-10-25T14:37:50Z Using wallet wallet.dat 2018-10-25T14:37:50Z init message: Loading wallet... 2018-10-25T14:37:50Z [wallet2] nFileVersion = 170000 2018-10-25T14:37:50Z [wallet2] Keys: 0 plaintext, 4002 encrypted, 4002 w/ metadata, 4002 total. Unknown wallet records: 1 2018-10-25T14:37:50Z [wallet2] Wallet completed loading in 62ms 2018-10-25T14:37:50Z [wallet2] setKeyPool.size() = 2000 2018-10-25T14:37:50Z [wallet2] mapWallet.size() = 0 2018-10-25T14:37:50Z [wallet2] mapAddressBook.size() = 0 2018-10-25T14:37:50Z [wallet2] Releasing wallet 2018-10-25T14:37:50Z Using BerkeleyDB version Berkeley DB 4.8.30: (April 9, 2010) 2018-10-25T14:37:50Z Using wallet wallet.dat 2018-10-25T14:37:50Z init message: Loading wallet... 2018-10-25T14:37:50Z [wallet1] nFileVersion = 179900 2018-10-25T14:37:50Z [wallet1] Keys: 0 plaintext, 4035 encrypted, 4035 w/ metadata, 4035 total. Unknown wallet records: 1 2018-10-25T14:37:50Z [wallet1] Wallet completed loading in 77ms 2018-10-25T14:37:50Z [wallet1] setKeyPool.size() = 1999 2018-10-25T14:37:50Z [wallet1] mapWallet.size() = 15 2018-10-25T14:37:50Z [wallet1] mapAddressBook.size() = 34 2018-10-25T14:37:50Z [wallet1] Releasing wallet

please notice time stamps.

and here is log before crash, when I requests were send to load "a same" wallet

2018-10-25T14:40:22Z Using BerkeleyDB version Berkeley DB 4.8.30: (April 9, 2010) 2018-10-25T14:40:22Z Using wallet wallet.dat 2018-10-25T14:40:22Z init message: Loading wallet... 2018-10-25T14:40:22Z Using BerkeleyDB version Berkeley DB 4.8.30: (April 9, 2010) 2018-10-25T14:40:22Z Using wallet wallet.dat

crashed RIP

What behavior did you expect?

• Daemon to not crash and produce an error message via RPC so implementing apps can make necessary adjustments in their logic and flow

There is some prior discussion about this in another issue, starting at #14538 (comment)

I think even with recent fix #14320 for detecting attempts to load already loaded wallets, there are still going to be race conditions and crashes if clients are loading and unloading wallets simultaneously, because underlying code wasn't written to handle this and doesn't have appropriate locking.

I think incremental fixes are probably possible, but a more comprehensive fix might force all database accesses to go through the BerkeleyDatabase object instead of bypassing it with BerkeleyEnvironment objects and raw path arguments. I think this could be implemented by:

1. Changing Verify/Salvage/Recover methods that currently use raw paths and envs to take BerkeleyDatabase arguments instead, and constructing BerkeleyDatabase earlier before calling them.

2. Building on 9c945d011abde24f8649d877e694d392e1a5727e from #14552, and having BerkeleyDatabase constructor acquire cs_db before inserting itself into the global map, so it not possible to have a race condition that creates conflicting BerkeleyDatabase instances.

As follow-on cleanup, the changes to Verify/Salvage/Recover should also allow mapFileUseCount and m_fileids maps to be eliminated and replaced with BerkeleyDatabase data members.

I've changed test/functional/wallet_multiwallet.py to reproduce the crash with no success:

        while True:
            self.nodes[0].unloadwallet('w1')
            self.nodes[0].loadwallet('w1')

I've changed test/functional/wallet_multiwallet.py to reproduce the crash with no success:

        while True:
            self.nodes[0].unloadwallet('w1')
            self.nodes[0].loadwallet('w1')

I am not sure about this test but I am pretty sure it crashes when a request is sent to load a wallet while it is already in process of loading from a previous request

@furqansiddiqui you mean concurrent loadwallet calls? A quick fix is to prevent that, I can create a branch with that so you can test.

concurrent loadwallet calls is what it is I believe, yes please let me know when to test, which branch

@furqansiddiqui try this https://github.com/promag/bitcoin/tree/2010-10-loadunloadwallet

@furqansiddiqui ping.

I think #14941 fixed this.

@fanquake I think this can be closed. It is no longer possible to load a wallet if it didn't complete unload.