From dcbf38d0b370cc0f412157b11961dd0b0e007251 Mon Sep 17 00:00:00 2001 From: Bas Westerbaan Date: Wed, 28 Aug 2024 01:08:16 +0200 Subject: [PATCH 01/10] tls: use Go default kex for the moment that include PQC (#6542) By default Go 1.23 enables X25519Kyber768, a post-quantum key agreement method that is enabled by default on Chrome. Go 1.23 does not expose the CurveID, so we cannot add it by specifying it in CurvePreferences. The reason is that X25519Kyber768 is a preliminary key agreement that will be supplanted by X25519MLKEM768. For the moment there is value in enabling it. A consequence of this is that by default Caddy will enable support for P-384 and P-521. This PR also removes the special code to add support for X25519Kyber768 via the Cloudflare Go branch. Cf #6540 --- cmd/caddy/main.go | 5 +++++ modules/caddytls/cf.go | 24 ------------------------ modules/caddytls/connpolicy.go | 10 +++++++++- modules/caddytls/values.go | 5 +++++ 4 files changed, 19 insertions(+), 25 deletions(-) delete mode 100644 modules/caddytls/cf.go diff --git a/cmd/caddy/main.go b/cmd/caddy/main.go index 48fa149aa08..f1aeda0a420 100644 --- a/cmd/caddy/main.go +++ b/cmd/caddy/main.go @@ -1,3 +1,8 @@ +// The below line is required to enable post-quantum key agreement in Go 1.23 +// by default without insisting on setting a minimum version of 1.23 in go.mod. +// See https://github.com/caddyserver/caddy/issues/6540#issuecomment-2313094905 +//go:debug tlskyber=1 + // Copyright 2015 Matthew Holt and The Caddy Authors // // Licensed under the Apache License, Version 2.0 (the "License"); diff --git a/modules/caddytls/cf.go b/modules/caddytls/cf.go deleted file mode 100644 index e61a59c09e1..00000000000 --- a/modules/caddytls/cf.go +++ /dev/null @@ -1,24 +0,0 @@ -//go:build cfgo - -package caddytls - -// This file adds support for X25519Kyber768Draft00, a post-quantum -// key agreement that is currently being rolled out by Chrome [1] -// and Cloudflare [2,3]. For more context, see the PR [4]. -// -// [1] https://blog.chromium.org/2023/08/protecting-chrome-traffic-with-hybrid.html -// [2] https://blog.cloudflare.com/post-quantum-for-all/ -// [3] https://blog.cloudflare.com/post-quantum-to-origins/ -// [4] https://github.com/caddyserver/caddy/pull/5852 - -import ( - "crypto/tls" -) - -func init() { - SupportedCurves["X25519Kyber768Draft00"] = tls.X25519Kyber768Draft00 - defaultCurves = append( - []tls.CurveID{tls.X25519Kyber768Draft00}, - defaultCurves..., - ) -} diff --git a/modules/caddytls/connpolicy.go b/modules/caddytls/connpolicy.go index 4ec0e673a77..e2890c848ab 100644 --- a/modules/caddytls/connpolicy.go +++ b/modules/caddytls/connpolicy.go @@ -841,7 +841,15 @@ func setDefaultTLSParams(cfg *tls.Config) { cfg.CipherSuites = append([]uint16{tls.TLS_FALLBACK_SCSV}, cfg.CipherSuites...) if len(cfg.CurvePreferences) == 0 { - cfg.CurvePreferences = defaultCurves + // We would want to write + // + // cfg.CurvePreferences = defaultCurves + // + // but that would disable the post-quantum key agreement X25519Kyber768 + // supported in Go 1.23, for which the CurveID is not exported. + // Instead, we'll set CurvePreferences to nil, which will enable PQC. + // See https://github.com/caddyserver/caddy/issues/6540 + cfg.CurvePreferences = nil } if cfg.MinVersion == 0 { diff --git a/modules/caddytls/values.go b/modules/caddytls/values.go index 4e8c1adc244..20fe45ff8fd 100644 --- a/modules/caddytls/values.go +++ b/modules/caddytls/values.go @@ -108,6 +108,11 @@ var supportedCertKeyTypes = map[string]certmagic.KeyType{ // implementation exists (e.g. P256). The latter ones can be // found here: // https://github.com/golang/go/tree/master/src/crypto/elliptic +// +// Temporily we ignore these default, to take advantage of X25519Kyber768 +// in Go's defaults (X25519Kyber768, X25519, P-256, P-384, P-521), which +// isn't exported. See https://github.com/caddyserver/caddy/issues/6540 +// nolint:unused var defaultCurves = []tls.CurveID{ tls.X25519, tls.CurveP256, From 141c785420aa1cc8fd35e5fd2defa7b8af230a2f Mon Sep 17 00:00:00 2001 From: WeidiDeng Date: Fri, 30 Aug 2024 04:11:25 +0800 Subject: [PATCH 02/10] ci: prepare syso files for windows embedding in release (#6406) * prepare syso files for windows embedding * don't specify main so version info will be embedded correctly --------- Co-authored-by: Mohammed Al Sahaf --- .goreleaser.yml | 5 ++++- 1 file changed, 4 insertions(+), 1 deletion(-) diff --git a/.goreleaser.yml b/.goreleaser.yml index 22f96b588bb..c7d01571ee4 100644 --- a/.goreleaser.yml +++ b/.goreleaser.yml @@ -12,6 +12,10 @@ before: - mkdir -p caddy-build - cp cmd/caddy/main.go caddy-build/main.go - /bin/sh -c 'cd ./caddy-build && go mod init caddy' + # prepare syso files for windows embedding + - go install github.com/caddyserver/xcaddy/cmd/xcaddy@latest + - /bin/sh -c 'for a in amd64 arm arm64; do XCADDY_SKIP_BUILD=1 GOOS=windows GOARCH=$a $GOPATH/bin/xcaddy build {{.Env.TAG}}; done' + - /bin/sh -c 'mv /tmp/buildenv_*/*.syso caddy-build' # GoReleaser doesn't seem to offer {{.Tag}} at this stage, so we have to embed it into the env # so we run: TAG=$(git describe --abbrev=0) goreleaser release --rm-dist --skip-publish --skip-validate - go mod edit -require=github.com/caddyserver/caddy/v2@{{.Env.TAG}} ./caddy-build/go.mod @@ -31,7 +35,6 @@ builds: - env: - CGO_ENABLED=0 - GO111MODULE=on - main: main.go dir: ./caddy-build binary: caddy goos: From ffd28be90ab85206474739b1f479ef49a6f0d7c3 Mon Sep 17 00:00:00 2001 From: Alexander Stecher <45872305+AlliBalliBaba@users.noreply.github.com> Date: Fri, 30 Aug 2024 16:46:51 +0200 Subject: [PATCH 03/10] rewrite: Only serialize request if necessary (#6541) * Prevents serializing the caddy request if log level is not debug. * Extracts message to const. --- modules/caddyhttp/rewrite/rewrite.go | 8 +++++++- 1 file changed, 7 insertions(+), 1 deletion(-) diff --git a/modules/caddyhttp/rewrite/rewrite.go b/modules/caddyhttp/rewrite/rewrite.go index 9a4995186bf..c45ad98a20a 100644 --- a/modules/caddyhttp/rewrite/rewrite.go +++ b/modules/caddyhttp/rewrite/rewrite.go @@ -131,6 +131,12 @@ func (rewr *Rewrite) Provision(ctx caddy.Context) error { func (rewr Rewrite) ServeHTTP(w http.ResponseWriter, r *http.Request, next caddyhttp.Handler) error { repl := r.Context().Value(caddy.ReplacerCtxKey).(*caddy.Replacer) + const message = "rewrote request" + + if rewr.logger.Check(zap.DebugLevel, message) == nil { + rewr.Rewrite(r, repl) + return next.ServeHTTP(w, r) + } logger := rewr.logger.With( zap.Object("request", caddyhttp.LoggableHTTPRequest{Request: r}), @@ -139,7 +145,7 @@ func (rewr Rewrite) ServeHTTP(w http.ResponseWriter, r *http.Request, next caddy changed := rewr.Rewrite(r, repl) if changed { - logger.Debug("rewrote request", + logger.Debug(message, zap.String("method", r.Method), zap.String("uri", r.RequestURI), ) From 5c47c2f147e5bef44fc8cb48a655d31f5a2a817c Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?lollipopkit=F0=9F=8F=B3=EF=B8=8F=E2=80=8D=E2=9A=A7?= =?UTF-8?q?=EF=B8=8F?= <10864310+lollipopkit@users.noreply.github.com> Date: Fri, 30 Aug 2024 23:01:37 +0800 Subject: [PATCH 04/10] fileserver: browse: Configurable default sort (#6502) * fileserver: add `sort` options * fix: test * fileserver: check options in `Provison` * fileserver: more obvious err alerts in sort options * fileserver: move `sort` to `browse` --------- Co-authored-by: Matt Holt --- .../file_server_sort.caddyfiletest | 17 +++++---- modules/caddyhttp/fileserver/browse.go | 13 ++++++- modules/caddyhttp/fileserver/caddyfile.go | 21 ++++++----- modules/caddyhttp/fileserver/staticfiles.go | 36 ++++++++----------- 4 files changed, 46 insertions(+), 41 deletions(-) diff --git a/caddytest/integration/caddyfile_adapt/file_server_sort.caddyfiletest b/caddytest/integration/caddyfile_adapt/file_server_sort.caddyfiletest index 62bfd0cbab5..7f07cba8051 100644 --- a/caddytest/integration/caddyfile_adapt/file_server_sort.caddyfiletest +++ b/caddytest/integration/caddyfile_adapt/file_server_sort.caddyfiletest @@ -1,7 +1,9 @@ :80 -file_server browse { - sort size desc +file_server { + browse { + sort size desc + } } ---------- { @@ -16,14 +18,15 @@ file_server browse { { "handle": [ { - "browse": {}, + "browse": { + "sort": [ + "size", + "desc" + ] + }, "handler": "file_server", "hide": [ "./Caddyfile" - ], - "sort": [ - "size", - "desc" ] } ] diff --git a/modules/caddyhttp/fileserver/browse.go b/modules/caddyhttp/fileserver/browse.go index bd02c584fec..f5cc16b42ab 100644 --- a/modules/caddyhttp/fileserver/browse.go +++ b/modules/caddyhttp/fileserver/browse.go @@ -52,8 +52,19 @@ var BrowseTemplate string type Browse struct { // Filename of the template to use instead of the embedded browse template. TemplateFile string `json:"template_file,omitempty"` + // Determines whether or not targets of symlinks should be revealed. RevealSymlinks bool `json:"reveal_symlinks,omitempty"` + + // Override the default sort. + // It includes the following options: + // - sort_by: name(default), namedirfirst, size, time + // - order: asc(default), desc + // eg.: + // - `sort time desc` will sort by time in descending order + // - `sort size` will sort by size in ascending order + // The first option must be `sort_by` and the second option must be `order` (if exists). + SortOptions []string `json:"sort,omitempty"` } func (fsrv *FileServer) serveBrowse(fileSystem fs.FS, root, dirPath string, w http.ResponseWriter, r *http.Request, next caddyhttp.Handler) error { @@ -210,7 +221,7 @@ func (fsrv *FileServer) browseApplyQueryParams(w http.ResponseWriter, r *http.Re // The configs in Caddyfile have lower priority than Query params, // so put it at first. - for idx, item := range fsrv.SortOptions { + for idx, item := range fsrv.Browse.SortOptions { // Only `sort` & `order`, 2 params are allowed if idx >= 2 { break diff --git a/modules/caddyhttp/fileserver/caddyfile.go b/modules/caddyhttp/fileserver/caddyfile.go index 603a828c968..71b7638e477 100644 --- a/modules/caddyhttp/fileserver/caddyfile.go +++ b/modules/caddyhttp/fileserver/caddyfile.go @@ -119,6 +119,16 @@ func (fsrv *FileServer) UnmarshalCaddyfile(d *caddyfile.Dispenser) error { return d.Err("Symlinks path reveal is already enabled") } fsrv.Browse.RevealSymlinks = true + case "sort": + for d.NextArg() { + dVal := d.Val() + switch dVal { + case sortByName, sortByNameDirFirst, sortBySize, sortByTime, sortOrderAsc, sortOrderDesc: + fsrv.Browse.SortOptions = append(fsrv.Browse.SortOptions, dVal) + default: + return d.Errf("unknown sort option '%s'", dVal) + } + } default: return d.Errf("unknown subdirective '%s'", d.Val()) } @@ -171,17 +181,6 @@ func (fsrv *FileServer) UnmarshalCaddyfile(d *caddyfile.Dispenser) error { } fsrv.EtagFileExtensions = etagFileExtensions - case "sort": - for d.NextArg() { - dVal := d.Val() - switch dVal { - case sortByName, sortBySize, sortByTime, sortOrderAsc, sortOrderDesc: - fsrv.SortOptions = append(fsrv.SortOptions, dVal) - default: - return d.Errf("unknown sort option '%s'", dVal) - } - } - default: return d.Errf("unknown subdirective '%s'", d.Val()) } diff --git a/modules/caddyhttp/fileserver/staticfiles.go b/modules/caddyhttp/fileserver/staticfiles.go index 48812cfec3d..2dd237ae7dc 100644 --- a/modules/caddyhttp/fileserver/staticfiles.go +++ b/modules/caddyhttp/fileserver/staticfiles.go @@ -153,16 +153,6 @@ type FileServer struct { // a 404 error. By default, this is false (disabled). PassThru bool `json:"pass_thru,omitempty"` - // Override the default sort. - // It includes the following options: - // - sort_by: name(default), namedirfirst, size, time - // - order: asc(default), desc - // eg.: - // - `sort time desc` will sort by time in descending order - // - `sort size` will sort by size in ascending order - // The first option must be `sort_by` and the second option must be `order` (if exists). - SortOptions []string `json:"sort,omitempty"` - // Selection of encoders to use to check for precompressed files. PrecompressedRaw caddy.ModuleMap `json:"precompressed,omitempty" caddy:"namespace=http.precompressed"` @@ -246,19 +236,21 @@ func (fsrv *FileServer) Provision(ctx caddy.Context) error { fsrv.precompressors[ae] = p } - // check sort options - for idx, sortOption := range fsrv.SortOptions { - switch idx { - case 0: - if sortOption != sortByName && sortOption != sortByNameDirFirst && sortOption != sortBySize && sortOption != sortByTime { - return fmt.Errorf("the first option must be one of the following: %s, %s, %s, %s, but got %s", sortByName, sortByNameDirFirst, sortBySize, sortByTime, sortOption) - } - case 1: - if sortOption != sortOrderAsc && sortOption != sortOrderDesc { - return fmt.Errorf("the second option must be one of the following: %s, %s, but got %s", sortOrderAsc, sortOrderDesc, sortOption) + if fsrv.Browse != nil { + // check sort options + for idx, sortOption := range fsrv.Browse.SortOptions { + switch idx { + case 0: + if sortOption != sortByName && sortOption != sortByNameDirFirst && sortOption != sortBySize && sortOption != sortByTime { + return fmt.Errorf("the first option must be one of the following: %s, %s, %s, %s, but got %s", sortByName, sortByNameDirFirst, sortBySize, sortByTime, sortOption) + } + case 1: + if sortOption != sortOrderAsc && sortOption != sortOrderDesc { + return fmt.Errorf("the second option must be one of the following: %s, %s, but got %s", sortOrderAsc, sortOrderDesc, sortOption) + } + default: + return fmt.Errorf("only max 2 sort options are allowed, but got %d", idx+1) } - default: - return fmt.Errorf("only max 2 sort options are allowed, but got %d", idx+1) } } From c050a37e1c3228708a6716c8971361134243e941 Mon Sep 17 00:00:00 2001 From: Steffen Busch <37350514+steffenbusch@users.noreply.github.com> Date: Fri, 30 Aug 2024 19:53:56 +0200 Subject: [PATCH 05/10] reverse_proxy: add placeholder http.reverse_proxy.retries (#6553) * Add placeholder http.reverse_proxy.lb.retries * Renamed placeholder to http.reverse_proxy.retries --- modules/caddyhttp/reverseproxy/reverseproxy.go | 4 ++++ 1 file changed, 4 insertions(+) diff --git a/modules/caddyhttp/reverseproxy/reverseproxy.go b/modules/caddyhttp/reverseproxy/reverseproxy.go index 1883ac0721a..44cc2f9d9a6 100644 --- a/modules/caddyhttp/reverseproxy/reverseproxy.go +++ b/modules/caddyhttp/reverseproxy/reverseproxy.go @@ -67,6 +67,7 @@ func init() { // `{http.reverse_proxy.upstream.duration_ms}` | Same as 'upstream.duration', but in milliseconds. // `{http.reverse_proxy.duration}` | Total time spent proxying, including selecting an upstream, retries, and writing response. // `{http.reverse_proxy.duration_ms}` | Same as 'duration', but in milliseconds. +// `{http.reverse_proxy.retries}` | The number of retries actually performed to communicate with an upstream. type Handler struct { // Configures the method of transport for the proxy. A transport // is what performs the actual "round trip" to the backend. @@ -443,6 +444,9 @@ func (h *Handler) ServeHTTP(w http.ResponseWriter, r *http.Request, next caddyht retries++ } + // number of retries actually performed + repl.Set("http.reverse_proxy.retries", retries) + if proxyErr != nil { return statusError(proxyErr) } From 91e62db666b799ba4bb6577d8548fbe779d91c28 Mon Sep 17 00:00:00 2001 From: Jesper Brix Rosenkilde Date: Tue, 3 Sep 2024 19:57:55 +0200 Subject: [PATCH 06/10] caddyhttp: Make route provisioning idempotent (#6558) ref: https://github.com/caddyserver/caddy/issues/6551 --- modules/caddyhttp/routes.go | 3 +++ 1 file changed, 3 insertions(+) diff --git a/modules/caddyhttp/routes.go b/modules/caddyhttp/routes.go index 6f2371495cf..54a3f38e62a 100644 --- a/modules/caddyhttp/routes.go +++ b/modules/caddyhttp/routes.go @@ -159,6 +159,9 @@ func (r *Route) ProvisionHandlers(ctx caddy.Context, metrics *Metrics) error { r.Handlers = append(r.Handlers, handler.(MiddlewareHandler)) } + // Make ProvisionHandlers idempotent by clearing the middleware field + r.middleware = []Middleware{} + // pre-compile the middleware handler chain for _, midhandler := range r.Handlers { r.middleware = append(r.middleware, wrapMiddleware(ctx, midhandler, metrics)) From 2d12fb7ac6c7dfcbb8abeafbfb64af5ad1175bb3 Mon Sep 17 00:00:00 2001 From: vnxme <46669194+vnxme@users.noreply.github.com> Date: Thu, 12 Sep 2024 05:51:59 +0300 Subject: [PATCH 07/10] caddytls: Add sni_regexp matcher (#6569) --- modules/caddytls/matchers.go | 155 +++++++++++++++++++++++++++++- modules/caddytls/matchers_test.go | 46 +++++++++ 2 files changed, 199 insertions(+), 2 deletions(-) diff --git a/modules/caddytls/matchers.go b/modules/caddytls/matchers.go index f946223741b..65bbfa311e1 100644 --- a/modules/caddytls/matchers.go +++ b/modules/caddytls/matchers.go @@ -19,6 +19,8 @@ import ( "fmt" "net" "net/netip" + "regexp" + "strconv" "strings" "github.com/caddyserver/certmagic" @@ -31,6 +33,7 @@ import ( func init() { caddy.RegisterModule(MatchServerName{}) + caddy.RegisterModule(MatchServerNameRE{}) caddy.RegisterModule(MatchRemoteIP{}) caddy.RegisterModule(MatchLocalIP{}) } @@ -91,6 +94,146 @@ func (m *MatchServerName) UnmarshalCaddyfile(d *caddyfile.Dispenser) error { return nil } +// MatchRegexp is an embeddable type for matching +// using regular expressions. It adds placeholders +// to the request's replacer. In fact, it is a copy of +// caddyhttp.MatchRegexp with a local replacer prefix +// and placeholders support in a regular expression pattern. +type MatchRegexp struct { + // A unique name for this regular expression. Optional, + // but useful to prevent overwriting captures from other + // regexp matchers. + Name string `json:"name,omitempty"` + + // The regular expression to evaluate, in RE2 syntax, + // which is the same general syntax used by Go, Perl, + // and Python. For details, see + // [Go's regexp package](https://golang.org/pkg/regexp/). + // Captures are accessible via placeholders. Unnamed + // capture groups are exposed as their numeric, 1-based + // index, while named capture groups are available by + // the capture group name. + Pattern string `json:"pattern"` + + compiled *regexp.Regexp +} + +// Provision compiles the regular expression which may include placeholders. +func (mre *MatchRegexp) Provision(caddy.Context) error { + repl := caddy.NewReplacer() + re, err := regexp.Compile(repl.ReplaceAll(mre.Pattern, "")) + if err != nil { + return fmt.Errorf("compiling matcher regexp %s: %v", mre.Pattern, err) + } + mre.compiled = re + return nil +} + +// Validate ensures mre is set up correctly. +func (mre *MatchRegexp) Validate() error { + if mre.Name != "" && !wordRE.MatchString(mre.Name) { + return fmt.Errorf("invalid regexp name (must contain only word characters): %s", mre.Name) + } + return nil +} + +// Match returns true if input matches the compiled regular +// expression in m. It sets values on the replacer repl +// associated with capture groups, using the given scope +// (namespace). +func (mre *MatchRegexp) Match(input string, repl *caddy.Replacer) bool { + matches := mre.compiled.FindStringSubmatch(input) + if matches == nil { + return false + } + + // save all capture groups, first by index + for i, match := range matches { + keySuffix := "." + strconv.Itoa(i) + if mre.Name != "" { + repl.Set(regexpPlaceholderPrefix+"."+mre.Name+keySuffix, match) + } + repl.Set(regexpPlaceholderPrefix+keySuffix, match) + } + + // then by name + for i, name := range mre.compiled.SubexpNames() { + // skip the first element (the full match), and empty names + if i == 0 || name == "" { + continue + } + + keySuffix := "." + name + if mre.Name != "" { + repl.Set(regexpPlaceholderPrefix+"."+mre.Name+keySuffix, matches[i]) + } + repl.Set(regexpPlaceholderPrefix+keySuffix, matches[i]) + } + + return true +} + +// UnmarshalCaddyfile implements caddyfile.Unmarshaler. +func (mre *MatchRegexp) UnmarshalCaddyfile(d *caddyfile.Dispenser) error { + // iterate to merge multiple matchers into one + for d.Next() { + // If this is the second iteration of the loop + // then there's more than one *_regexp matcher, + // and we would end up overwriting the old one + if mre.Pattern != "" { + return d.Err("regular expression can only be used once per named matcher") + } + + args := d.RemainingArgs() + switch len(args) { + case 1: + mre.Pattern = args[0] + case 2: + mre.Name = args[0] + mre.Pattern = args[1] + default: + return d.ArgErr() + } + + // Default to the named matcher's name, if no regexp name is provided. + // Note: it requires d.SetContext(caddyfile.MatcherNameCtxKey, value) + // called before this unmarshalling, otherwise it wouldn't work. + if mre.Name == "" { + mre.Name = d.GetContextString(caddyfile.MatcherNameCtxKey) + } + + if d.NextBlock(0) { + return d.Err("malformed regexp matcher: blocks are not supported") + } + } + return nil +} + +// MatchServerNameRE matches based on SNI using a regular expression. +type MatchServerNameRE struct{ MatchRegexp } + +// CaddyModule returns the Caddy module information. +func (MatchServerNameRE) CaddyModule() caddy.ModuleInfo { + return caddy.ModuleInfo{ + ID: "tls.handshake_match.sni_regexp", + New: func() caddy.Module { return new(MatchServerNameRE) }, + } +} + +// Match matches hello based on SNI using a regular expression. +func (m MatchServerNameRE) Match(hello *tls.ClientHelloInfo) bool { + repl := caddy.NewReplacer() + // caddytls.TestServerNameMatcher calls this function without any context + if ctx := hello.Context(); ctx != nil { + // In some situations the existing context may have no replacer + if replAny := ctx.Value(caddy.ReplacerCtxKey); replAny != nil { + repl = replAny.(*caddy.Replacer) + } + } + + return m.MatchRegexp.Match(hello.ServerName, repl) +} + // MatchRemoteIP matches based on the remote IP of the // connection. Specific IPs or CIDR ranges can be specified. // @@ -331,13 +474,21 @@ func (m *MatchLocalIP) UnmarshalCaddyfile(d *caddyfile.Dispenser) error { // Interface guards var ( - _ ConnectionMatcher = (*MatchServerName)(nil) + _ ConnectionMatcher = (*MatchLocalIP)(nil) _ ConnectionMatcher = (*MatchRemoteIP)(nil) + _ ConnectionMatcher = (*MatchServerName)(nil) + _ ConnectionMatcher = (*MatchServerNameRE)(nil) _ caddy.Provisioner = (*MatchLocalIP)(nil) - _ ConnectionMatcher = (*MatchLocalIP)(nil) + _ caddy.Provisioner = (*MatchRemoteIP)(nil) + _ caddy.Provisioner = (*MatchServerNameRE)(nil) _ caddyfile.Unmarshaler = (*MatchLocalIP)(nil) _ caddyfile.Unmarshaler = (*MatchRemoteIP)(nil) _ caddyfile.Unmarshaler = (*MatchServerName)(nil) + _ caddyfile.Unmarshaler = (*MatchServerNameRE)(nil) ) + +var wordRE = regexp.MustCompile(`\w+`) + +const regexpPlaceholderPrefix = "tls.regexp" diff --git a/modules/caddytls/matchers_test.go b/modules/caddytls/matchers_test.go index 54dfdb9c45c..824f7207098 100644 --- a/modules/caddytls/matchers_test.go +++ b/modules/caddytls/matchers_test.go @@ -89,6 +89,52 @@ func TestServerNameMatcher(t *testing.T) { } } +func TestServerNameREMatcher(t *testing.T) { + for i, tc := range []struct { + pattern string + input string + expect bool + }{ + { + pattern: "^example\\.(com|net)$", + input: "example.com", + expect: true, + }, + { + pattern: "^example\\.(com|net)$", + input: "foo.com", + expect: false, + }, + { + pattern: "^example\\.(com|net)$", + input: "", + expect: false, + }, + { + pattern: "", + input: "", + expect: true, + }, + { + pattern: "^example\\.(com|net)$", + input: "foo.example.com", + expect: false, + }, + } { + chi := &tls.ClientHelloInfo{ServerName: tc.input} + mre := MatchServerNameRE{MatchRegexp{Pattern: tc.pattern}} + ctx, _ := caddy.NewContext(caddy.Context{Context: context.Background()}) + if mre.Provision(ctx) != nil { + t.Errorf("Test %d: Failed to provision a regexp matcher (pattern=%v)", i, tc.pattern) + } + actual := mre.Match(chi) + if actual != tc.expect { + t.Errorf("Test %d: Expected %t but got %t (input=%s match=%v)", + i, tc.expect, actual, tc.input, tc.pattern) + } + } +} + func TestRemoteIPMatcher(t *testing.T) { ctx, cancel := caddy.NewContext(caddy.Context{Context: context.Background()}) defer cancel() From 21f9c20a04ec5c2ac430daa8e4ba8fbdef67f773 Mon Sep 17 00:00:00 2001 From: mister-turtle <50653342+mister-turtle@users.noreply.github.com> Date: Fri, 13 Sep 2024 08:22:03 +0100 Subject: [PATCH 08/10] rewrite: Avoid panic on bad arg count for `uri` (#6571) --- modules/caddyhttp/rewrite/caddyfile.go | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/modules/caddyhttp/rewrite/caddyfile.go b/modules/caddyhttp/rewrite/caddyfile.go index 0ce5c41d217..89f44c79bf3 100644 --- a/modules/caddyhttp/rewrite/caddyfile.go +++ b/modules/caddyhttp/rewrite/caddyfile.go @@ -106,7 +106,7 @@ func parseCaddyfileURI(h httpcaddyfile.Helper) (caddyhttp.MiddlewareHandler, err switch args[0] { case "strip_prefix": - if len(args) > 2 { + if len(args) != 2 { return nil, h.ArgErr() } rewr.StripPathPrefix = args[1] @@ -115,7 +115,7 @@ func parseCaddyfileURI(h httpcaddyfile.Helper) (caddyhttp.MiddlewareHandler, err } case "strip_suffix": - if len(args) > 2 { + if len(args) != 2 { return nil, h.ArgErr() } rewr.StripPathSuffix = args[1] From f4bf4e0097853438eb69c573bbaa0581e9b9c02d Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?K=C3=A9vin=20Dunglas?= Date: Fri, 13 Sep 2024 19:16:37 +0200 Subject: [PATCH 09/10] perf: use zap's Check() to prevent useless allocs (#6560) * perf: use zap's Check() to prevent useless allocs * fix * fix * fix * fix * restore previous replacer behavior * fix linter --- modules/caddyhttp/caddyauth/caddyauth.go | 7 +- modules/caddyhttp/fileserver/browse.go | 11 +- .../caddyhttp/fileserver/browsetplcontext.go | 7 +- modules/caddyhttp/fileserver/matcher.go | 14 +- modules/caddyhttp/fileserver/staticfiles.go | 91 +++++++---- modules/caddyhttp/intercept/intercept.go | 5 +- modules/caddyhttp/ip_matchers.go | 10 +- modules/caddyhttp/logging.go | 12 +- modules/caddyhttp/push/handler.go | 24 ++- modules/caddyhttp/requestbody/requestbody.go | 9 +- .../caddyhttp/reverseproxy/fastcgi/client.go | 10 +- .../caddyhttp/reverseproxy/fastcgi/fastcgi.go | 11 +- .../caddyhttp/reverseproxy/healthchecks.go | 154 +++++++++++------- .../caddyhttp/reverseproxy/httptransport.go | 9 +- modules/caddyhttp/reverseproxy/metrics.go | 10 +- .../caddyhttp/reverseproxy/reverseproxy.go | 54 ++++-- modules/caddyhttp/reverseproxy/streaming.go | 84 +++++++--- modules/caddyhttp/reverseproxy/upstreams.go | 62 ++++--- modules/caddyhttp/rewrite/rewrite.go | 10 +- modules/caddyhttp/server.go | 141 ++++++++++------ modules/caddyhttp/server_test.go | 23 +++ modules/caddyhttp/tracing/tracerprovider.go | 5 +- modules/caddypki/acmeserver/acmeserver.go | 13 +- modules/caddytls/acmeissuer.go | 5 +- modules/caddytls/automation.go | 28 +++- modules/caddytls/certmanagers.go | 5 +- modules/caddytls/connpolicy.go | 6 +- modules/caddytls/matchers.go | 9 +- modules/caddytls/ondemand.go | 25 ++- modules/caddytls/tls.go | 27 ++- 30 files changed, 599 insertions(+), 282 deletions(-) diff --git a/modules/caddyhttp/caddyauth/caddyauth.go b/modules/caddyhttp/caddyauth/caddyauth.go index c60de880b8b..f799d7a0cb0 100644 --- a/modules/caddyhttp/caddyauth/caddyauth.go +++ b/modules/caddyhttp/caddyauth/caddyauth.go @@ -19,6 +19,7 @@ import ( "net/http" "go.uber.org/zap" + "go.uber.org/zap/zapcore" "github.com/caddyserver/caddy/v2" "github.com/caddyserver/caddy/v2/modules/caddyhttp" @@ -76,9 +77,9 @@ func (a Authentication) ServeHTTP(w http.ResponseWriter, r *http.Request, next c for provName, prov := range a.Providers { user, authed, err = prov.Authenticate(w, r) if err != nil { - a.logger.Error("auth provider returned error", - zap.String("provider", provName), - zap.Error(err)) + if c := a.logger.Check(zapcore.ErrorLevel, "auth provider returned error"); c != nil { + c.Write(zap.String("provider", provName), zap.Error(err)) + } continue } if authed { diff --git a/modules/caddyhttp/fileserver/browse.go b/modules/caddyhttp/fileserver/browse.go index f5cc16b42ab..a19b4e17a85 100644 --- a/modules/caddyhttp/fileserver/browse.go +++ b/modules/caddyhttp/fileserver/browse.go @@ -33,6 +33,7 @@ import ( "time" "go.uber.org/zap" + "go.uber.org/zap/zapcore" "github.com/caddyserver/caddy/v2" "github.com/caddyserver/caddy/v2/modules/caddyhttp" @@ -68,9 +69,9 @@ type Browse struct { } func (fsrv *FileServer) serveBrowse(fileSystem fs.FS, root, dirPath string, w http.ResponseWriter, r *http.Request, next caddyhttp.Handler) error { - fsrv.logger.Debug("browse enabled; listing directory contents", - zap.String("path", dirPath), - zap.String("root", root)) + if c := fsrv.logger.Check(zapcore.DebugLevel, "browse enabled; listing directory contents"); c != nil { + c.Write(zap.String("path", dirPath), zap.String("root", root)) + } // Navigation on the client-side gets messed up if the // URL doesn't end in a trailing slash because hrefs to @@ -92,7 +93,9 @@ func (fsrv *FileServer) serveBrowse(fileSystem fs.FS, root, dirPath string, w ht origReq := r.Context().Value(caddyhttp.OriginalRequestCtxKey).(http.Request) if r.URL.Path == "" || path.Base(origReq.URL.Path) == path.Base(r.URL.Path) { if !strings.HasSuffix(origReq.URL.Path, "/") { - fsrv.logger.Debug("redirecting to trailing slash to preserve hrefs", zap.String("request_path", r.URL.Path)) + if c := fsrv.logger.Check(zapcore.DebugLevel, "redirecting to trailing slash to preserve hrefs"); c != nil { + c.Write(zap.String("request_path", r.URL.Path)) + } return redirect(w, r, origReq.URL.Path+"/") } } diff --git a/modules/caddyhttp/fileserver/browsetplcontext.go b/modules/caddyhttp/fileserver/browsetplcontext.go index 0251bc581f6..37e1cc3dda8 100644 --- a/modules/caddyhttp/fileserver/browsetplcontext.go +++ b/modules/caddyhttp/fileserver/browsetplcontext.go @@ -28,6 +28,7 @@ import ( "github.com/dustin/go-humanize" "go.uber.org/zap" + "go.uber.org/zap/zapcore" "github.com/caddyserver/caddy/v2" "github.com/caddyserver/caddy/v2/modules/caddyhttp" @@ -57,9 +58,9 @@ func (fsrv *FileServer) directoryListing(ctx context.Context, fileSystem fs.FS, info, err := entry.Info() if err != nil { - fsrv.logger.Error("could not get info about directory entry", - zap.String("name", entry.Name()), - zap.String("root", root)) + if c := fsrv.logger.Check(zapcore.ErrorLevel, "could not get info about directory entry"); c != nil { + c.Write(zap.String("name", entry.Name()), zap.String("root", root)) + } continue } diff --git a/modules/caddyhttp/fileserver/matcher.go b/modules/caddyhttp/fileserver/matcher.go index c315b8e38d7..6ab2180ad77 100644 --- a/modules/caddyhttp/fileserver/matcher.go +++ b/modules/caddyhttp/fileserver/matcher.go @@ -33,6 +33,7 @@ import ( "github.com/google/cel-go/common/types/ref" "github.com/google/cel-go/parser" "go.uber.org/zap" + "go.uber.org/zap/zapcore" "github.com/caddyserver/caddy/v2" "github.com/caddyserver/caddy/v2/caddyconfig/caddyfile" @@ -326,7 +327,9 @@ func (m MatchFile) selectFile(r *http.Request) (matched bool) { fileSystem, ok := m.fsmap.Get(fsName) if !ok { - m.logger.Error("use of unregistered filesystem", zap.String("fs", fsName)) + if c := m.logger.Check(zapcore.ErrorLevel, "use of unregistered filesystem"); c != nil { + c.Write(zap.String("fs", fsName)) + } return false } type matchCandidate struct { @@ -356,7 +359,10 @@ func (m MatchFile) selectFile(r *http.Request) (matched bool) { return val, nil }) if err != nil { - m.logger.Error("evaluating placeholders", zap.Error(err)) + if c := m.logger.Check(zapcore.ErrorLevel, "evaluating placeholders"); c != nil { + c.Write(zap.Error(err)) + } + expandedFile = file // "oh well," I guess? } @@ -379,7 +385,9 @@ func (m MatchFile) selectFile(r *http.Request) (matched bool) { } else { globResults, err = fs.Glob(fileSystem, fullPattern) if err != nil { - m.logger.Error("expanding glob", zap.Error(err)) + if c := m.logger.Check(zapcore.ErrorLevel, "expanding glob"); c != nil { + c.Write(zap.Error(err)) + } } } diff --git a/modules/caddyhttp/fileserver/staticfiles.go b/modules/caddyhttp/fileserver/staticfiles.go index 2dd237ae7dc..4ae69b64761 100644 --- a/modules/caddyhttp/fileserver/staticfiles.go +++ b/modules/caddyhttp/fileserver/staticfiles.go @@ -31,6 +31,7 @@ import ( "strings" "go.uber.org/zap" + "go.uber.org/zap/zapcore" "github.com/caddyserver/caddy/v2" "github.com/caddyserver/caddy/v2/modules/caddyhttp" @@ -286,11 +287,14 @@ func (fsrv *FileServer) ServeHTTP(w http.ResponseWriter, r *http.Request, next c // remove any trailing `/` as it breaks fs.ValidPath() in the stdlib filename := strings.TrimSuffix(caddyhttp.SanitizedPathJoin(root, r.URL.Path), "/") - fsrv.logger.Debug("sanitized path join", - zap.String("site_root", root), - zap.String("fs", fsName), - zap.String("request_path", r.URL.Path), - zap.String("result", filename)) + if c := fsrv.logger.Check(zapcore.DebugLevel, "sanitized path join"); c != nil { + c.Write( + zap.String("site_root", root), + zap.String("fs", fsName), + zap.String("request_path", r.URL.Path), + zap.String("result", filename), + ) + } // get information about the file info, err := fs.Stat(fileSystem, filename) @@ -313,9 +317,12 @@ func (fsrv *FileServer) ServeHTTP(w http.ResponseWriter, r *http.Request, next c indexPath := caddyhttp.SanitizedPathJoin(filename, indexPage) if fileHidden(indexPath, filesToHide) { // pretend this file doesn't exist - fsrv.logger.Debug("hiding index file", - zap.String("filename", indexPath), - zap.Strings("files_to_hide", filesToHide)) + if c := fsrv.logger.Check(zapcore.DebugLevel, "hiding index file"); c != nil { + c.Write( + zap.String("filename", indexPath), + zap.Strings("files_to_hide", filesToHide), + ) + } continue } @@ -335,7 +342,9 @@ func (fsrv *FileServer) ServeHTTP(w http.ResponseWriter, r *http.Request, next c info = indexInfo filename = indexPath implicitIndexFile = true - fsrv.logger.Debug("located index file", zap.String("filename", filename)) + if c := fsrv.logger.Check(zapcore.DebugLevel, "located index file"); c != nil { + c.Write(zap.String("filename", filename)) + } break } } @@ -343,9 +352,12 @@ func (fsrv *FileServer) ServeHTTP(w http.ResponseWriter, r *http.Request, next c // if still referencing a directory, delegate // to browse or return an error if info.IsDir() { - fsrv.logger.Debug("no index file in directory", - zap.String("path", filename), - zap.Strings("index_filenames", fsrv.IndexNames)) + if c := fsrv.logger.Check(zapcore.DebugLevel, "no index file in directory"); c != nil { + c.Write( + zap.String("path", filename), + zap.Strings("index_filenames", fsrv.IndexNames), + ) + } if fsrv.Browse != nil && !fileHidden(filename, filesToHide) { return fsrv.serveBrowse(fileSystem, root, filename, w, r, next) } @@ -355,9 +367,12 @@ func (fsrv *FileServer) ServeHTTP(w http.ResponseWriter, r *http.Request, next c // one last check to ensure the file isn't hidden (we might // have changed the filename from when we last checked) if fileHidden(filename, filesToHide) { - fsrv.logger.Debug("hiding file", - zap.String("filename", filename), - zap.Strings("files_to_hide", filesToHide)) + if c := fsrv.logger.Check(zapcore.DebugLevel, "hiding file"); c != nil { + c.Write( + zap.String("filename", filename), + zap.Strings("files_to_hide", filesToHide), + ) + } return fsrv.notFound(w, r, next) } @@ -375,15 +390,21 @@ func (fsrv *FileServer) ServeHTTP(w http.ResponseWriter, r *http.Request, next c if path.Base(origReq.URL.Path) == path.Base(r.URL.Path) { if implicitIndexFile && !strings.HasSuffix(origReq.URL.Path, "/") { to := origReq.URL.Path + "/" - fsrv.logger.Debug("redirecting to canonical URI (adding trailing slash for directory)", - zap.String("from_path", origReq.URL.Path), - zap.String("to_path", to)) + if c := fsrv.logger.Check(zapcore.DebugLevel, "redirecting to canonical URI (adding trailing slash for directory"); c != nil { + c.Write( + zap.String("from_path", origReq.URL.Path), + zap.String("to_path", to), + ) + } return redirect(w, r, to) } else if !implicitIndexFile && strings.HasSuffix(origReq.URL.Path, "/") { to := origReq.URL.Path[:len(origReq.URL.Path)-1] - fsrv.logger.Debug("redirecting to canonical URI (removing trailing slash for file)", - zap.String("from_path", origReq.URL.Path), - zap.String("to_path", to)) + if c := fsrv.logger.Check(zapcore.DebugLevel, "redirecting to canonical URI (removing trailing slash for file"); c != nil { + c.Write( + zap.String("from_path", origReq.URL.Path), + zap.String("to_path", to), + ) + } return redirect(w, r, to) } } @@ -411,13 +432,19 @@ func (fsrv *FileServer) ServeHTTP(w http.ResponseWriter, r *http.Request, next c compressedFilename := filename + precompress.Suffix() compressedInfo, err := fs.Stat(fileSystem, compressedFilename) if err != nil || compressedInfo.IsDir() { - fsrv.logger.Debug("precompressed file not accessible", zap.String("filename", compressedFilename), zap.Error(err)) + if c := fsrv.logger.Check(zapcore.DebugLevel, "precompressed file not accessible"); c != nil { + c.Write(zap.String("filename", compressedFilename), zap.Error(err)) + } continue } - fsrv.logger.Debug("opening compressed sidecar file", zap.String("filename", compressedFilename), zap.Error(err)) + if c := fsrv.logger.Check(zapcore.DebugLevel, "opening compressed sidecar file"); c != nil { + c.Write(zap.String("filename", compressedFilename), zap.Error(err)) + } file, err = fsrv.openFile(fileSystem, compressedFilename, w) if err != nil { - fsrv.logger.Warn("opening precompressed file failed", zap.String("filename", compressedFilename), zap.Error(err)) + if c := fsrv.logger.Check(zapcore.WarnLevel, "opening precompressed file failed"); c != nil { + c.Write(zap.String("filename", compressedFilename), zap.Error(err)) + } if caddyErr, ok := err.(caddyhttp.HandlerError); ok && caddyErr.StatusCode == http.StatusServiceUnavailable { return err } @@ -448,7 +475,9 @@ func (fsrv *FileServer) ServeHTTP(w http.ResponseWriter, r *http.Request, next c // no precompressed file found, use the actual file if file == nil { - fsrv.logger.Debug("opening file", zap.String("filename", filename)) + if c := fsrv.logger.Check(zapcore.DebugLevel, "opening file"); c != nil { + c.Write(zap.String("filename", filename)) + } // open the file file, err = fsrv.openFile(fileSystem, filename, w) @@ -548,10 +577,14 @@ func (fsrv *FileServer) openFile(fileSystem fs.FS, filename string, w http.Respo if err != nil { err = fsrv.mapDirOpenError(fileSystem, err, filename) if errors.Is(err, fs.ErrNotExist) { - fsrv.logger.Debug("file not found", zap.String("filename", filename), zap.Error(err)) + if c := fsrv.logger.Check(zapcore.DebugLevel, "file not found"); c != nil { + c.Write(zap.String("filename", filename), zap.Error(err)) + } return nil, caddyhttp.Error(http.StatusNotFound, err) } else if errors.Is(err, fs.ErrPermission) { - fsrv.logger.Debug("permission denied", zap.String("filename", filename), zap.Error(err)) + if c := fsrv.logger.Check(zapcore.DebugLevel, "permission denied"); c != nil { + c.Write(zap.String("filename", filename), zap.Error(err)) + } return nil, caddyhttp.Error(http.StatusForbidden, err) } // maybe the server is under load and ran out of file descriptors? @@ -559,7 +592,9 @@ func (fsrv *FileServer) openFile(fileSystem fs.FS, filename string, w http.Respo //nolint:gosec backoff := weakrand.Intn(maxBackoff-minBackoff) + minBackoff w.Header().Set("Retry-After", strconv.Itoa(backoff)) - fsrv.logger.Debug("retry after backoff", zap.String("filename", filename), zap.Int("backoff", backoff), zap.Error(err)) + if c := fsrv.logger.Check(zapcore.DebugLevel, "retry after backoff"); c != nil { + c.Write(zap.String("filename", filename), zap.Int("backoff", backoff), zap.Error(err)) + } return nil, caddyhttp.Error(http.StatusServiceUnavailable, err) } return file, nil diff --git a/modules/caddyhttp/intercept/intercept.go b/modules/caddyhttp/intercept/intercept.go index 720a09333aa..29889dcc0ed 100644 --- a/modules/caddyhttp/intercept/intercept.go +++ b/modules/caddyhttp/intercept/intercept.go @@ -23,6 +23,7 @@ import ( "sync" "go.uber.org/zap" + "go.uber.org/zap/zapcore" "github.com/caddyserver/caddy/v2" "github.com/caddyserver/caddy/v2/caddyconfig/caddyfile" @@ -165,7 +166,9 @@ func (ir Intercept) ServeHTTP(w http.ResponseWriter, r *http.Request, next caddy } repl.Set("http.intercept.status_code", rec.Status()) - ir.logger.Debug("handling response", zap.Int("handler", rec.handlerIndex)) + if c := ir.logger.Check(zapcore.DebugLevel, "handling response"); c != nil { + c.Write(zap.Int("handler", rec.handlerIndex)) + } // pass the request through the response handler routes return rec.handler.Routes.Compile(next).ServeHTTP(w, r) diff --git a/modules/caddyhttp/ip_matchers.go b/modules/caddyhttp/ip_matchers.go index 2e735cb6903..99eb39dff78 100644 --- a/modules/caddyhttp/ip_matchers.go +++ b/modules/caddyhttp/ip_matchers.go @@ -26,6 +26,7 @@ import ( "github.com/google/cel-go/cel" "github.com/google/cel-go/common/types/ref" "go.uber.org/zap" + "go.uber.org/zap/zapcore" "github.com/caddyserver/caddy/v2" "github.com/caddyserver/caddy/v2/caddyconfig/caddyfile" @@ -150,12 +151,17 @@ func (m MatchRemoteIP) Match(r *http.Request) bool { address := r.RemoteAddr clientIP, zoneID, err := parseIPZoneFromString(address) if err != nil { - m.logger.Error("getting remote IP", zap.Error(err)) + if c := m.logger.Check(zapcore.ErrorLevel, "getting remote "); c != nil { + c.Write(zap.Error(err)) + } + return false } matches, zoneFilter := matchIPByCidrZones(clientIP, zoneID, m.cidrs, m.zones) if !matches && !zoneFilter { - m.logger.Debug("zone ID from remote IP did not match", zap.String("zone", zoneID)) + if c := m.logger.Check(zapcore.DebugLevel, "zone ID from remote IP did not match"); c != nil { + c.Write(zap.String("zone", zoneID)) + } } return matches } diff --git a/modules/caddyhttp/logging.go b/modules/caddyhttp/logging.go index 823763e911e..0a389fe16a1 100644 --- a/modules/caddyhttp/logging.go +++ b/modules/caddyhttp/logging.go @@ -193,7 +193,7 @@ func (sa *StringArray) UnmarshalJSON(b []byte) error { // to use, the error log message, and any extra fields. // If err is a HandlerError, the returned values will // have richer information. -func errLogValues(err error) (status int, msg string, fields []zapcore.Field) { +func errLogValues(err error) (status int, msg string, fields func() []zapcore.Field) { var handlerErr HandlerError if errors.As(err, &handlerErr) { status = handlerErr.StatusCode @@ -202,10 +202,12 @@ func errLogValues(err error) (status int, msg string, fields []zapcore.Field) { } else { msg = handlerErr.Err.Error() } - fields = []zapcore.Field{ - zap.Int("status", handlerErr.StatusCode), - zap.String("err_id", handlerErr.ID), - zap.String("err_trace", handlerErr.Trace), + fields = func() []zapcore.Field { + return []zapcore.Field{ + zap.Int("status", handlerErr.StatusCode), + zap.String("err_id", handlerErr.ID), + zap.String("err_trace", handlerErr.Trace), + } } return } diff --git a/modules/caddyhttp/push/handler.go b/modules/caddyhttp/push/handler.go index 031a8991fb5..1fbe53d8366 100644 --- a/modules/caddyhttp/push/handler.go +++ b/modules/caddyhttp/push/handler.go @@ -20,6 +20,7 @@ import ( "strings" "go.uber.org/zap" + "go.uber.org/zap/zapcore" "github.com/caddyserver/caddy/v2" "github.com/caddyserver/caddy/v2/modules/caddyhttp" @@ -92,14 +93,17 @@ func (h Handler) ServeHTTP(w http.ResponseWriter, r *http.Request, next caddyhtt // push first! for _, resource := range h.Resources { - h.logger.Debug("pushing resource", - zap.String("uri", r.RequestURI), - zap.String("push_method", resource.Method), - zap.String("push_target", resource.Target), - zap.Object("push_headers", caddyhttp.LoggableHTTPHeader{ - Header: hdr, - ShouldLogCredentials: shouldLogCredentials, - })) + if c := h.logger.Check(zapcore.DebugLevel, "pushing resource"); c != nil { + c.Write( + zap.String("uri", r.RequestURI), + zap.String("push_method", resource.Method), + zap.String("push_target", resource.Target), + zap.Object("push_headers", caddyhttp.LoggableHTTPHeader{ + Header: hdr, + ShouldLogCredentials: shouldLogCredentials, + }), + ) + } err := pusher.Push(repl.ReplaceAll(resource.Target, "."), &http.PushOptions{ Method: resource.Method, Header: hdr, @@ -209,7 +213,9 @@ func (lp linkPusher) WriteHeader(statusCode int) { if links, ok := lp.ResponseWriter.Header()["Link"]; ok { // only initiate these pushes if it hasn't been done yet if val := caddyhttp.GetVar(lp.request.Context(), pushedLink); val == nil { - lp.handler.logger.Debug("pushing Link resources", zap.Strings("linked", links)) + if c := lp.handler.logger.Check(zapcore.DebugLevel, "pushing Link resources"); c != nil { + c.Write(zap.Strings("linked", links)) + } caddyhttp.SetVar(lp.request.Context(), pushedLink, true) lp.handler.servePreloadLinks(lp.pusher, lp.header, links) } diff --git a/modules/caddyhttp/requestbody/requestbody.go b/modules/caddyhttp/requestbody/requestbody.go index d00455a8c97..1c804aa134a 100644 --- a/modules/caddyhttp/requestbody/requestbody.go +++ b/modules/caddyhttp/requestbody/requestbody.go @@ -20,6 +20,7 @@ import ( "time" "go.uber.org/zap" + "go.uber.org/zap/zapcore" "github.com/caddyserver/caddy/v2" "github.com/caddyserver/caddy/v2/modules/caddyhttp" @@ -69,12 +70,16 @@ func (rb RequestBody) ServeHTTP(w http.ResponseWriter, r *http.Request, next cad rc := http.NewResponseController(w) if rb.ReadTimeout > 0 { if err := rc.SetReadDeadline(time.Now().Add(rb.ReadTimeout)); err != nil { - rb.logger.Error("could not set read deadline", zap.Error(err)) + if c := rb.logger.Check(zapcore.ErrorLevel, "could not set read deadline"); c != nil { + c.Write(zap.Error(err)) + } } } if rb.WriteTimeout > 0 { if err := rc.SetWriteDeadline(time.Now().Add(rb.WriteTimeout)); err != nil { - rb.logger.Error("could not set write deadline", zap.Error(err)) + if c := rb.logger.Check(zapcore.ErrorLevel, "could not set write deadline"); c != nil { + c.Write(zap.Error(err)) + } } } } diff --git a/modules/caddyhttp/reverseproxy/fastcgi/client.go b/modules/caddyhttp/reverseproxy/fastcgi/client.go index d944c5778c1..7284fe67285 100644 --- a/modules/caddyhttp/reverseproxy/fastcgi/client.go +++ b/modules/caddyhttp/reverseproxy/fastcgi/client.go @@ -40,6 +40,7 @@ import ( "time" "go.uber.org/zap" + "go.uber.org/zap/zapcore" ) // FCGIListenSockFileno describes listen socket file number. @@ -184,10 +185,13 @@ func (f clientCloser) Close() error { return f.rwc.Close() } + logLevel := zapcore.WarnLevel if f.status >= 400 { - f.logger.Error("stderr", zap.ByteString("body", stderr)) - } else { - f.logger.Warn("stderr", zap.ByteString("body", stderr)) + logLevel = zapcore.ErrorLevel + } + + if c := f.logger.Check(logLevel, "stderr"); c != nil { + c.Write(zap.ByteString("body", stderr)) } return f.rwc.Close() diff --git a/modules/caddyhttp/reverseproxy/fastcgi/fastcgi.go b/modules/caddyhttp/reverseproxy/fastcgi/fastcgi.go index 31febdd4efe..3985465ba1a 100644 --- a/modules/caddyhttp/reverseproxy/fastcgi/fastcgi.go +++ b/modules/caddyhttp/reverseproxy/fastcgi/fastcgi.go @@ -148,10 +148,13 @@ func (t Transport) RoundTrip(r *http.Request) (*http.Response, error) { zap.Object("request", loggableReq), zap.Object("env", loggableEnv), ) - logger.Debug("roundtrip", - zap.String("dial", address), - zap.Object("env", loggableEnv), - zap.Object("request", loggableReq)) + if c := t.logger.Check(zapcore.DebugLevel, "roundtrip"); c != nil { + c.Write( + zap.String("dial", address), + zap.Object("env", loggableEnv), + zap.Object("request", loggableReq), + ) + } // connect to the backend dialer := net.Dialer{Timeout: time.Duration(t.DialTimeout)} diff --git a/modules/caddyhttp/reverseproxy/healthchecks.go b/modules/caddyhttp/reverseproxy/healthchecks.go index efa1dbf09b7..179805f2028 100644 --- a/modules/caddyhttp/reverseproxy/healthchecks.go +++ b/modules/caddyhttp/reverseproxy/healthchecks.go @@ -28,6 +28,7 @@ import ( "time" "go.uber.org/zap" + "go.uber.org/zap/zapcore" "github.com/caddyserver/caddy/v2" "github.com/caddyserver/caddy/v2/modules/caddyhttp" @@ -270,9 +271,12 @@ type CircuitBreaker interface { func (h *Handler) activeHealthChecker() { defer func() { if err := recover(); err != nil { - h.HealthChecks.Active.logger.Error("active health checker panicked", - zap.Any("error", err), - zap.ByteString("stack", debug.Stack())) + if c := h.HealthChecks.Active.logger.Check(zapcore.ErrorLevel, "active health checker panicked"); c != nil { + c.Write( + zap.Any("error", err), + zap.ByteString("stack", debug.Stack()), + ) + } } }() ticker := time.NewTicker(time.Duration(h.HealthChecks.Active.Interval)) @@ -295,26 +299,33 @@ func (h *Handler) doActiveHealthCheckForAllHosts() { go func(upstream *Upstream) { defer func() { if err := recover(); err != nil { - h.HealthChecks.Active.logger.Error("active health check panicked", - zap.Any("error", err), - zap.ByteString("stack", debug.Stack())) + if c := h.HealthChecks.Active.logger.Check(zapcore.ErrorLevel, "active health checker panicked"); c != nil { + c.Write( + zap.Any("error", err), + zap.ByteString("stack", debug.Stack()), + ) + } } }() networkAddr, err := caddy.NewReplacer().ReplaceOrErr(upstream.Dial, true, true) if err != nil { - h.HealthChecks.Active.logger.Error("invalid use of placeholders in dial address for active health checks", - zap.String("address", networkAddr), - zap.Error(err), - ) + if c := h.HealthChecks.Active.logger.Check(zapcore.ErrorLevel, "invalid use of placeholders in dial address for active health checks"); c != nil { + c.Write( + zap.String("address", networkAddr), + zap.Error(err), + ) + } return } addr, err := caddy.ParseNetworkAddress(networkAddr) if err != nil { - h.HealthChecks.Active.logger.Error("bad network address", - zap.String("address", networkAddr), - zap.Error(err), - ) + if c := h.HealthChecks.Active.logger.Check(zapcore.ErrorLevel, "bad network address"); c != nil { + c.Write( + zap.String("address", networkAddr), + zap.Error(err), + ) + } return } if hcp := uint(upstream.activeHealthCheckPort); hcp != 0 { @@ -324,9 +335,11 @@ func (h *Handler) doActiveHealthCheckForAllHosts() { addr.StartPort, addr.EndPort = hcp, hcp } if addr.PortRangeSize() != 1 { - h.HealthChecks.Active.logger.Error("multiple addresses (upstream must map to only one address)", - zap.String("address", networkAddr), - ) + if c := h.HealthChecks.Active.logger.Check(zapcore.ErrorLevel, "multiple addresses (upstream must map to only one address)"); c != nil { + c.Write( + zap.String("address", networkAddr), + ) + } return } hostAddr := addr.JoinHostPort(0) @@ -339,10 +352,12 @@ func (h *Handler) doActiveHealthCheckForAllHosts() { } err = h.doActiveHealthCheck(DialInfo{Network: addr.Network, Address: dialAddr}, hostAddr, networkAddr, upstream) if err != nil { - h.HealthChecks.Active.logger.Error("active health check failed", - zap.String("address", hostAddr), - zap.Error(err), - ) + if c := h.HealthChecks.Active.logger.Check(zapcore.ErrorLevel, "active health check failed"); c != nil { + c.Write( + zap.String("address", hostAddr), + zap.Error(err), + ) + } } }(upstream) } @@ -441,9 +456,12 @@ func (h *Handler) doActiveHealthCheck(dialInfo DialInfo, hostAddr string, networ // increment failures and then check if it has reached the threshold to mark unhealthy err := upstream.Host.countHealthFail(1) if err != nil { - h.HealthChecks.Active.logger.Error("could not count active health failure", - zap.String("host", upstream.Dial), - zap.Error(err)) + if c := h.HealthChecks.Active.logger.Check(zapcore.ErrorLevel, "could not count active health failure"); c != nil { + c.Write( + zap.String("host", upstream.Dial), + zap.Error(err), + ) + } return } if upstream.Host.activeHealthFails() >= h.HealthChecks.Active.Fails { @@ -459,14 +477,19 @@ func (h *Handler) doActiveHealthCheck(dialInfo DialInfo, hostAddr string, networ // increment passes and then check if it has reached the threshold to be healthy err := upstream.Host.countHealthPass(1) if err != nil { - h.HealthChecks.Active.logger.Error("could not count active health pass", - zap.String("host", upstream.Dial), - zap.Error(err)) + if c := h.HealthChecks.Active.logger.Check(zapcore.ErrorLevel, "could not count active health pass"); c != nil { + c.Write( + zap.String("host", upstream.Dial), + zap.Error(err), + ) + } return } if upstream.Host.activeHealthPasses() >= h.HealthChecks.Active.Passes { if upstream.setHealthy(true) { - h.HealthChecks.Active.logger.Info("host is up", zap.String("host", hostAddr)) + if c := h.HealthChecks.Active.logger.Check(zapcore.InfoLevel, "host is up"); c != nil { + c.Write(zap.String("host", hostAddr)) + } h.events.Emit(h.ctx, "healthy", map[string]any{"host": hostAddr}) upstream.Host.resetHealth() } @@ -476,10 +499,12 @@ func (h *Handler) doActiveHealthCheck(dialInfo DialInfo, hostAddr string, networ // do the request, being careful to tame the response body resp, err := h.HealthChecks.Active.httpClient.Do(req) if err != nil { - h.HealthChecks.Active.logger.Info("HTTP request failed", - zap.String("host", hostAddr), - zap.Error(err), - ) + if c := h.HealthChecks.Active.logger.Check(zapcore.InfoLevel, "HTTP request failed"); c != nil { + c.Write( + zap.String("host", hostAddr), + zap.Error(err), + ) + } markUnhealthy() return nil } @@ -496,18 +521,22 @@ func (h *Handler) doActiveHealthCheck(dialInfo DialInfo, hostAddr string, networ // if status code is outside criteria, mark down if h.HealthChecks.Active.ExpectStatus > 0 { if !caddyhttp.StatusCodeMatches(resp.StatusCode, h.HealthChecks.Active.ExpectStatus) { - h.HealthChecks.Active.logger.Info("unexpected status code", - zap.Int("status_code", resp.StatusCode), - zap.String("host", hostAddr), - ) + if c := h.HealthChecks.Active.logger.Check(zapcore.InfoLevel, "unexpected status code"); c != nil { + c.Write( + zap.Int("status_code", resp.StatusCode), + zap.String("host", hostAddr), + ) + } markUnhealthy() return nil } } else if resp.StatusCode < 200 || resp.StatusCode >= 300 { - h.HealthChecks.Active.logger.Info("status code out of tolerances", - zap.Int("status_code", resp.StatusCode), - zap.String("host", hostAddr), - ) + if c := h.HealthChecks.Active.logger.Check(zapcore.InfoLevel, "status code out of tolerances"); c != nil { + c.Write( + zap.Int("status_code", resp.StatusCode), + zap.String("host", hostAddr), + ) + } markUnhealthy() return nil } @@ -516,17 +545,21 @@ func (h *Handler) doActiveHealthCheck(dialInfo DialInfo, hostAddr string, networ if h.HealthChecks.Active.bodyRegexp != nil { bodyBytes, err := io.ReadAll(body) if err != nil { - h.HealthChecks.Active.logger.Info("failed to read response body", - zap.String("host", hostAddr), - zap.Error(err), - ) + if c := h.HealthChecks.Active.logger.Check(zapcore.InfoLevel, "failed to read response body"); c != nil { + c.Write( + zap.String("host", hostAddr), + zap.Error(err), + ) + } markUnhealthy() return nil } if !h.HealthChecks.Active.bodyRegexp.Match(bodyBytes) { - h.HealthChecks.Active.logger.Info("response body failed expectations", - zap.String("host", hostAddr), - ) + if c := h.HealthChecks.Active.logger.Check(zapcore.InfoLevel, "response body failed expectations"); c != nil { + c.Write( + zap.String("host", hostAddr), + ) + } markUnhealthy() return nil } @@ -556,9 +589,12 @@ func (h *Handler) countFailure(upstream *Upstream) { // count failure immediately err := upstream.Host.countFail(1) if err != nil { - h.HealthChecks.Passive.logger.Error("could not count failure", - zap.String("host", upstream.Dial), - zap.Error(err)) + if c := h.HealthChecks.Active.logger.Check(zapcore.ErrorLevel, "could not count failure"); c != nil { + c.Write( + zap.String("host", upstream.Dial), + zap.Error(err), + ) + } return } @@ -566,9 +602,12 @@ func (h *Handler) countFailure(upstream *Upstream) { go func(host *Host, failDuration time.Duration) { defer func() { if err := recover(); err != nil { - h.HealthChecks.Passive.logger.Error("passive health check failure forgetter panicked", - zap.Any("error", err), - zap.ByteString("stack", debug.Stack())) + if c := h.HealthChecks.Active.logger.Check(zapcore.ErrorLevel, "passive health check failure forgetter panicked"); c != nil { + c.Write( + zap.Any("error", err), + zap.ByteString("stack", debug.Stack()), + ) + } } }() timer := time.NewTimer(failDuration) @@ -581,9 +620,12 @@ func (h *Handler) countFailure(upstream *Upstream) { } err := host.countFail(-1) if err != nil { - h.HealthChecks.Passive.logger.Error("could not forget failure", - zap.String("host", upstream.Dial), - zap.Error(err)) + if c := h.HealthChecks.Active.logger.Check(zapcore.ErrorLevel, "could not forget failure"); c != nil { + c.Write( + zap.String("host", upstream.Dial), + zap.Error(err), + ) + } } }(upstream.Host, failDuration) } diff --git a/modules/caddyhttp/reverseproxy/httptransport.go b/modules/caddyhttp/reverseproxy/httptransport.go index 9929ae5d17e..144960cf920 100644 --- a/modules/caddyhttp/reverseproxy/httptransport.go +++ b/modules/caddyhttp/reverseproxy/httptransport.go @@ -33,6 +33,7 @@ import ( "github.com/pires/go-proxyproto" "github.com/quic-go/quic-go/http3" "go.uber.org/zap" + "go.uber.org/zap/zapcore" "golang.org/x/net/http2" "github.com/caddyserver/caddy/v2" @@ -750,7 +751,9 @@ func (c *tcpRWTimeoutConn) Read(b []byte) (int, error) { if c.readTimeout > 0 { err := c.TCPConn.SetReadDeadline(time.Now().Add(c.readTimeout)) if err != nil { - c.logger.Error("failed to set read deadline", zap.Error(err)) + if ce := c.logger.Check(zapcore.ErrorLevel, "failed to set read deadline"); ce != nil { + ce.Write(zap.Error(err)) + } } } return c.TCPConn.Read(b) @@ -760,7 +763,9 @@ func (c *tcpRWTimeoutConn) Write(b []byte) (int, error) { if c.writeTimeout > 0 { err := c.TCPConn.SetWriteDeadline(time.Now().Add(c.writeTimeout)) if err != nil { - c.logger.Error("failed to set write deadline", zap.Error(err)) + if ce := c.logger.Check(zapcore.ErrorLevel, "failed to set write deadline"); ce != nil { + ce.Write(zap.Error(err)) + } } } return c.TCPConn.Write(b) diff --git a/modules/caddyhttp/reverseproxy/metrics.go b/modules/caddyhttp/reverseproxy/metrics.go index d3c8ee03ee2..f744756d3f9 100644 --- a/modules/caddyhttp/reverseproxy/metrics.go +++ b/modules/caddyhttp/reverseproxy/metrics.go @@ -8,6 +8,7 @@ import ( "github.com/prometheus/client_golang/prometheus" "github.com/prometheus/client_golang/prometheus/promauto" "go.uber.org/zap" + "go.uber.org/zap/zapcore" ) var reverseProxyMetrics = struct { @@ -48,9 +49,12 @@ func (m *metricsUpstreamsHealthyUpdater) Init() { go func() { defer func() { if err := recover(); err != nil { - reverseProxyMetrics.logger.Error("upstreams healthy metrics updater panicked", - zap.Any("error", err), - zap.ByteString("stack", debug.Stack())) + if c := reverseProxyMetrics.logger.Check(zapcore.ErrorLevel, "upstreams healthy metrics updater panicked"); c != nil { + c.Write( + zap.Any("error", err), + zap.ByteString("stack", debug.Stack()), + ) + } } }() diff --git a/modules/caddyhttp/reverseproxy/reverseproxy.go b/modules/caddyhttp/reverseproxy/reverseproxy.go index 44cc2f9d9a6..bcbc1ff4691 100644 --- a/modules/caddyhttp/reverseproxy/reverseproxy.go +++ b/modules/caddyhttp/reverseproxy/reverseproxy.go @@ -33,6 +33,7 @@ import ( "time" "go.uber.org/zap" + "go.uber.org/zap/zapcore" "golang.org/x/net/http/httpguts" "github.com/caddyserver/caddy/v2" @@ -439,7 +440,9 @@ func (h *Handler) ServeHTTP(w http.ResponseWriter, r *http.Request, next caddyht if h.LoadBalancing != nil { lbWait = time.Duration(h.LoadBalancing.TryInterval) } - h.logger.Debug("retrying", zap.Error(proxyErr), zap.Duration("after", lbWait)) + if c := h.logger.Check(zapcore.DebugLevel, "retrying"); c != nil { + c.Write(zap.Error(proxyErr), zap.Duration("after", lbWait)) + } } retries++ } @@ -466,13 +469,17 @@ func (h *Handler) proxyLoopIteration(r *http.Request, origReq *http.Request, w h if h.DynamicUpstreams != nil { dUpstreams, err := h.DynamicUpstreams.GetUpstreams(r) if err != nil { - h.logger.Error("failed getting dynamic upstreams; falling back to static upstreams", zap.Error(err)) + if c := h.logger.Check(zapcore.ErrorLevel, "failed getting dynamic upstreams; falling back to static upstreams"); c != nil { + c.Write(zap.Error(err)) + } } else { upstreams = dUpstreams for _, dUp := range dUpstreams { h.provisionUpstream(dUp) } - h.logger.Debug("provisioned dynamic upstreams", zap.Int("count", len(dUpstreams))) + if c := h.logger.Check(zapcore.DebugLevel, "provisioned dynamic upstreams"); c != nil { + c.Write(zap.Int("count", len(dUpstreams))) + } defer func() { // these upstreams are dynamic, so they are only used for this iteration // of the proxy loop; be sure to let them go away when we're done with them @@ -503,9 +510,12 @@ func (h *Handler) proxyLoopIteration(r *http.Request, origReq *http.Request, w h return true, fmt.Errorf("making dial info: %v", err) } - h.logger.Debug("selected upstream", - zap.String("dial", dialInfo.Address), - zap.Int("total_upstreams", len(upstreams))) + if c := h.logger.Check(zapcore.DebugLevel, "selected upstream"); c != nil { + c.Write( + zap.String("dial", dialInfo.Address), + zap.Int("total_upstreams", len(upstreams)), + ) + } // attach to the request information about how to dial the upstream; // this is necessary because the information cannot be sufficiently @@ -811,16 +821,22 @@ func (h *Handler) reverseProxy(rw http.ResponseWriter, req *http.Request, origRe ShouldLogCredentials: shouldLogCredentials, }), ) + if err != nil { - logger.Debug("upstream roundtrip", zap.Error(err)) + if c := logger.Check(zapcore.DebugLevel, "upstream roundtrip"); c != nil { + c.Write(zap.Error(err)) + } return err } - logger.Debug("upstream roundtrip", - zap.Object("headers", caddyhttp.LoggableHTTPHeader{ - Header: res.Header, - ShouldLogCredentials: shouldLogCredentials, - }), - zap.Int("status", res.StatusCode)) + if c := logger.Check(zapcore.DebugLevel, "upstream roundtrip"); c != nil { + c.Write( + zap.Object("headers", caddyhttp.LoggableHTTPHeader{ + Header: res.Header, + ShouldLogCredentials: shouldLogCredentials, + }), + zap.Int("status", res.StatusCode), + ) + } // duration until upstream wrote response headers (roundtrip duration) repl.Set("http.reverse_proxy.upstream.latency", duration) @@ -879,7 +895,9 @@ func (h *Handler) reverseProxy(rw http.ResponseWriter, req *http.Request, origRe repl.Set("http.reverse_proxy.status_code", res.StatusCode) repl.Set("http.reverse_proxy.status_text", res.Status) - logger.Debug("handling response", zap.Int("handler", i)) + if c := logger.Check(zapcore.DebugLevel, "handling response"); c != nil { + c.Write(zap.Int("handler", i)) + } // we make some data available via request context to child routes // so that they may inherit some options and functions from the @@ -975,7 +993,9 @@ func (h *Handler) finalizeResponse( err := h.copyResponse(rw, res.Body, h.flushInterval(req, res), logger) errClose := res.Body.Close() // close now, instead of defer, to populate res.Trailer if h.VerboseLogs || errClose != nil { - logger.Debug("closed response body from upstream", zap.Error(errClose)) + if c := logger.Check(zapcore.DebugLevel, "closed response body from upstream"); c != nil { + c.Write(zap.Error(errClose)) + } } if err != nil { // we're streaming the response and we've already written headers, so @@ -983,7 +1003,9 @@ func (h *Handler) finalizeResponse( // we'll just log the error and abort the stream here and panic just as // the standard lib's proxy to propagate the stream error. // see issue https://github.com/caddyserver/caddy/issues/5951 - logger.Warn("aborting with incomplete response", zap.Error(err)) + if c := logger.Check(zapcore.WarnLevel, "aborting with incomplete response"); c != nil { + c.Write(zap.Error(err)) + } // no extra logging from stdlib panic(http.ErrAbortHandler) } diff --git a/modules/caddyhttp/reverseproxy/streaming.go b/modules/caddyhttp/reverseproxy/streaming.go index a696ac7fbed..c871a3fa12b 100644 --- a/modules/caddyhttp/reverseproxy/streaming.go +++ b/modules/caddyhttp/reverseproxy/streaming.go @@ -31,6 +31,7 @@ import ( "unsafe" "go.uber.org/zap" + "go.uber.org/zap/zapcore" "golang.org/x/net/http/httpguts" ) @@ -41,14 +42,18 @@ func (h *Handler) handleUpgradeResponse(logger *zap.Logger, wg *sync.WaitGroup, // Taken from https://github.com/golang/go/commit/5c489514bc5e61ad9b5b07bd7d8ec65d66a0512a // We know reqUpType is ASCII, it's checked by the caller. if !asciiIsPrint(resUpType) { - logger.Debug("backend tried to switch to invalid protocol", - zap.String("backend_upgrade", resUpType)) + if c := logger.Check(zapcore.DebugLevel, "backend tried to switch to invalid protocol"); c != nil { + c.Write(zap.String("backend_upgrade", resUpType)) + } return } if !asciiEqualFold(reqUpType, resUpType) { - logger.Debug("backend tried to switch to unexpected protocol via Upgrade header", - zap.String("backend_upgrade", resUpType), - zap.String("requested_upgrade", reqUpType)) + if c := logger.Check(zapcore.DebugLevel, "backend tried to switch to unexpected protocol via Upgrade header"); c != nil { + c.Write( + zap.String("backend_upgrade", resUpType), + zap.String("requested_upgrade", reqUpType), + ) + } return } @@ -68,12 +73,16 @@ func (h *Handler) handleUpgradeResponse(logger *zap.Logger, wg *sync.WaitGroup, //nolint:bodyclose conn, brw, hijackErr := http.NewResponseController(rw).Hijack() if errors.Is(hijackErr, http.ErrNotSupported) { - h.logger.Error("can't switch protocols using non-Hijacker ResponseWriter", zap.String("type", fmt.Sprintf("%T", rw))) + if c := logger.Check(zapcore.ErrorLevel, "can't switch protocols using non-Hijacker ResponseWriter"); c != nil { + c.Write(zap.String("type", fmt.Sprintf("%T", rw))) + } return } if hijackErr != nil { - h.logger.Error("hijack failed on protocol switch", zap.Error(hijackErr)) + if c := logger.Check(zapcore.ErrorLevel, "hijack failed on protocol switch"); c != nil { + c.Write(zap.Error(hijackErr)) + } return } @@ -93,11 +102,15 @@ func (h *Handler) handleUpgradeResponse(logger *zap.Logger, wg *sync.WaitGroup, start := time.Now() defer func() { conn.Close() - logger.Debug("connection closed", zap.Duration("duration", time.Since(start))) + if c := logger.Check(zapcore.DebugLevel, "hijack failed on protocol switch"); c != nil { + c.Write(zap.Duration("duration", time.Since(start))) + } }() if err := brw.Flush(); err != nil { - logger.Debug("response flush", zap.Error(err)) + if c := logger.Check(zapcore.DebugLevel, "response flush"); c != nil { + c.Write(zap.Error(err)) + } return } @@ -107,7 +120,9 @@ func (h *Handler) handleUpgradeResponse(logger *zap.Logger, wg *sync.WaitGroup, data, _ := brw.Peek(buffered) _, err := backConn.Write(data) if err != nil { - logger.Debug("backConn write failed", zap.Error(err)) + if c := logger.Check(zapcore.DebugLevel, "backConn write failed"); c != nil { + c.Write(zap.Error(err)) + } return } } @@ -148,9 +163,13 @@ func (h *Handler) handleUpgradeResponse(logger *zap.Logger, wg *sync.WaitGroup, go spc.copyFromBackend(errc) select { case err := <-errc: - logger.Debug("streaming error", zap.Error(err)) + if c := logger.Check(zapcore.DebugLevel, "streaming error"); c != nil { + c.Write(zap.Error(err)) + } case time := <-timeoutc: - logger.Debug("stream timed out", zap.Time("timeout", time)) + if c := logger.Check(zapcore.DebugLevel, "stream timed out"); c != nil { + c.Write(zap.Time("timeout", time)) + } } } @@ -247,7 +266,9 @@ func (h Handler) copyBuffer(dst io.Writer, src io.Reader, buf []byte, logger *za logger.Debug("waiting to read from upstream") nr, rerr := src.Read(buf) logger := logger.With(zap.Int("read", nr)) - logger.Debug("read from upstream", zap.Error(rerr)) + if c := logger.Check(zapcore.DebugLevel, "read from upstream"); c != nil { + c.Write(zap.Error(rerr)) + } if rerr != nil && rerr != io.EOF && rerr != context.Canceled { // TODO: this could be useful to know (indeed, it revealed an error in our // fastcgi PoC earlier; but it's this single error report here that necessitates @@ -256,7 +277,9 @@ func (h Handler) copyBuffer(dst io.Writer, src io.Reader, buf []byte, logger *za // something we need to report to the client, but read errors are a problem on our // end for sure. so we need to decide what we want.) // p.logf("copyBuffer: ReverseProxy read error during body copy: %v", rerr) - h.logger.Error("reading from backend", zap.Error(rerr)) + if c := logger.Check(zapcore.ErrorLevel, "reading from backend"); c != nil { + c.Write(zap.Error(rerr)) + } } if nr > 0 { logger.Debug("writing to downstream") @@ -264,10 +287,13 @@ func (h Handler) copyBuffer(dst io.Writer, src io.Reader, buf []byte, logger *za if nw > 0 { written += int64(nw) } - logger.Debug("wrote to downstream", - zap.Int("written", nw), - zap.Int64("written_total", written), - zap.Error(werr)) + if c := logger.Check(zapcore.DebugLevel, "wrote to downstream"); c != nil { + c.Write( + zap.Int("written", nw), + zap.Int64("written_total", written), + zap.Error(werr), + ) + } if werr != nil { return written, fmt.Errorf("writing: %w", werr) } @@ -347,13 +373,17 @@ func (h *Handler) cleanupConnections() error { if len(h.connections) > 0 { delay := time.Duration(h.StreamCloseDelay) h.connectionsCloseTimer = time.AfterFunc(delay, func() { - h.logger.Debug("closing streaming connections after delay", - zap.Duration("delay", delay)) + if c := h.logger.Check(zapcore.DebugLevel, "closing streaming connections after delay"); c != nil { + c.Write(zap.Duration("delay", delay)) + } err := h.closeConnections() if err != nil { - h.logger.Error("failed to closed connections after delay", - zap.Error(err), - zap.Duration("delay", delay)) + if c := h.logger.Check(zapcore.ErrorLevel, "failed to closed connections after delay"); c != nil { + c.Write( + zap.Error(err), + zap.Duration("delay", delay), + ) + } } }) } @@ -494,7 +524,9 @@ func (m *maxLatencyWriter) Write(p []byte) (n int, err error) { m.mu.Lock() defer m.mu.Unlock() n, err = m.dst.Write(p) - m.logger.Debug("wrote bytes", zap.Int("n", n), zap.Error(err)) + if c := m.logger.Check(zapcore.DebugLevel, "wrote bytes"); c != nil { + c.Write(zap.Int("n", n), zap.Error(err)) + } if m.latency < 0 { m.logger.Debug("flushing immediately") //nolint:errcheck @@ -510,7 +542,9 @@ func (m *maxLatencyWriter) Write(p []byte) (n int, err error) { } else { m.t.Reset(m.latency) } - m.logger.Debug("timer set for delayed flush", zap.Duration("duration", m.latency)) + if c := m.logger.Check(zapcore.DebugLevel, "timer set for delayed flush"); c != nil { + c.Write(zap.Duration("duration", m.latency)) + } m.flushPending = true return } diff --git a/modules/caddyhttp/reverseproxy/upstreams.go b/modules/caddyhttp/reverseproxy/upstreams.go index c8ba930d203..aa59dc41b2f 100644 --- a/modules/caddyhttp/reverseproxy/upstreams.go +++ b/modules/caddyhttp/reverseproxy/upstreams.go @@ -12,6 +12,7 @@ import ( "time" "go.uber.org/zap" + "go.uber.org/zap/zapcore" "github.com/caddyserver/caddy/v2" ) @@ -136,10 +137,13 @@ func (su SRVUpstreams) GetUpstreams(r *http.Request) ([]*Upstream, error) { return allNew(cached.upstreams), nil } - su.logger.Debug("refreshing SRV upstreams", - zap.String("service", service), - zap.String("proto", proto), - zap.String("name", name)) + if c := su.logger.Check(zapcore.DebugLevel, "refreshing SRV upstreams"); c != nil { + c.Write( + zap.String("service", service), + zap.String("proto", proto), + zap.String("name", name), + ) + } _, records, err := su.resolver.LookupSRV(r.Context(), service, proto, name) if err != nil { @@ -148,23 +152,30 @@ func (su SRVUpstreams) GetUpstreams(r *http.Request) ([]*Upstream, error) { // only return an error if no records were also returned. if len(records) == 0 { if su.GracePeriod > 0 { - su.logger.Error("SRV lookup failed; using previously cached", zap.Error(err)) + if c := su.logger.Check(zapcore.ErrorLevel, "SRV lookup failed; using previously cached"); c != nil { + c.Write(zap.Error(err)) + } cached.freshness = time.Now().Add(time.Duration(su.GracePeriod) - time.Duration(su.Refresh)) srvs[suAddr] = cached return allNew(cached.upstreams), nil } return nil, err } - su.logger.Warn("SRV records filtered", zap.Error(err)) + if c := su.logger.Check(zapcore.WarnLevel, "SRV records filtered"); c != nil { + c.Write(zap.Error(err)) + } } upstreams := make([]Upstream, len(records)) for i, rec := range records { - su.logger.Debug("discovered SRV record", - zap.String("target", rec.Target), - zap.Uint16("port", rec.Port), - zap.Uint16("priority", rec.Priority), - zap.Uint16("weight", rec.Weight)) + if c := su.logger.Check(zapcore.DebugLevel, "discovered SRV record"); c != nil { + c.Write( + zap.String("target", rec.Target), + zap.Uint16("port", rec.Port), + zap.Uint16("priority", rec.Priority), + zap.Uint16("weight", rec.Weight), + ) + } addr := net.JoinHostPort(rec.Target, strconv.Itoa(int(rec.Port))) upstreams[i] = Upstream{Dial: addr} } @@ -361,10 +372,13 @@ func (au AUpstreams) GetUpstreams(r *http.Request) ([]*Upstream, error) { name := repl.ReplaceAll(au.Name, "") port := repl.ReplaceAll(au.Port, "") - au.logger.Debug("refreshing A upstreams", - zap.String("version", ipVersion), - zap.String("name", name), - zap.String("port", port)) + if c := au.logger.Check(zapcore.DebugLevel, "refreshing A upstreams"); c != nil { + c.Write( + zap.String("version", ipVersion), + zap.String("name", name), + zap.String("port", port), + ) + } ips, err := au.resolver.LookupIP(r.Context(), ipVersion, name) if err != nil { @@ -373,8 +387,9 @@ func (au AUpstreams) GetUpstreams(r *http.Request) ([]*Upstream, error) { upstreams := make([]Upstream, len(ips)) for i, ip := range ips { - au.logger.Debug("discovered A record", - zap.String("ip", ip.String())) + if c := au.logger.Check(zapcore.DebugLevel, "discovered A record"); c != nil { + c.Write(zap.String("ip", ip.String())) + } upstreams[i] = Upstream{ Dial: net.JoinHostPort(ip.String(), port), } @@ -467,11 +482,16 @@ func (mu MultiUpstreams) GetUpstreams(r *http.Request) ([]*Upstream, error) { up, err := src.GetUpstreams(r) if err != nil { - mu.logger.Error("upstream source returned error", - zap.Int("source_idx", i), - zap.Error(err)) + if c := mu.logger.Check(zapcore.ErrorLevel, "upstream source returned error"); c != nil { + c.Write( + zap.Int("source_idx", i), + zap.Error(err), + ) + } } else if len(up) == 0 { - mu.logger.Warn("upstream source returned 0 upstreams", zap.Int("source_idx", i)) + if c := mu.logger.Check(zapcore.WarnLevel, "upstream source returned 0 upstreams"); c != nil { + c.Write(zap.Int("source_idx", i)) + } } else { upstreams = append(upstreams, up...) } diff --git a/modules/caddyhttp/rewrite/rewrite.go b/modules/caddyhttp/rewrite/rewrite.go index c45ad98a20a..e766827298b 100644 --- a/modules/caddyhttp/rewrite/rewrite.go +++ b/modules/caddyhttp/rewrite/rewrite.go @@ -133,19 +133,17 @@ func (rewr Rewrite) ServeHTTP(w http.ResponseWriter, r *http.Request, next caddy repl := r.Context().Value(caddy.ReplacerCtxKey).(*caddy.Replacer) const message = "rewrote request" - if rewr.logger.Check(zap.DebugLevel, message) == nil { + c := rewr.logger.Check(zap.DebugLevel, message) + if c == nil { rewr.Rewrite(r, repl) return next.ServeHTTP(w, r) } - logger := rewr.logger.With( - zap.Object("request", caddyhttp.LoggableHTTPRequest{Request: r}), - ) - changed := rewr.Rewrite(r, repl) if changed { - logger.Debug(message, + c.Write( + zap.Object("request", caddyhttp.LoggableHTTPRequest{Request: r}), zap.String("method", r.Method), zap.String("uri", r.RequestURI), ) diff --git a/modules/caddyhttp/server.go b/modules/caddyhttp/server.go index 6caaabcdaf0..9dfa1bb6d3b 100644 --- a/modules/caddyhttp/server.go +++ b/modules/caddyhttp/server.go @@ -275,7 +275,9 @@ func (s *Server) ServeHTTP(w http.ResponseWriter, r *http.Request) { if r.ProtoMajor < 3 { err := s.h3server.SetQUICHeaders(w.Header()) if err != nil { - s.logger.Error("setting HTTP/3 Alt-Svc header", zap.Error(err)) + if c := s.logger.Check(zapcore.ErrorLevel, "setting HTTP/3 Alt-Svc header"); c != nil { + c.Write(zap.Error(err)) + } } } } @@ -283,9 +285,12 @@ func (s *Server) ServeHTTP(w http.ResponseWriter, r *http.Request) { // reject very long methods; probably a mistake or an attack if len(r.Method) > 32 { if s.shouldLogRequest(r) { - s.accessLogger.Debug("rejecting request with long method", - zap.String("method_trunc", r.Method[:32]), - zap.String("remote_addr", r.RemoteAddr)) + if c := s.accessLogger.Check(zapcore.DebugLevel, "rejecting request with long method"); c != nil { + c.Write( + zap.String("method_trunc", r.Method[:32]), + zap.String("remote_addr", r.RemoteAddr), + ) + } } w.WriteHeader(http.StatusMethodNotAllowed) return @@ -300,7 +305,9 @@ func (s *Server) ServeHTTP(w http.ResponseWriter, r *http.Request) { //nolint:bodyclose err := http.NewResponseController(w).EnableFullDuplex() if err != nil { - s.logger.Warn("failed to enable full duplex", zap.Error(err)) + if c := s.logger.Check(zapcore.WarnLevel, "failed to enable full duplex"); c != nil { + c.Write(zap.Error(err)) + } } } @@ -379,6 +386,7 @@ func (s *Server) ServeHTTP(w http.ResponseWriter, r *http.Request) { // add HTTP error information to request context r = s.Errors.WithError(r, err) + var fields []zapcore.Field if s.Errors != nil && len(s.Errors.Routes) > 0 { // execute user-defined error handling route err2 := s.errorHandlerChain.ServeHTTP(w, r) @@ -386,17 +394,28 @@ func (s *Server) ServeHTTP(w http.ResponseWriter, r *http.Request) { // user's error route handled the error response // successfully, so now just log the error for _, logger := range errLoggers { - logger.Debug(errMsg, errFields...) + if c := logger.Check(zapcore.DebugLevel, errMsg); c != nil { + if fields == nil { + fields = errFields() + } + + c.Write(fields...) + } } } else { // well... this is awkward - errFields = append([]zapcore.Field{ - zap.String("error", err2.Error()), - zap.Namespace("first_error"), - zap.String("msg", errMsg), - }, errFields...) for _, logger := range errLoggers { - logger.Error("error handling handler error", errFields...) + if c := logger.Check(zapcore.ErrorLevel, "error handling handler error"); c != nil { + if fields == nil { + fields = errFields() + fields = append([]zapcore.Field{ + zap.String("error", err2.Error()), + zap.Namespace("first_error"), + zap.String("msg", errMsg), + }, fields...) + } + c.Write(fields...) + } } if handlerErr, ok := err.(HandlerError); ok { w.WriteHeader(handlerErr.StatusCode) @@ -405,11 +424,17 @@ func (s *Server) ServeHTTP(w http.ResponseWriter, r *http.Request) { } } } else { + logLevel := zapcore.DebugLevel + if errStatus >= 500 { + logLevel = zapcore.ErrorLevel + } + for _, logger := range errLoggers { - if errStatus >= 500 { - logger.Error(errMsg, errFields...) - } else { - logger.Debug(errMsg, errFields...) + if c := logger.Check(logLevel, errMsg); c != nil { + if fields == nil { + fields = errFields() + } + c.Write(fields...) } } w.WriteHeader(errStatus) @@ -746,7 +771,9 @@ func (s *Server) logTrace(mh MiddlewareHandler) { if s.Logs == nil || !s.Logs.Trace { return } - s.traceLogger.Debug(caddy.GetModuleName(mh), zap.Any("module", mh)) + if c := s.traceLogger.Check(zapcore.DebugLevel, caddy.GetModuleName(mh)); c != nil { + c.Write(zap.Any("module", mh)) + } } // logRequest logs the request to access logs, unless skipped. @@ -759,50 +786,64 @@ func (s *Server) logRequest( return } - repl.Set("http.response.status", wrec.Status()) // will be 0 if no response is written by us (Go will write 200 to client) - repl.Set("http.response.size", wrec.Size()) + status := wrec.Status() + size := wrec.Size() + + repl.Set("http.response.status", status) // will be 0 if no response is written by us (Go will write 200 to client) + repl.Set("http.response.size", size) repl.Set("http.response.duration", duration) repl.Set("http.response.duration_ms", duration.Seconds()*1e3) // multiply seconds to preserve decimal (see #4666) - userID, _ := repl.GetString("http.auth.user.id") - - reqBodyLength := 0 - if bodyReader != nil { - reqBodyLength = bodyReader.Length - } - - extra := r.Context().Value(ExtraLogFieldsCtxKey).(*ExtraLogFields) - - fieldCount := 6 - fields := make([]zapcore.Field, 0, fieldCount+len(extra.fields)) - fields = append(fields, - zap.Int("bytes_read", reqBodyLength), - zap.String("user_id", userID), - zap.Duration("duration", *duration), - zap.Int("size", wrec.Size()), - zap.Int("status", wrec.Status()), - zap.Object("resp_headers", LoggableHTTPHeader{ - Header: wrec.Header(), - ShouldLogCredentials: shouldLogCredentials, - })) - fields = append(fields, extra.fields...) - loggers := []*zap.Logger{accLog} if s.Logs != nil { loggers = s.Logs.wrapLogger(accLog, r) } - // wrapping may return multiple loggers, so we log to all of them + message := "handled request" + if nop, ok := GetVar(r.Context(), "unhandled").(bool); ok && nop { + message = "NOP" + } + + logLevel := zapcore.InfoLevel + if status >= 500 { + logLevel = zapcore.ErrorLevel + } + + var fields []zapcore.Field for _, logger := range loggers { - logAtLevel := logger.Info - if wrec.Status() >= 500 { - logAtLevel = logger.Error + c := logger.Check(logLevel, message) + if c == nil { + continue } - message := "handled request" - if nop, ok := GetVar(r.Context(), "unhandled").(bool); ok && nop { - message = "NOP" + + if fields == nil { + + userID, _ := repl.GetString("http.auth.user.id") + + reqBodyLength := 0 + if bodyReader != nil { + reqBodyLength = bodyReader.Length + } + + extra := r.Context().Value(ExtraLogFieldsCtxKey).(*ExtraLogFields) + + fieldCount := 6 + fields = make([]zapcore.Field, 0, fieldCount+len(extra.fields)) + fields = append(fields, + zap.Int("bytes_read", reqBodyLength), + zap.String("user_id", userID), + zap.Duration("duration", *duration), + zap.Int("size", size), + zap.Int("status", status), + zap.Object("resp_headers", LoggableHTTPHeader{ + Header: wrec.Header(), + ShouldLogCredentials: shouldLogCredentials, + }), + ) + fields = append(fields, extra.fields...) } - logAtLevel(message, fields...) + + c.Write(fields...) } } diff --git a/modules/caddyhttp/server_test.go b/modules/caddyhttp/server_test.go index d382a6963de..2c8033d45d2 100644 --- a/modules/caddyhttp/server_test.go +++ b/modules/caddyhttp/server_test.go @@ -121,6 +121,29 @@ func BenchmarkServer_LogRequest(b *testing.B) { } } +func BenchmarkServer_LogRequest_NopLogger(b *testing.B) { + s := &Server{} + + extra := new(ExtraLogFields) + ctx := context.WithValue(context.Background(), ExtraLogFieldsCtxKey, extra) + + req := httptest.NewRequest(http.MethodGet, "/", nil).WithContext(ctx) + rec := httptest.NewRecorder() + wrec := NewResponseRecorder(rec, nil, nil) + + duration := 50 * time.Millisecond + repl := NewTestReplacer(req) + bodyReader := &lengthReader{Source: req.Body} + + accLog := zap.NewNop() + + b.ResetTimer() + + for i := 0; i < b.N; i++ { + s.logRequest(accLog, req, wrec, &duration, repl, bodyReader, false) + } +} + func BenchmarkServer_LogRequest_WithTraceID(b *testing.B) { s := &Server{} diff --git a/modules/caddyhttp/tracing/tracerprovider.go b/modules/caddyhttp/tracing/tracerprovider.go index 035425ed646..0a376697471 100644 --- a/modules/caddyhttp/tracing/tracerprovider.go +++ b/modules/caddyhttp/tracing/tracerprovider.go @@ -7,6 +7,7 @@ import ( sdktrace "go.opentelemetry.io/otel/sdk/trace" "go.uber.org/zap" + "go.uber.org/zap/zapcore" ) // globalTracerProvider stores global tracer provider and is responsible for graceful shutdown when nobody is using it. @@ -47,7 +48,9 @@ func (t *tracerProvider) cleanupTracerProvider(logger *zap.Logger) error { if t.tracerProvider != nil { // tracerProvider.ForceFlush SHOULD be invoked according to https://github.com/open-telemetry/opentelemetry-specification/blob/main/specification/trace/sdk.md#forceflush if err := t.tracerProvider.ForceFlush(context.Background()); err != nil { - logger.Error("forcing flush", zap.Error(err)) + if c := logger.Check(zapcore.ErrorLevel, "forcing flush"); c != nil { + c.Write(zap.Error(err)) + } } // tracerProvider.Shutdown MUST be invoked according to https://github.com/open-telemetry/opentelemetry-specification/blob/main/specification/trace/sdk.md#shutdown diff --git a/modules/caddypki/acmeserver/acmeserver.go b/modules/caddypki/acmeserver/acmeserver.go index eaf6e930ab2..aeb4eab8ec3 100644 --- a/modules/caddypki/acmeserver/acmeserver.go +++ b/modules/caddypki/acmeserver/acmeserver.go @@ -35,6 +35,7 @@ import ( "github.com/smallstep/certificates/db" "github.com/smallstep/nosql" "go.uber.org/zap" + "go.uber.org/zap/zapcore" "github.com/caddyserver/caddy/v2" "github.com/caddyserver/caddy/v2/modules/caddyhttp" @@ -243,10 +244,14 @@ func (ash Handler) Cleanup() error { key := ash.getDatabaseKey() deleted, err := databasePool.Delete(key) if deleted { - ash.logger.Debug("unloading unused CA database", zap.String("db_key", key)) + if c := ash.logger.Check(zapcore.DebugLevel, "unloading unused CA database"); c != nil { + c.Write(zap.String("db_key", key)) + } } if err != nil { - ash.logger.Error("closing CA database", zap.String("db_key", key), zap.Error(err)) + if c := ash.logger.Check(zapcore.ErrorLevel, "closing CA database"); c != nil { + c.Write(zap.String("db_key", key), zap.Error(err)) + } } return err } @@ -271,7 +276,9 @@ func (ash Handler) openDatabase() (*db.AuthDB, error) { }) if loaded { - ash.logger.Debug("loaded preexisting CA database", zap.String("db_key", key)) + if c := ash.logger.Check(zapcore.DebugLevel, "loaded preexisting CA database"); c != nil { + c.Write(zap.String("db_key", key)) + } } return database.(databaseCloser).DB, err diff --git a/modules/caddytls/acmeissuer.go b/modules/caddytls/acmeissuer.go index f46e296e3ea..9dfeff724a1 100644 --- a/modules/caddytls/acmeissuer.go +++ b/modules/caddytls/acmeissuer.go @@ -30,6 +30,7 @@ import ( "github.com/caddyserver/zerossl" "github.com/mholt/acmez/v2/acme" "go.uber.org/zap" + "go.uber.org/zap/zapcore" "github.com/caddyserver/caddy/v2" "github.com/caddyserver/caddy/v2/caddyconfig" @@ -321,7 +322,9 @@ func (iss *ACMEIssuer) generateZeroSSLEABCredentials(ctx context.Context, acct a return nil, acct, fmt.Errorf("failed getting EAB credentials: HTTP %d", resp.StatusCode) } - iss.logger.Info("generated EAB credentials", zap.String("key_id", result.EABKID)) + if c := iss.logger.Check(zapcore.InfoLevel, "generated EAB credentials"); c != nil { + c.Write(zap.String("key_id", result.EABKID)) + } return &acme.EAB{ KeyID: result.EABKID, diff --git a/modules/caddytls/automation.go b/modules/caddytls/automation.go index 781818ed139..e2e02221df3 100644 --- a/modules/caddytls/automation.go +++ b/modules/caddytls/automation.go @@ -26,6 +26,7 @@ import ( "github.com/caddyserver/certmagic" "github.com/mholt/acmez/v2" "go.uber.org/zap" + "go.uber.org/zap/zapcore" "github.com/caddyserver/caddy/v2" ) @@ -292,21 +293,30 @@ func (ap *AutomationPolicy) Provision(tlsApp *TLS) error { remoteIP, _, _ = net.SplitHostPort(remote.String()) } } - tlsApp.logger.Debug("asking for permission for on-demand certificate", - zap.String("remote_ip", remoteIP), - zap.String("domain", name)) + if c := tlsApp.logger.Check(zapcore.DebugLevel, "asking for permission for on-demand certificate"); c != nil { + c.Write( + zap.String("remote_ip", remoteIP), + zap.String("domain", name), + ) + } // ask the permission module if this cert is allowed if err := tlsApp.Automation.OnDemand.permission.CertificateAllowed(ctx, name); err != nil { // distinguish true errors from denials, because it's important to elevate actual errors if errors.Is(err, ErrPermissionDenied) { - tlsApp.logger.Debug("on-demand certificate issuance denied", - zap.String("domain", name), - zap.Error(err)) + if c := tlsApp.logger.Check(zapcore.DebugLevel, "on-demand certificate issuance denied"); c != nil { + c.Write( + zap.String("domain", name), + zap.Error(err), + ) + } } else { - tlsApp.logger.Error("failed to get permission for on-demand certificate", - zap.String("domain", name), - zap.Error(err)) + if c := tlsApp.logger.Check(zapcore.ErrorLevel, "failed to get permission for on-demand certificate"); c != nil { + c.Write( + zap.String("domain", name), + zap.Error(err), + ) + } } return err } diff --git a/modules/caddytls/certmanagers.go b/modules/caddytls/certmanagers.go index f65a78b09ad..56950bc84df 100644 --- a/modules/caddytls/certmanagers.go +++ b/modules/caddytls/certmanagers.go @@ -12,6 +12,7 @@ import ( "github.com/caddyserver/certmagic" "github.com/tailscale/tscert" "go.uber.org/zap" + "go.uber.org/zap/zapcore" "github.com/caddyserver/caddy/v2" "github.com/caddyserver/caddy/v2/caddyconfig/caddyfile" @@ -46,7 +47,9 @@ func (ts Tailscale) GetCertificate(ctx context.Context, hello *tls.ClientHelloIn return nil, nil // pass-thru: Tailscale can't offer a cert for this name } if err != nil { - ts.logger.Warn("could not get status; will try to get certificate anyway", zap.Error(err)) + if c := ts.logger.Check(zapcore.WarnLevel, "could not get status; will try to get certificate anyway"); c != nil { + c.Write(zap.Error(err)) + } } return tscert.GetCertificateWithContext(ctx, hello) } diff --git a/modules/caddytls/connpolicy.go b/modules/caddytls/connpolicy.go index e2890c848ab..2ff41f7b221 100644 --- a/modules/caddytls/connpolicy.go +++ b/modules/caddytls/connpolicy.go @@ -28,6 +28,7 @@ import ( "github.com/mholt/acmez/v2" "go.uber.org/zap" + "go.uber.org/zap/zapcore" "github.com/caddyserver/caddy/v2" "github.com/caddyserver/caddy/v2/caddyconfig" @@ -338,8 +339,9 @@ func (p *ConnectionPolicy) buildStandardTLSConfig(ctx caddy.Context) error { cfg.KeyLogWriter = logFile.(io.Writer) - tlsApp.logger.Warn("TLS SECURITY COMPROMISED: secrets logging is enabled!", - zap.String("log_filename", filename)) + if c := tlsApp.logger.Check(zapcore.WarnLevel, "TLS SECURITY COMPROMISED: secrets logging is enabled!"); c != nil { + c.Write(zap.String("log_filename", filename)) + } } setDefaultTLSParams(cfg) diff --git a/modules/caddytls/matchers.go b/modules/caddytls/matchers.go index 65bbfa311e1..f44b4c02a5b 100644 --- a/modules/caddytls/matchers.go +++ b/modules/caddytls/matchers.go @@ -25,6 +25,7 @@ import ( "github.com/caddyserver/certmagic" "go.uber.org/zap" + "go.uber.org/zap/zapcore" "github.com/caddyserver/caddy/v2" "github.com/caddyserver/caddy/v2/caddyconfig/caddyfile" @@ -291,7 +292,9 @@ func (m MatchRemoteIP) Match(hello *tls.ClientHelloInfo) bool { } ipAddr, err := netip.ParseAddr(ipStr) if err != nil { - m.logger.Error("invalid client IP address", zap.String("ip", ipStr)) + if c := m.logger.Check(zapcore.ErrorLevel, "invalid client IP address"); c != nil { + c.Write(zap.String("ip", ipStr)) + } return false } return (len(m.cidrs) == 0 || m.matches(ipAddr, m.cidrs)) && @@ -408,7 +411,9 @@ func (m MatchLocalIP) Match(hello *tls.ClientHelloInfo) bool { } ipAddr, err := netip.ParseAddr(ipStr) if err != nil { - m.logger.Error("invalid local IP address", zap.String("ip", ipStr)) + if c := m.logger.Check(zapcore.ErrorLevel, "invalid local IP address"); c != nil { + c.Write(zap.String("ip", ipStr)) + } return false } return (len(m.cidrs) == 0 || m.matches(ipAddr, m.cidrs)) diff --git a/modules/caddytls/ondemand.go b/modules/caddytls/ondemand.go index 060a3ac6a74..89abfe03f41 100644 --- a/modules/caddytls/ondemand.go +++ b/modules/caddytls/ondemand.go @@ -26,6 +26,7 @@ import ( "github.com/caddyserver/certmagic" "go.uber.org/zap" + "go.uber.org/zap/zapcore" "github.com/caddyserver/caddy/v2" "github.com/caddyserver/caddy/v2/caddyconfig/caddyfile" @@ -156,10 +157,13 @@ func (p PermissionByHTTP) CertificateAllowed(ctx context.Context, name string) e remote = chi.Conn.RemoteAddr().String() } - p.logger.Debug("asking permission endpoint", - zap.String("remote", remote), - zap.String("domain", name), - zap.String("url", askURLString)) + if c := p.logger.Check(zapcore.DebugLevel, "asking permission endpoint"); c != nil { + c.Write( + zap.String("remote", remote), + zap.String("domain", name), + zap.String("url", askURLString), + ) + } resp, err := onDemandAskClient.Get(askURLString) if err != nil { @@ -168,11 +172,14 @@ func (p PermissionByHTTP) CertificateAllowed(ctx context.Context, name string) e } resp.Body.Close() - p.logger.Debug("response from permission endpoint", - zap.String("remote", remote), - zap.String("domain", name), - zap.String("url", askURLString), - zap.Int("status", resp.StatusCode)) + if c := p.logger.Check(zapcore.DebugLevel, "response from permission endpoint"); c != nil { + c.Write( + zap.String("remote", remote), + zap.String("domain", name), + zap.String("url", askURLString), + zap.Int("status", resp.StatusCode), + ) + } if resp.StatusCode < 200 || resp.StatusCode > 299 { return fmt.Errorf("%s: %w %s - non-2xx status code %d", name, ErrPermissionDenied, askEndpoint, resp.StatusCode) diff --git a/modules/caddytls/tls.go b/modules/caddytls/tls.go index b30b10c24ad..5f3d0eaeba1 100644 --- a/modules/caddytls/tls.go +++ b/modules/caddytls/tls.go @@ -27,6 +27,7 @@ import ( "github.com/caddyserver/certmagic" "go.uber.org/zap" + "go.uber.org/zap/zapcore" "github.com/caddyserver/caddy/v2" "github.com/caddyserver/caddy/v2/modules/caddyevents" @@ -323,8 +324,9 @@ func (t *TLS) Start() error { if t.Automation.OnDemand == nil || (t.Automation.OnDemand.Ask == "" && t.Automation.OnDemand.permission == nil) { for _, ap := range t.Automation.Policies { if ap.OnDemand && ap.isWildcardOrDefault() { - t.logger.Warn("YOUR SERVER MAY BE VULNERABLE TO ABUSE: on-demand TLS is enabled, but no protections are in place", - zap.String("docs", "https://caddyserver.com/docs/automatic-https#on-demand-tls")) + if c := t.logger.Check(zapcore.WarnLevel, "YOUR SERVER MAY BE VULNERABLE TO ABUSE: on-demand TLS is enabled, but no protections are in place"); c != nil { + c.Write(zap.String("docs", "https://caddyserver.com/docs/automatic-https#on-demand-tls")) + } break } } @@ -408,9 +410,12 @@ func (t *TLS) Cleanup() error { // give the new TLS app a "kick" to manage certs that it is configured for // with its own configuration instead of the one we just evicted if err := nextTLSApp.Manage(reManage); err != nil { - t.logger.Error("re-managing unloaded certificates with new config", - zap.Strings("subjects", reManage), - zap.Error(err)) + if c := t.logger.Check(zapcore.ErrorLevel, "re-managing unloaded certificates with new config"); c != nil { + c.Write( + zap.Strings("subjects", reManage), + zap.Error(err), + ) + } } } else { // no more TLS app running, so delete in-memory cert cache @@ -653,7 +658,9 @@ func (t *TLS) cleanStorageUnits() { id, err := caddy.InstanceID() if err != nil { - t.logger.Warn("unable to get instance ID; storage clean stamps will be incomplete", zap.Error(err)) + if c := t.logger.Check(zapcore.WarnLevel, "unable to get instance ID; storage clean stamps will be incomplete"); c != nil { + c.Write(zap.Error(err)) + } } options := certmagic.CleanStorageOptions{ Logger: t.logger, @@ -669,7 +676,9 @@ func (t *TLS) cleanStorageUnits() { if err != nil { // probably don't want to return early, since we should still // see if any other storages can get cleaned up - t.logger.Error("could not clean default/global storage", zap.Error(err)) + if c := t.logger.Check(zapcore.ErrorLevel, "could not clean default/global storage"); c != nil { + c.Write(zap.Error(err)) + } } // then clean each storage defined in ACME automation policies @@ -679,7 +688,9 @@ func (t *TLS) cleanStorageUnits() { continue } if err := certmagic.CleanStorage(t.ctx, ap.storage, options); err != nil { - t.logger.Error("could not clean storage configured in automation policy", zap.Error(err)) + if c := t.logger.Check(zapcore.ErrorLevel, "could not clean storage configured in automation policy"); c != nil { + c.Write(zap.Error(err)) + } } } } From 6ab9fb6f7424026ed67ceb112d99a4c483ef468b Mon Sep 17 00:00:00 2001 From: Mohammed Al Sahaf Date: Mon, 16 Sep 2024 16:50:26 +0300 Subject: [PATCH 10/10] ci: update the linter action version (#6575) * ci: update the linter action version Signed-off-by: Mohammed Al Sahaf * exclude rule `G115`; disable deprecated linter Signed-off-by: Mohammed Al Sahaf --------- Signed-off-by: Mohammed Al Sahaf --- .github/workflows/lint.yml | 2 +- .golangci.yml | 4 +++- modules/caddyhttp/server.go | 1 - 3 files changed, 4 insertions(+), 3 deletions(-) diff --git a/.github/workflows/lint.yml b/.github/workflows/lint.yml index 94250f88f35..22e13973fe0 100644 --- a/.github/workflows/lint.yml +++ b/.github/workflows/lint.yml @@ -49,7 +49,7 @@ jobs: - name: golangci-lint uses: golangci/golangci-lint-action@v6 with: - version: v1.60 + version: latest # Windows times out frequently after about 5m50s if we don't set a longer timeout. args: --timeout 10m diff --git a/.golangci.yml b/.golangci.yml index 74e3503c484..e8b2a55d3f5 100644 --- a/.golangci.yml +++ b/.golangci.yml @@ -35,7 +35,6 @@ linters: - errcheck - errname - exhaustive - - exportloopref - gci - gofmt - goimports @@ -145,6 +144,9 @@ output: issues: exclude-rules: + - text: 'G115' # TODO: Either we should fix the issues or nuke the linter if it's bad + linters: + - gosec # we aren't calling unknown URL - text: 'G107' # G107: Url provided to HTTP request as taint input linters: diff --git a/modules/caddyhttp/server.go b/modules/caddyhttp/server.go index 9dfa1bb6d3b..e301bdc68a4 100644 --- a/modules/caddyhttp/server.go +++ b/modules/caddyhttp/server.go @@ -817,7 +817,6 @@ func (s *Server) logRequest( } if fields == nil { - userID, _ := repl.GetString("http.auth.user.id") reqBodyLength := 0