Centralized error handling
Let’s neaten up our application by moving some of the error handling code into helper methods. This will help separate our concerns and stop us repeating code as we progress through the build.
Go ahead and add a new helpers.go
file under the cmd/web
directory:
$ cd $HOME/code/snippetbox $ touch cmd/web/helpers.go
And add the following code:
package main import ( "fmt" "net/http" "runtime/debug" ) // The serverError helper writes an error message and stack trace to the errorLog, // then sends a generic 500 Internal Server Error response to the user. func (app *application) serverError(w http.ResponseWriter, err error) { trace := fmt.Sprintf("%s\n%s", err.Error(), debug.Stack()) app.errorLog.Print(trace) http.Error(w, http.StatusText(http.StatusInternalServerError), http.StatusInternalServerError) } // The clientError helper sends a specific status code and corresponding description // to the user. We'll use this later in the book to send responses like 400 "Bad // Request" when there's a problem with the request that the user sent. func (app *application) clientError(w http.ResponseWriter, status int) { http.Error(w, http.StatusText(status), status) } // For consistency, we'll also implement a notFound helper. This is simply a // convenience wrapper around clientError which sends a 404 Not Found response to // the user. func (app *application) notFound(w http.ResponseWriter) { app.clientError(w, http.StatusNotFound) }
There’s not a huge amount of new code here, but it does introduce a couple of features which are worth discussing.
In the
serverError()
helper we use thedebug.Stack()
function to get a stack trace for the current goroutine and append it to the log message. Being able to see the execution path of the application via the stack trace can be helpful when you’re trying to debug errors.In the
clientError()
helper we use thehttp.StatusText()
function to automatically generate a human-friendly text representation of a given HTTP status code. For example,http.StatusText(400)
will return the string"Bad Request"
.
Once that’s done, head back to your handlers.go
file and update it to use the new helpers:
package main import ( "fmt" "html/template" "net/http" "strconv" ) func (app *application) home(w http.ResponseWriter, r *http.Request) { if r.URL.Path != "/" { app.notFound(w) // Use the notFound() helper return } files := []string{ "./ui/html/base.tmpl", "./ui/html/partials/nav.tmpl", "./ui/html/pages/home.tmpl", } ts, err := template.ParseFiles(files...) if err != nil { app.serverError(w, err) // Use the serverError() helper. return } err = ts.ExecuteTemplate(w, "base", nil) if err != nil { app.serverError(w, err) // Use the serverError() helper. } } func (app *application) snippetView(w http.ResponseWriter, r *http.Request) { id, err := strconv.Atoi(r.URL.Query().Get("id")) if err != nil || id < 1 { app.notFound(w) // Use the notFound() helper. return } fmt.Fprintf(w, "Display a specific snippet with ID %d...", id) } func (app *application) snippetCreate(w http.ResponseWriter, r *http.Request) { if r.Method != http.MethodPost { w.Header().Set("Allow", http.MethodPost) app.clientError(w, http.StatusMethodNotAllowed) // Use the clientError() helper. return } w.Write([]byte("Create a new snippet...")) }
When that’s updated, restart your application and make a request to http://localhost:4000
in your browser.
Again, this should result in our (deliberate) error being raised and you should see the corresponding error message and stack trace in your terminal:
$ go run ./cmd/web INFO 2022/01/29 16:22:14 Starting server on :4000 ERROR 2022/01/29 16:22:19 helpers.go:13: open ./ui/html/pages/home.tmpl: no such file or directory goroutine 6 [running]: runtime/debug.Stack() /usr/local/go/src/runtime/debug/stack.go:24 +0x65 main.(*application).serverError(0xc000012ca0, {0x79eb70, 0xc0001481c0}, {0x798180, 0xc000101830}) /home/alex/Desktop/snippetbox.v2/cmd/web/helpers.go:12 +0x66 main.(*application).home(0xc000151a30, {0x79eb70, 0xc0001481c0}, 0x0) /home/alex/Desktop/snippetbox.v2/cmd/web/handlers.go:24 +0x194 net/http.HandlerFunc.ServeHTTP(0x0, {0x79eb70, 0xc0001481c0}, 0x0) /usr/local/go/src/net/http/server.go:2046 +0x2f net/http.(*ServeMux).ServeHTTP(0x0, {0x79eb70, 0xc0001481c0}, 0xc000170000) /usr/local/go/src/net/http/server.go:2424 +0x149 net/http.serverHandler.ServeHTTP({0xc000101170}, {0x79eb70, 0xc0001481c0}, 0xc000170000) /usr/local/go/src/net/http/server.go:2878 +0x43b net/http.(*conn).serve(0xc000110e60, {0x79fdc0, 0xc000101080}) /usr/local/go/src/net/http/server.go:1929 +0xb08 created by net/http.(*Server).Serve /usr/local/go/src/net/http/server.go:3033 +0x4e8
If you look closely at this you’ll notice a small problem: the file name and line number being reported in the ERROR
log line is now helpers.go:13
— because this is where the log message is now being written from.
What we want to report is the file name and line number one step back in the stack trace, which would give us a clearer idea of where the error actually originated from.
We can do this by changing the serverError()
helper to use our logger’s Output()
function and setting the frame depth to 2. Reopen your helpers.go
file and update it like so:
package main ... func (app *application) serverError(w http.ResponseWriter, err error) { trace := fmt.Sprintf("%s\n%s", err.Error(), debug.Stack()) app.errorLog.Output(2, trace) http.Error(w, http.StatusText(http.StatusInternalServerError), http.StatusInternalServerError) } ...
And if you try again now, you should find that the appropriate file name and line number (handlers.go:24
) is being reported in the ERROR
log line:
$ go run ./cmd/web INFO 2022/01/29 16:24:00 Starting server on :4000 ERROR 2022/01/29 16:24:02 handlers.go:24: open ./ui/html/pages/home.tmpl: no such file or directory goroutine 6 [running]: runtime/debug.Stack() /usr/local/go/src/runtime/debug/stack.go:24 +0x65 main.(*application).serverError(0xc000012ca0, {0x79eb90, 0xc0001481c0}, {0x798180, 0xc000101830}) /home/alex/Desktop/snippetbox.v2/cmd/web/helpers.go:10 +0x58 main.(*application).home(0xc000151a30, {0x79eb90, 0xc0001481c0}, 0x0) /home/alex/Desktop/snippetbox.v2/cmd/web/handlers.go:24 +0x194 net/http.HandlerFunc.ServeHTTP(0x0, {0x79eb90, 0xc0001481c0}, 0x0) /usr/local/go/src/net/http/server.go:2046 +0x2f net/http.(*ServeMux).ServeHTTP(0x0, {0x79eb90, 0xc0001481c0}, 0xc000170000) /usr/local/go/src/net/http/server.go:2424 +0x149 net/http.serverHandler.ServeHTTP({0xc000101170}, {0x79eb90, 0xc0001481c0}, 0xc000170000) /usr/local/go/src/net/http/server.go:2878 +0x43b net/http.(*conn).serve(0xc000110f00, {0x79fde0, 0xc000101080}) /usr/local/go/src/net/http/server.go:1929 +0xb08 created by net/http.(*Server).Serve /usr/local/go/src/net/http/server.go:3033 +0x4e8
Revert the deliberate error
At this point we don’t need the deliberate error anymore, so go ahead and fix it like so:
$ cd $HOME/code/snippetbox $ mv ui/html/pages/home.bak ui/html/pages/home.tmpl