IPC crash with client disconnecting during IPC call

[ryanofsky]

bitcoin/bitcoin#32345 fixes different bitcoin-node crashes during shutdown when IPC connections are not terminated cleanly (either disconnected or unresponsive), letting the node shut down cleanly without blocking in all cases.

But testing bitcoin/bitcoin#32345 in combination with bitcoin/bitcoin#29409 and a custom client that connects and disconnects in a loop @darosior found another crash that seems to happen when a client disconnects in the middle of an IPC call apparently because an assumption in the ~Connection destructor is violated:

libmultiprocess/src/mp/proxy.cpp

Lines 53 to 57 in 27c7e8e

	// Shut down RPC system first, since this will garbage collect Server
	// objects that were not freed before the connection was closed, some of
	// which may call addAsyncCleanup and add more cleanup callbacks which can
	// run below.
	m_rpc_system.reset();

that cap'n proto will garbage collect server objects right away when the canp::RpcSystem is destroyed.

Apparently this does not happen if an asynchronous call is currently in progress.

I was able to reproduce the problem with ryanofsky/bitcoin@87b2ae6 (tag) and I think the fix will probably require the Connection refcounting described #176 (comment) that I started implementing but abandoned later #176 (comment) because it didn't seem necessary.

[ryanofsky]

Other information from @darosior:

log

2025-06-10T13:46:38Z [ipc] {bitcoin-node-2129701/b-capnp-loop-2129703} IPC server recv request  #28647 Init.construct$Params ()
2025-06-10T13:46:38Z [ipc] {bitcoin-node-2129701/b-capnp-loop-2129703} IPC server send response #28647 Init.construct$Results (threadMap = <external capability>)
2025-06-10T13:46:38Z [ipc] {bitcoin-node-2129701/b-capnp-loop-2129703} IPC server recv request  #28648 Init.makeChain$Params (context = (thread = <external capability>))
2025-06-10T13:46:38Z [ipc] {bitcoin-node-2129701/b-capnp-loop-2129703} IPC server post request  #28648 {bitcoin-node-2129701/b-capnp-loop-2167998 (from )}
2025-06-10T13:46:38Z [ipc] {bitcoin-node-2129701/b-capnp-loop-2129703} IPC server send response #28648 Init.makeChain$Results (result = <external capability>)
2025-06-10T13:46:38Z [ipc] {bitcoin-node-2129701/b-capnp-loop-2129703} IPC server recv request  #28649 Chain.initMessage$Params (context = (thread = <external capability>), message = "Oxydation of the Bitcoin Core wallet in progress..")
2025-06-10T13:46:38Z [ipc] {bitcoin-node-2129701/b-capnp-loop-2129703} IPC server post request  #28649 {bitcoin-node-2129701/b-capnp-loop-2167998 (from )}
2025-06-10T13:46:38Z init message: Oxydation of the Bitcoin Core wallet in progress..
2025-06-10T13:46:38Z [ipc] {bitcoin-node-2129701/b-capnp-loop-2129703} IPC server send response #28649 Chain.initMessage$Results ()
2025-06-10T13:46:38Z [ipc] {bitcoin-node-2129701/b-capnp-loop-2129703} IPC server destroy N2mp11ProxyServerIN3ipc5capnp8messages5ChainEEE
2025-06-10T13:46:38Z [ipc] {bitcoin-node-2129701/b-capnp-loop-2129703} IPC server: socket disconnected.
2025-06-10T13:46:38Z [ipc] {bitcoin-node-2129701/b-capnp-loop-2129703} IPC server destroy N2mp11ProxyServerIN3ipc5capnp8messages4InitEEE
2025-06-10T13:46:38Z [ipc] {bitcoin-node-2129701/b-capnp-loop-2129703} IPC server recv request  #28650 Init.construct$Params ()
2025-06-10T13:46:38Z [ipc] {bitcoin-node-2129701/b-capnp-loop-2129703} IPC server send response #28650 Init.construct$Results (threadMap = <external capability>)
2025-06-10T13:46:38Z [ipc] {bitcoin-node-2129701/b-capnp-loop-2129703} IPC server recv request  #28651 Init.makeChain$Params (context = (thread = <external capability>))
2025-06-10T13:46:38Z [ipc] {bitcoin-node-2129701/b-capnp-loop-2129703} IPC server post request  #28651 {bitcoin-node-2129701/b-capnp-loop-2168002 (from )}
2025-06-10T13:46:38Z [ipc] {bitcoin-node-2129701/b-capnp-loop-2129703} IPC server send response #28651 Init.makeChain$Results (result = <external capability>)
2025-06-10T13:46:38Z [ipc] {bitcoin-node-2129701/b-capnp-loop-2129703} IPC server recv request  #28652 Chain.initMessage$Params (context = (thread = <external capability>), message = "Oxydation of the Bitcoin Core wallet in progress..")
2025-06-10T13:46:38Z [ipc] {bitcoin-node-2129701/b-capnp-loop-2129703} IPC server post request  #28652 {bitcoin-node-2129701/b-capnp-loop-2168002 (from )}
2025-06-10T13:46:38Z init message: Oxydation of the Bitcoin Core wallet in progress..
2025-06-10T13:46:38Z [ipc] {bitcoin-node-2129701/b-capnp-loop-2129703} IPC server send response #28652 Chain.initMessage$Results ()
2025-06-10T13:46:38Z [ipc] {bitcoin-node-2129701/b-capnp-loop-2129703} IPC server destroy N2mp11ProxyServerIN3ipc5capnp8messages5ChainEEE
2025-06-10T13:46:38Z [ipc] {bitcoin-node-2129701/b-capnp-loop-2129703} IPC server: socket disconnected.
2025-06-10T13:46:38Z [ipc] {bitcoin-node-2129701/b-capnp-loop-2129703} IPC server destroy N2mp11ProxyServerIN3ipc5capnp8messages4InitEEE
2025-06-10T13:46:38Z [ipc] {bitcoin-node-2129701/b-capnp-loop-2129703} IPC server recv request  #28653 Init.construct$Params ()
2025-06-10T13:46:38Z [ipc] {bitcoin-node-2129701/b-capnp-loop-2129703} IPC server send response #28653 Init.construct$Results (threadMap = <external capability>)
2025-06-10T13:46:38Z [ipc] {bitcoin-node-2129701/b-capnp-loop-2129703} IPC server recv request  #28654 Init.makeChain$Params (context = (thread = <external capability>))
2025-06-10T13:46:38Z [ipc] {bitcoin-node-2129701/b-capnp-loop-2129703} IPC server post request  #28654 {bitcoin-node-2129701/b-capnp-loop-2168006 (from )}
2025-06-10T13:46:38Z [ipc] {bitcoin-node-2129701/b-capnp-loop-2129703} IPC server send response #28654 Init.makeChain$Results (result = <external capability>)
2025-06-10T13:46:38Z [ipc] {bitcoin-node-2129701/b-capnp-loop-2129703} IPC server recv request  #28655 Chain.initMessage$Params (context = (thread = <external capability>), message = "Oxydation of the Bitcoin Core wallet in progress..")
2025-06-10T13:46:38Z [ipc] {bitcoin-node-2129701/b-capnp-loop-2129703} IPC server post request  #28655 {bitcoin-node-2129701/b-capnp-loop-2168006 (from )}
2025-06-10T13:46:38Z init message: Oxydation of the Bitcoin Core wallet in progress..
2025-06-10T13:46:38Z [ipc] {bitcoin-node-2129701/b-capnp-loop-2129703} IPC server send response #28655 Chain.initMessage$Results ()
2025-06-10T13:46:38Z [ipc] {bitcoin-node-2129701/b-capnp-loop-2129703} IPC server destroy N2mp11ProxyServerIN3ipc5capnp8messages5ChainEEE
2025-06-10T13:46:38Z [ipc] {bitcoin-node-2129701/b-capnp-loop-2129703} IPC server: socket disconnected.
2025-06-10T13:46:38Z [ipc] {bitcoin-node-2129701/b-capnp-loop-2129703} IPC server destroy N2mp11ProxyServerIN3ipc5capnp8messages4InitEEE
2025-06-10T13:46:38Z [ipc] {bitcoin-node-2129701/b-capnp-loop-2129703} IPC server recv request  #28656 Init.construct$Params ()
2025-06-10T13:46:38Z [ipc] {bitcoin-node-2129701/b-capnp-loop-2129703} IPC server send response #28656 Init.construct$Results (threadMap = <external capability>)
2025-06-10T13:46:38Z [ipc] {bitcoin-node-2129701/b-capnp-loop-2129703} IPC server recv request  #28657 Init.makeChain$Params (context = (thread = <external capability>))
2025-06-10T13:46:38Z [ipc] {bitcoin-node-2129701/b-capnp-loop-2129703} IPC server post request  #28657 {bitcoin-node-2129701/b-capnp-loop-2168010 (from )}
2025-06-10T13:46:38Z [ipc] {bitcoin-node-2129701/b-capnp-loop-2129703} IPC server: socket disconnected.
bitcoin-node: ./ipc/libmultiprocess/include/mp/proxy.h:63: mp::EventLoop& mp::EventLoopRef::operator*() const: Assertion `m_loop' failed.
Aborted

log + stack trace

2025-06-10T14:16:01Z [ipc] {bitcoin-node-2177791/b-capnp-loop-2177793} IPC server recv request  #1885 Init.construct$Params ()
2025-06-10T14:16:01Z [ipc] {bitcoin-node-2177791/b-capnp-loop-2177793} IPC server send response #1885 Init.construct$Results (threadMap = <external capability>)
2025-06-10T14:16:01Z [ipc] {bitcoin-node-2177791/b-capnp-loop-2177793} IPC server recv request  #1886 Init.makeChain$Params (context = (thread = <external capability>))
2025-06-10T14:16:01Z [ipc] {bitcoin-node-2177791/b-capnp-loop-2177793} IPC server post request  #1886 {bitcoin-node-2177791/b-capnp-loop-2180334 (from )}
2025-06-10T14:16:01Z [ipc] {bitcoin-node-2177791/b-capnp-loop-2177793} IPC server send response #1886 Init.makeChain$Results (result = <external capability>)
2025-06-10T14:16:01Z [ipc] {bitcoin-node-2177791/b-capnp-loop-2177793} IPC server recv request  #1887 Chain.initMessage$Params (context = (thread = <external capability>), message = "Oxydation of the Bitcoin Core wallet in progress..")
2025-06-10T14:16:01Z [ipc] {bitcoin-node-2177791/b-capnp-loop-2177793} IPC server post request  #1887 {bitcoin-node-2177791/b-capnp-loop-2180334 (from )}
2025-06-10T14:16:01Z init message: Oxydation of the Bitcoin Core wallet in progress..
2025-06-10T14:16:01Z [ipc] {bitcoin-node-2177791/b-capnp-loop-2177793} IPC server: socket disconnected.
2025-06-10T14:16:01Z [ipc] {bitcoin-node-2177791/b-capnp-loop-2177793} IPC server destroy N2mp11ProxyServerIN3ipc5capnp8messages4InitEEE
2025-06-10T14:16:01Z [ipc] {bitcoin-node-2177791/b-capnp-loop-2177793} IPC server send response #1887 Chain.initMessage$Results ()
2025-06-10T14:16:01Z [ipc] {bitcoin-node-2177791/b-capnp-loop-2177793} IPC server destroy N2mp11ProxyServerIN3ipc5capnp8messages5ChainEEE
=================================================================
==2177791==ERROR: AddressSanitizer: heap-use-after-free on address 0x619000145090 at pc 0x55e3f7305d91 bp 0x7ffa213914f0 sp 0x7ffa213914e8
READ of size 8 at 0x619000145090 thread T2 (b-capnp-loop)
    #0 0x55e3f7305d90 in mp::EventLoopRef::operator->() const ipc/libmultiprocess/include/mp/proxy.h:64
    #1 0x55e3f7305d90 in mp::Connection::addAsyncCleanup(std::function<void ()>) ipc/libmultiprocess/src/mp/proxy.cpp:168
    #2 0x55e3f4c96b89 in mp::ProxyServerBase<ipc::capnp::messages::Chain, interfaces::Chain>::~ProxyServerBase() ipc/libmultiprocess/include/mp/proxy-io.h:480
    #3 0x55e3f4c6fdf0 in mp::ProxyServer<ipc::capnp::messages::Chain>::~ProxyServer() /home/darosior/code/core/bitcoin/sanmultiprocbuild/src/ipc/capnp/chain.capnp.proxy-types.c++:8
    #4 0x7ffa266b6985 in non-virtual thunk to capnp::LocalClient::~LocalClient() (/lib/x86_64-linux-gnu/libcapnp-rpc-0.9.2.so+0x7b985)
    #5 0x7ffa266b6ca4 in kj::_::HeapDisposer<kj::_::AttachmentPromiseNode<kj::Own<capnp::LocalClient> > >::disposeImpl(void*) const (/lib/x86_64-linux-gnu/libcapnp-rpc-0.9.2.so+0x7bca4)
    #6 0x7ffa2644e3e8 in kj::_::runCatchingExceptions(kj::_::Runnable&) (/lib/x86_64-linux-gnu/libkj-0.9.2.so+0x343e8)
    #7 0x7ffa264edc81 in kj::_::ForkHubBase::fire() (/lib/x86_64-linux-gnu/libkj-async-0.9.2.so+0x46c81)
    #8 0x7ffa264ea797 in kj::EventLoop::turn() (/lib/x86_64-linux-gnu/libkj-async-0.9.2.so+0x43797)
    #9 0x7ffa264f1fb8 in kj::_::waitImpl(kj::Own<kj::_::PromiseNode>&&, kj::_::ExceptionOrValue&, kj::WaitScope&) (/lib/x86_64-linux-gnu/libkj-async-0.9.2.so+0x4afb8)
    #10 0x55e3f733ecf9 in kj::Promise<unsigned long>::wait(kj::WaitScope&) /usr/include/kj/async-inl.h:1120
    #11 0x55e3f7331c3e in mp::EventLoop::loop() ipc/libmultiprocess/src/mp/proxy.cpp:227
    #12 0x55e3f4272383 in operator() ipc/capnp/protocol.cpp:96
    #13 0x55e3f4272383 in __invoke_impl<void, ipc::capnp::(anonymous namespace)::CapnpProtocol::startLoop(char const*)::<lambda()> > /usr/include/c++/12/bits/invoke.h:61
    #14 0x55e3f4272383 in __invoke<ipc::capnp::(anonymous namespace)::CapnpProtocol::startLoop(char const*)::<lambda()> > /usr/include/c++/12/bits/invoke.h:96
    #15 0x55e3f4272383 in _M_invoke<0> /usr/include/c++/12/bits/std_thread.h:252
    #16 0x55e3f4272383 in operator() /usr/include/c++/12/bits/std_thread.h:259
    #17 0x55e3f4272383 in _M_run /usr/include/c++/12/bits/std_thread.h:210
    #18 0x7ffa260d44a2  (/lib/x86_64-linux-gnu/libstdc++.so.6+0xd44a2)
    #19 0x7ffa256a81f4 in start_thread nptl/pthread_create.c:442
    #20 0x7ffa2572889b in clone3 ../sysdeps/unix/sysv/linux/x86_64/clone3.S:81

0x619000145090 is located 16 bytes inside of 1032-byte region [0x619000145080,0x619000145488)
freed by thread T2 (b-capnp-loop) here:
    #0 0x7ffa268ba3c8 in operator delete(void*, unsigned long) ../../../../src/libsanitizer/asan/asan_new_delete.cpp:164
    #1 0x55e3f429b035 in std::__new_allocator<std::_List_node<mp::Connection> >::deallocate(std::_List_node<mp::Connection>*, unsigned long) /usr/include/c++/12/bits/new_allocator.h:158
    #2 0x55e3f429b035 in std::allocator<std::_List_node<mp::Connection> >::deallocate(std::_List_node<mp::Connection>*, unsigned long) /usr/include/c++/12/bits/allocator.h:200
    #3 0x55e3f429b035 in std::allocator_traits<std::allocator<std::_List_node<mp::Connection> > >::deallocate(std::allocator<std::_List_node<mp::Connection> >&, std::_List_node<mp::Connection>*, unsigned long) /usr/include/c++/12/bits/alloc_traits.h:496
    #4 0x55e3f429b035 in std::__cxx11::_List_base<mp::Connection, std::allocator<mp::Connection> >::_M_put_node(std::_List_node<mp::Connection>*) /usr/include/c++/12/bits/stl_list.h:522
    #5 0x55e3f429b035 in std::__cxx11::list<mp::Connection, std::allocator<mp::Connection> >::_M_erase(std::_List_iterator<mp::Connection>) /usr/include/c++/12/bits/stl_list.h:2024
    #6 0x55e3f429b035 in std::__cxx11::list<mp::Connection, std::allocator<mp::Connection> >::erase(std::_List_const_iterator<mp::Connection>) /usr/include/c++/12/bits/list.tcc:158
    #7 0x55e3f429b035 in mp::_Serve<ipc::capnp::messages::Init, interfaces::Init>(mp::EventLoop&, kj::Own<kj::AsyncIoStream>&&, interfaces::Init&)::{lambda()#2}::operator()() const ipc/libmultiprocess/include/mp/proxy-io.h:590

previously allocated by thread T2 (b-capnp-loop) here:
    #0 0x7ffa268b94c8 in operator new(unsigned long) ../../../../src/libsanitizer/asan/asan_new_delete.cpp:95
    #1 0x55e3f42be0a8 in std::__new_allocator<std::_List_node<mp::Connection> >::allocate(unsigned long, void const*) /usr/include/c++/12/bits/new_allocator.h:137
    #2 0x55e3f42be0a8 in std::allocator<std::_List_node<mp::Connection> >::allocate(unsigned long) /usr/include/c++/12/bits/allocator.h:188
    #3 0x55e3f42be0a8 in std::allocator_traits<std::allocator<std::_List_node<mp::Connection> > >::allocate(std::allocator<std::_List_node<mp::Connection> >&, unsigned long) /usr/include/c++/12/bits/alloc_traits.h:464
    #4 0x55e3f42be0a8 in std::__cxx11::_List_base<mp::Connection, std::allocator<mp::Connection> >::_M_get_node() /usr/include/c++/12/bits/stl_list.h:518
    #5 0x55e3f42be0a8 in std::_List_node<mp::Connection>* std::__cxx11::list<mp::Connection, std::allocator<mp::Connection> >::_M_create_node<mp::EventLoop&, kj::Own<kj::AsyncIoStream>, mp::_Serve<ipc::capnp::messages::Init, interfaces::Init>(mp::EventLoop&, kj::Own<kj::AsyncIoStream>&&, interfaces::Init&)::{lambda(mp::Connection&)#1}>(mp::EventLoop&, kj::Own<kj::AsyncIoStream>&&, mp::_Serve<ipc::capnp::messages::Init, interfaces::Init>(mp::EventLoop&, kj::Own<kj::AsyncIoStream>&&, interfaces::Init&)::{lambda(mp::Connection&)#1}&&) /usr/include/c++/12/bits/stl_list.h:710
    #6 0x55e3f42be0a8 in void std::__cxx11::list<mp::Connection, std::allocator<mp::Connection> >::_M_insert<mp::EventLoop&, kj::Own<kj::AsyncIoStream>, mp::_Serve<ipc::capnp::messages::Init, interfaces::Init>(mp::EventLoop&, kj::Own<kj::AsyncIoStream>&&, interfaces::Init&)::{lambda(mp::Connection&)#1}>(std::_List_iterator<mp::Connection>, mp::EventLoop&, kj::Own<kj::AsyncIoStream>&&, mp::_Serve<ipc::capnp::messages::Init, interfaces::Init>(mp::EventLoop&, kj::Own<kj::AsyncIoStream>&&, interfaces::Init&)::{lambda(mp::Connection&)#1}&&) /usr/include/c++/12/bits/stl_list.h:2005
    #7 0x55e3f42be0a8 in mp::Connection& std::__cxx11::list<mp::Connection, std::allocator<mp::Connection> >::emplace_front<mp::EventLoop&, kj::Own<kj::AsyncIoStream>, mp::_Serve<ipc::capnp::messages::Init, interfaces::Init>(mp::EventLoop&, kj::Own<kj::AsyncIoStream>&&, interfaces::Init&)::{lambda(mp::Connection&)#1}>(mp::EventLoop&, kj::Own<kj::AsyncIoStream>&&, mp::_Serve<ipc::capnp::messages::Init, interfaces::Init>(mp::EventLoop&, kj::Own<kj::AsyncIoStream>&&, interfaces::Init&)::{lambda(mp::Connection&)#1}&&) /usr/include/c++/12/bits/stl_list.h:1271
    #8 0x55e3f42be0a8 in void mp::_Serve<ipc::capnp::messages::Init, interfaces::Init>(mp::EventLoop&, kj::Own<kj::AsyncIoStream>&&, interfaces::Init&) ipc/libmultiprocess/include/mp/proxy-io.h:581

Thread T2 (b-capnp-loop) created by T0 here:
    #0 0x7ffa26849726 in __interceptor_pthread_create ../../../../src/libsanitizer/asan/asan_interceptors.cpp:207
    #1 0x7ffa260d4578 in std::thread::_M_start_thread(std::unique_ptr<std::thread::_State, std::default_delete<std::thread::_State> >, void (*)()) (/lib/x86_64-linux-gnu/libstdc++.so.6+0xd4578)

SUMMARY: AddressSanitizer: heap-use-after-free ipc/libmultiprocess/include/mp/proxy.h:64 in mp::EventLoopRef::operator->() const
Shadow bytes around the buggy address:
  0x0c32800209c0: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x0c32800209d0: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x0c32800209e0: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x0c32800209f0: fd fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
  0x0c3280020a00: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
=>0x0c3280020a10: fd fd[fd]fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x0c3280020a20: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x0c3280020a30: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x0c3280020a40: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x0c3280020a50: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x0c3280020a60: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
Shadow byte legend (one shadow byte represents 8 application bytes):
  Addressable:           00
  Partially addressable: 01 02 03 04 05 06 07 
  Heap left redzone:       fa
  Freed heap region:       fd
  Stack left redzone:      f1
  Stack mid redzone:       f2
  Stack right redzone:     f3
  Stack after return:      f5
  Stack use after scope:   f8
  Global redzone:          f9
  Global init order:       f6
  Poisoned by user:        f7
  Container overflow:      fc
  Array cookie:            ac
  Intra object redzone:    bb
  ASan internal:           fe
  Left alloca redzone:     ca
  Right alloca redzone:    cb
==2177791==ABORTING

[ryanofsky]

I was able to write a unit test that reproduces the crash and confirms cap'n proto really is not destroying server objects before m_rpc_system.reset(); returns if a connection is destroyed is in the middle of an IPC call. Code was written with the assumption that the reset call would free all Server objects, so to fix the bug I need to switch to another approach like the connection refcounting one I started implementing #176 (comment).

New unit test is in commit 6d7c88b (tag)

[ryanofsky]

Latest version of bitcoin/bitcoin#32345 (tag pr/ipc-stop.8) should fix these issues. The actual fixes are implemented in base PR #160 in these commits:

• 42caa69 Prevent EventLoop async cleanup thread early exit during shutdown
• 5c40b17 Prevent IPC server crash if disconnected during IPC call
• 4c33734 test: Test disconnects during IPC calls

Contrary to previous comment I did not wind up needing to implement the connection refcounting approach since I found a simpler more direct fix. But I did do more work on it before finding the simpler fix and plan to make it a followup since it is a bigger change but simplifies things overall