IPC stability bugs

Bug 24

IPC shutdown locks a mutex after its event loop was destroyed

Status
Fixed
Symptom
Crash; worst effect seen: crash
Where seen
Bitcoin Core unit tests, Bitcoin Core functional tests
Trigger
The process closes its own connection while the peer is still there
First reported
2024-04-16 (first report)
Fixed
2025-02-10
Fix
mp#159
Shipped to Bitcoin Core
bitcoin#31945, bitcoin#31741
In released binaries
No; the code was in source releases only
Defect ever on master
Yes

Summary

At IPC shutdown, EventLoop::post and EventLoop::removeClient could lock EventLoop::m_mutex again after EventLoop::loop() had returned. Bitcoin Core destroys the EventLoop as soon as loop() returns, so the lock was on a destroyed mutex. Depending on the platform this threw std::system_error: mutex lock failed: Invalid argument (macOS, FreeBSD, NetBSD), tripped a glibc assertion, or hung (Linux). It made ipc_tests and rpc_misc.py fail intermittently in Bitcoin Core CI, and in rpc_misc.py the parent bitcoin-node exited with an uncaught exception after "Shutdown: done". Source builds of v22 through v28 with multiprocess enabled have it. Fixed in mp#159, shipped in v29.0.

What happened

Root cause

EventLoop::post and EventLoop::removeClient (src/mp/proxy.cpp) used the Unlock() helper to drop m_mutex, write() a wake-up byte to the loop's pipe, and lock m_mutex again. That write can be what lets loop() return. In post, the loop thread could consume the wake-up, see done(), return from loop() and, in Bitcoin Core's CapnpProtocol::startLoop, run m_loop.reset(), destroying the mutex before the posting thread relocked it. removeClient had the same window around its final write when done() became true, though that case was not observed. Locking a destroyed std::mutex is undefined behavior: libc++ returns EINVAL and throws, glibc's robust-mutex path asserts, or the lock hangs.

The path is the parent-side shutdown of a connection, where the local process releases the last client reference itself instead of the peer disconnecting. Only rpc_misc.py (through the echoipc connection) and ipc_tests exercised it, and the window is a few instructions wide. It surfaced once those tests ran on many platforms in the months before libmultiprocess became a subtree of Bitcoin Core: in bitcoin#30975's CI jobs, in the macOS CI of bitcoin#31802, and in hebasto's BSD nightly builds.

The code

Quoted from 48d01bcca76e^. EventLoop::post (src/mp/proxy.cpp) hands a function to the event-loop thread and wakes it with a pipe write, releasing m_mutex around the write with the Unlock() helper, which relocks it when the callback returns:

std::unique_lock<std::mutex> lock(m_mutex);
m_cv.wait(lock, [this] { return m_post_fn == nullptr; });
m_post_fn = &fn;
int post_fd{m_post_fd};
Unlock(lock, [&] {
    char buffer = 0;
    KJ_SYSCALL(write(post_fd, &buffer, 1));
});
m_cv.wait(lock, [this, &fn] { return m_post_fn != &fn; });

EventLoop::removeClient uses the same pattern for its final wake-up:

m_num_clients -= 1;
if (done(lock)) {
    m_cv.notify_all();
    int post_fd{m_post_fd};
    Unlock(lock, [&] {
        char buffer = 0;
        KJ_SYSCALL(write(post_fd, &buffer, 1)); // NOLINT(bugprone-suspicious-semicolon)
    });
}

Nothing stops EventLoop::loop() from returning between the write and the relock, and Bitcoin Core destroys the EventLoop, mutex included, as soon as loop() returns. In the macOS failure the posting thread was destroying the Init client:

  1. Client thread: ~ProxyClient<Init> calls sync(), which calls post(); it writes the wake-up byte and is delayed before Unlock() relocks.
  2. Event loop: runs the posted cleanup, whose removeClient drops the last client reference and makes done() true; the loop exits.
  3. Bitcoin Core's loop thread destroys the EventLoop.
  4. Client thread: Unlock() relocks the destroyed m_mutex; libc++ throws system_error and the process terminates.

The removeClient window is the same, but was not observed. The fix (48d01bcca76e) does not relock in removeClient once done, and has post() hold a client reference while it waits (the startAsyncThread change that uses the new return value is omitted):

@@ -225,6 +225,7 @@ void EventLoop::post(const std::function<void()>& fn)
     std::unique_lock<std::mutex> lock(m_mutex);
+    addClient(lock);
     m_cv.wait(lock, [this] { return m_post_fn == nullptr; });
@@ -233,21 +234,23 @@ void EventLoop::post(const std::function<void()>& fn)
     m_cv.wait(lock, [this, &fn] { return m_post_fn != &fn; });
+    removeClient(lock);
 }
@@
-void EventLoop::removeClient(std::unique_lock<std::mutex>& lock)
+bool EventLoop::removeClient(std::unique_lock<std::mutex>& lock)
 {
     m_num_clients -= 1;
     if (done(lock)) {
         m_cv.notify_all();
         int post_fd{m_post_fd};
-        Unlock(lock, [&] {
-            char buffer = 0;
-            KJ_SYSCALL(write(post_fd, &buffer, 1)); // NOLINT(bugprone-suspicious-semicolon)
-        });
+        lock.unlock();
+        char buffer = 0;
+        KJ_SYSCALL(write(post_fd, &buffer, 1)); // NOLINT(bugprone-suspicious-semicolon)
+        return true;
     }

While post() holds its client reference done() stays false, so the loop cannot exit until post() has relocked and released it; and the removeClient call that makes done() true no longer touches the mutex after the write that lets the loop exit.

Fix

The fix commit 48d01bcca76e, in mp#159 ("bugfix: Do not lock EventLoop::mutex after EventLoop is done"), makes removeClient call lock.unlock() without relocking once the loop is done and return true, so startAsyncThread stops, and has post hold a client reference (addClient/removeClient) while it waits, so loop() cannot finish while a post is in progress (+10/-7). The commit message says there was "not technically a bug here in the libmultiprocess code or API", since the EventLoop was safe as long as callers waited for its methods to return before deleting it, which the original code on the bitcoin#10102 branch did. Later code for unix-socket connections and unit tests deleted it right after loop() returned.

An earlier attempt in Bitcoin Core, bitcoin#31815 ("multiprocess: Lock CapnpProtocol::m_loop with mutex"), covered only the removeClient case, still failed in CI and was closed. mp#160 ("refactor: EventLoop locking cleanups + client disconnect exception") later moved the same logic into an EventLoopRef class.

Timeline

Lessons

What would have prevented this bug, found it sooner, or made it easier to debug. The patterns page groups these lessons across all bugs.

Pattern An object outliving what it points to: An object touched after allowing its destruction

  • Prevented by a clear ownership model, a design rule
  • Earliest detector ThreadSanitizer (did not exist then)
  • Diagnosis hard
  • Fix design moderate
  • Debugging aids symbolized stack traces, logging, a reproduction script
  • Rust yes

Would Rust have prevented it? Yes. Post() holds a borrow of the EventLoop for its whole body, so the loop thread could not drop it in the middle; in practice the loop would live in an Arc, which is the reference count the fix added by hand and which delays destruction rather than forbidding the ordering. More on Rust

Could it have been prevented?

Yes, by either of two rules the fix sequence arrived at. EventLoop::post and removeClient wrote the wake-up byte that can let loop() return and then relocked m_mutex, a member of an object the caller was free to destroy the moment loop() returned. The first rule is "never touch this after the action that may end its life", which is how removeClient was fixed (48d01bcca76e: unlock and return without relocking). The second is that a thread inside an EventLoop method holds a counted reference for the duration, which is how post was fixed and what mp#160 then made structural with EventLoopRef. The commit message says the library API was not at fault, since callers were expected to wait for its methods to return before deleting the loop; that expectation was never written down, and the unix-socket and unit-test code added in 2024 broke it without anyone noticing. A documented lifetime contract, or the refcount that makes the contract unnecessary, was the missing piece.

Could it have been found sooner?

Probably, by running ipc_tests under ThreadSanitizer. The relock and the mutex's destruction are unordered accesses to the same object from two threads, which TSan reports whether or not the bad interleaving happens on that run, whereas the window itself is a few instructions wide and needs the loop thread to exit and destroy the loop between another thread's write() and its relock. Neither repository ran the library under TSan when the code was written, and Bitcoin Core's ASan job, which did build ipc_tests from late 2024, only sees the failure when the timing lands. The test that exercises the path existed from 2021; what it lacked was a tool that converts a rare interleaving into a deterministic report.

What made it hard to debug?

Five reports over ten months with three different symptoms: a glibc robust-mutex assertion on i686 (bitcoin#29889, no stack trace, linked to this bug only a year later), system_error: Invalid argument on macOS and the BSDs, and a 2508 s hang on Linux (bitcoin#31921), because locking a destroyed mutex is undefined behavior and each libc does something different. The macOS report was first attributed to the Broken pipe race fixed days earlier in mp#129 and its issue closed, and the first fix attempt (bitcoin#31815) guarded the wrong side, the m_loop.reset() in Bitcoin Core, and still failed. What settled it was a stack trace from a macOS VM showing ~ProxyClient<Init> -> sync -> post -> ~UnlockGuard terminating, with the log line order (EventLoop::loop bye. before IPC client destroy) placing the destruction first. A symbolized trace from the first failure would have saved most of the ten months.

Lesson

Once a method has done the thing that lets its object be destroyed, it must not touch the object again, not even to release a lock; if the method has to keep working, hold a counted reference for its whole duration and let the count decide when the object goes.

Classification

The survey's classification of this bug. The explorer charts these fields across all bugs; the method page explains them.

Field Value
Symptom crash
Worst effect observed crash, hang
Seen in unit-test, functional-test
Scope production
Trigger Process closes its own connection (local-disconnect)
Phase shutdown
Side eventloop
Component eventloop
Root cause kind lifetime
Fix kind local-fix
Detection ci-intermittent
Needs a peer that is not libmultiprocess C++ no
Needed a sanitizer to see no
Defect ever on master yes
Released source
Confidence high