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, 02:15 UTC
| 1 | // Copyright 2015 Matthew Holt and The Caddy Authors |
| 2 | // |
| 3 | // Licensed under the Apache License, Version 2.0 (the "License"); |
| 4 | // you may not use this file except in compliance with the License. |
| 5 | // You may obtain a copy of the License at |
| 6 | // |
| 7 | // http://www.apache.org/licenses/LICENSE-2.0 |
| 8 | // |
| 9 | // Unless required by applicable law or agreed to in writing, software |
| 10 | // distributed under the License is distributed on an "AS IS" BASIS, |
| 11 | // WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. |
| 12 | // See the License for the specific language governing permissions and |
| 13 | // limitations under the License. |
| 14 | |
| 15 | package fastcgi |
| 16 | |
| 17 | import ( |
| 18 | "bytes" |
| 19 | "cmp" |
| 20 | "errors" |
| 21 | "fmt" |
| 22 | "io" |
| 23 | "net" |
| 24 | "net/http" |
| 25 | "net/http/httptest" |
| 26 | "os" |
| 27 | "strings" |
| 28 | "sync/atomic" |
| 29 | "testing" |
| 30 | "time" |
| 31 | |
| 32 | "go.uber.org/zap" |
| 33 | "go.uber.org/zap/zapcore" |
| 34 | "go.uber.org/zap/zaptest/observer" |
| 35 | |
| 36 | "github.com/caddyserver/caddy/v2" |
| 37 | "github.com/caddyserver/caddy/v2/caddyconfig" |
| 38 | "github.com/caddyserver/caddy/v2/modules/caddyhttp" |
| 39 | "github.com/caddyserver/caddy/v2/modules/caddyhttp/reverseproxy" |
| 40 | ) |
| 41 | |
| 42 | // extra is sent past the declared body and must never be logged. |
| 43 | const extra = "EXTRA-BODY-BYTES" |
| 44 | |
| 45 | type fcgiRecord struct { |
| 46 | recType uint8 |
| 47 | content string |
| 48 | delay time.Duration // before sending |
| 49 | } |
| 50 | |
| 51 | func stdout(s string) fcgiRecord { return fcgiRecord{recType: Stdout, content: s} } |
| 52 | |
| 53 | func sendRecords(recs ...fcgiRecord) func(*streamWriter) error { |
| 54 | return func(w *streamWriter) error { |
| 55 | for _, rec := range recs { |
| 56 | time.Sleep(rec.delay) |
| 57 | if err := w.writeRecord(rec.recType, []byte(rec.content)); err != nil { |
| 58 | return err |
| 59 | } |
| 60 | } |
| 61 | return w.writeRecord(EndRequest, make([]byte, 8)) |
| 62 | } |
| 63 | } |
| 64 | |
| 65 | // fcgiResponder accepts one connection, reads the request and calls respond, |
| 66 | // which unlike net/http/fcgi can send any body. It then holds the connection |
| 67 | // open until the client closes it, and closes the returned channel. |
| 68 | func fcgiResponder(t *testing.T, respond func(*streamWriter) error) (string, <-chan struct{}) { |
| 69 | t.Helper() |
| 70 | ln, err := net.Listen("tcp", "127.0.0.1:0") |
| 71 | if err != nil { |
| 72 | t.Fatal(err) |
| 73 | } |
| 74 | t.Cleanup(func() { ln.Close() }) |
| 75 | |
| 76 | closed := make(chan struct{}) |
| 77 | go func() { |
| 78 | defer close(closed) |
| 79 | conn, err := ln.Accept() |
| 80 | if err != nil { |
| 81 | return |
| 82 | } |
| 83 | defer conn.Close() |
| 84 | var rec record |
| 85 | for rec.fill(conn) == nil && (rec.h.Type != Stdin || rec.h.ContentLength > 0) { |
| 86 | _, _ = io.Copy(io.Discard, &rec) |
| 87 | } |
| 88 | _ = respond(&streamWriter{c: &client{rwc: conn, reqID: 1}, buf: new(bytes.Buffer)}) |
| 89 | _, _ = io.Copy(io.Discard, conn) |
| 90 | }() |
| 91 | return ln.Addr().String(), closed |
| 92 | } |
| 93 | |
| 94 | // fcgiRequest sends a request to the responder at addr as Transport.RoundTrip |
| 95 | // does, and returns the response and the client's logs. |
| 96 | func fcgiRequest(t *testing.T, addr, method string, readTimeout time.Duration) (*http.Response, *observer.ObservedLogs) { |
| 97 | t.Helper() |
| 98 | conn, err := net.Dial("tcp", addr) |
| 99 | if err != nil { |
| 100 | t.Fatal(err) |
| 101 | } |
| 102 | t.Cleanup(func() { conn.Close() }) |
| 103 | _ = conn.SetReadDeadline(time.Now().Add(5 * time.Second)) // fail rather than hang |
| 104 | |
| 105 | core, logs := observer.New(zapcore.DebugLevel) |
| 106 | c := &client{rwc: conn, reqID: 1, stderr: true, logger: zap.New(core)} |
| 107 | _ = c.SetReadTimeout(readTimeout) |
| 108 | resp, err := c.Request(map[string]string{"REQUEST_METHOD": method, "CONTENT_LENGTH": "0"}, nil) |
| 109 | if err != nil { |
| 110 | t.Fatal(err) |
| 111 | } |
| 112 | return resp, logs |
| 113 | } |
| 114 | |
| 115 | func waitClosed(t *testing.T, closed <-chan struct{}) { |
| 116 | t.Helper() |
| 117 | select { |
| 118 | case <-closed: |
| 119 | case <-time.After(5 * time.Second): |
| 120 | t.Error("connection to the responder was not closed") |
| 121 | } |
| 122 | } |
| 123 | |
| 124 | // surplusLogged returns the surplus_bytes of the one surplus warning, or 0 |
| 125 | // without one, and fails the test if any entry carries body bytes. |
| 126 | func surplusLogged(t *testing.T, logs *observer.ObservedLogs) int64 { |
| 127 | t.Helper() |
| 128 | var n int64 |
| 129 | for _, e := range logs.All() { |
| 130 | if strings.Contains(e.Message+fmt.Sprint(e.ContextMap()), extra) { |
| 131 | t.Errorf("log entry %q contains body bytes", e.Message) |
| 132 | } |
| 133 | if e.Message == "discarding upstream response bytes beyond the declared Content-Length" { |
| 134 | if n != 0 || e.Level != zapcore.WarnLevel { |
| 135 | t.Errorf("want one surplus warning at warn level, got another at %s", e.Level) |
| 136 | } |
| 137 | n = e.ContextMap()["surplus_bytes"].(int64) |
| 138 | } |
| 139 | } |
| 140 | return n |
| 141 | } |
| 142 | |
| 143 | func TestResponseBody(t *testing.T) { |
| 144 | t.Parallel() |
| 145 | |
| 146 | const page = "Content-Length: 5\r\n\r\nhello" |
| 147 | warning := fcgiRecord{recType: Stderr, content: "PHP Warning"} |
| 148 | lateWarning := fcgiRecord{recType: Stderr, content: "PHP Warning", delay: maxSurplusWait + 200*time.Millisecond} |
| 149 | |
| 150 | for _, tc := range []struct { |
| 151 | name string |
| 152 | method string |
| 153 | records []fcgiRecord |
| 154 | readTimeout time.Duration |
| 155 | body string |
| 156 | err error |
| 157 | surplus int |
| 158 | stderr string |
| 159 | }{ |
| 160 | {name: "exact, then stderr", records: []fcgiRecord{stdout(page), warning}, body: "hello", stderr: "PHP Warning"}, |
| 161 | {name: "exact, then stderr after a pause", records: []fcgiRecord{stdout(page), lateWarning}, body: "hello", stderr: "PHP Warning"}, |
| 162 | {name: "exact, then the read timeout", records: []fcgiRecord{stdout(page), lateWarning}, readTimeout: 300 * time.Millisecond, body: "hello", err: os.ErrDeadlineExceeded}, |
| 163 | {name: "shorter", records: []fcgiRecord{stdout("Content-Length: 10\r\n\r\nhello")}, body: "hello", err: io.ErrUnexpectedEOF}, |
| 164 | {name: "excessive, then stderr", records: []fcgiRecord{stdout(page + extra), warning}, body: "hello", surplus: len(extra), stderr: "PHP Warning"}, |
| 165 | {name: "zero length", records: []fcgiRecord{stdout("Content-Length: 0\r\n\r\n" + extra)}, surplus: len(extra)}, |
| 166 | // Unknown lengths, and responses without a body, are read in full as before. |
| 167 | {name: "no length", records: []fcgiRecord{stdout("Content-Type: text/plain\r\n\r\nhello" + extra)}, body: "hello" + extra}, |
| 168 | {name: "invalid length", records: []fcgiRecord{stdout("Content-Length: abc\r\n\r\nhello" + extra)}, body: "hello" + extra}, |
| 169 | {name: "negative length", records: []fcgiRecord{stdout("Content-Length: -5\r\n\r\nhello" + extra)}, body: "hello" + extra}, |
| 170 | {name: "chunked", records: []fcgiRecord{stdout("Transfer-Encoding: chunked\r\nContent-Length: 2\r\n\r\n5\r\nhello\r\n0\r\n\r\n")}, body: "hello"}, |
| 171 | {name: "HEAD", method: http.MethodHead, records: []fcgiRecord{stdout(page + extra)}, body: "hello" + extra}, |
| 172 | {name: "1xx", records: []fcgiRecord{stdout("Status: 103 Early Hints\r\n" + page + extra)}, body: "hello" + extra}, |
| 173 | {name: "204", records: []fcgiRecord{stdout("Status: 204 No Content\r\n" + page + extra)}, body: "hello" + extra}, |
| 174 | {name: "304", records: []fcgiRecord{stdout("Status: 304 Not Modified\r\n" + page + extra)}, body: "hello" + extra}, |
| 175 | } { |
| 176 | t.Run(tc.name, func(t *testing.T) { |
| 177 | t.Parallel() |
| 178 | addr, closed := fcgiResponder(t, sendRecords(tc.records...)) |
| 179 | resp, logs := fcgiRequest(t, addr, cmp.Or(tc.method, http.MethodGet), tc.readTimeout) |
| 180 | |
| 181 | body, err := io.ReadAll(resp.Body) |
| 182 | if string(body) != tc.body || !errors.Is(err, tc.err) { |
| 183 | t.Errorf("ReadAll() = %q, %v; want %q, %v", body, err, tc.body, tc.err) |
| 184 | } |
| 185 | if tc.err != nil { |
| 186 | // The proxy can read again after an error. |
| 187 | if _, err := resp.Body.Read(make([]byte, 1)); !errors.Is(err, tc.err) { |
| 188 | t.Errorf("Read() after the error = %v, want %v", err, tc.err) |
| 189 | } |
| 190 | } |
| 191 | resp.Body.Close() |
| 192 | waitClosed(t, closed) |
| 193 | |
| 194 | if got := surplusLogged(t, logs); got != int64(tc.surplus) { |
| 195 | t.Errorf("surplus_bytes = %d, want %d", got, tc.surplus) |
| 196 | } |
| 197 | var stderr string |
| 198 | for _, e := range logs.FilterMessage("stderr").All() { |
| 199 | stderr += e.ContextMap()["body"].(string) |
| 200 | } |
| 201 | if stderr != tc.stderr { |
| 202 | t.Errorf("logged stderr %q, want %q", stderr, tc.stderr) |
| 203 | } |
| 204 | }) |
| 205 | } |
| 206 | } |
| 207 | |
| 208 | // TestResponseSurplusIsBounded checks that a responder writing past its body |
| 209 | // cannot hold the connection: reading to the end stops within the surplus |
| 210 | // limits, and Close returns at once, even when the body was not read to its |
| 211 | // end. The proxy stops flushing once the body ends, so any wait in Close |
| 212 | // would hold back what it had not yet sent. |
| 213 | func TestResponseSurplusIsBounded(t *testing.T) { |
| 214 | t.Parallel() |
| 215 | |
| 216 | hold := func(response string) func(*streamWriter) error { |
| 217 | return func(w *streamWriter) error { return w.writeRecord(Stdout, []byte(response)) } |
| 218 | } |
| 219 | // overflow writes past the body for 3s, so reading fails rather than hangs |
| 220 | // without the limits. |
| 221 | overflow := func(interval time.Duration, size int) func(*streamWriter) error { |
| 222 | return func(w *streamWriter) error { |
| 223 | data := []byte("Content-Length: 5\r\n\r\nhello") |
| 224 | for start := time.Now(); time.Since(start) < 3*time.Second; data = make([]byte, size) { |
| 225 | if err := w.writeRecord(Stdout, data); err != nil { |
| 226 | return err |
| 227 | } |
| 228 | time.Sleep(interval) |
| 229 | } |
| 230 | return w.writeRecord(EndRequest, make([]byte, 8)) |
| 231 | } |
| 232 | } |
| 233 | |
| 234 | for _, tc := range []struct { |
| 235 | name string |
| 236 | respond func(*streamWriter) error |
| 237 | read int64 // before Close; more than the body reads it to its end |
| 238 | readTimeout time.Duration |
| 239 | max time.Duration // to read and close |
| 240 | warn bool |
| 241 | }{ |
| 242 | {name: "body partly read", respond: hold("Content-Length: 10\r\n\r\nhello"), read: 5, max: 100 * time.Millisecond}, |
| 243 | {name: "empty body not read", respond: hold("Content-Length: 0\r\n\r\n"), max: 100 * time.Millisecond}, |
| 244 | {name: "flood", respond: overflow(0, 4096), read: 6, max: 500 * time.Millisecond, warn: true}, |
| 245 | {name: "trickle", respond: overflow(20*time.Millisecond, 1), read: 6, max: 1500 * time.Millisecond, warn: true}, |
| 246 | {name: "trickle past read timeout", respond: overflow(20*time.Millisecond, 1), read: 6, readTimeout: 300 * time.Millisecond, max: 800 * time.Millisecond, warn: true}, |
| 247 | } { |
| 248 | t.Run(tc.name, func(t *testing.T) { |
| 249 | t.Parallel() |
| 250 | addr, closed := fcgiResponder(t, tc.respond) |
| 251 | resp, logs := fcgiRequest(t, addr, http.MethodGet, tc.readTimeout) |
| 252 | start := time.Now() |
| 253 | _, _ = io.CopyN(io.Discard, resp.Body, tc.read) |
| 254 | closing := time.Now() |
| 255 | resp.Body.Close() |
| 256 | if took := time.Since(closing); took > 100*time.Millisecond { |
| 257 | t.Errorf("Close() took %s, want it to return at once", took) |
| 258 | } |
| 259 | if took := time.Since(start); took > tc.max { |
| 260 | t.Errorf("reading and closing took %s, want at most %s", took, tc.max) |
| 261 | } |
| 262 | waitClosed(t, closed) |
| 263 | |
| 264 | if got := surplusLogged(t, logs); (got > 0) != tc.warn { |
| 265 | t.Errorf("surplus_bytes = %d, want a warning: %v", got, tc.warn) |
| 266 | } |
| 267 | }) |
| 268 | } |
| 269 | } |
| 270 | |
| 271 | // fastcgiProxy serves a reverse proxy to the responder at addr, and returns a |
| 272 | // func that waits for its one request and reports whether the proxy aborted |
| 273 | // the response, which it does by panicking with http.ErrAbortHandler. |
| 274 | func fastcgiProxy(t *testing.T, addr string, http2 bool) (*httptest.Server, *observer.ObservedLogs, func() bool) { |
| 275 | t.Helper() |
| 276 | cfgCtx, err := caddy.ProvisionContext(&caddy.Config{}) |
| 277 | if err != nil { |
| 278 | t.Fatal(err) |
| 279 | } |
| 280 | cfgCtx.Context = t.Context() // keeps the config, which Handler.Provision needs |
| 281 | ctx, cancel := caddy.NewContext(cfgCtx) |
| 282 | t.Cleanup(cancel) |
| 283 | h := &reverseproxy.Handler{ |
| 284 | TransportRaw: caddyconfig.JSONModuleObject(Transport{Root: "/", ReadTimeout: caddy.Duration(5 * time.Second)}, "protocol", "fastcgi", nil), |
| 285 | Upstreams: reverseproxy.UpstreamPool{{Dial: addr}}, |
| 286 | } |
| 287 | if err := h.Provision(ctx); err != nil { |
| 288 | t.Fatal(err) |
| 289 | } |
| 290 | t.Cleanup(func() { _ = h.Cleanup() }) |
| 291 | core, logs := observer.New(zapcore.DebugLevel) |
| 292 | h.Transport.(*Transport).logger = zap.New(core) |
| 293 | |
| 294 | var aborted atomic.Bool |
| 295 | done := make(chan struct{}) |
| 296 | srv := httptest.NewUnstartedServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { |
| 297 | defer func() { |
| 298 | v := recover() |
| 299 | aborted.Store(v == http.ErrAbortHandler) |
| 300 | close(done) |
| 301 | if v != nil { |
| 302 | panic(v) |
| 303 | } |
| 304 | }() |
| 305 | r = caddyhttp.PrepareRequest(r, caddy.NewReplacer(), w, &caddyhttp.Server{}) |
| 306 | if err := h.ServeHTTP(w, r, caddyhttp.HandlerFunc(func(http.ResponseWriter, *http.Request) error { return nil })); err != nil { |
| 307 | w.WriteHeader(http.StatusBadGateway) |
| 308 | } |
| 309 | })) |
| 310 | t.Cleanup(srv.Close) |
| 311 | srv.EnableHTTP2 = http2 |
| 312 | if http2 { |
| 313 | srv.StartTLS() |
| 314 | } else { |
| 315 | srv.Start() |
| 316 | } |
| 317 | |
| 318 | return srv, logs, func() bool { <-done; return aborted.Load() } |
| 319 | } |
| 320 | |
| 321 | // TestProxyResponseBody checks what clients of the proxy receive over HTTP/1.1 |
| 322 | // and HTTP/2. It and its subtests run one at a time because provisioning |
| 323 | // writes package-level state in caddy and reverseproxy. |
| 324 | func TestProxyResponseBody(t *testing.T) { |
| 325 | for _, proto := range []string{"HTTP/1.1", "HTTP/2.0"} { |
| 326 | for _, tc := range []struct { |
| 327 | name string |
| 328 | response string |
| 329 | body string // and no error, unless shorter |
| 330 | shorter bool |
| 331 | surplus int |
| 332 | }{ |
| 333 | {name: "exact", response: "Content-Length: 5\r\n\r\nhello", body: "hello"}, |
| 334 | {name: "excessive", response: "Content-Length: 5\r\n\r\nhello" + extra, body: "hello", surplus: len(extra)}, |
| 335 | {name: "shorter", response: "Content-Length: 10\r\n\r\nhello", shorter: true}, |
| 336 | } { |
| 337 | t.Run(proto+"/"+tc.name, func(t *testing.T) { |
| 338 | addr, closed := fcgiResponder(t, sendRecords(stdout(tc.response))) |
| 339 | srv, logs, aborted := fastcgiProxy(t, addr, proto == "HTTP/2.0") |
| 340 | |
| 341 | req, err := http.NewRequestWithContext(t.Context(), http.MethodGet, srv.URL+"/index.php", nil) |
| 342 | if err != nil { |
| 343 | t.Fatal(err) |
| 344 | } |
| 345 | resp, err := srv.Client().Do(req) |
| 346 | if err != nil { |
| 347 | t.Fatal(err) |
| 348 | } |
| 349 | defer resp.Body.Close() |
| 350 | if resp.Proto != proto { |
| 351 | t.Fatalf("response protocol = %s, want %s", resp.Proto, proto) |
| 352 | } |
| 353 | body, err := io.ReadAll(resp.Body) |
| 354 | if tc.shorter != (err != nil) || !tc.shorter && string(body) != tc.body { |
| 355 | t.Errorf("ReadAll() = %q, %v; want %q and an error: %v", body, err, tc.body, tc.shorter) |
| 356 | } |
| 357 | waitClosed(t, closed) |
| 358 | if aborted() != tc.shorter { |
| 359 | t.Errorf("proxy aborted the response: %v, want %v", !tc.shorter, tc.shorter) |
| 360 | } |
| 361 | |
| 362 | if got := surplusLogged(t, logs); got != int64(tc.surplus) { |
| 363 | t.Errorf("surplus_bytes = %d, want %d", got, tc.surplus) |
| 364 | } |
| 365 | for _, e := range logs.FilterMessage("discarding upstream response bytes beyond the declared Content-Length").All() { |
| 366 | if req, _ := e.ContextMap()["request"].(map[string]any); req["uri"] != "/index.php" { |
| 367 | t.Errorf("surplus warning has request %v, want the request URI", req) |
| 368 | } |
| 369 | } |
| 370 | }) |
| 371 | } |
| 372 | } |
| 373 | } |