A request that takes longer than eight seconds gets no answer, because the server's write timeout runs out before the request timeout #208
No Assignees
Notifications
Due Date
No due date set.
Dependencies
No dependencies set.
Reference: wiki-cafe/member-console#208
Reference in New Issue
Block a user
What happens
Startininternal/server/server.gobuilds thehttp.ServerwithWriteTimeout: 8 * time.Secondand puts every request throughmiddleware.Timeout(32*time.Second). Go sets the connection's write deadline eight seconds after it reads the request's headers. The request timeout ishttp.TimeoutHandler. It holds the handler's response in a buffer and writes it only when the handler returns, or it writes its own 503 "Request timed out" at 32 seconds.So when a handler runs past eight seconds, its work still finishes, but writing its answer fails and the server closes the connection. The person waits the whole time and gets no response from the console. Instead, the proxy in front shows its own gateway error, or the browser reports a dropped connection. The 503 that the request timeout writes at 32 seconds runs into the same expired deadline, so it never reaches anyone either. Nothing stops the handler at eight seconds: it keeps running until it returns, and its context is cancelled only at 32 seconds.
Two kinds of handler can run past eight seconds today:
internal/fulfillment/plan_change.go). Each call uses the Stripe library's defaults: an 80-second timeout and two retries. When Stripe is slow, the change can go through while the member sees an error.workflowStartTimeoutininternal/integrations/fedwiki/web/requests.go). When Temporal is slow, the console records the request and starts the workflow, but the member never gets the answer.Timeout's doc comment says the client gets a 503 once the deadline passes, andopenspec/specs/http-security-headers/spec.mdrequires that 503 to carry the security headers. The test of that 503 ininternal/middleware/tests/security_headers_test.gowrites to a recorder that has no write deadline, so it passes.What should happen
The request timeout fires before the write timeout. A request that runs too long gets the 503 "Request timed out" with the security headers, and the write timeout only catches a client that is too slow to read the answer. Either the request timeout comes down below eight seconds, or the write timeout goes above 32 with room left to write the 503.
Where
internal/server/server.go(Start: thehttp.ServerandpreAuthStack);internal/middleware/timeout.go(Timeout).Steps
Add
time.Sleep(9 * time.Second)to any handler, run the console, and request that path directly withcurl -v. After nine seconds curl reports "Empty reply from server". With a 40-second sleep you get the same empty reply at 32 seconds, which is when the 503 should arrive.Why it matters
When Stripe, Temporal or the database slows a request past eight seconds, the console sends no answer at all, even if the work was done, and its "Request timed out" response is never seen.
FedWiki's site actions are not the only Temporal calls that can outlast the eight seconds. The Temporal SDK the console uses (v1.38.0) gives every client call a 10-second timeout by default (
defaultRPCTimeoutin itsinternal/internal_utils.go). Several handlers start or signal a workflow with the request's own context and no deadline of their own, among them the grant expiry start (internal/server/operator_enrollment.go:716and:977) and the domain claim signals (internal/server/member_domains.go:511,internal/integrations/fedwiki/web/customdomain.go:449), so each of them can run past the write deadline when Temporal is slow.A request whose handler took longer than eight seconds lost its answer: the server stopped writing eight seconds after it read the request, while the handler was allowed 32 seconds. A plan change during a slow Stripe call, or a FedWiki request that waited on a site's retention purge, did its work and showed the member nothing. The server now keeps writing for 40 seconds, the 32 a handler may run and 8 more for the answer, so such a request shows its result, and one still running at 32 seconds shows the timeout error, which was lost before as well. The same holds for a request that waits on a Temporal call, such as starting a grant's expiry or signalling a domain claim, each of which can take up to 10 seconds. Neither limit is a setting. A proxy in front of the console needs to wait at least 40 seconds for an answer; the deployment guide says so.
Commit:
1d35f03860