From cfe830cf4457912a85f4efd685b1356d7db9961f Mon Sep 17 00:00:00 2001 From: Swung0x48 Date: Wed, 23 Sep 2026 18:15:22 -0400 Subject: [PATCH] [MG_Remote, MG_Test, MG_IntegrationTest, scripts] (P7): a spawned server reports SurfaceProgress while its apply thread runs a surface op, so the client's reply budget bounds silence and a cold bring-up past 20 s is waited for --- MobileGL/MG_IntegrationTest/CMakeLists.txt | 5 + MobileGL/MG_Remote/CONTRACT-P5.md | 4 +- MobileGL/MG_Remote/CONTRACT-P6.md | 4 +- MobileGL/MG_Remote/Client/ClientSession.cpp | 73 +++++++- MobileGL/MG_Remote/Client/ClientSession.h | 3 +- .../Protocol/generated/protocol_generated.h | 89 ++++++++- .../MG_Remote/Protocol/mg_protocol_base.h | 3 +- MobileGL/MG_Remote/Protocol/protocol.fbs | 14 ++ MobileGL/MG_Remote/Server/ServerLoop.cpp | 45 ++++- MobileGL/MG_Remote/Server/ServerLoop.h | 26 +++ MobileGL/MG_Remote/Server/ServerMain.cpp | 21 +++ MobileGL/MG_Test/Wire/ServerLoopTest.cpp | 170 ++++++++++++++++++ MobileGL/MG_Test/Wire/ServerSpawnTest.cpp | 110 ++++++++++++ scripts/ci/protocol_revision_pins.json | 3 +- 14 files changed, 556 insertions(+), 14 deletions(-) diff --git a/MobileGL/MG_IntegrationTest/CMakeLists.txt b/MobileGL/MG_IntegrationTest/CMakeLists.txt index 69f56e16..5f899f9f 100644 --- a/MobileGL/MG_IntegrationTest/CMakeLists.txt +++ b/MobileGL/MG_IntegrationTest/CMakeLists.txt @@ -2839,6 +2839,11 @@ if (MOBILEGL_BUILD_DISAGGREGATED) # "remote spawn bring-up failed" - the CI failure in miniature. A 3 s lever under a 2 s steady # knob was faster but proved less: the pre-fix client never read MOBILEGL_IPC_CONTROL_TIMEOUT_MS, # so its 5 s bound outlasted the lever and the entries were green at 14e1c8b9 (measured). + # SINCE p7/spawnhang THEY ARE NO LONGER THE BUDGET SELECTION'S RED-ONCE: a 20 s bring-up outran + # the cold-start budget too (run 35912252677), so both budgets now bound SILENCE - the server + # reports Wire::SurfaceProgress every 250 ms while it runs the op, and each report restarts the + # client's budget. These entries stay as the end-to-end check that a held bring-up is waited + # for on both backends; the mechanism's red-once is ServerSpawnTest's cold-bring-up case (unit). # Each entry takes ~25 s, because the harness's pre-flight child brings a server up as well. # NOT on integration-spawn: this is not a copy of the split lane (spawn_lane_parity.py). The # DirectVulkan entry does carry integration-gpu, unlike the Magma arms' informational tiers diff --git a/MobileGL/MG_Remote/CONTRACT-P5.md b/MobileGL/MG_Remote/CONTRACT-P5.md index 55f8a5a6..480c8dda 100644 --- a/MobileGL/MG_Remote/CONTRACT-P5.md +++ b/MobileGL/MG_Remote/CONTRACT-P5.md @@ -394,8 +394,8 @@ is a pull-build symbol and G1 admits **no resize**, which is the same reason the | `MOBILEGL_IPC_STRICT_ERRORS` | 0 | promotes BARRIER-PULLED reads — and, in a split build, the seven sticky forwards — to `Fatal`. | | `MOBILEGL_IPC_AUDIT` | 0 | `0xDD` over retired staging bytes (rule C's mechanical control). | | `MOBILEGL_IPC_SERVER_AFFINITY` | `auto` | kept as the raw string; whoever starts the apply thread logs the **resolved mask**, because an affinity that silently did nothing looks exactly like one that worked. | -| `MOBILEGL_IPC_CONTROL_TIMEOUT_MS` | 5000 | (P6 D5b, parsed from P7) a spawn/tcp client's wait for one surface-control `SurfaceReply` once the server's backend is up. Expiry is **not** fatal: dead latches device-lost, alive-but-silent is a named diagnostic. Range 100..600000. | -| `MOBILEGL_IPC_COLD_START_MS` | 20000 | (P7) the same wait for `CreatePbufferSurface` / `CreateWindowSurface` / `MakeCurrent` until the session's first `MakeCurrent` is answered ok - the ops a server brings its native backend up inside, lazily. Never shorter than `CONTROL_TIMEOUT_MS`. Measured need: retrace-split spawn legs outlasted 5 s on loaded CI runners. The test lever is the server's `MOBILEGL_TEST_DELAY_FIRST_BRINGUP_MS`. | +| `MOBILEGL_IPC_CONTROL_TIMEOUT_MS` | 5000 | (P6 D5b, parsed from P7) a spawn/tcp client's wait for one surface-control `SurfaceReply` once the server's backend is up. Expiry is **not** fatal: dead latches device-lost, alive-but-silent is a named diagnostic. Range 100..600000. Since p7/spawnhang it bounds **silence**, not the op: each `SurfaceProgress` the server sends while its apply thread runs the op (every 250 ms, `ServerLoop::kControlProgressIntervalMs`) restarts it, up to `kBarrierTimeoutMs` (120 s) from the send. | +| `MOBILEGL_IPC_COLD_START_MS` | 20000 | (P7) the same wait for `CreatePbufferSurface` / `CreateWindowSurface` / `MakeCurrent` until the session's first `MakeCurrent` is answered ok - the ops a server brings its native backend up inside, lazily. Never shorter than `CONTROL_TIMEOUT_MS`. Measured need: retrace-split spawn legs outlasted 5 s on loaded CI runners, and one outlasted 20 s (run 35912252677, `CreatePbufferSurface` seq 2) - which is why, since p7/spawnhang, this too is a silence budget that the server's `SurfaceProgress` reports restart (row above). The test lever is the server's `MOBILEGL_TEST_DELAY_FIRST_BRINGUP_MS`. | **One consequence, stated so it is not rediscovered.** In a build *without* `MOBILEGL_BUILD_DISAGGREGATED`, `MOBILEGL_TRANSPORT=inproc` is accepted by the environment and diff --git a/MobileGL/MG_Remote/CONTRACT-P6.md b/MobileGL/MG_Remote/CONTRACT-P6.md index 4d27a88f..78bf8841 100644 --- a/MobileGL/MG_Remote/CONTRACT-P6.md +++ b/MobileGL/MG_Remote/CONTRACT-P6.md @@ -335,7 +335,9 @@ into the pull build too, and is now guarded for the same reason. its expiry is `Fatal{ControlReplyTimeout, "@"}`. (b) The client's *cross-process* reply wait is bounded by `MOBILEGL_IPC_CONTROL_TIMEOUT_MS` (default 5000) and its expiry is **not** fatal: the client consults the doorbell's death latch — dead latches device-lost, alive-but-silent is a named -diagnostic. Packages: `cp` (a), `dl` (b). +diagnostic. Packages: `cp` (a), `dl` (b). (P7, p7/spawnhang: "silent" is now literal — a server whose +apply thread is running the op says so every 250 ms with `SurfaceProgress`, and each report restarts +the client's bound, up to 120 s; a server that never took the op, or is frozen, sends none.) > **D5c — the client's self-bell CANNOT witness the server's death, and `sm` is why.** Measured, not > predicted: `minecraft-1.21.4-fabric-iris-iterationrp-in-world` kills the *server* process outright diff --git a/MobileGL/MG_Remote/Client/ClientSession.cpp b/MobileGL/MG_Remote/Client/ClientSession.cpp index 231414e0..93db848a 100644 --- a/MobileGL/MG_Remote/Client/ClientSession.cpp +++ b/MobileGL/MG_Remote/Client/ClientSession.cpp @@ -1251,9 +1251,32 @@ namespace MobileGL::MG_Remote::Client { // The reply. A BOUNDED wait whose expiry is NOT fatal (CONTRACT-P6 §5.4 // D5b): a peer that is gone is a different fact from a peer that is slow, // and only the doorbell's death latch may say which. + // + // P7 (p7/spawnhang): THE BUDGET BOUNDS SILENCE, NOT THE OP. It used to be one deadline + // for the whole reply, so a server that was still running the op - a cold native + // bring-up, eglInitialize loading a software rasteriser off a runner's cold disk for + // ~20 s (retrace-split run 35912252677) - was reported ALIVE BUT SILENT and its surface + // creation failed, although it was about to answer. The server now says so while it runs + // an op it has taken (Wire::SurfaceProgress, every ServerLoop::kControlProgressIntervalMs), + // and each report restarts this budget. What still times out, named as before: a server + // that never took the op or is frozen (no report arrives), and one that reports progress + // past kBarrierTimeoutMs - the bound the verb barrier gives one record's apply, which is + // what a surface op that is being run IS. + const auto sentAt = std::chrono::steady_clock::now(); + const Uint32 ceilingMs = std::max(budgetMs, kBarrierTimeoutMs); + Uint32 progressReports = 0; + Uint32 lastProgressMs = 0; for (;;) { std::vector reply; - const MobileGLResult received = ReceiveControlFrame(reply, budgetMs); + Uint32 waitMs = budgetMs; + if (progressReports != 0) { + const auto spentMs = std::chrono::duration_cast( + std::chrono::steady_clock::now() - sentAt).count(); + waitMs = spentMs >= ceilingMs ? 0u : std::min(budgetMs, ceilingMs - static_cast(spentMs)); + } + // A zero wait is the ceiling, reached: answered exactly as an expired budget is. + const MobileGLResult received = + waitMs == 0 ? MOBILEGL_ERR_TIMEOUT : ReceiveControlFrame(reply, waitMs); if (received != MOBILEGL_OK) { // `dl` (D5b): THE EXPIRY IS NOT FATAL AND IT IS NOT ONE ANSWER. The transport // already distinguishes the two states this wait can end in, and the contract @@ -1272,6 +1295,14 @@ namespace MobileGL::MG_Remote::Client { } else if (const Transport::Doorbell* bell = m_producer.SelfDoorbell(); bell != nullptr && bell->PeerHungUp()) { LatchDeviceLost("a control reply timed out and the peer had hung up"); + } else if (progressReports != 0 && waitMs == 0) { + MGLOG_E("MG_Remote client: the server is ALIVE AND BUSY past the ceiling - it " + "reported %u time(s) that it was still running %s seq %llu (the last " + "at %u ms) and has not answered within %u ms, the bound the verb " + "barrier gives one apply. This is NOT device loss (CONTRACT-P6 5.4); " + "the op itself is not returning on the server's apply thread.", + progressReports, Server::SurfaceControlOpName(frame.kind), + static_cast(frame.seq), lastProgressMs, ceilingMs); } else { MGLOG_E("MG_Remote client: the server is ALIVE BUT SILENT - no SurfaceReply " "for %s seq %llu within %u ms (%s) and the control stream is still " @@ -1283,9 +1314,23 @@ namespace MobileGL::MG_Remote::Client { coldStart ? "the cold-start budget, MOBILEGL_IPC_COLD_START_MS: the " "server may still have been bringing its backend up" : "the steady bound, MOBILEGL_IPC_CONTROL_TIMEOUT_MS"); + // WHICH SILENCE (p7/spawnhang). A server running the op reports progress, so + // none at all means it never started it (or froze before it could say so); + // reports that stopped mean it froze mid-op. + if (progressReports == 0) + MGLOG_E("MG_Remote client: no SurfaceProgress arrived for seq %llu either (a " + "server reports every %u ms while it runs an op): it did not start " + "the op, or it is frozen", + static_cast(frame.seq), + Server::ServerLoop::kControlProgressIntervalMs); + else + MGLOG_E("MG_Remote client: the server had reported progress on seq %llu " + "%u time(s), the last at %u ms, and then stopped", + static_cast(frame.seq), progressReports, + lastProgressMs); } MGLOG_E("MG_Remote client: no SurfaceReply for seq %llu within %u ms (rc=%d)", - static_cast(frame.seq), budgetMs, + static_cast(frame.seq), waitMs == 0 ? ceilingMs : budgetMs, static_cast(received)); return received; } @@ -1304,6 +1349,30 @@ namespace MobileGL::MG_Remote::Client { } continue; } + if (envelope->msg_type() == ::MobileGL::Wire::CtrlMsg::SurfaceProgress) { + // THE SERVER IS STILL RUNNING THIS OP (p7/spawnhang, above): the budget restarts. + // One op is outstanding at a time (m_remoteControlMutex), so a report naming any + // other seq is a server that has lost track of which op it is running. + const auto* progress = envelope->msg_as_SurfaceProgress(); + if (progress == nullptr || progress->seq() != frame.seq) { + MGLOG_E("MG_Remote client: a SurfaceProgress names seq %llu while seq %llu is " + "the op outstanding", + static_cast(progress == nullptr ? 0 : progress->seq()), + static_cast(frame.seq)); + return MOBILEGL_ERR_PROTOCOL_MISMATCH; + } + if (progressReports == 0) { + MGLOG_I("MG_Remote client: the server is still running %s seq %llu (%u ms after " + "it was posted to its apply thread); the reply budget of %u ms restarts " + "on each progress report, up to %u ms", + Server::SurfaceControlOpName(frame.kind), + static_cast(frame.seq), progress->elapsedMs(), budgetMs, + ceilingMs); + } + ++progressReports; + lastProgressMs = progress->elapsedMs(); + continue; + } if (envelope->msg_type() == ::MobileGL::Wire::CtrlMsg::Fatal) { // `dl` step three: the server published a SessionFault before it aborted, so this // is a death that NAMES ITSELF instead of arriving as a bare EOF. Log the family diff --git a/MobileGL/MG_Remote/Client/ClientSession.h b/MobileGL/MG_Remote/Client/ClientSession.h index 2d007134..f009a0e8 100644 --- a/MobileGL/MG_Remote/Client/ClientSession.h +++ b/MobileGL/MG_Remote/Client/ClientSession.h @@ -458,7 +458,8 @@ namespace MobileGL::MG_Remote::Client { Uint64 m_remoteControlSeq = 0; // P7 CI: false until this session's first MakeCurrent is answered ok. Until then the // ops the server may bring its native backend up inside wait MOBILEGL_IPC_COLD_START_MS - // for their reply instead of MOBILEGL_IPC_CONTROL_TIMEOUT_MS (Config.h has both). + // for their reply instead of MOBILEGL_IPC_CONTROL_TIMEOUT_MS (Config.h has both). Either + // budget bounds SILENCE (p7/spawnhang): a Wire::SurfaceProgress for the op restarts it. // Guarded by m_remoteControlMutex, like the seq above; reset by Stop(). Bool m_serverBackendWarm = false; diff --git a/MobileGL/MG_Remote/Protocol/generated/protocol_generated.h b/MobileGL/MG_Remote/Protocol/generated/protocol_generated.h index 296ac651..97fecd26 100644 --- a/MobileGL/MG_Remote/Protocol/generated/protocol_generated.h +++ b/MobileGL/MG_Remote/Protocol/generated/protocol_generated.h @@ -77,6 +77,9 @@ struct FatalBuilder; struct LogLine; struct LogLineBuilder; +struct SurfaceProgress; +struct SurfaceProgressBuilder; + struct CtrlEnvelope; struct CtrlEnvelopeBuilder; @@ -506,11 +509,12 @@ enum class CtrlMsg : uint8_t { Refuse = 11, LogFlush = 12, DataBind = 13, + SurfaceProgress = 14, MIN = NONE, - MAX = DataBind + MAX = SurfaceProgress }; -inline const CtrlMsg (&EnumValuesCtrlMsg())[14] { +inline const CtrlMsg (&EnumValuesCtrlMsg())[15] { static const CtrlMsg values[] = { CtrlMsg::NONE, CtrlMsg::Hello, @@ -525,13 +529,14 @@ inline const CtrlMsg (&EnumValuesCtrlMsg())[14] { CtrlMsg::LogLine, CtrlMsg::Refuse, CtrlMsg::LogFlush, - CtrlMsg::DataBind + CtrlMsg::DataBind, + CtrlMsg::SurfaceProgress }; return values; } inline const char * const *EnumNamesCtrlMsg() { - static const char * const names[15] = { + static const char * const names[16] = { "NONE", "Hello", "Welcome", @@ -546,13 +551,14 @@ inline const char * const *EnumNamesCtrlMsg() { "Refuse", "LogFlush", "DataBind", + "SurfaceProgress", nullptr }; return names; } inline const char *EnumNameCtrlMsg(CtrlMsg e) { - if (::flatbuffers::IsOutRange(e, CtrlMsg::NONE, CtrlMsg::DataBind)) return ""; + if (::flatbuffers::IsOutRange(e, CtrlMsg::NONE, CtrlMsg::SurfaceProgress)) return ""; const size_t index = static_cast(e); return EnumNamesCtrlMsg()[index]; } @@ -613,6 +619,10 @@ template<> struct CtrlMsgTraits { static const CtrlMsg enum_value = CtrlMsg::DataBind; }; +template<> struct CtrlMsgTraits { + static const CtrlMsg enum_value = CtrlMsg::SurfaceProgress; +}; + template bool VerifyCtrlMsg(::flatbuffers::VerifierTemplate &verifier, const void *obj, CtrlMsg type); template @@ -2220,6 +2230,64 @@ inline ::flatbuffers::Offset CreateLogLineDirect( text__); } +struct SurfaceProgress FLATBUFFERS_FINAL_CLASS : private ::flatbuffers::Table { + typedef SurfaceProgressBuilder Builder; + struct Traits; + enum FlatBuffersVTableOffset FLATBUFFERS_VTABLE_UNDERLYING_TYPE { + VT_SEQ = 4, + VT_ELAPSEDMS = 6 + }; + uint64_t seq() const { + return GetField(VT_SEQ, 0); + } + uint32_t elapsedMs() const { + return GetField(VT_ELAPSEDMS, 0); + } + template + bool Verify(::flatbuffers::VerifierTemplate &verifier) const { + return VerifyTableStart(verifier) && + VerifyField(verifier, VT_SEQ, 8) && + VerifyField(verifier, VT_ELAPSEDMS, 4) && + verifier.EndTable(); + } +}; + +struct SurfaceProgressBuilder { + typedef SurfaceProgress Table; + ::flatbuffers::FlatBufferBuilder &fbb_; + ::flatbuffers::uoffset_t start_; + void add_seq(uint64_t seq) { + fbb_.AddElement(SurfaceProgress::VT_SEQ, seq, 0); + } + void add_elapsedMs(uint32_t elapsedMs) { + fbb_.AddElement(SurfaceProgress::VT_ELAPSEDMS, elapsedMs, 0); + } + explicit SurfaceProgressBuilder(::flatbuffers::FlatBufferBuilder &_fbb) + : fbb_(_fbb) { + start_ = fbb_.StartTable(); + } + ::flatbuffers::Offset Finish() { + const auto end = fbb_.EndTable(start_); + auto o = ::flatbuffers::Offset(end); + return o; + } +}; + +inline ::flatbuffers::Offset CreateSurfaceProgress( + ::flatbuffers::FlatBufferBuilder &_fbb, + uint64_t seq = 0, + uint32_t elapsedMs = 0) { + SurfaceProgressBuilder builder_(_fbb); + builder_.add_seq(seq); + builder_.add_elapsedMs(elapsedMs); + return builder_.Finish(); +} + +struct SurfaceProgress::Traits { + using type = SurfaceProgress; + static auto constexpr Create = CreateSurfaceProgress; +}; + struct CtrlEnvelope FLATBUFFERS_FINAL_CLASS : private ::flatbuffers::Table { typedef CtrlEnvelopeBuilder Builder; struct Traits; @@ -2273,6 +2341,9 @@ struct CtrlEnvelope FLATBUFFERS_FINAL_CLASS : private ::flatbuffers::Table { const MobileGL::Wire::DataBind *msg_as_DataBind() const { return msg_type() == MobileGL::Wire::CtrlMsg::DataBind ? static_cast(msg()) : nullptr; } + const MobileGL::Wire::SurfaceProgress *msg_as_SurfaceProgress() const { + return msg_type() == MobileGL::Wire::CtrlMsg::SurfaceProgress ? static_cast(msg()) : nullptr; + } template bool Verify(::flatbuffers::VerifierTemplate &verifier) const { return VerifyTableStart(verifier) && @@ -2335,6 +2406,10 @@ template<> inline const MobileGL::Wire::DataBind *CtrlEnvelope::msg_as inline const MobileGL::Wire::SurfaceProgress *CtrlEnvelope::msg_as() const { + return msg_as_SurfaceProgress(); +} + struct CtrlEnvelopeBuilder { typedef CtrlEnvelope Table; ::flatbuffers::FlatBufferBuilder &fbb_; @@ -2429,6 +2504,10 @@ inline bool VerifyCtrlMsg(::flatbuffers::VerifierTemplate &verifier, const vo auto ptr = reinterpret_cast(obj); return verifier.VerifyTable(ptr); } + case CtrlMsg::SurfaceProgress: { + auto ptr = reinterpret_cast(obj); + return verifier.VerifyTable(ptr); + } default: return true; } } diff --git a/MobileGL/MG_Remote/Protocol/mg_protocol_base.h b/MobileGL/MG_Remote/Protocol/mg_protocol_base.h index 579d59d6..27d1765e 100644 --- a/MobileGL/MG_Remote/Protocol/mg_protocol_base.h +++ b/MobileGL/MG_Remote/Protocol/mg_protocol_base.h @@ -64,7 +64,8 @@ extern "C" { // it runs as ProtocolSchema.RevisionPinsDigest (label unit) and in CI's flatc-check job. After a // bump: `python3 scripts/ci/protocol_revision_pin.py --write` records the new row. // 1 P7 wave 2-F, PH-7 (4): Welcome.dataNonce and the DataBind message. -#define MOBILEGL_PROTOCOL_CONTROL_REVISION 1 +// 2 P7 (p7/spawnhang): the SurfaceProgress message. +#define MOBILEGL_PROTOCOL_CONTROL_REVISION 2 #define MOBILEGL_ABI_VERSION(major, minor) (((uint32_t)(major) << 16) | (uint32_t)(minor)) #define MOBILEGL_ABI_MAJOR_OF(version) ((uint32_t)(version) >> 16) diff --git a/MobileGL/MG_Remote/Protocol/protocol.fbs b/MobileGL/MG_Remote/Protocol/protocol.fbs index 6c0f80a5..ac552158 100644 --- a/MobileGL/MG_Remote/Protocol/protocol.fbs +++ b/MobileGL/MG_Remote/Protocol/protocol.fbs @@ -340,6 +340,19 @@ table LogLine { text: string; } +// P7 (p7/spawnhang). THE SERVER IS STILL RUNNING THE CLIENT'S SURFACE OP. Sent only by the +// server's control pump, only while its apply thread is running a SurfaceOp it has TAKEN, and +// only before that op's SurfaceReply - once per progress interval after the op has run that long +// (ServerLoop.cpp, kControlProgressIntervalMs). It is how a client tells a server that is BUSY +// with its op (a cold native bring-up inside the first surface creation or MakeCurrent: eglInitialize +// loading a software rasteriser off a cold disk) from one that is SILENT: the client's reply budget +// restarts on each report, up to a ceiling. A server that never took the op, or is frozen, sends +// none and still times out by name (CONTRACT-P6 5.4 D5b). +table SurfaceProgress { + seq: ulong; // the SurfaceOp.seq being run + elapsedMs: uint; // since the op was posted to the apply thread +} + // --------------------------------------------------------------------------- // Envelope // --------------------------------------------------------------------------- @@ -363,6 +376,7 @@ union CtrlMsg { Refuse, LogFlush, DataBind, + SurfaceProgress, } table CtrlEnvelope { diff --git a/MobileGL/MG_Remote/Server/ServerLoop.cpp b/MobileGL/MG_Remote/Server/ServerLoop.cpp index 2902ee72..79160095 100644 --- a/MobileGL/MG_Remote/Server/ServerLoop.cpp +++ b/MobileGL/MG_Remote/Server/ServerLoop.cpp @@ -633,9 +633,21 @@ namespace MobileGL::MG_Remote::Server { // The dispatch runs OUTSIDE the lock, exactly as the old work(user) did, and fills the // frame's reply half; the reply is then published back into the slot under the lock so // the poster's copy-out after m_controlDone sees it. + const auto dispatchStart = std::chrono::steady_clock::now(); const MobileGLResult result = ApplySurfaceControlFrame( frame, m_controlProbeHook.load(std::memory_order_acquire), m_controlProbeUser.load(std::memory_order_acquire)); + // p7/spawnhang: A SLOW DISPATCH NAMES ITSELF. The first surface creation / MakeCurrent is + // where a lazy native bring-up runs, and on a cold CI runner it outran the client's whole + // reply budget with nothing in this log to say so - the investigation had to infer it. + const auto dispatchMs = std::chrono::duration_cast( + std::chrono::steady_clock::now() - dispatchStart).count(); + if (dispatchMs >= static_cast(kSlowControlDispatchMs)) { + MGLOG_W("MG_Remote server: %s seq %llu ran %lld ms on mgl-srv-apply (a lazy native " + "bring-up runs inside the first surface creation or MakeCurrent)", + SurfaceControlOpName(frame.kind), static_cast(frame.seq), + static_cast(dispatchMs)); + } { const std::lock_guard lock(m_controlMutex); m_controlFrame = frame; @@ -844,11 +856,42 @@ namespace MobileGL::MG_Remote::Server { if (m_session != nullptr) { m_session->DataLink()->ConsumerBell().Notify(); } - m_controlDone.wait(lock, [this] { return m_controlFinished; }); + // p7/spawnhang: THE WAIT IS SLICED, AND A SLICE THE APPLY THREAD SPENT RUNNING THIS FRAME IS + // REPORTED (SetControlProgressSink). It used to be one untimed wait, so the poster - under + // spawn, the control pump in ServerMain, the only thread that talks to the client - was mute + // for as long as the dispatch ran, and a client could not tell a cold bring-up from a wedge. + // "Running" is read under this lock from the mailbox's own fields: the pump clears the + // shadow when it TAKES the frame (PumpControlRequest), and m_controlPending stays true until + // the reply is published under this same lock. Posted-but-not-taken says nothing. The sink + // runs without the lock, so a dispatch finishing meanwhile is not held up by the send; the + // predicate is re-asked on the way back in. Only the timing of the wakeups changed: the + // handshake, the C2 exit block's answer and the copy-out below are exactly as before. + const auto postedAt = std::chrono::steady_clock::now(); + while (!m_controlDone.wait_for(lock, std::chrono::milliseconds(kControlProgressIntervalMs), + [this] { return m_controlFinished; })) { + const Bool running = m_controlPending && !m_controlPosted.load(std::memory_order_acquire); + const ControlProgressSink sink = m_progressSink; + void* const user = m_progressUser; + if (!running || sink == nullptr) continue; + const auto elapsedMs = std::chrono::duration_cast( + std::chrono::steady_clock::now() - postedAt).count(); + lock.unlock(); + sink(user, frame.kind, frame.seq, + static_cast(std::min(elapsedMs, 0xFFFFFFFFll))); + lock.lock(); + } frame = m_controlFrame; // the reply half, written by the dispatch return m_controlResult; } + void ServerLoop::SetControlProgressSink(ControlProgressSink sink, void* user) { + // Under the mailbox's lock, which the poster holds when it reads the pair, so a sink is + // never called with another sink's user. + const std::lock_guard lock(m_controlMutex); + m_progressSink = sink; + m_progressUser = user; + } + MobileGLResult ServerLoop::RunProbeOnApplyThreadForTesting(ControlProbeHook hook, void* user) { SurfaceControlFrame frame; frame.kind = SurfaceControlOp::ProbeForTesting; diff --git a/MobileGL/MG_Remote/Server/ServerLoop.h b/MobileGL/MG_Remote/Server/ServerLoop.h index 6b1455ca..3cef426b 100644 --- a/MobileGL/MG_Remote/Server/ServerLoop.h +++ b/MobileGL/MG_Remote/Server/ServerLoop.h @@ -249,6 +249,28 @@ namespace MobileGL::MG_Remote::Server { using ControlProbeHook = MobileGLResult (*)(void* user); MobileGLResult RunProbeOnApplyThreadForTesting(ControlProbeHook hook, void* user); + // P7 (p7/spawnhang). WHAT A POSTER SAYS WHILE THE APPLY THREAD RUNS ITS FRAME. + // + // A posted frame is waited for in slices of kControlProgressIntervalMs, and after every + // slice in which the apply thread is RUNNING it - taken, not yet answered - the poster calls + // this sink with the frame's kind, its seq and how long ago it was posted, WITHOUT + // m_controlMutex held. ServerMain installs one that sends Wire::SurfaceProgress on the + // control connection: that is how a spawn / TCP client tells a server BUSY with its op (a + // cold native bring-up - eglInitialize loading a software rasteriser off a cold disk ran + // ~20 s on a CI runner) from a SILENT one, and restarts its reply budget. A frame posted but + // NOT TAKEN reports nothing, because that silence is exactly what the client's budget + // exists to name. Null (inproc, and every case that does not set one): the slices are + // waited out and nothing is said. Read on the posting thread, set from any (both under + // m_controlMutex). + using ControlProgressSink = void (*)(void* user, SurfaceControlOp kind, Uint64 seq, Uint32 elapsedMs); + void SetControlProgressSink(ControlProgressSink sink, void* user); + // Well inside the smallest default reply budget (MOBILEGL_IPC_CONTROL_TIMEOUT_MS, 5000), + // and a frame's worth of bytes per interval only while an op runs that long. + static constexpr Uint32 kControlProgressIntervalMs = 250; + // A dispatch that runs at least this long is logged, with its op, seq and duration, on the + // apply thread when it returns - the line the retrace-split investigation did not have. + static constexpr Uint32 kSlowControlDispatchMs = 1000; + // How many frames this loop has dispatched (every kind, probe included). Reset by // Start(). The frame channel's own red-once handle: a forwarder that stopped posting // frames leaves this unmoved. @@ -451,6 +473,10 @@ namespace MobileGL::MG_Remote::Server { // published; held until its reply returns. Re-entrant probes use call-local arguments. std::atomic m_controlProbeHook{nullptr}; std::atomic m_controlProbeUser{nullptr}; + // SetControlProgressSink's pair (p7/spawnhang). Guarded by m_controlMutex: the poster reads + // both while it holds that lock between slices, so the pair is always read whole. + ControlProgressSink m_progressSink = nullptr; + void* m_progressUser = nullptr; // The BOUNDED join's other half. std::thread::join has no deadline, so a lost wakeup // would wedge CI rather than fail it; the thread signals here last and Stop() waits diff --git a/MobileGL/MG_Remote/Server/ServerMain.cpp b/MobileGL/MG_Remote/Server/ServerMain.cpp index 21b0dc44..f61c9b74 100644 --- a/MobileGL/MG_Remote/Server/ServerMain.cpp +++ b/MobileGL/MG_Remote/Server/ServerMain.cpp @@ -57,6 +57,22 @@ void ForwardLog(void* user, const char* text) { (void)transport.SendFrame({builder.GetBufferPointer(), builder.GetSize()}); } +// p7/spawnhang. THE PROGRESS REPORT: Wire::SurfaceProgress, sent by the thread that posted the op +// - RunSession's control pump, waiting in ServerApplyWireSurfaceOp - after each +// ServerLoop::kControlProgressIntervalMs that mgl-srv-apply has spent running it +// (ServerLoop::SetControlProgressSink). The client's reply budget restarts on each one, so a cold +// native bring-up that outruns MOBILEGL_IPC_COLD_START_MS is waited for instead of being reported +// ALIVE BUT SILENT (retrace-split run 35912252677). A send failure is left to the reply's send, +// which already ends the session on it. +void SendSurfaceProgress(void* user, Server::SurfaceControlOp, std::uint64_t seq, std::uint32_t elapsedMs) { + auto& transport = *static_cast(user); + flatbuffers::FlatBufferBuilder builder(64); + auto progress = Protocol::CreateSurfaceProgress(builder, seq, elapsedMs); + auto envelope = Protocol::CreateCtrlEnvelope(builder, Protocol::CtrlMsg::SurfaceProgress, progress.Union()); + Protocol::FinishCtrlEnvelopeBuffer(builder, envelope); + (void)transport.SendFrame({builder.GetBufferPointer(), builder.GetSize()}); +} + void RefuseBusy(SocketTransport& transport, const char* detail) { // Unread Hello bytes can make close send RST and discard our Refuse. std::uint64_t bytes = 0; @@ -459,6 +475,10 @@ void DelaySessionHandshakeForTest() { if (tcp && (!forwarding || std::strcmp(forwarding, "0") != 0)) MobileGL::MG_Util::Debug::SetLogForwarder(&ForwardLog, control.get()); auto& loop = Server::ServerLoopInstance(); + // p7/spawnhang: this thread posts every surface op the client sends (ServerApplyWireSurfaceOp, + // below) and is the one that says "still running" while the apply thread runs it. Cleared + // after the loop, on this same thread, so no post can be in flight when it goes. + loop.SetControlProgressSink(&SendSurfaceProgress, control.get()); if (loop.Start(session) != MOBILEGL_OK) ::_exit(70); WireLogError("MG_Remote server: pid=%d transport=spawn role=server ready control=%s data=%s", selfPid, tcp ? "tcp" : "unix", tcp ? "stream" : "shm"); @@ -595,6 +615,7 @@ void DelaySessionHandshakeForTest() { break; } } + loop.SetControlProgressSink(nullptr, nullptr); loop.Stop(); // Publish the final server window while log forwarding is still attached. MobileGL::MG_Util::PipeStats::Shutdown(); diff --git a/MobileGL/MG_Test/Wire/ServerLoopTest.cpp b/MobileGL/MG_Test/Wire/ServerLoopTest.cpp index 8c84248b..6c84d8d3 100644 --- a/MobileGL/MG_Test/Wire/ServerLoopTest.cpp +++ b/MobileGL/MG_Test/Wire/ServerLoopTest.cpp @@ -75,6 +75,7 @@ #include #include #include +#include #include #include #include @@ -444,6 +445,175 @@ TEST(ServerLoopTest, TheControlShadowIsClearedWhenThePumpTakesTheRequest) { fixture.Stop(); } +// ===================================================================================== +// p7/spawnhang: the poster reports a frame the apply thread is RUNNING, and only that +// ===================================================================================== +// +// retrace-split run 35912252677: a spawned server's first CreatePbufferSurface ran its lazy native +// bring-up (eglInitialize, a software rasteriser read off a cold runner disk) for ~20 s - the whole +// cold-start reply budget - and the client, which could not tell a busy server from a wedged one, +// gave up while the server was about to answer. The poster now waits in slices and, after every +// slice the apply thread spent RUNNING its frame, tells the installed sink (ServerMain's sends +// Wire::SurfaceProgress; ServerSpawnTest's cold-bring-up case is the end-to-end half). Two +// halves, each red for its own reason: +// - a frame the apply thread runs for several slices IS reported, with its kind, one seq and a +// growing elapsed time - with the old untimed wait there is no report at all; +// - a frame POSTED BUT NOT TAKEN (the apply thread is held in a drain) is NOT, however long it +// waits: that silence is what the client's budget still names, and a poster that reported +// every slice regardless would turn a stuck apply thread into an endless wait. +namespace { + struct ProgressLog { + struct Report { + Server::SurfaceControlOp kind; + Uint64 seq; + Uint32 elapsedMs; + }; + std::mutex mutex; + std::vector reports; + + static void Sink(void* user, Server::SurfaceControlOp kind, Uint64 seq, Uint32 elapsedMs) { + auto* log = static_cast(user); + const std::lock_guard lock(log->mutex); + log->reports.push_back(Report{kind, seq, elapsedMs}); + } + std::vector Snapshot() { + const std::lock_guard lock(mutex); + return reports; + } + }; + + // Six slices: long enough that a poster oversleeping by most of a second under a loaded `-j` + // still wakes at least once while the frame runs. + constexpr Uint32 kProgressProbeRunMs = 6 * Server::ServerLoop::kControlProgressIntervalMs; + + // Posts `hook` from a helper thread (N-9's reason: a lost post must be said in the case's own + // words, not as ctest's timeout) and waits for its answer within `deadlineMs`. + bool PostProbeAndWait(Server::ServerLoop::ControlProbeHook hook, void* user, Uint32 deadlineMs, + MobileGLResult* rc, long long* waitedMs) { + std::atomic answered{false}; + std::thread poster([&] { + const auto start = std::chrono::steady_clock::now(); + *rc = Server::ServerLoopInstance().RunProbeOnApplyThreadForTesting(hook, user); + *waitedMs = std::chrono::duration_cast( + std::chrono::steady_clock::now() - start).count(); + answered.store(true, std::memory_order_release); + }); + const auto deadline = std::chrono::steady_clock::now() + std::chrono::milliseconds(deadlineMs); + while (!answered.load(std::memory_order_acquire) && std::chrono::steady_clock::now() < deadline) { + std::this_thread::sleep_for(std::chrono::milliseconds(1)); + } + const Bool ok = answered.load(std::memory_order_acquire); + if (!ok) Server::ServerLoopInstance().Stop(); // frees the poster (C2's exit block answers it) + poster.join(); + return ok; + } +} // namespace + +TEST(ServerLoopTest, AFrameTheApplyThreadIsRunningIsReportedToTheProgressSinkWhileItRuns) { + ServerFixture fixture; + ASSERT_TRUE(fixture.Handshake()); + ASSERT_TRUE(fixture.StartLoop()); + Server::ServerLoop& loop = Server::ServerLoopInstance(); + ProgressLog log; + loop.SetControlProgressSink(&ProgressLog::Sink, &log); + + MobileGLResult rc = MOBILEGL_ERR_INVALID_ARGUMENT; + long long waitedMs = 0; + const Bool answered = PostProbeAndWait( + +[](void*) -> MobileGLResult { + std::this_thread::sleep_for(std::chrono::milliseconds(kProgressProbeRunMs)); + return MOBILEGL_OK; + }, + nullptr, 20000, &rc, &waitedMs); + loop.SetControlProgressSink(nullptr, nullptr); + // EXPECT, never ASSERT, from here to Stop(): a case that returns early leaves the apply thread + // parked and the process does not exit. + EXPECT_TRUE(answered) << "a posted probe was never answered"; + EXPECT_EQ(rc, MOBILEGL_OK); + + const std::vector reports = log.Snapshot(); + EXPECT_FALSE(reports.empty()) + << "the apply thread ran the frame for " << waitedMs << " ms and the poster said nothing: " + << "a spawn client would have seen silence for the whole of a cold bring-up and given up " + "on a server that was about to answer"; + for (std::size_t i = 0; i < reports.size(); ++i) { + EXPECT_EQ(reports[i].kind, Server::SurfaceControlOp::ProbeForTesting) << "report " << i; + EXPECT_NE(reports[i].seq, 0u) << "report " << i << " names no seq"; + EXPECT_EQ(reports[i].seq, reports.front().seq) << "one frame, one seq (report " << i << ")"; + EXPECT_GE(reports[i].elapsedMs, Server::ServerLoop::kControlProgressIntervalMs) + << "report " << i << " came before one whole interval had passed"; + if (i != 0) EXPECT_GT(reports[i].elapsedMs, reports[i - 1].elapsedMs) << "report " << i; + } + + // THE SERVER LOG NAMES THE SLOW DISPATCH TOO: the line the investigation did not have. + const std::string text = ReadLog(); + EXPECT_NE(text.find("ProbeForTesting seq"), std::string::npos) + << "a dispatch that ran " << waitedMs << " ms was not named in the server log"; + EXPECT_NE(text.find("ms on mgl-srv-apply"), std::string::npos); + + fixture.Stop(); +} + +TEST(ServerLoopTest, AFramePostedButNotYetTakenIsNotReportedHoweverLongItWaits) { + ServerFixture fixture; + ASSERT_TRUE(fixture.Handshake()); + ASSERT_TRUE(fixture.StartLoop()); + Server::ServerLoop& loop = Server::ServerLoopInstance(); + + // HOLD THE APPLY THREAD IN A DRAIN, where it cannot take a posted frame: the retire hook runs + // on the apply thread after a record is applied and before it is retired (DrainRing). + static std::atomic s_inDrain{false}; + static std::atomic s_releaseDrain{false}; + s_inDrain.store(false); + s_releaseDrain.store(false); + loop.SetBeforeRetireHookForTesting(+[] { + s_inDrain.store(true, std::memory_order_release); + const auto deadline = std::chrono::steady_clock::now() + std::chrono::seconds(10); + while (!s_releaseDrain.load(std::memory_order_acquire) && std::chrono::steady_clock::now() < deadline) { + std::this_thread::sleep_for(std::chrono::milliseconds(1)); + } + }); + const MG_Pipe::MGPClear clear = WholeFramebufferClear(); + const Uint64 seq = fixture.encoder.EncodeRecord(MG_Pipe::MGPWireOp::Clear, &clear, sizeof(clear)); + ASSERT_NE(seq, Codec::kInvalidSeq); + fixture.encoder.Publish(); + fixture.producer.PublishAndNotify(seq); + const auto holdDeadline = std::chrono::steady_clock::now() + std::chrono::seconds(5); + while (!s_inDrain.load(std::memory_order_acquire) && std::chrono::steady_clock::now() < holdDeadline) { + std::this_thread::sleep_for(std::chrono::milliseconds(1)); + } + ASSERT_TRUE(s_inDrain.load(std::memory_order_acquire)) << "the apply thread never reached the drain"; + + ProgressLog log; + loop.SetControlProgressSink(&ProgressLog::Sink, &log); + // The probe is posted from a helper while the drain holds the apply thread for six slices, + // then the drain is let go from here and the probe - instant once taken - is answered. + std::thread releaser([] { + std::this_thread::sleep_for(std::chrono::milliseconds(kProgressProbeRunMs)); + s_releaseDrain.store(true, std::memory_order_release); + }); + MobileGLResult rc = MOBILEGL_ERR_INVALID_ARGUMENT; + long long waitedMs = 0; + const Bool answered = + PostProbeAndWait(+[](void*) -> MobileGLResult { return MOBILEGL_OK; }, nullptr, 20000, &rc, &waitedMs); + releaser.join(); + loop.SetControlProgressSink(nullptr, nullptr); + loop.SetBeforeRetireHookForTesting(nullptr); + EXPECT_TRUE(answered) << "a posted probe was never answered once the drain let go"; + EXPECT_EQ(rc, MOBILEGL_OK); + + // THE WINDOW WAS REAL: the probe waited behind the drain for several slices. + EXPECT_GE(waitedMs, static_cast(2 * Server::ServerLoop::kControlProgressIntervalMs)) + << "the probe was answered after " << waitedMs << " ms, so it was never posted-and-waiting " + "long enough for this case to say anything"; + EXPECT_TRUE(log.Snapshot().empty()) + << log.Snapshot().size() << " progress report(s) for a frame the apply thread had NOT " + << "taken: the poster reports every slice, so a client would wait on a server whose apply " + "thread never started its op"; + + fixture.Stop(); +} + // Re-entrancy is not a deadlock: ~BackendObject_DirectGLES reaches ReleaseEGLResources FROM the // apply thread, so a post from there must run inline. TEST(ServerLoopTest, APostFromTheApplyThreadItselfRunsInlineRatherThanDeadlocking) { diff --git a/MobileGL/MG_Test/Wire/ServerSpawnTest.cpp b/MobileGL/MG_Test/Wire/ServerSpawnTest.cpp index 39c6c156..7cb51073 100644 --- a/MobileGL/MG_Test/Wire/ServerSpawnTest.cpp +++ b/MobileGL/MG_Test/Wire/ServerSpawnTest.cpp @@ -33,6 +33,7 @@ // SCM_RIGHTS works across - the mechanism the four segments ride on, proven // the boundary before the data plane needs it. +#include #include #include #include @@ -968,6 +969,115 @@ TEST(ServerSpawnTest, AnEglControlOpCrossesToTheOtherProcessAndAnswers) { ASSERT_EQ(Server::ReapServer(session.server, 5000, &exitCode), MOBILEGL_OK); } +namespace { + // p7/spawnhang. The client's two reply budgets, shortened for one case and put back after it, + // and the harness's headless EGL for the server it starts (EventForfeitPeerTest's PinHeadlessEgl: + // the first surface creation runs a real eglInitialize, and a runner has no DISPLAY). + struct ShortReplyBudgets { + MobileGL::Uint32 steady = MobileGL::MG_Config::Ipc.ControlTimeoutMs; + MobileGL::Uint32 cold = MobileGL::MG_Config::Ipc.ColdStartMs; + explicit ShortReplyBudgets(MobileGL::Uint32 ms) { + MobileGL::MG_Config::Ipc.ControlTimeoutMs = ms; + MobileGL::MG_Config::Ipc.ColdStartMs = ms; + } + ~ShortReplyBudgets() { + MobileGL::MG_Config::Ipc.ControlTimeoutMs = steady; + MobileGL::MG_Config::Ipc.ColdStartMs = cold; + } + }; + + std::string HeadlessEglPlatform() { + const char* pinned = std::getenv("EGL_PLATFORM"); + return pinned != nullptr ? pinned : "surfaceless"; + } + + Server::SurfaceControlFrame PbufferCreation() { + Server::SurfaceControlFrame frame{}; + frame.kind = Server::SurfaceControlOp::CreatePbufferSurface; + frame.surface = 1; + frame.width = 16; + frame.height = 16; + return frame; + } + + long long MillisecondsSince(std::chrono::steady_clock::time_point start) { + return std::chrono::duration_cast(std::chrono::steady_clock::now() - start) + .count(); + } +} // namespace + +// p7/spawnhang: retrace-split run 35912252677, in miniature and in seconds instead of twenty. +// +// A spawned server brings its native backend up lazily, INSIDE the first surface creation +// (eglInitialize). On a cold CI runner that read a software rasteriser off disk for ~20 s - the +// whole MOBILEGL_IPC_COLD_START_MS - and the client, which measured the op's DURATION against a +// budget meant for SILENCE, reported the server ALIVE BUT SILENT and failed the pbuffer with +// EGL_BAD_ALLOC while the server was about to answer. The server now reports progress while its +// apply thread runs an op it has taken (Wire::SurfaceProgress), and each report restarts the +// client's budget. +// +// Here the server's own test lever holds its first CreatePbufferSurface for 3000 ms and the client's +// budgets are 1000 ms - the same shape as 20 s of bring-up against a 20 s budget, three times over. +// Against the client and server as they were (one untimed wait on the server, one deadline on the +// client) the op comes back TIMEOUT at ~1000 ms: the CI failure, named the way CI named it. With +// the progress reports it comes back answered, after the lever let it go. +TEST(ServerSpawnTest, AColdBringUpThatOutlastsTheReplyBudgetIsWaitedForBecauseTheServerReportsProgress) { + const ScopedEnvironment lever("MOBILEGL_TEST_DELAY_FIRST_BRINGUP_MS", "3000"); + const ScopedEnvironment headless("EGL_PLATFORM", HeadlessEglPlatform()); + const ShortReplyBudgets budgets(1000); + + Session session; + ASSERT_TRUE(Bring("coldprogress", &session)); + ScopedSessionCleanup cleanup{session}; + ASSERT_EQ(Handshake(session), MOBILEGL_OK); + + Server::SurfaceControlFrame frame = PbufferCreation(); + const auto start = std::chrono::steady_clock::now(); + const MobileGLResult rc = Client::ClientSessionInstance().RunRemoteSurfaceControlFrame(frame); + const long long elapsedMs = MillisecondsSince(start); + + // THE ROUND TRIP, not the EGL answer: whether a headless runner can make a pbuffer is not + // this case's question (`ok` is whatever the driver said); whether the reply was WAITED FOR is. + EXPECT_EQ(rc, MOBILEGL_OK) + << "the op came back rc=" << static_cast(rc) << " after " << elapsedMs + << " ms: the client gave up on a server that was still running it - the retrace-split " + "failure (\"ALIVE BUT SILENT - no SurfaceReply for CreatePbufferSurface seq 2\")"; + if (rc == MOBILEGL_OK) { + EXPECT_GE(elapsedMs, 3000) + << "the reply came back before the server's lever released the op, so the lever did not " + "hold the bring-up and this case proved nothing about waiting for one"; + } + EXPECT_FALSE(Client::ClientSession::DeviceLost()) << "a slow server is not a lost device (5.4)"; +} + +// The other half, and the reason the budget still exists: a server that is ALIVE BUT FROZEN reports +// nothing, so the same op against it still ends at the budget, by name, rather than waiting on +// progress that never comes. SIGSTOP freezes the whole process - the pump that would report as well +// as the apply thread - and keeps every descriptor open, so it is not a hangup either. +TEST(ServerSpawnTest, AFrozenServerReportsNoProgressAndTheOpStillTimesOutAtTheBudget) { + const ScopedEnvironment headless("EGL_PLATFORM", HeadlessEglPlatform()); + const ShortReplyBudgets budgets(1000); + + Session session; + ASSERT_TRUE(Bring("frozenprogress", &session)); + ScopedSessionCleanup cleanup{session}; + ASSERT_EQ(Handshake(session), MOBILEGL_OK); + ASSERT_EQ(::kill(session.server.pid, SIGSTOP), 0); + + Server::SurfaceControlFrame frame = PbufferCreation(); + const auto start = std::chrono::steady_clock::now(); + const MobileGLResult rc = Client::ClientSessionInstance().RunRemoteSurfaceControlFrame(frame); + const long long elapsedMs = MillisecondsSince(start); + (void)::kill(session.server.pid, SIGCONT); + + EXPECT_EQ(rc, MOBILEGL_ERR_TIMEOUT) + << "a frozen server was not timed out (rc=" << static_cast(rc) << ")"; + EXPECT_LT(elapsedMs, 10000) + << "took " << elapsedMs << " ms against a 1000 ms budget: something other than a progress " + "report restarted the wait"; + EXPECT_FALSE(Client::ClientSession::DeviceLost()) << "a frozen server is not a lost device (5.4)"; +} + TEST(ServerSpawnTest, TheHandshakeCarriesTwoDifferentProcessIdsAndNotTwoZeroes) { // CONTRACT-P6 4.3. Hello::pid was hard-coded 0 and Welcome::serverPid ECHOED it back, so the // handshake carried 0 and 0 and named nothing at all. Both now carry real ids, which makes diff --git a/scripts/ci/protocol_revision_pins.json b/scripts/ci/protocol_revision_pins.json index a0a1006d..fb01fcde 100644 --- a/scripts/ci/protocol_revision_pins.json +++ b/scripts/ci/protocol_revision_pins.json @@ -1,3 +1,4 @@ { - "1": "7fc859f7fa756818401f4162e7d49a25d430b91e44d89c297321e3cb36c69638" + "1": "7fc859f7fa756818401f4162e7d49a25d430b91e44d89c297321e3cb36c69638", + "2": "b30928e6fc93ddc015fd86f634a6820f775a6f2f6de5a848d273981e706b2597" }