fix(http): bound the WinHTTP response-header wait, and stop docs triggering builds #5
@@ -31,7 +31,29 @@ on:
|
|||||||
# job is ordinary commits.
|
# job is ordinary commits.
|
||||||
branches:
|
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:
|
pull_request:
|
||||||
|
paths-ignore:
|
||||||
|
- "**.md"
|
||||||
|
- "LICENSE"
|
||||||
|
- "NOTICE"
|
||||||
|
- ".gitea/workflows/release.yml"
|
||||||
|
- ".gitea/scripts/publish-release.sh"
|
||||||
|
|
||||||
jobs:
|
jobs:
|
||||||
linux:
|
linux:
|
||||||
|
|||||||
+147
-23
@@ -19,8 +19,13 @@ You may obtain a copy of the License at
|
|||||||
#include <windows.h>
|
#include <windows.h>
|
||||||
#include <winhttp.h>
|
#include <winhttp.h>
|
||||||
|
|
||||||
|
#include <atomic>
|
||||||
|
#include <chrono>
|
||||||
|
#include <condition_variable>
|
||||||
#include <cstddef>
|
#include <cstddef>
|
||||||
|
#include <mutex>
|
||||||
#include <string>
|
#include <string>
|
||||||
|
#include <thread>
|
||||||
#include <vector>
|
#include <vector>
|
||||||
|
|
||||||
namespace stplugin {
|
namespace stplugin {
|
||||||
@@ -72,6 +77,79 @@ private:
|
|||||||
HINTERNET h_ = nullptr;
|
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<std::mutex> 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<std::mutex> 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<HINTERNET> handle_;
|
||||||
|
std::atomic<bool> expired_{false};
|
||||||
|
std::mutex mutex_;
|
||||||
|
std::condition_variable cv_;
|
||||||
|
bool finished_ = false;
|
||||||
|
std::thread watchdog_;
|
||||||
|
};
|
||||||
|
|
||||||
class WinHttpClient : public HttpClient {
|
class WinHttpClient : public HttpClient {
|
||||||
public:
|
public:
|
||||||
HttpResponse send(const HttpRequest &request) override
|
HttpResponse send(const HttpRequest &request) override
|
||||||
@@ -116,6 +194,39 @@ public:
|
|||||||
WinHttpSetTimeouts(session.get(), static_cast<int>(timeout), static_cast<int>(timeout),
|
WinHttpSetTimeouts(session.get(), static_cast<int>(timeout), static_cast<int>(timeout),
|
||||||
static_cast<int>(timeout), static_cast<int>(timeout));
|
static_cast<int>(timeout), static_cast<int>(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));
|
Handle connect(WinHttpConnect(session.get(), host, parts.nPort, 0));
|
||||||
if (!connect) {
|
if (!connect) {
|
||||||
response.network_error = lastErrorMessage("WinHttpConnect");
|
response.network_error = lastErrorMessage("WinHttpConnect");
|
||||||
@@ -126,13 +237,36 @@ public:
|
|||||||
target += extra;
|
target += extra;
|
||||||
|
|
||||||
const DWORD flags = (parts.nScheme == INTERNET_SCHEME_HTTPS) ? WINHTTP_FLAG_SECURE : 0u;
|
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,
|
HINTERNET raw_req = WinHttpOpenRequest(connect.get(), widen(request.method).c_str(), target.c_str(),
|
||||||
WINHTTP_NO_REFERER, WINHTTP_DEFAULT_ACCEPT_TYPES, flags));
|
nullptr, WINHTTP_NO_REFERER, WINHTTP_DEFAULT_ACCEPT_TYPES,
|
||||||
if (!req) {
|
flags);
|
||||||
|
if (!raw_req) {
|
||||||
response.network_error = lastErrorMessage("WinHttpOpenRequest");
|
response.network_error = lastErrorMessage("WinHttpOpenRequest");
|
||||||
return response;
|
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;
|
std::wstring headers;
|
||||||
if (!request.content_type.empty())
|
if (!request.content_type.empty())
|
||||||
headers = L"Content-Type: " + widen(request.content_type) + L"\r\n";
|
headers = L"Content-Type: " + widen(request.content_type) + L"\r\n";
|
||||||
@@ -144,31 +278,23 @@ public:
|
|||||||
: const_cast<char *>(request.body.data());
|
: const_cast<char *>(request.body.data());
|
||||||
const DWORD body_len = static_cast<DWORD>(request.body.size());
|
const DWORD body_len = static_cast<DWORD>(request.body.size());
|
||||||
|
|
||||||
if (!WinHttpSendRequest(req.get(), header_ptr, header_len, body_ptr, body_len, body_len, 0)) {
|
if (!WinHttpSendRequest(req.get(), header_ptr, header_len, body_ptr, body_len, body_len, 0))
|
||||||
response.network_error = lastErrorMessage("WinHttpSendRequest");
|
return fail("WinHttpSendRequest");
|
||||||
return response;
|
if (!WinHttpReceiveResponse(req.get(), nullptr))
|
||||||
}
|
return fail("WinHttpReceiveResponse");
|
||||||
if (!WinHttpReceiveResponse(req.get(), nullptr)) {
|
|
||||||
response.network_error = lastErrorMessage("WinHttpReceiveResponse");
|
|
||||||
return response;
|
|
||||||
}
|
|
||||||
|
|
||||||
DWORD status = 0;
|
DWORD status = 0;
|
||||||
DWORD status_size = sizeof(status);
|
DWORD status_size = sizeof(status);
|
||||||
if (!WinHttpQueryHeaders(req.get(), WINHTTP_QUERY_STATUS_CODE | WINHTTP_QUERY_FLAG_NUMBER,
|
if (!WinHttpQueryHeaders(req.get(), WINHTTP_QUERY_STATUS_CODE | WINHTTP_QUERY_FLAG_NUMBER,
|
||||||
WINHTTP_HEADER_NAME_BY_INDEX, &status, &status_size, WINHTTP_NO_HEADER_INDEX)) {
|
WINHTTP_HEADER_NAME_BY_INDEX, &status, &status_size, WINHTTP_NO_HEADER_INDEX))
|
||||||
response.network_error = lastErrorMessage("WinHttpQueryHeaders");
|
return fail("WinHttpQueryHeaders");
|
||||||
return response;
|
|
||||||
}
|
|
||||||
response.status = static_cast<long>(status);
|
response.status = static_cast<long>(status);
|
||||||
|
|
||||||
std::string body;
|
std::string body;
|
||||||
for (;;) {
|
for (;;) {
|
||||||
DWORD available = 0;
|
DWORD available = 0;
|
||||||
if (!WinHttpQueryDataAvailable(req.get(), &available)) {
|
if (!WinHttpQueryDataAvailable(req.get(), &available))
|
||||||
response.network_error = lastErrorMessage("WinHttpQueryDataAvailable");
|
return fail("WinHttpQueryDataAvailable");
|
||||||
return response;
|
|
||||||
}
|
|
||||||
if (available == 0)
|
if (available == 0)
|
||||||
break;
|
break;
|
||||||
if (body.size() + available > kMaxResponseBytes) {
|
if (body.size() + available > kMaxResponseBytes) {
|
||||||
@@ -177,10 +303,8 @@ public:
|
|||||||
}
|
}
|
||||||
std::vector<char> chunk(available);
|
std::vector<char> chunk(available);
|
||||||
DWORD read = 0;
|
DWORD read = 0;
|
||||||
if (!WinHttpReadData(req.get(), chunk.data(), available, &read)) {
|
if (!WinHttpReadData(req.get(), chunk.data(), available, &read))
|
||||||
response.network_error = lastErrorMessage("WinHttpReadData");
|
return fail("WinHttpReadData");
|
||||||
return response;
|
|
||||||
}
|
|
||||||
if (read == 0)
|
if (read == 0)
|
||||||
break;
|
break;
|
||||||
body.append(chunk.data(), read);
|
body.append(chunk.data(), read);
|
||||||
|
|||||||
@@ -16,6 +16,7 @@ You may obtain a copy of the License at
|
|||||||
// three runners rather than assumed to work.
|
// three runners rather than assumed to work.
|
||||||
|
|
||||||
#include <chrono>
|
#include <chrono>
|
||||||
|
#include <cstdio>
|
||||||
#include <memory>
|
#include <memory>
|
||||||
#include <string>
|
#include <string>
|
||||||
#include <thread>
|
#include <thread>
|
||||||
@@ -422,22 +423,77 @@ void testPlatformBackendTimeout()
|
|||||||
{
|
{
|
||||||
// A server that accepts and then stalls. The plugin must give up on its
|
// A server that accepts and then stalls. The plugin must give up on its
|
||||||
// own timeout rather than blocking an OBS thread indefinitely.
|
// own timeout rather than blocking an OBS thread indefinitely.
|
||||||
sttest::LoopbackServer server([](const std::string &) {
|
//
|
||||||
std::this_thread::sleep_for(std::chrono::seconds(5));
|
// INSTRUMENTED (2026-09-09) while chasing an intermittent Windows-only
|
||||||
return sttest::httpResponse(200, "OK", R"({"slots":[]})");
|
// 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 --
|
||||||
ST_ASSERT(server.valid());
|
// 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<HttpClient> http(createPlatformHttpClient());
|
int timed_out = 0;
|
||||||
HttpRequest request;
|
for (int i = 0; i < kProbes; ++i) {
|
||||||
request.url = server.baseUrl() + "/api/obs/main-room/slots?key=k";
|
// A FRESH server per attempt, deliberately. `LoopbackServer` accepts
|
||||||
request.timeout_ms = 700;
|
// 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();
|
std::shared_ptr<HttpClient> http(createPlatformHttpClient());
|
||||||
const HttpResponse response = http->send(request);
|
HttpRequest request;
|
||||||
const auto elapsed = std::chrono::steady_clock::now() - start;
|
request.url = server.baseUrl() + "/api/obs/main-room/slots?key=k";
|
||||||
ST_ASSERT(!response.ok());
|
request.timeout_ms = kTimeoutMs;
|
||||||
ST_ASSERT(std::chrono::duration_cast<std::chrono::milliseconds>(elapsed).count() < 4000);
|
|
||||||
|
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<std::chrono::milliseconds>(elapsed).count();
|
||||||
|
|
||||||
|
// 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;
|
||||||
|
|
||||||
|
// 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 < kCeilingMs);
|
||||||
|
}
|
||||||
|
std::fprintf(stderr, " [timeout-probe] %d/%d attempts honoured the %ldms timeout\n",
|
||||||
|
timed_out, kProbes, kTimeoutMs);
|
||||||
}
|
}
|
||||||
|
|
||||||
} // namespace
|
} // namespace
|
||||||
|
|||||||
Reference in New Issue
Block a user