Fast and extensible multi-platform HTTP/1-2-3 web server with automatic HTTPS
Mirrored from https://github.com/Slazee/caddy.git
Synced Nov 11, 03:30 UTC
reverseproxy: log HTTP/3 client cancellations at debug level (#8135)
Saleh committed
Oct 4, 2026 at 15:48 UTC
f7eeb1d65c80b2f634b3ce406fa71ba1f0e078a2
3 files changed
+120
-2
modules/caddyhttp/reverseproxy/client_disconnect_test.go
+96
@@ -2,11 +2,19 @@ package reverseproxy
2
3
import (
4
"context"
5
+ "errors"
6
"net/http"
7
"net/http/httptest"
8
+ "strings"
9
"sync"
10
"testing"
11
12
+ "github.com/quic-go/quic-go/http3"
13
+ "go.uber.org/zap"
14
+ "go.uber.org/zap/zapcore"
15
+ "go.uber.org/zap/zaptest/observer"
16
+
17
+ "github.com/caddyserver/caddy/v2"
18
"github.com/caddyserver/caddy/v2/modules/caddyhttp"
19
)
20
@@ -52,3 +60,91 @@ func TestClientDisconnectRecordsStatus(t *testing.T) {
60
t.Errorf("expected status 499 after client disconnect, got %d", got)
61
}
62
}
63
+
64
+// failingWriter is a ResponseWriter whose body writes fail with err.
65
+type failingWriter struct {
66
+ *httptest.ResponseRecorder
67
+ err error
68
+}
69
+
70
+func (w failingWriter) Write([]byte) (int, error) { return 0, w.err }
71
+
72
+// failingReader is a response body from the backend whose reads fail with err.
73
+type failingReader struct{ err error }
74
+
75
+func (r failingReader) Read([]byte) (int, error) { return 0, r.err }
76
+
77
+// TestClientCancelAbortLogLevel verifies that an HTTP/3 client canceling the
78
+// request while the response is streamed is logged at debug level, while
79
+// other errors that abort the response, including the same error coming from
80
+// the backend, are still logged as warnings.
81
+func TestClientCancelAbortLogLevel(t *testing.T) {
82
+ for _, tc := range []struct {
83
+ name string
84
+ err error
85
+ readErr bool // fail reading from the backend instead of writing to the client
86
+ want zapcore.Level
87
+ }{
88
+ {
89
+ name: "http3 request canceled by client",
90
+ err: &http3.Error{Remote: true, ErrorCode: http3.ErrCodeRequestCanceled},
91
+ want: zapcore.DebugLevel,
92
+ },
93
+ {
94
+ name: "http3 request canceled locally",
95
+ err: &http3.Error{Remote: false, ErrorCode: http3.ErrCodeRequestCanceled},
96
+ want: zapcore.WarnLevel,
97
+ },
98
+ {
99
+ name: "other http3 error",
100
+ err: &http3.Error{Remote: true, ErrorCode: http3.ErrCodeInternalError},
101
+ want: zapcore.WarnLevel,
102
+ },
103
+ {
104
+ name: "other error",
105
+ err: errors.New("broken pipe"),
106
+ want: zapcore.WarnLevel,
107
+ },
108
+ {
109
+ name: "http3 response canceled by backend",
110
+ err: &http3.Error{Remote: true, ErrorCode: http3.ErrCodeRequestCanceled},
111
+ readErr: true,
112
+ want: zapcore.WarnLevel,
113
+ },
114
+ } {
115
+ t.Run(tc.name, func(t *testing.T) {
116
+ core, logs := observer.New(zapcore.DebugLevel)
117
+ h := &Handler{logger: zap.New(core)}
118
+
119
+ req := httptest.NewRequest(http.MethodGet, "/", nil)
120
+ req = req.WithContext(context.WithValue(req.Context(), caddyhttp.VarsCtxKey, map[string]any{}))
121
+ res := &http.Response{
122
+ StatusCode: http.StatusOK,
123
+ Header: http.Header{},
124
+ Body: fakeRWC{strings.NewReader("hello")},
125
+ }
126
+ var rw http.ResponseWriter = failingWriter{ResponseRecorder: httptest.NewRecorder(), err: tc.err}
127
+ if tc.readErr {
128
+ res.Body = fakeRWC{failingReader{tc.err}}
129
+ rw = httptest.NewRecorder()
130
+ }
131
+
132
+ func() {
133
+ defer func() {
134
+ if r := recover(); r != http.ErrAbortHandler {
135
+ t.Fatalf("expected panic with http.ErrAbortHandler, got %v", r)
136
+ }
137
+ }()
138
+ _ = h.finalizeResponse(rw, req, res, caddy.NewReplacer(), fakeStart, h.logger, "example.test:443")
139
+ }()
140
+
141
+ entries := logs.FilterMessage("aborting with incomplete response").All()
142
+ if len(entries) != 1 {
143
+ t.Fatalf("expected 1 log entry, got %d", len(entries))
144
+ }
145
+ if got := entries[0].Level; got != tc.want {
146
+ t.Errorf("log level = %s, want %s", got, tc.want)
147
+ }
148
+ })
149
+ }
150
+}
modules/caddyhttp/reverseproxy/reverseproxy.go
+19
-1
@@ -36,6 +36,7 @@ import (
36
"time"
37
38
"github.com/dunglas/httpsfv"
39
+ "github.com/quic-go/quic-go/http3"
40
"go.uber.org/zap"
41
"go.uber.org/zap/zapcore"
42
"golang.org/x/net/http/httpguts"
@@ -1452,7 +1453,13 @@ func (h *Handler) finalizeResponse(
1453
// we'll just log the error and abort the stream here and panic just as
1454
// the standard lib's proxy to propagate the stream error.
1455
// see issue https://github.com/caddyserver/caddy/issues/5951
1455
- if c := logger.Check(zapcore.WarnLevel, "aborting with incomplete response"); c != nil {
1456
+ lvl := zapcore.WarnLevel
1457
+ if isClientCanceledH3(err) {
1458
+ // the client canceled the request; expected and not actionable
1459
+ // see issue https://github.com/caddyserver/caddy/issues/5766
1460
+ lvl = zapcore.DebugLevel
1461
+ }
1462
+ if c := logger.Check(lvl, "aborting with incomplete response"); c != nil {
1463
c.Write(zap.Error(err))
1464
}
1465
// flush the buffer to ensure the client sees the partial response
@@ -1494,6 +1501,17 @@ func (h *Handler) finalizeResponse(
1501
return nil
1502
}
1503
1504
+// isClientCanceledH3 returns true if err is an HTTP/3 client canceling
1505
+// its request (H3_REQUEST_CANCELLED) while the response was being written.
1506
+// The same error read from an HTTP/3 backend is the backend's doing.
1507
+func isClientCanceledH3(err error) bool {
1508
+ if !errors.Is(err, errWritingDownstream) {
1509
+ return false
1510
+ }
1511
+ h3Err, ok := errors.AsType[*http3.Error](err)
1512
+ return ok && h3Err.Remote && h3Err.ErrorCode == http3.ErrCodeRequestCanceled
1513
+}
1514
+
1515
// tryAgain takes the time that the handler was initially invoked,
1516
// the amount of retries already performed, as well as any error
1517
// currently obtained, and the request being tried, and returns
modules/caddyhttp/reverseproxy/streaming.go
+5
-1
@@ -464,6 +464,10 @@ func (h Handler) copyResponse(dst http.ResponseWriter, src io.Reader, flushInter
464
return err
465
}
466
467
+// errWritingDownstream wraps errors from writing the response to the client,
468
+// to tell them apart from errors reading the response from the backend.
469
+var errWritingDownstream = errors.New("writing")
470
+
471
// copyBuffer returns any write errors or non-EOF read errors, and the amount
472
// of bytes written.
473
func (h Handler) copyBuffer(dst io.Writer, src io.Reader, buf []byte, logger *zap.Logger) (int64, error) {
@@ -504,7 +508,7 @@ func (h Handler) copyBuffer(dst io.Writer, src io.Reader, buf []byte, logger *za
508
)
509
}
510
if werr != nil {
507
- return written, fmt.Errorf("writing: %w", werr)
511
+ return written, fmt.Errorf("%w: %w", errWritingDownstream, werr)
512
}
513
if nr != nw {
514
return written, io.ErrShortWrite