Skip to content

server: kill and reap the render on timeout and on client disconnect - #44

Closed
dib-adhoc wants to merge 1 commit into
acsone:masterfrom
dib-adhoc:fix/render-timeout-and-child-cleanup
Closed

dib-adhoc wants to merge 1 commit into
acsone:masterfrom
dib-adhoc:fix/render-timeout-and-child-cleanup

Conversation

@dib-adhoc

Copy link
Copy Markdown

What this is about

When a render takes too long, it currently takes the caller down with it. The request never comes back, and the process that was rendering stays alive with nobody reading its output — so the memory and the file descriptors stay taken too. Nothing reports it: the server keeps answering /status while this happens, so a pod in this state still looks healthy.

We hit this on a fleet of Odoo tenants that share one deployment of this server. On one cluster we counted 9 episodes over two and a half days, all during working hours, none of which ever surfaced as an error. Each one left the tenant with a few minutes of failed requests.

The defects

  1. No deadline, no cancellation. exec.Command is started without a context, and the request context is never watched. If the render hangs, the copy blocks for as long as the renderer lives, and nothing notices that the caller already left.

  2. The child is not reaped on the error path. When io.Copy fails, the handler calls httpAbort and returns without cmd.Wait(). The child is left behind — and because nobody drains its stdout pipe any more, it can block on a full pipe and stay there indefinitely, rather than exiting and being collected later.

  3. Killing the direct child is not enough. Its own children inherit the stdout pipe and hold it open, so the copy stays blocked until the last of them exits. A timeout that only kills the direct child does not release the caller — verified below, it took 6s to return with a 2s timeout.

What this PR does

  • Runs the render under a context bound to r.Context(), with a timeout from KWKHTMLTOPDF_TIMEOUT (seconds, default 120, 0 disables it).
  • Starts the render in its own process group and kills the group, so descendants cannot keep the pipe open.
  • Reaps the child on every exit path, including the aborted ones.
  • Logs the timeout explicitly: render timed out after 2s: signal: killed.

The default of 120s is meant to sit below the timeouts callers usually have; a render that outlives it has no reader left anyway.

How it was verified

A fake renderer that writes and then hangs, against binaries built from master and from this branch:

Scenario master this branch
Client disconnects mid-render child still alive after 12s (sh + dd, state S), never reaped no child processes left
Render hangs, client waits returns after 8s — as long as the renderer lives returns after 2.0s with the timeout logged

gofmt, go vet and builds for linux, windows and darwin are clean.

The fake renderer and the check
# a renderer that emits output and then hangs
cat > /tmp/fake <<'EOF'
#!/bin/sh
dd if=/dev/zero bs=1024 count=262144 2>/dev/null
sleep 8
EOF
chmod +x /tmp/fake

# start the server under test, POST a render, cut the client off after 1s
KWKHTMLTOPDF_BIN=/tmp/fake ./server-under-test &
sleep 1
# ... multipart POST to /pdf with a 1s client timeout ...
sleep 12
ps -eo pid,ppid,stat,comm      # master: the child is still there; this branch: nothing

For the second row, use a renderer that only does sleep 8, set KWKHTMLTOPDF_TIMEOUT=2,
and let the client wait: master returns after 8s, this branch after 2s.

Notes for the reviewer

  • server/ now has three files, so go run server/kwkhtmltopdf_server.go no longer works — the README was updated to go run ./server.
  • The unix and windows helpers are split by build tag because SysProcAttr.Setpgid does not exist on windows; the windows path falls back to killing the direct child only.
  • Deliberately left out: w.WriteHeader(http.StatusOK) still runs before the copy, so a timeout aborts the response instead of returning 504. Deferring the header until the first byte would allow a real status code, but it changes observable behaviour for every client — happy to do it here if you prefer.
  • HISTORY.md was left untouched, assuming release notes are yours to write.

cc @az-adhoc

The handler started wkhtmltopdf with no deadline and without watching the
request context, so a render that never finished held the connection and
the child process for as long as it took. When io.Copy failed, the handler
returned without cmd.Wait(), and the child was left behind.

Killing the direct child is not enough: its own children inherit the stdout
pipe and keep the copy blocked until the last one exits, so the render runs
in its own process group and the group is killed.

Add KWKHTMLTOPDF_TIMEOUT, in seconds, default 120, 0 to disable.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant