Files
logos-protocol/tests/protocol/test_plain_cancel_pending_race.cpp
Dario LipicarandClaude Opus 5 e6d5b575c2 fix(plain): a second handle must not steal the first's event channel (#52)
* fix(plain): give every handle its own event subscription on the shared connection

RpcConnection::m_eventCallbacks was keyed by (object, eventName) and ASSIGNED.
One RpcConnection is shared by every PlainLogosObject a PlainTransportConnection
hands out, and requestObject() mints a fresh handle per acquire, so the second
handle to subscribe to the same event on the same module silently took the first
one's channel — including the deferred ("multi") completion channel every handle
subscribes to on its first call.

No concurrency is needed to reach it. Measured on cf1b9b0: handle A's deferred
call answers 8/8 in 0 ms alone, and 0/8 in 1505 ms (timeout, INVALID) once a
second handle merely exists. Identical on master.

THE WIRE DOES NOT MOVE. Subscribe/Unsubscribe still carry (object, event) and
nothing else. The host keeps ONE sink per (object, event, connection) — the right
model, since every sink for a connection is the same "write this frame back down
that socket" — and the CONSUMER, the only end that knows how many of its own
handles want an event, does the demultiplexing: a list of registrations per key,
a subscription id to withdraw one of them, and an Unsubscribe frame only when the
last local registration for the pair is gone, because that frame is
connection-wide.

Also here, because the consumer-side fan-out makes it observable as a doubled
delivery: PlainTransportHost::fanOutEvent sent a connection subscribed both by
name and by wildcard two copies of the same event. One copy per connection now.

And the parked-completion staging area is gated. It exists for one ordering — a
"multi" worker that finishes before the sentinel it answers has been written, so
the completion event overtakes its own Result — and a completion arriving that
early is not attributable to a handle at all. Every handle now sees every
completion on the object, so parking is allowed only while this handle has a call
outstanding, the map is emptied the instant none is, and it is capped at 512 with
oldest-first eviction. Pre-fix the same leak existed with one victim instead of N:
the handle that had stolen the channel parked every other handle's completions and
never claimed one.

Detectors: nine tests in test_plain_event_sub_sharing.cpp, all validated RED on
cf1b9b0 and on master and green here, including both mixed-version directions (a
new consumer against a verbatim pre-fix host, and an old consumer's frame sequence
against the new host over a raw socket).

── REBASED ONTO #50, THE FIRST REPLAY IN THIS STACK WITH A REAL PRODUCTION
   CONFLICT (and then onto #51, which lands cleanly) ──────────────────────────

the object (a live-reference count with deferred destruction) and to give async
callbacks somewhere to land in a Qt-free process (a never-destroyed
DeliveryService). Both of those and both of this commit's changes are kept; the
resolution picks no side anywhere.

  * plain_logos_object.cpp, hunk 1 — #50 replaced postToQtEventLoop's comment
    header with DeliveryService; this commit inserted SyncCallScope immediately
    above it. The insert point survives, the replaced header does not:
    SyncCallScope now sits above #50's DeliveryService block.
  * plain_logos_object.cpp, hunk 2 — #50 split disconnectEvents() into a guarded
    entry point plus an unguarded disconnectEventsImpl() (release() and the
    destructor must not take a reference to what they are destroying); this
    commit changed that body's local from (name, callback) pairs to subscription
    ids. Kept as #50's split with this commit's body. onEvent() auto-merged the
    same way: #50's EntryGuard declared FIRST, then the m_mu-across-the-subscribe
    body from here.
  * test_sync_call_release_race.cpp — not a text conflict and not visible to git:
    #50's StalledConnection double implements RpcConnectionBase, and this commit
    changes that interface, so it became abstract and the file stopped compiling.
    Its stub now returns a DISTINCT id per subscribe, so it cannot hide a bug
    that withdraws the wrong registration.
  * tests/protocol/CMakeLists.txt — both detector lists are additive and both are
    in. The prose is NOT concatenated: an earlier replay on this stack had
    grafted a duplicated fragment ("per-path test as evidence the gate is there.
    Nor is") into the middle of a paragraph, and the sentence it belonged to is
    now where it was meant to go, at the end of the "what is NOT on that list"
    paragraph. #50's "the CAS is TWO gates" correction is untouched. #51's own
    additions to the same file merged without a conflict on the second replay.

gives the five LiveHost fixtures a teardown that destroys the host on the thread
that emits into it, and the host in test_plain_event_sub_sharing.cpp is not that
shape — its ModuleProxy stays on the test thread, so there is no worker to race.

RE-VERIFIED BY RUNNING, on macOS arm64, Debug, all after the rebase:

  * THIS FIX still fixes the bug on the NEW master. The ten
    PlainEventSubSharingTest cases compile unmodified on 5be3a84 and nine go RED
    there: handle A alone 8/8 answered at 0 ms avg, handle A once B exists 0/8 at
    1503 ms avg with 8 timeouts, and 0/4 with 4 timeouts through the shipping
    host. On this commit: 8/8 and 4/4, 0 ms avg, 0 timeouts. So neither #50 nor
    #51 caused or masked this defect, and this branch is not a no-op.
  * #50's FIX still works through this change. SyncCallReleaseRaceTest 8/8 green
    (release() returns in 0 ms with a call parked, destroyed=1 only after the
    caller leaves; 400 release-wake races, one destruction each), the whole no-Qt
    binary 7/7 plus the after-main() probe (delivered=1, off the issuing thread,
    exit 0), and its mechanisms are still in the source: m_liveRefs with the
    EntryGuard reference-first/reference-last ordering, release() dropping the
    owner's reference instead of `delete this`, DeliveryService `new`-ed with
    `~DeliveryService() = delete` and a detached thread, and NO m_conn.reset() in
    release().
  * EXACTLY-ONCE, in the release-race shape rather than the per-path pins. Qt
    vehicle: 20 rounds x 500 calls released mid-burst, answered-by-reply=1034,
    cancelled-by-teardown=8966, 0 doubles, 0 dropped. No-Qt twin: 1130 / 8870, 0
    and 0. Both resolvers live in both. Re-validated as a DETECTOR on this merged
    tree by removing BOTH gates (claim()'s CAS and takeCallback()'s swap) in a
    throwaway build: 19 doubles Qt, 13 doubles no-Qt, both FAIL, while the
    per-path exactly-once tests stay green — which is the difference the
    CMakeLists note describes.
  * NO USE-AFTER-FREE. Guard Malloc clean over SyncCallReleaseRace, IoFold,
    PlainObjectTeardown, PlainCompletionSubLifetime, PlainCancelPendingRace,
    PlainWaiterReaping, PlainHostEventTeardown, PlainEventSubSharing and
    PlainParkedCompletionGate (52/52), and over the whole no-Qt binary (7/7,
    exit 0).
  * TEARDOWN AND DEADLINES. release() with 32 calls in flight: 0 ms. release()
    after 100 reaped calls: 0 ms. A 200 ms deadline fires at 200 ms while an
    onEvent handler holds the io thread for 2001 ms; a 250 ms deadline fires at
    250 ms with the io thread blocked forever; 12 idle 200 ms deadlines
    min=200 median=200 max=202 ms.
  * NO USER CALLBACK INLINE ON AN IO THREAD: no-Qt replies 300/300 with
    on-caller-thread=0 and delivery-thread!=io-thread=1; cancellations 20/20 with
    inside-release=0 and on-releasing-thread=0.
  * Full suite 433/433 (was 421 on master; this adds 12), and `nix build .#tests`
    433/433.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>

* test(plain): make the subscription detectors barrier-driven instead of timed

Every "wait a bit then count" in the new tests is now an in-band round trip: a
Methods request travels the same socket and is dispatched on the same strand as
everything written before it, so its reply proves the earlier Subscribe /
Unsubscribe frames have been applied AND that the Event frames the peer wrote
before answering have been dispatched. The audits are exact counts rather than
polls with a timeout, which is what they have to be on a loaded CI runner — a
short sleep there fails the test rather than skipping it.

Still 9 of 10 RED on cf1b9b0 and on master, with the teardown pin green; the set
now runs in 9s instead of 110s.

* test(plain): drop the poll helper the barrier replaced

---------

Co-authored-by: Claude Opus 5 <noreply@anthropic.com>
2026-08-12 19:06:16 -03:00

416 lines
16 KiB
C++

// WHERE EXACTLY-ONCE RESTS, ONCE cancelPending() EXISTS.
//
// cancelPending() withdraws a call's registration from the connection's pending
// map. It is tempting — and rpc_connection.h used to say — that a caller which
// has given up therefore "is never called back at all". It is not true, and the
// distance between the two matters, because it decides whether the callers of
// sendCallAsync() need idempotent handlers or merely tidy ones.
//
// dispatchIncoming() COPIES the handler out of the map under m_mu and invokes it
// with the mutex RELEASED. A cancelPending() that arrives in that gap erases an
// entry that is no longer there and returns having stopped nothing; the handler
// then runs to completion. So:
//
// * at-most-once INVOCATION of a registered handler is the connection's, and
// it comes from the extract-and-erase under m_mu — three contenders
// (dispatchIncoming, fail()'s sweep, cancelPending) and only one can win;
// * exactly-once DELIVERY to the user is NOT the connection's. It belongs to
// the handler, and for PlainLogosObject it is AsyncCall::deliver()'s CAS.
//
// These tests construct that interleaving by hand rather than racing for it: a
// connection stub reproduces dispatchIncoming's extract-then-invoke exactly and
// lets the test stand between the two halves.
//
// The second test is a validated detector: against a transport whose
// AsyncCall::claim() does not compare-exchange and whose takeCallback() copies
// rather than swaps — a local edit in a throwaway checkout, not a switch in
// this tree; see the top of test_iofold.cpp — it reports 2 deliveries for 1
// call.
#include <gtest/gtest.h>
#include "incoming_call_handler.h"
#include "json_codec.h"
#include "logos_call_error.h"
#include "plain_logos_object.h"
#include "rpc_connection.h"
#include "rpc_message.h"
#include <boost/asio/executor_work_guard.hpp>
#include <boost/asio/io_context.hpp>
#include <boost/asio/local/connect_pair.hpp>
#include <boost/asio/local/stream_protocol.hpp>
#include <QCoreApplication>
#include <QElapsedTimer>
#include <QVariant>
#include <QVariantList>
#include <atomic>
#include <chrono>
#include <future>
#include <map>
#include <memory>
#include <mutex>
#include <string>
#include <thread>
using namespace logos::plain;
namespace {
// A connection that goes no further than its pending map, so a test can occupy
// the gap dispatchIncoming leaves between taking a handler out and running it.
// Everything below m_pending mirrors RpcConnection: registration under the
// mutex, extract-and-erase under the mutex, invocation with it released.
class StubConnection : public RpcConnectionBase {
public:
void start() override {}
void stop(const std::string&) override { m_open = false; }
bool isOpen() const override { return m_open; }
std::future<ResultMessage> sendCall(CallMessage msg) override
{
// The OTHER shape of handler in this codebase: a promise. Registered
// through the same path, deliberately, so the tests below can reach it.
auto p = std::make_shared<std::promise<ResultMessage>>();
auto f = p->get_future();
sendCallAsync(std::move(msg), [p](ResultMessage r) {
try { p->set_value(std::move(r)); } catch (...) {}
});
return f;
}
void sendCallAsync(CallMessage msg, ResultHandler handler) override
{
if (!handler) return;
std::lock_guard<std::mutex> g(m_mu);
m_lastId = msg.id;
m_pending[msg.id] = std::move(handler);
}
std::future<MethodsResultMessage> sendMethods(MethodsMessage msg) override
{
std::promise<MethodsResultMessage> p;
MethodsResultMessage r; r.id = msg.id; r.ok = true;
p.set_value(std::move(r));
return p.get_future();
}
void cancelPending(std::uint64_t id) override
{
std::lock_guard<std::mutex> g(m_mu);
m_pending.erase(id);
m_cancels.fetch_add(1);
}
SubscriptionId sendSubscribe(SubscribeMessage,
std::function<void(EventMessage)>) override
{
return m_nextSub.fetch_add(1);
}
void sendUnsubscribe(SubscriptionId) override {}
void sendEvent(EventMessage) override {}
void sendToken(TokenMessage) override {}
void setErrorHandler(ErrorHandler) override {}
std::uint64_t nextId() override { return m_next.fetch_add(1); }
// dispatchIncoming's FIRST half, verbatim: find under the mutex, move out,
// erase, drop the mutex. The caller decides when the second half runs.
ResultHandler extract(std::uint64_t id)
{
std::lock_guard<std::mutex> g(m_mu);
auto it = m_pending.find(id);
if (it == m_pending.end()) return nullptr;
ResultHandler h = std::move(it->second);
m_pending.erase(it);
return h;
}
std::uint64_t lastId() const { return m_lastId; }
int cancels() const { return m_cancels.load(); }
size_t pendingCount() { std::lock_guard<std::mutex> g(m_mu); return m_pending.size(); }
private:
std::mutex m_mu;
std::map<std::uint64_t, ResultHandler> m_pending;
std::atomic<std::uint64_t> m_next{1};
std::atomic<SubscriptionId> m_nextSub{1};
std::atomic<std::uint64_t> m_lastId{0};
std::atomic<int> m_cancels{0};
bool m_open = true;
};
QCoreApplication* ensureApp()
{
static int argc = 0;
static char* argv[] = { nullptr };
if (!QCoreApplication::instance()) new QCoreApplication(argc, argv);
return QCoreApplication::instance();
}
// Deliveries land on the Qt loop, so nothing is counted until it is pumped.
void pumpUntil(std::atomic<int>& counter, int target, int budgetMs)
{
QElapsedTimer t; t.start();
while (counter.load() < target && t.elapsed() < budgetMs)
QCoreApplication::processEvents(QEventLoop::AllEvents, 5);
}
void pump(int ms)
{
QElapsedTimer t; t.start();
while (t.elapsed() < ms) QCoreApplication::processEvents(QEventLoop::AllEvents, 5);
}
ResultMessage okResult(std::uint64_t id, int value)
{
ResultMessage res;
res.id = id;
res.ok = true;
res.value = RpcValue{static_cast<int64_t>(value)};
return res;
}
} // namespace
// ── 1. the literal claim: cancelPending() does NOT prevent a callback ────────
TEST(PlainCancelPendingRaceTest, CancelPendingCannotStopAnAlreadyExtractedHandler)
{
ensureApp();
auto conn = std::make_shared<StubConnection>();
auto* obj = new PlainLogosObject("cancel_probe", conn);
std::atomic<int> deliveries{0};
obj->callMethodAsyncWithError(QStringLiteral("tok"), QStringLiteral("ping"),
QVariantList{}, 20000,
[&deliveries](QVariant, const logos::CallError&) {
deliveries.fetch_add(1);
});
const std::uint64_t id = conn->lastId();
// The reply is decoded: the handler leaves the map.
RpcConnectionBase::ResultHandler h = conn->extract(id);
ASSERT_TRUE(h) << "the call never registered a handler";
// The caller gives up HERE, in the gap. cancelPending() finds nothing.
conn->cancelPending(id);
EXPECT_EQ(conn->pendingCount(), 0u);
EXPECT_EQ(deliveries.load(), 0) << "nothing should have been delivered yet";
// ...and the handler runs anyway.
h(okResult(id, 42));
pumpUntil(deliveries, 1, 2000);
EXPECT_EQ(deliveries.load(), 1)
<< "cancelPending() ran before this callback and did not stop it — which "
"is the point: the comment claiming a cancelled caller 'is never "
"called back at all' is what is wrong, not the code";
obj->release();
pump(50);
}
// ── 2. so exactly-once has to come from somewhere else: the CAS ─────────────
//
// The same gap, but with the second resolver being the one that actually exists
// in production — teardown, which cancels every outstanding call. Both paths
// reach AsyncCall::deliver() for the same call. With the CAS removed this
// reports 2.
TEST(PlainCancelPendingRaceTest, AnExtractedReplyRacingTeardownDeliversExactlyOnce)
{
ensureApp();
auto conn = std::make_shared<StubConnection>();
auto* obj = new PlainLogosObject("cancel_probe", conn);
std::atomic<int> deliveries{0};
std::atomic<int> released{0}; // callErrorReleased — teardown won
std::atomic<int> answered{0}; // no error — the reply won
obj->callMethodAsyncWithError(QStringLiteral("tok"), QStringLiteral("ping"),
QVariantList{}, 20000,
[&](QVariant, const logos::CallError& e) {
deliveries.fetch_add(1);
if (e.ok()) answered.fetch_add(1);
else released.fetch_add(1);
});
const std::uint64_t id = conn->lastId();
// The io thread has the handler in hand...
RpcConnectionBase::ResultHandler h = conn->extract(id);
ASSERT_TRUE(h);
// ...teardown resolves the call and frees the handle out from under it...
obj->release();
// ...and only then does the reply run. It holds a shared_ptr to its
// AsyncCall, so it is safe to run at all — and finds the gate taken.
h(okResult(id, 42));
pumpUntil(deliveries, 1, 2000);
pump(100); // a second delivery would land in here
EXPECT_EQ(deliveries.load(), 1)
<< "the call was delivered " << deliveries.load()
<< " times; exactly-once is AsyncCall::deliver()'s CAS and nothing else";
EXPECT_EQ(released.load(), 1) << "teardown should have been the resolver";
EXPECT_EQ(answered.load(), 0);
pump(50);
}
// ── 3. the OTHER caller of sendCallAsync: a promise, not an AsyncCall ────────
//
// RpcConnection::sendCall() registers a promise-fulfilling handler through the
// same path, and callMethodWithError() / getMethods() call cancelPending() on
// their timeout. Neither of those handlers has a CAS — so the question is
// whether at-most-once INVOCATION is enough for them, and it is: the extract is
// what makes it single, and firing into a future nobody will read is harmless.
// Run here rather than argued, on a REAL RpcConnection.
TEST(PlainCancelPendingRaceTest, ThePromiseShapedHandlerSurvivesTheSameGap)
{
auto conn = std::make_shared<StubConnection>();
CallMessage msg;
msg.id = conn->nextId();
msg.object = "promise_probe";
msg.method = "ping";
auto fut = conn->sendCall(std::move(msg));
const std::uint64_t id = conn->lastId();
// Extract, cancel in the gap, then run the promise handler.
RpcConnectionBase::ResultHandler h = conn->extract(id);
ASSERT_TRUE(h);
conn->cancelPending(id);
EXPECT_EQ(conn->pendingCount(), 0u)
<< "nobody else can reach this handler now — that is what makes the "
"single invocation single";
// Fulfils a future the caller has already walked away from. No throw, no
// second invocation possible.
EXPECT_NO_THROW(h(okResult(id, 7)));
ASSERT_EQ(fut.wait_for(std::chrono::seconds(1)), std::future_status::ready);
EXPECT_TRUE(fut.get().ok);
// And the abandoned-future case, which is what the sync path actually does:
// the caller times out, returns, and its future dies before the reply lands.
CallMessage msg2;
msg2.id = conn->nextId();
msg2.object = "promise_probe";
msg2.method = "ping";
{
auto doomed = conn->sendCall(std::move(msg2));
(void)doomed; // goes out of scope exactly as callMethodWithError's does
}
const std::uint64_t id2 = conn->lastId();
RpcConnectionBase::ResultHandler h2 = conn->extract(id2);
ASSERT_TRUE(h2);
conn->cancelPending(id2);
EXPECT_NO_THROW(h2(okResult(id2, 9)))
<< "setting a value on a shared state whose future is gone must be a "
"no-op, not a throw";
}
// ── 4. the same gap on the REAL connection, not a stub ───────────────────────
//
// Everything above uses a stub that copies dispatchIncoming's shape. This checks
// the shape really is the connection's: a genuine RpcConnection pair, a provider
// that HOLDS its reply until the test says so, and a caller that cancels in
// between. The reply then travels the real wire into the real dispatchIncoming,
// which must find no registration and drop it in silence.
TEST(PlainCancelPendingRaceTest, ARealConnectionDropsAReplyThatArrivesAfterCancel)
{
using LocalSocket = boost::asio::local::stream_protocol::socket;
using LocalConnection = RpcConnection<LocalSocket>;
// A provider that answers nothing until told to.
class HeldReplyProvider : public IncomingCallHandler {
public:
void onCall(const CallMessage& req, CallReply reply) override
{
std::lock_guard<std::mutex> g(mu);
id = req.id;
held = std::move(reply);
arrived.fetch_add(1);
}
void onMethods(const MethodsMessage& req, MethodsReply reply) override
{
MethodsResultMessage r; r.id = req.id; r.ok = true; reply(std::move(r));
}
void onSubscribe(const SubscribeMessage&, EventSink, const void*) override {}
void onUnsubscribe(const UnsubscribeMessage&, const void*) override {}
void onConnectionClosed(const void*) override {}
void onToken(const TokenMessage&) override {}
void answer()
{
CallReply r;
std::uint64_t rid = 0;
{
std::lock_guard<std::mutex> g(mu);
r = std::move(held);
rid = id;
}
if (!r) return;
ResultMessage res;
res.id = rid; res.ok = true;
res.value = RpcValue{static_cast<int64_t>(1)};
r(std::move(res));
}
std::mutex mu;
CallReply held;
std::uint64_t id = 0;
std::atomic<int> arrived{0};
};
boost::asio::io_context ioc;
auto guard = boost::asio::make_work_guard(ioc);
std::thread worker([&ioc] { ioc.run(); });
LocalSocket a(ioc), b(ioc);
boost::system::error_code ec;
boost::asio::local::connect_pair(a, b, ec);
ASSERT_FALSE(ec) << ec.message();
HeldReplyProvider provider;
auto codec = std::make_shared<JsonCodec>();
auto client = std::make_shared<LocalConnection>(std::move(a), codec, nullptr);
auto provider_conn =
std::make_shared<LocalConnection>(std::move(b), codec, &provider);
client->start();
provider_conn->start();
std::atomic<int> handlerRuns{0};
CallMessage msg;
msg.id = client->nextId();
msg.object = "real_probe";
msg.method = "ping";
const std::uint64_t id = msg.id;
client->sendCallAsync(std::move(msg), [&handlerRuns](ResultMessage) {
handlerRuns.fetch_add(1);
});
// Wait for the provider to be holding the call, then give up on it.
QElapsedTimer t; t.start();
while (provider.arrived.load() == 0 && t.elapsed() < 5000)
std::this_thread::sleep_for(std::chrono::milliseconds(2));
ASSERT_EQ(provider.arrived.load(), 1) << "the call never reached the provider";
client->cancelPending(id);
// Only now does the answer go out, over the real wire.
provider.answer();
std::this_thread::sleep_for(std::chrono::milliseconds(300));
EXPECT_EQ(handlerRuns.load(), 0)
<< "a reply arriving after cancelPending() must find no registration — "
"that is the semantic cancelPending() exists for, and it is the half "
"of the comment that IS true";
client->stop();
provider_conn->stop();
guard.reset();
ioc.stop();
worker.join();
}