v2: Logging! (#2831)

* logging: Initial implementation

* logging: More encoder formats, better defaults

* logging: Fix repetition bug with FilterEncoder; add more presets

* logging: DiscardWriter; delete or no-op logs that discard their output

* logging: Add http.handlers.log module; enhance Replacer methods

The Replacer interface has new methods to customize how to handle empty
or unrecognized placeholders. Closes #2815.

* logging: Overhaul HTTP logging, fix bugs, improve filtering, etc.

* logging: General cleanup, begin transitioning to using new loggers

* Fixes after merge conflict

11 files changed, 412 insertions, 96 deletions

diff --git a/modules/caddyhttp/caddyhttp.go b/modules/caddyhttp/caddyhttp.go
index 29a5ab0..aae65ab 100644
--- a/modules/caddyhttp/caddyhttp.go
+++ b/modules/caddyhttp/caddyhttp.go
@@ -21,7 +21,6 @@ import (
 	"encoding/json"
 	"fmt"
 	"io"
-	"log"
 	weakrand "math/rand"
 	"net"
 	"net/http"
@@ -33,6 +32,7 @@ import (
 	"github.com/caddyserver/caddy/v2/modules/caddytls"
 	"github.com/lucas-clemente/quic-go/http3"
 	"github.com/mholt/certmagic"
+	"go.uber.org/zap"
 )
 
 func init() {
@@ -40,7 +40,7 @@ func init() {
 
 	err := caddy.RegisterModule(App{})
 	if err != nil {
-		log.Fatal(err)
+		caddy.Log().Fatal(err.Error())
 	}
 }
 
@@ -55,7 +55,8 @@ type App struct {
 	h3servers   []*http3.Server
 	h3listeners []net.PacketConn
 
-	ctx caddy.Context
+	ctx    caddy.Context
+	logger *zap.Logger
 }
 
 // CaddyModule returns the Caddy module information.
@@ -69,10 +70,15 @@ func (App) CaddyModule() caddy.ModuleInfo {
 // Provision sets up the app.
 func (app *App) Provision(ctx caddy.Context) error {
 	app.ctx = ctx
+	app.logger = ctx.Logger(app)
 
 	repl := caddy.NewReplacer()
 
-	for _, srv := range app.Servers {
+	for srvName, srv := range app.Servers {
+		srv.logger = app.logger.Named("log")
+		srv.accessLogger = app.logger.Named("log.access")
+		srv.errorLogger = app.logger.Named("log.error")
+
 		if srv.AutoHTTPS == nil {
 			// avoid nil pointer dereferences
 			srv.AutoHTTPS = new(AutoHTTPSConfig)
@@ -93,20 +99,25 @@ func (app *App) Provision(ctx caddy.Context) error {
 		}
 
 		for i := range srv.Listen {
-			srv.Listen[i] = repl.ReplaceAll(srv.Listen[i], "")
+			lnOut, err := repl.ReplaceOrErr(srv.Listen[i], true, true)
+			if err != nil {
+				return fmt.Errorf("server %s, listener %d: %v",
+					srvName, i, err)
+			}
+			srv.Listen[i] = lnOut
 		}
 
 		if srv.Routes != nil {
 			err := srv.Routes.Provision(ctx)
 			if err != nil {
-				return fmt.Errorf("setting up server routes: %v", err)
+				return fmt.Errorf("server %s: setting up server routes: %v", srvName, err)
 			}
 		}
 
 		if srv.Errors != nil {
 			err := srv.Errors.Routes.Provision(ctx)
 			if err != nil {
-				return fmt.Errorf("setting up server error handling routes: %v", err)
+				return fmt.Errorf("server %s: setting up server error handling routes: %v", srvName, err)
 			}
 		}
 
@@ -194,7 +205,9 @@ func (app *App) Start() error {
 					/////////
 					// TODO: HTTP/3 support is experimental for now
 					if srv.ExperimentalHTTP3 {
-						log.Printf("[INFO] Enabling experimental HTTP/3 listener on %s", addr)
+						app.logger.Info("enabling experimental HTTP/3 listener",
+							zap.String("addr", addr),
+						)
 						h3ln, err := caddy.ListenPacket("udp", addr)
 						if err != nil {
 							return fmt.Errorf("getting HTTP/3 UDP listener: %v", err)
@@ -284,19 +297,25 @@ func (app *App) automaticHTTPS() error {
 
 		// skip if all listeners use the HTTP port
 		if !srv.listenersUseAnyPortOtherThan(app.httpPort()) {
-			log.Printf("[INFO] Server %s is only listening on the HTTP port %d, so no automatic HTTPS will be applied to this server",
-				srvName, app.httpPort())
+			app.logger.Info("server is only listening on the HTTP port, so no automatic HTTPS will be applied to this server",
+				zap.String("server_name", srvName),
+				zap.Int("http_port", app.httpPort()),
+			)
 			continue
 		}
 
 		// find all qualifying domain names, de-duplicated
 		domainSet := make(map[string]struct{})
-		for _, route := range srv.Routes {
-			for _, matcherSet := range route.MatcherSets {
-				for _, m := range matcherSet {
+		for routeIdx, route := range srv.Routes {
+			for matcherSetIdx, matcherSet := range route.MatcherSets {
+				for matcherIdx, m := range matcherSet {
 					if hm, ok := m.(*MatchHost); ok {
-						for _, d := range *hm {
-							d = repl.ReplaceAll(d, "")
+						for hostMatcherIdx, d := range *hm {
+							d, err = repl.ReplaceOrErr(d, true, false)
+							if err != nil {
+								return fmt.Errorf("%s: route %d, matcher set %d, matcher %d, host matcher %d: %v",
+									srvName, routeIdx, matcherSetIdx, matcherIdx, hostMatcherIdx, err)
+							}
 							if certmagic.HostQualifies(d) &&
 								!srv.AutoHTTPS.Skipped(d, srv.AutoHTTPS.Skip) {
 								domainSet[d] = struct{}{}
@@ -318,7 +337,10 @@ func (app *App) automaticHTTPS() error {
 					// supposed to ignore loaded certificates
 					if !srv.AutoHTTPS.IgnoreLoadedCerts &&
 						len(tlsApp.AllMatchingCertificates(d)) > 0 {
-						log.Printf("[INFO][%s] Skipping automatic certificate management because one or more matching certificates are already loaded", d)
+						app.logger.Info("skipping automatic certificate management because one or more matching certificates are already loaded",
+							zap.String("domain", d),
+							zap.String("server_name", srvName),
+						)
 						continue
 					}
 					domainsForCerts = append(domainsForCerts, d)
@@ -351,7 +373,9 @@ func (app *App) automaticHTTPS() error {
 				})
 
 			// manage their certificates
-			log.Printf("[INFO] Enabling automatic TLS certificate management for %v", domainsForCerts)
+			app.logger.Info("enabling automatic TLS certificate management",
+				zap.Strings("domains", domainsForCerts),
+			)
 			err := tlsApp.Manage(domainsForCerts)
 			if err != nil {
 				return fmt.Errorf("%s: managing certificate for %s: %s", srvName, domains, err)
@@ -368,7 +392,9 @@ func (app *App) automaticHTTPS() error {
 				continue
 			}
 
-			log.Printf("[INFO] Enabling automatic HTTP->HTTPS redirects for %v", domains)
+			app.logger.Info("enabling automatic HTTP->HTTPS redirects",
+				zap.Strings("domains", domains),
+			)
 
 			// create HTTP->HTTPS redirects
 			for _, addr := range srv.Listen {
@@ -434,8 +460,10 @@ func (app *App) automaticHTTPS() error {
 					// that the redirect runs from; simply append our
 					// redirect route to the existing routes, with a
 					// caveat that their config might override ours
-					log.Printf("[WARNING] Server %s is listening on %s, so automatic HTTP->HTTPS redirects might be overridden by your own configuration",
-						srvName, addr)
+					app.logger.Warn("server is listening on same interface as redirects, so automatic HTTP->HTTPS redirects might be overridden by your own configuration",
+						zap.String("server_name", srvName),
+						zap.String("interface", addr),
+					)
 					srv.Routes = append(srv.Routes, redirRoute)
 					continue redirRoutesLoop
 				}
@@ -524,8 +552,8 @@ var emptyHandler HandlerFunc = func(http.ResponseWriter, *http.Request) error {
 
 // WeakString is a type that unmarshals any JSON value
 // as a string literal, with the following exceptions:
-// 1) actual string values are decoded as strings, and
-// 2) null is decoded as empty string
+// 1) actual string values are decoded as strings; and
+// 2) null is decoded as empty string;
 // and provides methods for getting the value as various
 // primitive types. However, using this type removes any
 // type safety as far as deserializing JSON is concerned.
diff --git a/modules/caddyhttp/fileserver/staticfiles.go b/modules/caddyhttp/fileserver/staticfiles.go
index 3e4cccc..26c0efe 100644
--- a/modules/caddyhttp/fileserver/staticfiles.go
+++ b/modules/caddyhttp/fileserver/staticfiles.go
@@ -18,6 +18,7 @@ import (
 	"bytes"
 	"fmt"
 	"html/template"
+	"io"
 	weakrand "math/rand"
 	"mime"
 	"net/http"
@@ -191,6 +192,24 @@ func (fsrv *FileServer) ServeHTTP(w http.ResponseWriter, r *http.Request, _ cadd
 		}
 	}
 
+	// if this handler exists in an error context (i.e. is
+	// part of a handler chain that is supposed to handle
+	// a previous error), we have to serve the content
+	// manually in order to write the correct status code
+	if reqErr, ok := r.Context().Value(caddyhttp.ErrorCtxKey).(error); ok {
+		statusCode := http.StatusInternalServerError
+		if handlerErr, ok := reqErr.(caddyhttp.HandlerError); ok {
+			if handlerErr.StatusCode > 0 {
+				statusCode = handlerErr.StatusCode
+			}
+		}
+		w.WriteHeader(statusCode)
+		if r.Method != "HEAD" {
+			io.Copy(w, file)
+		}
+		return nil
+	}
+
 	// let the standard library do what it does best; note, however,
 	// that errors generated by ServeContent are written immediately
 	// to the response, so we cannot handle them (but errors there
diff --git a/modules/caddyhttp/marshalers.go b/modules/caddyhttp/marshalers.go
new file mode 100644
index 0000000..a672132
--- /dev/null
+++ b/modules/caddyhttp/marshalers.go
@@ -0,0 +1,89 @@
+// Copyright 2015 Matthew Holt and The Caddy Authors
+//
+// Licensed under the Apache License, Version 2.0 (the "License");
+// you may not use this file except in compliance with the License.
+// You may obtain a copy of the License at
+//
+//     http://www.apache.org/licenses/LICENSE-2.0
+//
+// Unless required by applicable law or agreed to in writing, software
+// distributed under the License is distributed on an "AS IS" BASIS,
+// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+// See the License for the specific language governing permissions and
+// limitations under the License.
+
+package caddyhttp
+
+import (
+	"crypto/tls"
+	"net/http"
+
+	"go.uber.org/zap/zapcore"
+)
+
+// LoggableHTTPRequest makes an HTTP request loggable with zap.Object().
+type LoggableHTTPRequest struct{ *http.Request }
+
+// MarshalLogObject satisfies the zapcore.ObjectMarshaler interface.
+func (r LoggableHTTPRequest) MarshalLogObject(enc zapcore.ObjectEncoder) error {
+	enc.AddString("method", r.Method)
+	enc.AddString("uri", r.RequestURI)
+	enc.AddString("proto", r.Proto)
+	enc.AddString("remote_addr", r.RemoteAddr)
+	enc.AddString("host", r.Host)
+	enc.AddObject("headers", LoggableHTTPHeader(r.Header))
+	if r.TLS != nil {
+		enc.AddObject("tls", LoggableTLSConnState(*r.TLS))
+	}
+	return nil
+}
+
+// LoggableHTTPHeader makes an HTTP header loggable with zap.Object().
+type LoggableHTTPHeader http.Header
+
+// MarshalLogObject satisfies the zapcore.ObjectMarshaler interface.
+func (h LoggableHTTPHeader) MarshalLogObject(enc zapcore.ObjectEncoder) error {
+	if h == nil {
+		return nil
+	}
+	for key, val := range h {
+		enc.AddArray(key, LoggableStringArray(val))
+	}
+	return nil
+}
+
+// LoggableStringArray makes a slice of strings marshalable for logging.
+type LoggableStringArray []string
+
+// MarshalLogArray satisfies the zapcore.ArrayMarshaler interface.
+func (sa LoggableStringArray) MarshalLogArray(enc zapcore.ArrayEncoder) error {
+	if sa == nil {
+		return nil
+	}
+	for _, s := range sa {
+		enc.AppendString(s)
+	}
+	return nil
+}
+
+// LoggableTLSConnState makes a TLS connection state loggable with zap.Object().
+type LoggableTLSConnState tls.ConnectionState
+
+// MarshalLogObject satisfies the zapcore.ObjectMarshaler interface.
+func (t LoggableTLSConnState) MarshalLogObject(enc zapcore.ObjectEncoder) error {
+	enc.AddBool("resumed", t.DidResume)
+	enc.AddUint16("version", t.Version)
+	enc.AddUint16("resumed", t.CipherSuite)
+	enc.AddString("proto", t.NegotiatedProtocol)
+	enc.AddBool("proto_mutual", t.NegotiatedProtocolIsMutual)
+	enc.AddString("server_name", t.ServerName)
+	return nil
+}
+
+// Interface guards
+var (
+	_ zapcore.ObjectMarshaler = (*LoggableHTTPRequest)(nil)
+	_ zapcore.ObjectMarshaler = (*LoggableHTTPHeader)(nil)
+	_ zapcore.ArrayMarshaler  = (*LoggableStringArray)(nil)
+	_ zapcore.ObjectMarshaler = (*LoggableTLSConnState)(nil)
+)
diff --git a/modules/caddyhttp/replacer.go b/modules/caddyhttp/replacer.go
index db329be..ddbc250 100644
--- a/modules/caddyhttp/replacer.go
+++ b/modules/caddyhttp/replacer.go
@@ -19,7 +19,6 @@ import (
 	"net"
 	"net/http"
 	"net/textproto"
-	"net/url"
 	"path"
 	"strconv"
 	"strings"
@@ -112,27 +111,30 @@ func addHTTPVarsToReplacer(repl caddy.Replacer, req *http.Request, w http.Respon
 				}
 				return qs, true
 
-			// original URI, before any internal changes
+				// original request, before any internal changes
+			case "http.request.orig_method":
+				or, _ := req.Context().Value(OriginalRequestCtxKey).(http.Request)
+				return or.Method, true
 			case "http.request.orig_uri":
-				u, _ := req.Context().Value(OriginalURLCtxKey).(url.URL)
-				return u.RequestURI(), true
+				or, _ := req.Context().Value(OriginalRequestCtxKey).(http.Request)
+				return or.RequestURI, true
 			case "http.request.orig_uri.path":
-				u, _ := req.Context().Value(OriginalURLCtxKey).(url.URL)
-				return u.Path, true
+				or, _ := req.Context().Value(OriginalRequestCtxKey).(http.Request)
+				return or.URL.Path, true
 			case "http.request.orig_uri.path.file":
-				u, _ := req.Context().Value(OriginalURLCtxKey).(url.URL)
-				_, file := path.Split(u.Path)
+				or, _ := req.Context().Value(OriginalRequestCtxKey).(http.Request)
+				_, file := path.Split(or.URL.Path)
 				return file, true
 			case "http.request.orig_uri.path.dir":
-				u, _ := req.Context().Value(OriginalURLCtxKey).(url.URL)
-				dir, _ := path.Split(u.Path)
+				or, _ := req.Context().Value(OriginalRequestCtxKey).(http.Request)
+				dir, _ := path.Split(or.URL.Path)
 				return dir, true
 			case "http.request.orig_uri.query":
-				u, _ := req.Context().Value(OriginalURLCtxKey).(url.URL)
-				return u.RawQuery, true
+				or, _ := req.Context().Value(OriginalRequestCtxKey).(http.Request)
+				return or.URL.RawQuery, true
 			case "http.request.orig_uri.query_string":
-				u, _ := req.Context().Value(OriginalURLCtxKey).(url.URL)
-				qs := u.Query().Encode()
+				or, _ := req.Context().Value(OriginalRequestCtxKey).(http.Request)
+				qs := or.URL.Query().Encode()
 				if qs != "" {
 					qs = "?" + qs
 				}
@@ -183,7 +185,7 @@ func addHTTPVarsToReplacer(repl caddy.Replacer, req *http.Request, w http.Respon
 			// middleware variables
 			if strings.HasPrefix(key, varsReplPrefix) {
 				varName := key[len(varsReplPrefix):]
-				tbl := req.Context().Value(VarCtxKey).(map[string]interface{})
+				tbl := req.Context().Value(VarsCtxKey).(map[string]interface{})
 				raw, ok := tbl[varName]
 				if !ok {
 					// variables can be dynamic, so always return true
diff --git a/modules/caddyhttp/reverseproxy/fastcgi/fastcgi.go b/modules/caddyhttp/reverseproxy/fastcgi/fastcgi.go
index eaf1f86..21aeb17 100644
--- a/modules/caddyhttp/reverseproxy/fastcgi/fastcgi.go
+++ b/modules/caddyhttp/reverseproxy/fastcgi/fastcgi.go
@@ -19,7 +19,6 @@ import (
 	"crypto/tls"
 	"fmt"
 	"net/http"
-	"net/url"
 	"path"
 	"path/filepath"
 	"strconv"
@@ -53,6 +52,9 @@ type Transport struct {
 	// with the value of SplitPath. The first piece will be assumed as the
 	// actual resource (CGI script) name, and the second piece will be set to
 	// PATH_INFO for the CGI script to use.
+	// Future enhancements should be careful to avoid CVE-2019-11043,
+	// which can be mitigated with use of a try_files-like behavior
+	// that 404's if the fastcgi path info is not found.
 	SplitPath string `json:"split_path,omitempty"`
 
 	// Extra environment variables
@@ -191,12 +193,13 @@ func (t Transport) buildEnv(r *http.Request) (map[string]string, error) {
 	// original URI in as the value of REQUEST_URI (the user can overwrite this
 	// if desired). Most PHP apps seem to want the original URI. Besides, this is
 	// how nginx defaults: http://stackoverflow.com/a/12485156/1048862
-	reqURL, ok := r.Context().Value(caddyhttp.OriginalURLCtxKey).(url.URL)
+	origReq, ok := r.Context().Value(caddyhttp.OriginalRequestCtxKey).(http.Request)
 	if !ok {
 		// some requests, like active health checks, don't add this to
 		// the request context, so we can just use the current URL
-		reqURL = *r.URL
+		origReq = *r
 	}
+	reqURL := origReq.URL
 
 	requestScheme := "http"
 	if r.TLS != nil {
diff --git a/modules/caddyhttp/reverseproxy/reverseproxy.go b/modules/caddyhttp/reverseproxy/reverseproxy.go
index 566c9c4..c2fb751 100644
--- a/modules/caddyhttp/reverseproxy/reverseproxy.go
+++ b/modules/caddyhttp/reverseproxy/reverseproxy.go
@@ -441,6 +441,15 @@ func (h *Handler) reverseProxy(rw http.ResponseWriter, req *http.Request, di Dia
 		}
 	}
 
+	// TODO: there should be an option to return an error if the response
+	// matches some criteria; would solve https://github.com/caddyserver/caddy/issues/1447
+	// by allowing the backend to determine whether this server should treat
+	// a 400+ status code as an error -- but we might need to be careful that
+	// we do not affect the health status of the backend... still looking into
+	// that; if we need to avoid that, we should return a particular error type
+	// that the caller of this function checks for and only applies health
+	// status changes if the error is not this special type
+
 	rw.WriteHeader(res.StatusCode)
 
 	err = h.copyResponse(rw, res.Body, h.flushInterval(req, res))
diff --git a/modules/caddyhttp/rewrite/rewrite.go b/modules/caddyhttp/rewrite/rewrite.go
index 7d4c6f7..5a84a33 100644
--- a/modules/caddyhttp/rewrite/rewrite.go
+++ b/modules/caddyhttp/rewrite/rewrite.go
@@ -23,6 +23,7 @@ import (
 
 	"github.com/caddyserver/caddy/v2"
 	"github.com/caddyserver/caddy/v2/modules/caddyhttp"
+	"go.uber.org/zap"
 )
 
 func init() {
@@ -39,6 +40,8 @@ type Rewrite struct {
 
 	HTTPRedirect caddyhttp.WeakString `json:"http_redirect,omitempty"`
 	Rehandle     bool                 `json:"rehandle,omitempty"`
+
+	logger *zap.Logger
 }
 
 // CaddyModule returns the Caddy module information.
@@ -49,6 +52,12 @@ func (Rewrite) CaddyModule() caddy.ModuleInfo {
 	}
 }
 
+// Provision sets up rewr.
+func (rewr *Rewrite) Provision(ctx caddy.Context) error {
+	rewr.logger = ctx.Logger(rewr)
+	return nil
+}
+
 // Validate ensures rewr's configuration is valid.
 func (rewr Rewrite) Validate() error {
 	if rewr.HTTPRedirect != "" && rewr.Rehandle {
@@ -61,6 +70,10 @@ func (rewr Rewrite) ServeHTTP(w http.ResponseWriter, r *http.Request, next caddy
 	repl := r.Context().Value(caddy.ReplacerCtxKey).(caddy.Replacer)
 	var changed bool
 
+	logger := rewr.logger.With(
+		zap.Object("request", caddyhttp.LoggableHTTPRequest{Request: r}),
+	)
+
 	// rewrite the method
 	if rewr.Method != "" {
 		method := r.Method
@@ -114,18 +127,23 @@ func (rewr Rewrite) ServeHTTP(w http.ResponseWriter, r *http.Request, next caddy
 		r.RequestURI = newURI
 	}
 
-	if changed && rewr.Rehandle {
-		return caddyhttp.ErrRehandle
-	}
-
-	if changed && rewr.HTTPRedirect != "" {
-		statusCode, err := strconv.Atoi(repl.ReplaceAll(rewr.HTTPRedirect.String(), ""))
-		if err != nil {
-			return caddyhttp.Error(http.StatusInternalServerError, err)
+	if changed {
+		logger.Debug("rewrote request",
+			zap.String("method", r.Method),
+			zap.String("uri", r.RequestURI),
+		)
+		if rewr.Rehandle {
+			return caddyhttp.ErrRehandle
+		}
+		if rewr.HTTPRedirect != "" {
+			statusCode, err := strconv.Atoi(repl.ReplaceAll(rewr.HTTPRedirect.String(), ""))
+			if err != nil {
+				return caddyhttp.Error(http.StatusInternalServerError, err)
+			}
+			w.Header().Set("Location", r.RequestURI)
+			w.WriteHeader(statusCode)
+			return nil
 		}
-		w.Header().Set("Location", r.RequestURI)
-		w.WriteHeader(statusCode)
-		return nil
 	}
 
 	return next.ServeHTTP(w, r)
diff --git a/modules/caddyhttp/server.go b/modules/caddyhttp/server.go
index 366a307..2c0c44e 100644
--- a/modules/caddyhttp/server.go
+++ b/modules/caddyhttp/server.go
@@ -17,16 +17,18 @@ package caddyhttp
 import (
 	"context"
 	"fmt"
-	"log"
 	"net"
 	"net/http"
 	"net/url"
 	"strconv"
 	"strings"
+	"time"
 
 	"github.com/caddyserver/caddy/v2"
 	"github.com/caddyserver/caddy/v2/modules/caddytls"
 	"github.com/lucas-clemente/quic-go/http3"
+	"go.uber.org/zap"
+	"go.uber.org/zap/zapcore"
 )
 
 // Server is an HTTP server.
@@ -43,11 +45,15 @@ type Server struct {
 	AutoHTTPS         *AutoHTTPSConfig            `json:"automatic_https,omitempty"`
 	MaxRehandles      *int                        `json:"max_rehandles,omitempty"`
 	StrictSNIHost     *bool                       `json:"strict_sni_host,omitempty"`
+	Logs              *ServerLogConfig            `json:"logs,omitempty"`
 
 	// This field is not subject to compatibility promises
 	ExperimentalHTTP3 bool `json:"experimental_http3,omitempty"`
 
-	tlsApp *caddytls.TLS
+	tlsApp       *caddytls.TLS
+	logger       *zap.Logger
+	accessLogger *zap.Logger
+	errorLogger  *zap.Logger
 
 	h3server *http3.Server
 }
@@ -59,58 +65,106 @@ func (s *Server) ServeHTTP(w http.ResponseWriter, r *http.Request) {
 	if s.h3server != nil {
 		err := s.h3server.SetQuicHeaders(w.Header())
 		if err != nil {
-			log.Printf("[ERROR] Setting HTTP/3 Alt-Svc header: %v", err)
+			s.logger.Error("setting HTTP/3 Alt-Svc header", zap.Error(err))
 		}
 	}
 
-	if s.tlsApp.HandleHTTPChallenge(w, r) {
-		return
-	}
-
 	// set up the context for the request
 	repl := caddy.NewReplacer()
 	ctx := context.WithValue(r.Context(), caddy.ReplacerCtxKey, repl)
 	ctx = context.WithValue(ctx, ServerCtxKey, s)
-	ctx = context.WithValue(ctx, VarCtxKey, make(map[string]interface{}))
-	ctx = context.WithValue(ctx, OriginalURLCtxKey, cloneURL(r.URL))
+	ctx = context.WithValue(ctx, VarsCtxKey, make(map[string]interface{}))
+	var url2 url.URL // avoid letting this escape to the heap
+	ctx = context.WithValue(ctx, OriginalRequestCtxKey, originalRequest(r, &url2))
 	r = r.WithContext(ctx)
 
 	// once the pointer to the request won't change
 	// anymore, finish setting up the replacer
 	addHTTPVarsToReplacer(repl, r, w)
 
-	// build and execute the main handler chain
+	loggableReq := LoggableHTTPRequest{r}
+	errLog := s.errorLogger.With(
+		// encode the request for logging purposes before
+		// it enters any handler chain; this is necessary
+		// to capture the original request in case it gets
+		// modified during handling
+		zap.Object("request", loggableReq),
+	)
+
+	if s.Logs != nil {
+		wrec := NewResponseRecorder(w, nil, nil)
+		w = wrec
+		accLog := s.accessLogger.With(
+			// capture the original version of the request
+			zap.Object("request", loggableReq),
+		)
+		start := time.Now()
+		defer func() {
+			latency := time.Since(start)
+
+			repl.Set("http.response.status", strconv.Itoa(wrec.Status()))
+			repl.Set("http.response.size", strconv.Itoa(wrec.Size()))
+			repl.Set("http.response.latency", latency.String())
+
+			logger := accLog
+			if s.Logs.LoggerNames != nil {
+				logger = logger.Named(s.Logs.LoggerNames[r.Host])
+			}
+
+			log := logger.Info
+			if wrec.Status() >= 400 {
+				log = logger.Error
+			}
+
+			log("request",
+				zap.String("common_log", repl.ReplaceAll(CommonLogFormat, "-")),
+				zap.Duration("latency", latency),
+				zap.Int("size", wrec.Size()),
+				zap.Int("status", wrec.Status()),
+			)
+		}()
+	}
+
+	// guarantee ACME HTTP challenges; handle them
+	// separately from any user-defined handlers
+	if s.tlsApp.HandleHTTPChallenge(w, r) {
+		return
+	}
+
+	// build and execute the primary handler chain
 	err := s.executeCompositeRoute(w, r, s.Routes)
 	if err != nil {
-		// add the raw error value to the request context
-		// so it can be accessed by error handlers
-		c := context.WithValue(r.Context(), ErrorCtxKey, err)
-		r = r.WithContext(c)
-
-		// add error values to the replacer
-		repl.Set("http.error", err.Error())
-		if handlerErr, ok := err.(HandlerError); ok {
-			repl.Set("http.error.status_code", strconv.Itoa(handlerErr.StatusCode))
-			repl.Set("http.error.status_text", http.StatusText(handlerErr.StatusCode))
-			repl.Set("http.error.message", handlerErr.Message)
-			repl.Set("http.error.trace", handlerErr.Trace)
-			repl.Set("http.error.id", handlerErr.ID)
+		// prepare the error log
+		logger := errLog
+		if s.Logs.LoggerNames != nil {
+			logger = logger.Named(s.Logs.LoggerNames[r.Host])
 		}
 
+		// get the values that will be used to log the error
+		errStatus, errMsg, errFields := errLogValues(err)
+
+		// add HTTP error information to request context
+		r = s.Errors.WithError(r, err)
+
 		if s.Errors != nil && len(s.Errors.Routes) > 0 {
-			err := s.executeCompositeRoute(w, r, s.Errors.Routes)
-			if err != nil {
-				// TODO: what should we do if the error handler has an error?
-				log.Printf("[ERROR] [%s %s] handling error: %v", r.Method, r.RequestURI, err)
-			}
-		} else {
-			// TODO: polish the default error handling
-			log.Printf("[ERROR] [%s %s] %v", r.Method, r.RequestURI, err)
-			if handlerErr, ok := err.(HandlerError); ok {
-				w.WriteHeader(handlerErr.StatusCode)
+			// execute user-defined error handling route
+			err2 := s.executeCompositeRoute(w, r, s.Errors.Routes)
+			if err2 == nil {
+				// user's error route handled the error response
+				// successfully, so now just log the error
+				logger.Error(errMsg, errFields...)
 			} else {
-				w.WriteHeader(http.StatusInternalServerError)
+				// well... this is awkward
+				errFields = append([]zapcore.Field{
+					zap.String("error", err2.Error()),
+					zap.Namespace("first_error"),
+					zap.String("msg", errMsg),
+				}, errFields...)
+				logger.Error("error handling handler error", errFields...)
 			}
+		} else {
+			logger.Error(errMsg, errFields...)
+			w.WriteHeader(errStatus)
 		}
 	}
 }
@@ -278,26 +332,101 @@ type HTTPErrorConfig struct {
 	Routes RouteList `json:"routes,omitempty"`
 }
 
+// WithError makes a shallow copy of r to add the error to its
+// context, and sets placeholders on the request's replacer
+// related to err. It returns the modified request which has
+// the error information in its context and replacer. It
+// overwrites any existing error values that are stored.
+func (*HTTPErrorConfig) WithError(r *http.Request, err error) *http.Request {
+	// add the raw error value to the request context
+	// so it can be accessed by error handlers
+	c := context.WithValue(r.Context(), ErrorCtxKey, err)
+	r = r.WithContext(c)
+
+	// add error values to the replacer
+	repl := r.Context().Value(caddy.ReplacerCtxKey).(caddy.Replacer)
+	repl.Set("http.error", err.Error())
+	if handlerErr, ok := err.(HandlerError); ok {
+		repl.Set("http.error.status_code", strconv.Itoa(handlerErr.StatusCode))
+		repl.Set("http.error.status_text", http.StatusText(handlerErr.StatusCode))
+		repl.Set("http.error.message", handlerErr.Message)
+		repl.Set("http.error.trace", handlerErr.Trace)
+		repl.Set("http.error.id", handlerErr.ID)
+	}
+
+	return r
+}
+
+// ServerLogConfig describes a server's logging configuration.
+type ServerLogConfig struct {
+	LoggerNames map[string]string `json:"logger_names,omitempty"`
+}
+
+// errLogValues inspects err and returns the status code
+// 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) {
+	if handlerErr, ok := err.(HandlerError); ok {
+		status = handlerErr.StatusCode
+		msg = handlerErr.Err.Error()
+		fields = []zapcore.Field{
+			zap.Int("status", handlerErr.StatusCode),
+			zap.String("err_id", handlerErr.ID),
+			zap.String("err_trace", handlerErr.Trace),
+		}
+		return
+	}
+	status = http.StatusInternalServerError
+	msg = err.Error()
+	return
+}
+
+// originalRequest returns a partial, shallow copy of
+// req, including: req.Method, deep copy of req.URL
+// (into the urlCopy parameter, which should be on the
+// stack), and req.RequestURI. Notably, headers are not
+// copied. This function is designed to be very fast
+// and efficient, and useful primarly for read-only
+// logging purposes.
+func originalRequest(req *http.Request, urlCopy *url.URL) http.Request {
+	urlCopy = cloneURL(req.URL)
+	return http.Request{
+		Method:     req.Method,
+		RequestURI: req.RequestURI,
+		URL:        urlCopy,
+	}
+}
+
 // cloneURL makes a copy of r.URL and returns a
 // new value that doesn't reference the original.
-func cloneURL(u *url.URL) url.URL {
+func cloneURL(u *url.URL) *url.URL {
 	urlCopy := *u
 	if u.User != nil {
 		userInfo := new(url.Userinfo)
 		*userInfo = *u.User
 		urlCopy.User = userInfo
 	}
-	return urlCopy
+	return &urlCopy
 }
 
+const (
+	// CommonLogFormat is the common log format. https://en.wikipedia.org/wiki/Common_Log_Format
+	CommonLogFormat = `{http.request.remote.host} ` + CommonLogEmptyValue + ` {http.handlers.authentication.user.id} [{time.now.common_log}] "{http.request.orig_method} {http.request.orig_uri} {http.request.proto}" {http.response.status} {http.response.size}`
+
+	// CommonLogEmptyValue is the common empty log value.
+	CommonLogEmptyValue = "-"
+)
+
 // Context keys for HTTP request context values.
 const (
 	// For referencing the server instance
 	ServerCtxKey caddy.CtxKey = "server"
 
 	// For the request's variable table
-	VarCtxKey caddy.CtxKey = "vars"
+	VarsCtxKey caddy.CtxKey = "vars"
 
-	// For the unmodified URL that originally came in with a request
-	OriginalURLCtxKey caddy.CtxKey = "original_url"
+	// For a partial copy of the unmodified request that
+	// originally came into the server's entry handler
+	OriginalRequestCtxKey caddy.CtxKey = "original_request"
 )
diff --git a/modules/caddyhttp/staticresp.go b/modules/caddyhttp/staticresp.go
index a435f87..732a3fb 100644
--- a/modules/caddyhttp/staticresp.go
+++ b/modules/caddyhttp/staticresp.go
@@ -112,7 +112,7 @@ func (s StaticResponse) ServeHTTP(w http.ResponseWriter, r *http.Request, _ Hand
 
 	// write response body
 	if s.Body != "" {
-		fmt.Fprint(w, repl.ReplaceAll(s.Body, ""))
+		fmt.Fprint(w, repl.ReplaceKnown(s.Body, ""))
 	}
 
 	return nil
diff --git a/modules/caddyhttp/subroute.go b/modules/caddyhttp/subroute.go
index 3b0d718..57fb80a 100644
--- a/modules/caddyhttp/subroute.go
+++ b/modules/caddyhttp/subroute.go
@@ -30,8 +30,15 @@ func init() {
 // matchers, or for routes with matchers that must be have deferred
 // evaluation (e.g. if they depend on placeholders created by other
 // matchers that need to be evaluated first).
+//
+// You can also use subroutes to handle errors from specific handlers.
+// First the primary Routes will be executed, and if they return an
+// error, the Errors routes will be executed; in that case, an error
+// is only returned to the entry point at the server if there is an
+// additional error returned from the errors routes.
 type Subroute struct {
-	Routes RouteList `json:"routes,omitempty"`
+	Routes RouteList        `json:"routes,omitempty"`
+	Errors *HTTPErrorConfig `json:"errors,omitempty"`
 }
 
 // CaddyModule returns the Caddy module information.
@@ -47,7 +54,13 @@ func (sr *Subroute) Provision(ctx caddy.Context) error {
 	if sr.Routes != nil {
 		err := sr.Routes.Provision(ctx)
 		if err != nil {
-			return fmt.Errorf("setting up routes: %v", err)
+			return fmt.Errorf("setting up subroutes: %v", err)
+		}
+		if sr.Errors != nil {
+			err := sr.Errors.Routes.Provision(ctx)
+			if err != nil {
+				return fmt.Errorf("setting up error subroutes: %v", err)
+			}
 		}
 	}
 	return nil
@@ -55,7 +68,13 @@ func (sr *Subroute) Provision(ctx caddy.Context) error {
 
 func (sr *Subroute) ServeHTTP(w http.ResponseWriter, r *http.Request, _ Handler) error {
 	subroute := sr.Routes.BuildCompositeRoute(r)
-	return subroute.ServeHTTP(w, r)
+	err := subroute.ServeHTTP(w, r)
+	if err != nil && sr.Errors != nil {
+		r = sr.Errors.WithError(r, err)
+		errRoute := sr.Errors.Routes.BuildCompositeRoute(r)
+		return errRoute.ServeHTTP(w, r)
+	}
+	return err
 }
 
 // Interface guards
diff --git a/modules/caddyhttp/vars.go b/modules/caddyhttp/vars.go
index bbd4568..3fb8fa3 100644
--- a/modules/caddyhttp/vars.go
+++ b/modules/caddyhttp/vars.go
@@ -38,7 +38,7 @@ func (VarsMiddleware) CaddyModule() caddy.ModuleInfo {
 }
 
 func (t VarsMiddleware) ServeHTTP(w http.ResponseWriter, r *http.Request, next Handler) error {
-	vars := r.Context().Value(VarCtxKey).(map[string]interface{})
+	vars := r.Context().Value(VarsCtxKey).(map[string]interface{})
 	repl := r.Context().Value(caddy.ReplacerCtxKey).(caddy.Replacer)
 	for k, v := range t {
 		keyExpanded := repl.ReplaceAll(k, "")
@@ -62,7 +62,7 @@ func (VarsMatcher) CaddyModule() caddy.ModuleInfo {
 
 // Match matches a request based on variables in the context.
 func (m VarsMatcher) Match(r *http.Request) bool {
-	vars := r.Context().Value(VarCtxKey).(map[string]string)
+	vars := r.Context().Value(VarsCtxKey).(map[string]string)
 	repl := r.Context().Value(caddy.ReplacerCtxKey).(caddy.Replacer)
 	for k, v := range m {
 		keyExpanded := repl.ReplaceAll(k, "")