Give the webhook handler a timeout (closes #38)
check / check (push) Successful in 38s
check / check (pull_request) Successful in 54s

The webhook handler's client had no timeout, and slog calls the handler
inside the log call, so a server that accepted the connection and never
answered stopped that log call for good, and every later one. A request
still running after 5 seconds now fails with a timeout error. The
handler also reads the answer to the end before closing it, so the
connection is reused for the next record.

A new test points the handler at a server that never answers and checks
that Handle returns a timeout error. The README states the timeout.

Model: opus-5-5
This commit is contained in:
2026-10-06 07:44:25 +00:00
committed by sneak
parent 8e53530434
commit d054848547
4 changed files with 56 additions and 3 deletions
+3 -1
View File
@@ -116,7 +116,9 @@ the record:
stdout, wrapped, so `errors.Is` still matches the original stdout, wrapped, so `errors.Is` still matches the original
- `WebhookHandler` returns an error when the request fails, and also when - `WebhookHandler` returns an error when the request fails, and also when
the server answers with a status outside 2xx, a redirect included, the server answers with a status outside 2xx, a redirect included,
since it does not follow redirects since it does not follow redirects. A request that has not finished
after 5 seconds fails with a timeout error, so a webhook server that
never answers holds up a log call for 5 seconds at most
- `MultiplexHandler`, which simplelog installs as the default, passes the - `MultiplexHandler`, which simplelog installs as the default, passes the
record to every handler it holds even after one of them fails, then record to every handler it holds even after one of them fails, then
returns all their errors joined with `errors.Join` (nil if none failed) returns all their errors joined with `errors.Join` (nil if none failed)
+3
View File
@@ -24,6 +24,9 @@ files it depends on: .golangci.yml, REPO_POLICIES.md, .editorconfig,
# Completed Steps # Completed Steps
* 2026-10-06: a webhook request now times out after 5 seconds, so a
server that never answers no longer stops every log call; the webhook
handler also reads each answer to the end so its connection is reused
* 2026-10-06: the linter runs only in Docker: `script/lint` builds the * 2026-10-06: the linter runs only in Docker: `script/lint` builds the
`lint` stage of the `Dockerfile`, every `docker build` in `script/` `lint` stage of the `Dockerfile`, every `docker build` in `script/`
runs without the build cache, and `script/bootstrap` no longer runs without the build cache, and `script/bootstrap` no longer
+34
View File
@@ -5,6 +5,7 @@ import (
"context" "context"
"errors" "errors"
"log/slog" "log/slog"
"net"
"net/http" "net/http"
"net/http/httptest" "net/http/httptest"
"strings" "strings"
@@ -160,3 +161,36 @@ func TestWebhookHandlerReturnsErrorOnRedirect(t *testing.T) {
t.Fatalf("Handle returned %v, want an error for the redirect", err) t.Fatalf("Handle returned %v, want an error for the redirect", err)
} }
} }
// A server that accepts the request and never answers must not hold up
// the log call: Handle gives up after webhookTimeout and says why.
func TestWebhookHandlerTimesOutOnServerThatNeverAnswers(t *testing.T) {
t.Parallel()
testEnded := make(chan struct{})
server := httptest.NewServer(http.HandlerFunc(
func(_ http.ResponseWriter, _ *http.Request) {
<-testEnded
},
))
// server.Close waits for running requests, so the server's handler
// is released first.
defer func() {
close(testEnded)
server.Close()
}()
handler, err := NewWebhookHandler(server.URL)
if err != nil {
t.Fatalf("NewWebhookHandler: %v", err)
}
err = handler.Handle(context.Background(), errorTestRecord())
var netErr net.Error
if !errors.As(err, &netErr) || !netErr.Timeout() {
t.Fatalf("Handle returned %v, want a timeout error", err)
}
}
+16 -2
View File
@@ -6,15 +6,22 @@ import (
"encoding/json" "encoding/json"
"errors" "errors"
"fmt" "fmt"
"io"
"log/slog" "log/slog"
"net/http" "net/http"
"net/url" "net/url"
"time"
) )
// errWebhookStatus is returned when the webhook answers with a status // errWebhookStatus is returned when the webhook answers with a status
// outside 2xx. // outside 2xx.
var errWebhookStatus = errors.New("webhook did not accept the record") var errWebhookStatus = errors.New("webhook did not accept the record")
// webhookTimeout bounds each webhook request, reading the answer
// included. Handle runs inside the log call, so a server that never
// answers would otherwise hold that call up for good.
const webhookTimeout = 5 * time.Second
// WebhookHandler POSTs each log record as JSON to a configured webhook // WebhookHandler POSTs each log record as JSON to a configured webhook
// URL. // URL.
type WebhookHandler struct { type WebhookHandler struct {
@@ -34,6 +41,7 @@ func NewWebhookHandler(webhookURL string) (*WebhookHandler, error) {
return &WebhookHandler{ return &WebhookHandler{
webhookURL: webhookURL, webhookURL: webhookURL,
client: &http.Client{ client: &http.Client{
Timeout: webhookTimeout,
// Following a redirect can resend the request as a GET // Following a redirect can resend the request as a GET
// without the record, so Handle gets the redirect answer // without the record, so Handle gets the redirect answer
// itself and returns it as an error. // itself and returns it as an error.
@@ -80,7 +88,8 @@ func (w *WebhookHandler) WithGroup(name string) slog.Handler {
// Handle marshals the record, with its attributes, to one JSON object and // Handle marshals the record, with its attributes, to one JSON object and
// POSTs it to the webhook URL. It returns an error when the request fails // POSTs it to the webhook URL. It returns an error when the request fails
// or the server answers with a status outside 2xx. // or runs past webhookTimeout, or when the server answers with a status
// outside 2xx.
func (w *WebhookHandler) Handle(ctx context.Context, record slog.Record) error { func (w *WebhookHandler) Handle(ctx context.Context, record slog.Record) error {
jsonData, err := json.Marshal(recordToMap(record, w.attrs)) jsonData, err := json.Marshal(recordToMap(record, w.attrs))
if err != nil { if err != nil {
@@ -104,7 +113,12 @@ func (w *WebhookHandler) Handle(ctx context.Context, record slog.Record) error {
return err return err
} }
defer func() { _ = response.Body.Close() }() // The answer is read to the end before closing, so the client can
// reuse the connection for the next record.
defer func() {
_, _ = io.Copy(io.Discard, response.Body)
_ = response.Body.Close()
}()
if response.StatusCode < http.StatusOK || if response.StatusCode < http.StatusOK ||
response.StatusCode >= http.StatusMultipleChoices { response.StatusCode >= http.StatusMultipleChoices {