From 8888e57d08d66a28ba0dce1e7447548e3d43a19a Mon Sep 17 00:00:00 2001 From: Josh Knapp Date: Wed, 9 Sep 2026 18:30:02 -0700 Subject: [PATCH 1/3] fix(http): bound the WinHTTP response-header wait, and stop docs triggering builds Two things, both prompted by an intermittent Windows CI failure in test_api_client's testPlatformBackendTimeout: roughly 2 runs in 6, both its assertions failed together, meaning a request with timeout_ms=700 waited out a 5s server stall and returned 200. Same failure on 2026-09-07 (job 5834) and 2026-09-09 (job 5911), on code that passed on other runs -- pre-existing and intermittent, not caused by a change. 1. The real bug. `WinHttpSetTimeouts`' receive parameter maps to WINHTTP_OPTION_RECEIVE_TIMEOUT, which Microsoft documents as a PER-PACKET Winsock-layer read timeout ("applies to fetching each packet of data off the socket"). The wait for the response HEADERS is a separate option, WINHTTP_OPTION_RECEIVE_RESPONSE_TIMEOUT, which WinHttpSetTimeouts does not set and which defaults to 90 SECONDS. So a server that accepts, reads the request and then stalls could block the calling thread for a minute and a half no matter what the caller passed as timeout_ms -- precisely the "blocking an OBS thread indefinitely" failure that test exists to prevent. Now set explicitly, guarded by #ifdef so an older SDK still builds. That is a genuine defect on its own merits. Whether it is the whole explanation for the intermittency is NOT established: the same docs say this timeout "is checked only when data is received from the socket", so neither option guarantees a hard deadline -- that needs a watchdog calling WinHttpCloseHandle, deliberately not done here. 2. Evidence, so the next run says more than pass/fail. The probe now runs 5 times and prints elapsed ms, ok, status, requests_seen and the backend's error string (carrying GetLastError) for every attempt, so one CI run yields a failure RATE and an error code. Each attempt gets a FRESH loopback server: the server handles one connection at a time on a single thread, so reusing it would leave attempts 2..n in the accept backlog -- never accepted, a different scenario from the one that fails. Verified on Linux: 5/5 attempts give up at ~701ms. Also: build.yml now has paths-ignore for **.md, LICENSE, NOTICE, and the two release-only files. This is a full three-platform build behind a runner with capacity:1, and six of them fired for one afternoon of documentation edits. Nothing that feeds a build or a test is on that list. Tradeoff: a docs-only push now shows no status at all rather than a green one. The WinHTTP change cannot be compiled locally (Linux host); CI is its first build. All 6 suites pass locally on Linux. Co-Authored-By: Claude Opus 5 (1M context) Claude-Session: https://claude.ai/code/session_01AzGnvQ6wfD7bw7PZN35ft9 --- .gitea/workflows/build.yml | 22 ++++++++++ core/src/http_winhttp.cpp | 33 +++++++++++++++ core/tests/test_api_client.cpp | 74 +++++++++++++++++++++++++++------- 3 files changed, 115 insertions(+), 14 deletions(-) diff --git a/.gitea/workflows/build.yml b/.gitea/workflows/build.yml index 585d8b4..ed5b3d4 100644 --- a/.gitea/workflows/build.yml +++ b/.gitea/workflows/build.yml @@ -31,7 +31,29 @@ on: # job is ordinary commits. branches: - "**" + # Documentation-only changes cannot break a build, and this workflow is a + # full three-platform build (Windows included) behind a runner with + # capacity:1. Six of these fired for one afternoon of README/release-notes + # edits on 2026-09-09. Anything that feeds a build or a test is absent + # from this list on purpose -- release.yml and publish-release.sh only run + # on a `v*` tag, via release.yml's own trigger. + # + # Tradeoff: a docs-only push now shows NO status at all on the branch, + # rather than a green one. If a required-status check is ever added, these + # paths have to be reconsidered. + paths-ignore: + - "**.md" + - "LICENSE" + - "NOTICE" + - ".gitea/workflows/release.yml" + - ".gitea/scripts/publish-release.sh" pull_request: + paths-ignore: + - "**.md" + - "LICENSE" + - "NOTICE" + - ".gitea/workflows/release.yml" + - ".gitea/scripts/publish-release.sh" jobs: linux: diff --git a/core/src/http_winhttp.cpp b/core/src/http_winhttp.cpp index 9982081..217406d 100644 --- a/core/src/http_winhttp.cpp +++ b/core/src/http_winhttp.cpp @@ -116,6 +116,39 @@ public: WinHttpSetTimeouts(session.get(), static_cast(timeout), static_cast(timeout), static_cast(timeout), static_cast(timeout)); + // WinHttpSetTimeouts' receive parameter maps to + // WINHTTP_OPTION_RECEIVE_TIMEOUT, which Microsoft documents as a + // PER-PACKET Winsock-layer read timeout ("applies to fetching each + // packet of data off the socket"), not a deadline on the response. + // The wait for the response HEADERS is a *separate* option, + // WINHTTP_OPTION_RECEIVE_RESPONSE_TIMEOUT ("to wait to receive all + // response headers to a request"), which WinHttpSetTimeouts does not + // touch and which defaults to 90 SECONDS. Without this call a server + // that accepts, reads the request and then stalls can hold this + // thread for a minute and a half regardless of request.timeout_ms -- + // exactly the "blocking an OBS thread indefinitely" failure + // testPlatformBackendTimeout exists to prevent, and the likely + // mechanism behind that test's intermittent Windows failures. + // + // Caveat, also documented: this timeout "is checked only when data is + // received from the socket", so it bounds the wait but does not + // guarantee a hard deadline. A guaranteed deadline needs a watchdog + // thread calling WinHttpCloseHandle; not done here. + // + // Guarded because the constant postdates some Windows SDK headers; a + // toolchain without it keeps the previous (90s default) behaviour + // rather than failing to build. +#ifdef WINHTTP_OPTION_RECEIVE_RESPONSE_TIMEOUT + DWORD response_timeout = timeout; + // Return value deliberately unchecked: a rejected option leaves the + // documented default in place, which is degraded but still correct + // behaviour, and there is no logging sink in this layer to report it + // to. The timeout probe in test_api_client.cpp is what would catch a + // regression here. + WinHttpSetOption(session.get(), WINHTTP_OPTION_RECEIVE_RESPONSE_TIMEOUT, &response_timeout, + sizeof(response_timeout)); +#endif + Handle connect(WinHttpConnect(session.get(), host, parts.nPort, 0)); if (!connect) { response.network_error = lastErrorMessage("WinHttpConnect"); diff --git a/core/tests/test_api_client.cpp b/core/tests/test_api_client.cpp index 4e15b7d..456a32a 100644 --- a/core/tests/test_api_client.cpp +++ b/core/tests/test_api_client.cpp @@ -16,6 +16,7 @@ You may obtain a copy of the License at // three runners rather than assumed to work. #include +#include #include #include #include @@ -422,22 +423,67 @@ void testPlatformBackendTimeout() { // A server that accepts and then stalls. The plugin must give up on its // own timeout rather than blocking an OBS thread indefinitely. - sttest::LoopbackServer server([](const std::string &) { - std::this_thread::sleep_for(std::chrono::seconds(5)); - return sttest::httpResponse(200, "OK", R"({"slots":[]})"); - }); - ST_ASSERT(server.valid()); + // + // INSTRUMENTED (2026-09-09) while chasing an intermittent Windows-only + // failure: on roughly 2 of 6 CI runs both assertions below fail together, + // meaning the request waited out the full 5s stall and returned 200 -- + // the timeout did not fire at all. Same failure seen on 2026-09-07 + // (job 5834) and 2026-09-09 (job 5911), on identical code that passed on + // other runs, so it is not a code change that caused it. + // + // The probe runs kProbes times and prints one line per attempt so a + // single CI run yields a failure RATE and the WinHTTP error code, rather + // than one bit. `ST_ASSERT` records and continues, so every attempt is + // reported even when one fails. Remove the loop and this comment once the + // mechanism is understood and fixed. + constexpr int kProbes = 5; + constexpr long long kStallMs = 5000; + constexpr long kTimeoutMs = 700; - std::shared_ptr http(createPlatformHttpClient()); - HttpRequest request; - request.url = server.baseUrl() + "/api/obs/main-room/slots?key=k"; - request.timeout_ms = 700; + int timed_out = 0; + for (int i = 0; i < kProbes; ++i) { + // A FRESH server per attempt, deliberately. `LoopbackServer` accepts + // and handles one connection at a time on a single thread, so reusing + // one server across attempts would leave attempts 2..n sitting in the + // accept backlog -- a different scenario (never accepted) from the one + // that fails on Windows (accepted, request read, then stalled). + sttest::LoopbackServer server([kStallMs](const std::string &) { + std::this_thread::sleep_for(std::chrono::milliseconds(kStallMs)); + return sttest::httpResponse(200, "OK", R"({"slots":[]})"); + }); + ST_ASSERT(server.valid()); - const auto start = std::chrono::steady_clock::now(); - const HttpResponse response = http->send(request); - const auto elapsed = std::chrono::steady_clock::now() - start; - ST_ASSERT(!response.ok()); - ST_ASSERT(std::chrono::duration_cast(elapsed).count() < 4000); + std::shared_ptr http(createPlatformHttpClient()); + HttpRequest request; + request.url = server.baseUrl() + "/api/obs/main-room/slots?key=k"; + request.timeout_ms = kTimeoutMs; + + const auto start = std::chrono::steady_clock::now(); + const HttpResponse response = http->send(request); + const auto elapsed = std::chrono::steady_clock::now() - start; + const long long ms = std::chrono::duration_cast(elapsed).count(); + + const bool gave_up = !response.ok() && ms < 4000; + if (gave_up) + ++timed_out; + + // Always printed, pass or fail: elapsed time and the backend's own + // error string (which carries GetLastError on Windows) are the + // evidence. requests_seen separates "the client never reached the + // server" (0) from "the server read the request and the client then + // waited it out" (1). + std::fprintf(stderr, + " [timeout-probe %d/%d] elapsed=%lldms ok=%d status=%ld " + "requests_seen=%d network_error='%s' -> %s\n", + i + 1, kProbes, ms, response.ok() ? 1 : 0, response.status, + server.requestCount(), response.network_error.c_str(), + gave_up ? "gave up (expected)" : "WAITED OUT THE STALL"); + + ST_ASSERT(!response.ok()); + ST_ASSERT(ms < 4000); + } + std::fprintf(stderr, " [timeout-probe] %d/%d attempts honoured the %ldms timeout\n", + timed_out, kProbes, kTimeoutMs); } } // namespace -- 2.52.0 From b23644fa3e6857699348d4112b6a07a66358ab29 Mon Sep 17 00:00:00 2001 From: Josh Knapp Date: Wed, 9 Sep 2026 18:37:58 -0700 Subject: [PATCH 2/3] fix(http): enforce a hard deadline on WinHTTP by cancelling the request Setting WINHTTP_OPTION_RECEIVE_RESPONSE_TIMEOUT (previous commit) fixed the original failure -- the request is now always cancelled instead of waiting out a stall and returning 200 -- but the instrumented CI probe shows it is not cancelled on TIME. Five attempts with a 700ms budget against a server that accepts and then stalls 5s returned after 1490, 1529, 2485, 3493 and 4506ms, every one of them ERROR_WINHTTP_TIMEOUT (12002). One exceeded the test's 4s bound, which is why Windows CI was still red. That is the documented behaviour, not a mystery: both receive timeouts are "checked only when data is received from the socket", so an expired timeout is not surfaced until the peer sends something. Neither option is a deadline. It matters because `fetchSlots` is called synchronously on the OBS UI thread, behind the properties dialog's "Refresh camera list" button (obs-adapter/src/plugin-main.cpp:486, kPropertiesTimeoutMs = 5000). At the overshoot ratio measured above, a stalling server freezes that dialog for something like half a minute -- the exact failure the shortened timeout there was chosen to avoid. So: a watchdog thread that closes the request handle once the deadline passes, which is the documented way to cancel a WinHTTP operation. `RequestDeadline` owns the handle and both threads close it through an `atomic::exchange(nullptr)`, so exactly one close ever happens. Failures are reported as a timeout rather than as a raw GetLastError when the deadline is what fired. The ceiling is twice the caller's budget, not the budget itself: resolve, connect, send and receive each get `timeout` from WinHttpSetTimeouts, so a slow-but-progressing exchange can legitimately exceed one budget and must not be cancelled. There is one accepted race, documented at the class: the caller can load the handle just before the watchdog closes it, turning the call into ERROR_INVALID_HANDLE instead. Both mean the deadline expired. Cross-compiled with mingw-w64 (`-fsyntax-only`) rather than waiting on CI to find syntax errors; also confirmed by preprocessor probe that WINHTTP_OPTION_RECEIVE_RESPONSE_TIMEOUT is defined in those headers, so the #ifdef guard is not silently skipping the option. Linux: all 6 suites pass. Real verification is the Windows job's probe output. Co-Authored-By: Claude Opus 5 (1M context) Claude-Session: https://claude.ai/code/session_01AzGnvQ6wfD7bw7PZN35ft9 --- core/src/http_winhttp.cpp | 137 +++++++++++++++++++++++++++++++------- 1 file changed, 114 insertions(+), 23 deletions(-) diff --git a/core/src/http_winhttp.cpp b/core/src/http_winhttp.cpp index 217406d..f479b44 100644 --- a/core/src/http_winhttp.cpp +++ b/core/src/http_winhttp.cpp @@ -19,8 +19,13 @@ You may obtain a copy of the License at #include #include +#include +#include +#include #include +#include #include +#include #include namespace stplugin { @@ -72,6 +77,79 @@ private: HINTERNET h_ = nullptr; }; +/// Hard deadline for one WinHTTP exchange, enforced by cancelling it. +/// +/// Neither receive timeout is a guaranteed deadline: Microsoft documents both +/// as "checked only when data is received from the socket", so an expired +/// timeout is not surfaced until the peer finally sends something. Measured on +/// the Windows CI runner against a server that accepts and then stalls 5s: a +/// 700ms budget returned after 1490, 1529, 2485, 3493 and 4506ms across five +/// attempts -- always cancelled, never on time. +/// +/// That overshoot matters because `fetchSlots` is called synchronously on the +/// OBS UI thread behind the properties dialog's "Refresh camera list" button +/// (obs-adapter/src/plugin-main.cpp), with a 5s budget. At the ratio above +/// that is a frozen dialog for half a minute. +/// +/// The documented way to force cancellation is to close the handle from +/// another thread; the pending call then fails with +/// ERROR_WINHTTP_OPERATION_CANCELLED. This owns the request handle so that +/// exactly one of the two threads ever closes it: `handle_.exchange(nullptr)` +/// hands the close to whichever gets there first. +/// +/// Known, accepted race: the caller may load the handle and have the watchdog +/// close it before the WinHttp* call reads it, in which case the call fails +/// with ERROR_INVALID_HANDLE instead. Both outcomes are "the deadline +/// expired", which is what the caller is told either way. +class RequestDeadline { +public: + RequestDeadline(HINTERNET request, DWORD after_ms) : handle_(request) + { + watchdog_ = std::thread([this, after_ms] { + std::unique_lock lock(mutex_); + if (cv_.wait_for(lock, std::chrono::milliseconds(after_ms), [this] { return finished_; })) + return; // exchange finished inside the deadline + if (closeOnce()) + expired_.store(true); + }); + } + + ~RequestDeadline() + { + { + std::lock_guard lock(mutex_); + finished_ = true; + } + cv_.notify_all(); + if (watchdog_.joinable()) + watchdog_.join(); + closeOnce(); // no-op if the watchdog got there first + } + + RequestDeadline(const RequestDeadline &) = delete; + RequestDeadline &operator=(const RequestDeadline &) = delete; + + HINTERNET get() const { return handle_.load(); } + bool expired() const { return expired_.load(); } + +private: + bool closeOnce() + { + HINTERNET h = handle_.exchange(nullptr); + if (!h) + return false; + WinHttpCloseHandle(h); + return true; + } + + std::atomic handle_; + std::atomic expired_{false}; + std::mutex mutex_; + std::condition_variable cv_; + bool finished_ = false; + std::thread watchdog_; +}; + class WinHttpClient : public HttpClient { public: HttpResponse send(const HttpRequest &request) override @@ -159,13 +237,36 @@ public: target += extra; const DWORD flags = (parts.nScheme == INTERNET_SCHEME_HTTPS) ? WINHTTP_FLAG_SECURE : 0u; - Handle req(WinHttpOpenRequest(connect.get(), widen(request.method).c_str(), target.c_str(), nullptr, - WINHTTP_NO_REFERER, WINHTTP_DEFAULT_ACCEPT_TYPES, flags)); - if (!req) { + HINTERNET raw_req = WinHttpOpenRequest(connect.get(), widen(request.method).c_str(), target.c_str(), + nullptr, WINHTTP_NO_REFERER, WINHTTP_DEFAULT_ACCEPT_TYPES, + flags); + if (!raw_req) { response.network_error = lastErrorMessage("WinHttpOpenRequest"); return response; } + // Ceiling at twice the caller's budget: each of the four + // WinHttpSetTimeouts phases (resolve, connect, send, receive) is + // allowed `timeout` on its own, so a slow-but-progressing exchange can + // legitimately exceed one budget, and this must not cancel those. The + // floor keeps a very small timeout_ms from producing a deadline the + // exchange cannot meet on a cold connection. + const DWORD deadline_ms = (timeout > 500u) ? (timeout * 2u) : 1000u; + RequestDeadline req(raw_req, deadline_ms); + + // From here on, `req.get()` can be closed underneath us by the + // watchdog; every WinHttp* failure below is therefore checked against + // req.expired() before its GetLastError text is reported, so an + // expired deadline reads as a timeout rather than as + // "WinHttpReceiveResponse failed (GetLastError=12017)". + const auto fail = [&](const char *what) -> HttpResponse { + if (req.expired()) + response.network_error = "timed out after " + std::to_string(deadline_ms) + " ms"; + else + response.network_error = lastErrorMessage(what); + return response; + }; + std::wstring headers; if (!request.content_type.empty()) headers = L"Content-Type: " + widen(request.content_type) + L"\r\n"; @@ -177,31 +278,23 @@ public: : const_cast(request.body.data()); const DWORD body_len = static_cast(request.body.size()); - if (!WinHttpSendRequest(req.get(), header_ptr, header_len, body_ptr, body_len, body_len, 0)) { - response.network_error = lastErrorMessage("WinHttpSendRequest"); - return response; - } - if (!WinHttpReceiveResponse(req.get(), nullptr)) { - response.network_error = lastErrorMessage("WinHttpReceiveResponse"); - return response; - } + if (!WinHttpSendRequest(req.get(), header_ptr, header_len, body_ptr, body_len, body_len, 0)) + return fail("WinHttpSendRequest"); + if (!WinHttpReceiveResponse(req.get(), nullptr)) + return fail("WinHttpReceiveResponse"); DWORD status = 0; DWORD status_size = sizeof(status); if (!WinHttpQueryHeaders(req.get(), WINHTTP_QUERY_STATUS_CODE | WINHTTP_QUERY_FLAG_NUMBER, - WINHTTP_HEADER_NAME_BY_INDEX, &status, &status_size, WINHTTP_NO_HEADER_INDEX)) { - response.network_error = lastErrorMessage("WinHttpQueryHeaders"); - return response; - } + WINHTTP_HEADER_NAME_BY_INDEX, &status, &status_size, WINHTTP_NO_HEADER_INDEX)) + return fail("WinHttpQueryHeaders"); response.status = static_cast(status); std::string body; for (;;) { DWORD available = 0; - if (!WinHttpQueryDataAvailable(req.get(), &available)) { - response.network_error = lastErrorMessage("WinHttpQueryDataAvailable"); - return response; - } + if (!WinHttpQueryDataAvailable(req.get(), &available)) + return fail("WinHttpQueryDataAvailable"); if (available == 0) break; if (body.size() + available > kMaxResponseBytes) { @@ -210,10 +303,8 @@ public: } std::vector chunk(available); DWORD read = 0; - if (!WinHttpReadData(req.get(), chunk.data(), available, &read)) { - response.network_error = lastErrorMessage("WinHttpReadData"); - return response; - } + if (!WinHttpReadData(req.get(), chunk.data(), available, &read)) + return fail("WinHttpReadData"); if (read == 0) break; body.append(chunk.data(), read); -- 2.52.0 From 17540c75b0f10befc00dc34e211e75ed4c386acb Mon Sep 17 00:00:00 2001 From: Josh Knapp Date: Wed, 9 Sep 2026 18:43:32 -0700 Subject: [PATCH 3/3] test: assert the 2x-budget ceiling the watchdog now guarantees, not 4s The Windows job went green, but CTest prints test output only on failure, so a pass says nothing about WHAT cancelled the request. Under the old 4000ms bound a pass is ambiguous: the watchdog firing at ~1400ms and WinHTTP's own erratic cancellation (measured at 1490-4506ms for this same 700ms budget) both fit under it. So assert the guarantee the code actually makes now -- a hard ceiling of twice the caller's budget -- at 2500ms, which is 1400ms plus slack for a loaded runner. If the watchdog stops doing the work, roughly half the attempts land above this and print their elapsed time and error string, instead of quietly passing. Linux is unaffected: curl honours the 700ms budget exactly, 5/5 at ~701ms. Co-Authored-By: Claude Opus 5 (1M context) Claude-Session: https://claude.ai/code/session_01AzGnvQ6wfD7bw7PZN35ft9 --- core/tests/test_api_client.cpp | 14 ++++++++++++-- 1 file changed, 12 insertions(+), 2 deletions(-) diff --git a/core/tests/test_api_client.cpp b/core/tests/test_api_client.cpp index 456a32a..b03973e 100644 --- a/core/tests/test_api_client.cpp +++ b/core/tests/test_api_client.cpp @@ -463,7 +463,17 @@ void testPlatformBackendTimeout() const auto elapsed = std::chrono::steady_clock::now() - start; const long long ms = std::chrono::duration_cast(elapsed).count(); - const bool gave_up = !response.ok() && ms < 4000; + // 4000 was the old bound, chosen when nothing bounded the wait. The + // code now promises a hard ceiling of 2x the caller's budget + // (RequestDeadline in http_winhttp.cpp), so assert THAT -- 1400ms + // here, plus slack for a loaded runner. This is also the only signal + // that survives a green run: CTest prints nothing on success, so if + // WinHTTP's own erratic cancellation (measured at 1490-4506ms for + // this same 700ms budget) were doing the work instead of the + // watchdog, roughly half the attempts would land above this bound and + // say so, instead of quietly passing under a 4s ceiling. + constexpr long long kCeilingMs = 2500; + const bool gave_up = !response.ok() && ms < kCeilingMs; if (gave_up) ++timed_out; @@ -480,7 +490,7 @@ void testPlatformBackendTimeout() gave_up ? "gave up (expected)" : "WAITED OUT THE STALL"); ST_ASSERT(!response.ok()); - ST_ASSERT(ms < 4000); + ST_ASSERT(ms < kCeilingMs); } std::fprintf(stderr, " [timeout-probe] %d/%d attempts honoured the %ldms timeout\n", timed_out, kProbes, kTimeoutMs); -- 2.52.0