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

1 files changed, 50 insertions, 22 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.