summaryrefslogtreecommitdiff
path: root/modules/caddyhttp/server.go
diff options
context:
space:
mode:
Diffstat (limited to 'modules/caddyhttp/server.go')
-rw-r--r--modules/caddyhttp/server.go207
1 files changed, 168 insertions, 39 deletions
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"
)