Timer Middleware memory leak

[snagles]

When investigating memory usage for an app that uses this project, I noticed that memory usage continually climbed over time with thousands of requests. After further investigation I think I have identified the problem being in the timer middleware.

Heap profile:

(pprof) top10
Showing nodes accounting for 1011.71MB, 88.76% of 1139.81MB total
Dropped 89 nodes (cum <= 5.70MB)
Showing top 10 nodes out of 46
      flat  flat%   sum%        cum   cum%
  214.05MB 18.78% 18.78%   298.56MB 26.19%  $NAME_REMOVED/vendor/github.com/ant0ine/go-json-rest/rest.(*TimerMiddleware).MiddlewareFunc.func1

Memory Allocation List:

(pprof) list MiddlewareFunc.func1
ROUTINE ======================== $NAME_REMOVED/vendor/github.com/ant0ine/go-json-rest/rest.(*TimerMiddleware).MiddlewareFunc.func1 in $NAME_REMOVED/vendor/github.com/ant0ine/go-json-rest/rest/timer.go
  214.05MB   298.56MB (flat, cum) 26.19% of Total
         .          .     11:
         .          .     12:// MiddlewareFunc makes TimerMiddleware implement the Middleware interface.
         .          .     13:func (mw *TimerMiddleware) MiddlewareFunc(h HandlerFunc) HandlerFunc {
         .          .     14:	return func(w ResponseWriter, r *Request) {
         .          .     15:
   22.50MB    22.50MB     16:		start := time.Now()
  189.55MB   189.55MB     17:		r.Env["START_TIME"] = &start
         .          .     18:
         .          .     19:		// call the handler
         .    84.51MB     20:		h(w, r)
         .          .     21:
         .          .     22:		end := time.Now()
       2MB        2MB     23:		elapsed := end.Sub(start)
         .          .     24:		r.Env["ELAPSED_TIME"] = &elapsed
         .          .     25:	}
         .          .     26:}

It seemed odd that there was a large memory profile for a time allocation. Looking into this closer it seemed like the env values were escaping to the heap and is not garbage collected:

$ go test -gcflags '-m'
# github.com/snagles/go-json-rest-test
./example_test.go:44:9: func literal escapes to heap
./example_test.go:44:9: func literal escapes to heap
./example_test.go:43:63: leaking param: h to result ~r1 level=-1
./example_test.go:47:23: &start escapes to heap
./example_test.go:47:25: &start escapes to heap
./example_test.go:46:3: moved to heap: start
./example_test.go:44:40: leaking param: w
./example_test.go:44:40: leaking param: r
./example_test.go:54:25: &elapsed escapes to heap
./example_test.go:54:27: &elapsed escapes to heap
./example_test.go:53:3: moved to heap: elapsed

I've removed the reference and changed &start and &end to "start" and "end" and that kept the memory on the stack.

Test Program

package test

import (
	"log"
	"sync"
	"testing"
	"time"

	"github.com/ant0ine/go-json-rest/rest"
	"github.com/ant0ine/go-json-rest/rest/test"
)

func TestSimpleRequest(t *testing.T) {
	api := rest.NewApi()
	api.Use(&TimerMiddleware{})
	router, err := rest.MakeRouter(
		rest.Get("/r", func(w rest.ResponseWriter, r *rest.Request) {
		}),
	)
	if err != nil {
		log.Fatal(err)
	}
	api.SetApp(router)

	var wg sync.WaitGroup
	wg.Add(5000)
	for i := 0; i < 5000; i++ {
		go func(wg *sync.WaitGroup) {
			test.RunRequest(t, api.MakeHandler(), test.MakeSimpleRequest("GET", "http://1.2.3.4/r", nil))
			wg.Done()
		}(&wg)
	}
	wg.Wait()

}

// TimerMiddleware computes the elapsed time spent during the execution of the wrapped handler.
// The result is available to the wrapping handlers as request.Env["ELAPSED_TIME"].(time.Duration),
// and as request.Env["START_TIME"].(time.Time)
type TimerMiddleware struct{}

// MiddlewareFunc makes TimerMiddleware implement the Middleware interface.
func (mw *TimerMiddleware) MiddlewareFunc(h rest.HandlerFunc) rest.HandlerFunc {
	return func(w rest.ResponseWriter, r *rest.Request) {

		start := time.Now()
		r.Env["START_TIME"] = start

		// call the handler
		h(w, r)

		end := time.Now()
		elapsed := end.Sub(start)
		r.Env["ELAPSED_TIME"] = elapsed
	}
}

Unless I'm misunderstanding, should all r.Env values be set to non-pointers?