The server error log
It’s important to be aware that Go’s http.Server may write its own log entries relating to things like unrecovered panics, or problems accepting or writing to HTTP connections.
By default, it writes these entries using the standard logger — which means they will be written to the standard error stream (instead of standard out like our other log entries), and they won’t be in the same format as the rest of our nice structured log entries.
To demonstrate this, let’s add a deliberate error to our application and set a Content-Length header with an invalid value on our responses. Go ahead and update the render() helper like so:
package main ... func (app *application) render(w http.ResponseWriter, r *http.Request, status int, page string, data templateData) { ts, ok := app.templateCache[page] if !ok { err := fmt.Errorf("the template %s does not exist", page) app.serverError(w, r, err) return } buf := new(bytes.Buffer) err := ts.ExecuteTemplate(buf, "base", data) if err != nil { app.serverError(w, r, err) return } // Deliberate error: set a Content-Length header with an invalid (non-integer) // value. w.Header().Set("Content-Length", "this isn't an integer!") w.WriteHeader(status) buf.WriteTo(w) } ...
Then run the application, make a request to http://localhost:4000, and check the application log. You should see that it looks similar to this:
$ go run ./cmd/web/ time=2024-03-18T11:29:23.000+00:00 level=INFO msg="starting server" addr=:4000 time=2024-03-18T11:29:23.000+00:00 level=INFO msg="received request" ip=127.0.0.1:60824 proto=HTTP/1.1 method=GET uri=/ 2024/03/18 11:29:23 http: invalid Content-Length of "this isn't an integer!" time=2024-03-18T11:29:23.000+00:00 level=INFO msg="received request" ip=127.0.0.1:60824 proto=HTTP/1.1 method=GET uri=/static/css/main.css time=2024-03-18T11:29:23.000+00:00 level=INFO msg="received request" ip=127.0.0.1:60830 proto=HTTP/1.1 method=GET uri=/static/img/logo.png
We can see that the third log entry here, which informs us of the Content-Length problem, is in a very different format to the others. That’s not great, especially if you want to filter your logs to look for errors, or use an external service to monitor them and send you alerts.
Unfortunately, it’s not possible to configure http.Server to use our new structured logger directly. Instead, we have to convert our structured logger handler into a *log.Logger which writes log entries at a specific fixed level, and then register that with the http.Server. We can do this conversion using the slog.NewLogLogger() function, like so:
package main ... func main() { addr := flag.String("addr", ":4000", "HTTP network address") dsn := flag.String("dsn", "web:pass@/snippetbox?parseTime=true", "MySQL data source name") flag.Parse() logger := slog.New(slog.NewTextHandler(os.Stdout, nil)) ... srv := &http.Server{ Addr: *addr, Handler: app.routes(), // Create a *log.Logger from our structured logger handler, which writes // log entries at Error level, and assign it to the ErrorLog field. If // you would prefer to log the server errors at Warn level instead, you // could pass slog.LevelWarn as the final parameter. ErrorLog: slog.NewLogLogger(logger.Handler(), slog.LevelError), } logger.Info("starting server", "addr", srv.Addr) err = srv.ListenAndServe() logger.Error(err.Error()) os.Exit(1) } ...
With that in place, any log messages that http.Server automatically writes will now be written using our structured logger at Error level. If you restart the application and make another request to http://localhost:4000, you should see that the log entries now look like this:
$ go run ./cmd/web/ time=2024-03-18T11:29:23.000+00:00 level=INFO msg="starting server" addr=:4000 time=2024-03-18T11:29:23.000+00:00 level=INFO msg="received request" ip=127.0.0.1:40854 proto=HTTP/1.1 method=GET uri=/ time=2024-03-18T11:29:23.000+00:00 level=ERROR msg="http: invalid Content-Length of \"this isn't an integer!\""
Before we go any further, head back to your cmd/web/helpers.go file and remove the deliberate error from the render() method:
package main ... func (app *application) render(w http.ResponseWriter, r *http.Request, status int, page string, data templateData) { ts, ok := app.templateCache[page] if !ok { err := fmt.Errorf("the template %s does not exist", page) app.serverError(w, r, err) return } buf := new(bytes.Buffer) err := ts.ExecuteTemplate(buf, "base", data) if err != nil { app.serverError(w, r, err) return } w.WriteHeader(status) buf.WriteTo(w) } ...