Go : add logging to each router

Go : add logging to each router

I want to log all my network request in Go web app.

Something like negroni:

// https://github.com/codegangsta/negroni/blob/master/logger.go
// NewLogger returns a new Logger instance
func NewLogger() *Logger {
  return &Logger{log.New(os.Stdout, "[negroni] ", 0)}
}

func (l *Logger) ServeHTTP(rw http.ResponseWriter, r *http.Request, next http.HandlerFunc) {
  start := time.Now()
  l.Printf("Started %s %s", r.Method, r.URL.Path)

  next(rw, r)

  res := rw.(ResponseWriter)
  l.Printf("Completed %v %s in %v", res.Status(), http.StatusText(res.Status()), time.Since(start))
}

So here's my code:

router := httprouter.New()

handler := func(w http.ResponseWriter, r *http.Request, _ httprouter.Params) {
  type Page struct {
    Title string
  }
  tp := template.Must(template.ParseFiles("templates/main.html", "templates/base.html"))
  err := tp.ExecuteTemplate(w, "base", &Page{Title: "AAA"})
  if err != nil {
    log.Fatal(err)
}

router.Handle("GET", "/", handler)

l := log.New(os.Stdout, "[AAA] ", 0)
l.Printf("Listening 0.0.0.0%s", PORT)

l.Fatal(http.ListenAndServe(PORT, router))

If I want to do this, I have to add start := time.Now() and time.Since(start) manually to each router in my code.package main

I think I should wrap it and use interface but don't know how to get started.

How do I implement one simple logging interface and apply all the routed handlers so that I can debug with all the loggings...

Negroni does like:

router := mux.NewRouter()
router.HandleFunc("/", HomeHandler)

n := negroni.New(Middleware1, Middleware2)
// Or use a middleware with the Use() function
n.Use(Middleware3)
// router goes last
n.UseHandler(router)

n.Run(":3000")

Wrap the root handler with a handler that logs and delegates to another handler:

 type RequestLogger struct {
     h http.Handler
     l *Logger
 }

 func (rl RequestLogger) ServeHTTP(w http.ResponseWriter, r *http.Request) {
     start := time.Now()
     rl.l.Printf("Started %s %s", r.Method, r.URL.Path)
     rl.h.ServeHTTP(w, r)
     rl.l.Printf("Completed %s %s in %v", r.Method, r.URL.Path, time.Since(start))
 }

 ---

 l := log.New(os.Stdout, "[AAA] ", 0)
 l.Printf("Listening 0.0.0.0%s", PORT)
 l.Fatal(http.ListenAndServe(PORT, RequestLogger{h:router, l:l}))

A simple middleware interceptor is probably the right approach. If you'd like an example, see a simple one here: https://github.com/jadekler/git-go-websiteskeleton/blob/master/main.go#L49. This can be contracted down to a smaller function, but YMMV.

Here is the relevant code:

At the top of your handlefuncs:

http.HandleFunc("/", httpInterceptor)

In your middleware:

func httpInterceptor(w http.ResponseWriter, req *http.Request) {
    router.ServeHTTP(w, req)

   logAccess(w, req)
}

Where logAccess is a function that logs whatever you'd like it to. For an example, see here.

It's rather easy to implement your own middleware in Go, one approach is something like:

var logger = log.New(os.Stdout, "[something shiny] ", 0)

func httpLogger(fn func(w http.ResponseWriter, r *http.Request)) func(w http.ResponseWriter, r *http.Request) {
	return func(w http.ResponseWriter, r *http.Request) {
		start := time.Now()
		logger.Printf("Started %s %s", r.Method, r.URL.Path)
		fn(w, r)
		logger.Printf("Completed in %v", time.Since(start))
	}
}

....

router.Handle("GET", "/", httpLogger(handler))