bitcoin: scheduler: crash after releasing wallet

From what I can tell, I’ve tracked down the cause of this crash.

A call to CWallet::BlockConnected while we are in wallet->Flush() phase of ReleaseWallet gives the scheduler the cs_wallet lock. We then loop calling SyncTransaction -> AddToWalletIfInvolvingMe which also calls AssertLockHeld(cs_wallet);. At some point we’ll be done flushing, and call delete wallet, which blows up as we are trying to delete cs_wallet which is still being held in the scheduler thread.

You can cause this crash running src/bitcoind and a Python script that is essentially:

while 1:
    rpc.unloadwallet('test')
    rpc.unloadwallet('test2')
    rpc.loadwallet('test')
    rpc.loadwallet('test2')

debug.log

2020-02-21T06:47:47.281600Z [scheduler] [test] SCHED: bool CWallet::AddToWalletIfInvolvingMe(const CTransactionRef &, CWalletTx::Confirmation, bool)
2020-02-21T06:47:47.281738Z [scheduler] [test] SCHED: bool CWallet::AddToWalletIfInvolvingMe(const CTransactionRef &, CWalletTx::Confirmation, bool)
2020-02-21T06:47:47.281919Z [scheduler] [test] SCHED: bool CWallet::AddToWalletIfInvolvingMe(const CTransactionRef &, CWalletTx::Confirmation, bool)
2020-02-21T06:47:47.289817Z [httpworker.3] BerkeleyEnvironment::Flush: wallet.dat closed
2020-02-21T06:47:47.289912Z [msghand] received: inv (541 bytes) peer=4
2020-02-21T06:47:47.290027Z [scheduler] [test] SCHED: bool CWallet::AddToWalletIfInvolvingMe(const CTransactionRef &, CWalletTx::Confirmation, bool)
2020-02-21T06:47:47.290102Z [httpworker.3] BerkeleyEnvironment::Flush: Flush(false) took              43ms
2020-02-21T06:47:47.290204Z [scheduler] [test] SCHED: bool CWallet::AddToWalletIfInvolvingMe(const CTransactionRef &, CWalletTx::Confirmation, bool)
Assertion failed: (e == 0), function ~recursive_mutex, file /BuildRoot/Library/Caches/com.apple.xbs/Sources/libcxx/libcxx-400.9.4/src/mutex.cpp, line 64.
Process 72347 stopped
* thread #2, name = 'b-httpworker.3', stop reason = signal SIGABRT
    frame #0: 0x00007fff5c4182c2 libsystem_kernel.dylib`__pthread_kill + 10
libsystem_kernel.dylib`__pthread_kill:
->  0x7fff5c4182c2 <+10>: jae    0x7fff5c4182cc            ; <+20>
    0x7fff5c4182c4 <+12>: movq   %rax, %rdi
    0x7fff5c4182c7 <+15>: jmp    0x7fff5c412453            ; cerror_nocancel
    0x7fff5c4182cc <+20>: retq   
Target 0: (bitcoind) stopped.

httpworker (unloadwallet) thread

(AnnotatedMixin<std::__1::recursive_mutex> *) this = 0x000000015b7ccf98

(lldb) frame select 6
frame #6: 0x00000001000aa6f3 bitcoind`AnnotatedMixin<std::__1::recursive_mutex>::~AnnotatedMixin(this=0x000000015b7ccf98) at sync.h:82:23
  79  	class LOCKABLE AnnotatedMixin : public PARENT
  80  	{
  81  	public:
-> 82  	    ~AnnotatedMixin() {
  83  	        DeleteLock((void*)this);
  84  	    }
  85  	

(lldb) frame select 7
frame #7: 0x00000001007d9ea0 bitcoind`CWallet::~CWallet(this=0x000000015b7cce20) at wallet.h:758:5
  755 	    {
  756 	        // Should not have slots connected at this point.
  757 	        assert(NotifyUnload.empty());
-> 758 	    }
  759 	
  760 	    bool IsCrypted() const;
  761 	    bool IsLocked() const override;
(lldb) frame select 8
frame #8: 0x00000001007c4373 bitcoind`CWallet::~CWallet(this=0x000000015b7cce20) at wallet.h:755:5
  752 	    }
  753 	
  754 	    ~CWallet()
-> 755 	    {
  756 	        // Should not have slots connected at this point.
  757 	        assert(NotifyUnload.empty());
  758 	    }

scheduler thread (10)

// in frame 14
frame variable criticalblock27
(DebugLock<decltype(this->cs_wallet)>) criticalblock27 = {
 std::__1::unique_lock<std::__1::recursive_mutex> = {
   __m_ = 0x000000015b7ccf98
   __owns_ = true
 }
}



(lldb) frame select 12
frame #12: 0x00000001007a76b3 bitcoind`CWallet::AddToWalletIfInvolvingMe(this=0x000000015b7cce20, ptx=std::__1::shared_ptr<const CTransaction>::element_type @ 0x000000015c6c3908 strong=1 weak=1, confirm=Confirmation @ 0x0000700007d2ab70, fUpdate=true) at wallet.cpp:914:9
  911 	{
  912 	    const CTransaction& tx = *ptx;
  913 	    {
-> 914 	        WalletLogPrintf("SCHED: %s\n", __PRETTY_FUNCTION__);
  915 	        // This assertion fails?
  916 	        AssertLockHeld(cs_wallet);
  917
(lldb) frame select 13
frame #13: 0x00000001007a91ca bitcoind`CWallet::SyncTransaction(this=0x000000015b7cce20, ptx=std::__1::shared_ptr<const CTransaction>::element_type @ 0x000000015c6c3908 strong=1 weak=1, confirm=Confirmation @ 0x0000700007d2ac10, update_tx=true) at wallet.cpp:1089:10
  1086	void CWallet::SyncTransaction(const CTransactionRef& ptx, CWalletTx::Confirmation confirm, bool update_tx)
  1087	{
  1088	    //WalletLogPrintf("SCHED: %s\n", __PRETTY_FUNCTION__);
-> 1089	    if (!AddToWalletIfInvolvingMe(ptx, confirm, update_tx))
  1090	        return; // Not one of ours
  1091	
  1092	    // If a transaction changes 'conflicted' state, that changes the balance
(lldb) frame variable cs_wallet
(RecursiveMutex) cs_wallet = {
 std::__1::recursive_mutex = {
   __m_ = (__sig = 1297437784, __opaque = "")
 }
}
(lldb) frame select 14
frame #14: 0x00000001007a99f2 bitcoind`CWallet::BlockConnected(this=0x000000015b7cce20, block=0x000000015c765d28, vtxConflicted=size=0, height=351323) at wallet.cpp:1129:9
  1126	    m_last_block_processed = block_hash;
  1127	    for (size_t index = 0; index < block.vtx.size(); index++) {
  1128	        CWalletTx::Confirmation confirm(CWalletTx::Status::CONFIRMED, height, block_hash, index);
-> 1129	        SyncTransaction(block.vtx[index], confirm);
  1130	        TransactionRemovedFromMempool(block.vtx[index]);
  1131	    }
  1132	    for (const CTransactionRef& ptx : vtxConflicted) {
(lldb) frame variable cs_wallet
(RecursiveMutex) cs_wallet = {
 std::__1::recursive_mutex = {
   __m_ = (__sig = 1297437784, __opaque = "")
 }
}
(lldb) frame select 15
frame #15: 0x00000001007a9bb2 bitcoind`non-virtual thunk to CWallet::BlockConnected(this=0x000000015b7cce20, block=0x000000015c765d28, vtxConflicted=size=0, height=351323) at wallet.cpp:0
  1   	// Copyright (c) 2009-2010 Satoshi Nakamoto
  2   	// Copyright (c) 2009-2020 The Bitcoin Core developers
  3   	// Distributed under the MIT software license, see the accompanying
  4   	// file COPYING or http://www.opensource.org/licenses/mit-license.php.
  5   	
  6   	#include <wallet/wallet.h>
  7   	
(lldb) frame variable cs_wallet
error: no variable named 'cs_wallet' found in this frame

httpworker (unloadwallet) bt

* thread #2, name = 'b-httpworker.3', stop reason = signal SIGABRT
    frame #0: 0x00007fff5c4182c2 libsystem_kernel.dylib`__pthread_kill + 10
    frame #1: 0x00007fff5c4d3bf1 libsystem_pthread.dylib`pthread_kill + 284
    frame #2: 0x00007fff5c3826a6 libsystem_c.dylib`abort + 127
    frame #3: 0x00007fff5c34b20d libsystem_c.dylib`__assert_rtn + 324
    frame #4: 0x00007fff59543092 libc++.1.dylib`std::__1::recursive_mutex::~recursive_mutex() + 46
    frame #5: 0x00000001000f1edb bitcoind`AnnotatedMixin<std::__1::recursive_mutex>::~AnnotatedMixin(this=0x000000015b7ccf98) at sync.h:84:5
  * frame #6: 0x00000001000aa6f3 bitcoind`AnnotatedMixin<std::__1::recursive_mutex>::~AnnotatedMixin(this=0x000000015b7ccf98) at sync.h:82:23
    frame #7: 0x00000001007d9ea0 bitcoind`CWallet::~CWallet(this=0x000000015b7cce20) at wallet.h:758:5
    frame #8: 0x00000001007c4373 bitcoind`CWallet::~CWallet(this=0x000000015b7cce20) at wallet.h:755:5
    frame #9: 0x00000001007c703a bitcoind`CWallet::~CWallet(this=0x000000015b7cce20) at wallet.h:755:5
    frame #10: 0x00000001007c4691 bitcoind`ReleaseWallet(wallet=0x000000015b7cce20) at wallet.cpp:117:5
    frame #11: 0x000000010083115e bitcoind`std::__1::__shared_ptr_pointer<CWallet*, void (*)(CWallet*), std::__1::allocator<CWallet> >::__on_zero_shared(this=0x00000001577e76c0) at memory:3511:5
    frame #12: 0x00000001000ebd1b bitcoind`std::__1::__shared_count::__release_shared(this=0x00000001577e76c0) at memory:3415:9
    frame #13: 0x00000001000ebc8d bitcoind`std::__1::__shared_weak_count::__release_shared(this=0x00000001577e76c0) at memory:3457:27
    frame #14: 0x000000010065a49a bitcoind`std::__1::shared_ptr<CWallet>::~shared_ptr(this=0x0000700007fb9738) at memory:4393:19
    frame #15: 0x000000010065a3f3 bitcoind`std::__1::shared_ptr<CWallet>::~shared_ptr(this=0x0000700007fb9738) at memory:4391:1
    frame #16: 0x0000000100797521 bitcoind`std::__1::shared_ptr<CWallet>::reset(this=0x0000700007fb9938) at memory:4528:5
    frame #17: 0x000000010079740e bitcoind`UnloadWallet(wallet=nullptr) at wallet.cpp:143:12
    frame #18: 0x000000010074f1e2 bitcoind`unloadwallet(request=0x0000700007fba990) at rpcwallet.cpp:2779:5

scheduler thread bt

* thread #10, name = 'b-scheduler'
    frame #0: 0x00007fff5c489799 libsystem_malloc.dylib`tiny_malloc_should_clear + 1176
    frame #1: 0x00007fff5c48920f libsystem_malloc.dylib`szone_malloc_should_clear + 66
    frame #2: 0x00007fff5c487c99 libsystem_malloc.dylib`malloc_zone_malloc + 103
    frame #3: 0x00007fff5c487c15 libsystem_malloc.dylib`malloc + 24
    frame #4: 0x00007fff5955b378 libc++abi.dylib`operator new(unsigned long) + 40
    frame #5: 0x00007fff59509521 libc++.1.dylib`std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >::__grow_by(unsigned long, unsigned long, unsigned long, unsigned long, unsigned long, unsigned long) + 141
    frame #6: 0x00007fff5950a3d7 libc++.1.dylib`std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >::push_back(char) + 85
    frame #7: 0x0000000100a29562 bitcoind`std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >::operator+=(this="[test] SCHED: bool CWa", __c='l') at string:992:84
    frame #8: 0x000000010099eccc bitcoind`BCLog::LogEscapeMessage(str="[test] SCHED: bool CWallet::AddToWalletIfInvolvingMe(const CTransactionRef &, CWalletTx::Confirmation, bool)\n") at logging.cpp:253:21
    frame #9: 0x000000010099eef1 bitcoind`BCLog::Logger::LogPrintStr(this=0x0000000103300000, str="[test] SCHED: bool CWallet::AddToWalletIfInvolvingMe(const CTransactionRef &, CWalletTx::Confirmation, bool)\n") at logging.cpp:265:32
    frame #10: 0x00000001007f7c86 bitcoind`void LogPrintf<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >, char const*>(fmt="%s SCHED: %s\n", args="[test]", args=0x0000700007d2a790) at logging.h:173:23
    frame #11: 0x00000001007a7e5e bitcoind`void CWallet::WalletLogPrintf<char const*>(this=0x000000015b7cce20, fmt="SCHED: %s\n", parameters="bool CWallet::AddToWalletIfInvolvingMe(const CTransactionRef &, CWalletTx::Confirmation, bool)") const at wallet.h:1139:9
  * frame #12: 0x00000001007a76b3 bitcoind`CWallet::AddToWalletIfInvolvingMe(this=0x000000015b7cce20, ptx=std::__1::shared_ptr<const CTransaction>::element_type @ 0x000000015c6c3908 strong=1 weak=1, confirm=Confirmation @ 0x0000700007d2ab70, fUpdate=true) at wallet.cpp:914:9
    frame #13: 0x00000001007a91ca bitcoind`CWallet::SyncTransaction(this=0x000000015b7cce20, ptx=std::__1::shared_ptr<const CTransaction>::element_type @ 0x000000015c6c3908 strong=1 weak=1, confirm=Confirmation @ 0x0000700007d2ac10, update_tx=true) at wallet.cpp:1089:10
    frame #14: 0x00000001007a99f2 bitcoind`CWallet::BlockConnected(this=0x000000015b7cce20, block=0x000000015c765d28, vtxConflicted=size=0, height=351323) at wallet.cpp:1129:9
    frame #15: 0x00000001007a9bb2 bitcoind`non-virtual thunk to CWallet::BlockConnected(this=0x000000015b7cce20, block=0x000000015c765d28, vtxConflicted=size=0, height=351323) at wallet.cpp:0
    frame #16: 0x00000001000a1e2e bitcoind`interfaces::(anonymous namespace)::NotificationsHandlerImpl::BlockConnected(this=0x00000001190f2ec0, block=std::__1::shared_ptr<const CBlock>::element_type @ 0x000000015c765d28 strong=2 weak=1, index=0x000000011309fd20, tx_conflicted=size=0) at chain.cpp:179:26
    frame #17: 0x00000001000a2114 bitcoind`non-virtual thunk to interfaces::(anonymous namespace)::NotificationsHandlerImpl::BlockConnected(this=0x00000001190f2ec8, block=std::__1::shared_ptr<const CBlock>::element_type @ 0x000000015c765d28 strong=2 weak=1, index=0x000000011309fd20, tx_conflicted=size=0) at chain.cpp:0

I’ve put together an AppleScript that can reproduce this issue fairly easily. It only requires a syncing Bitcoin-Core and creating a wallet named “test”.

tell application "System Events" to tell process "Bitcoin Core"
	-- sane window location and size
	set position of window 1 to {0, 20}
	set size of window 1 to {500, 500}
	set frontmost to true
	
	repeat
		click menu item "Close Wallet..." of menu "File" of menu bar 1
		click button "Yes" of group 1 of window 1
		delay 0.2
		click menu item "Close Wallet..." of menu "File" of menu bar 1
		click button "Yes" of group 1 of window 1
		delay 0.2
		click menu item "[default wallet]" of menu "Open Wallet" of menu item "Open Wallet" of menu "File" of menu bar 1
		delay 0.2
		click menu item "test" of menu "Open Wallet" of menu item "Open Wallet" of menu "File" of menu bar 1
		delay 0.2
	end repeat
end tell

cc @promag.