negroni logging benchmark fun

README.md

Benchmarking fun times for use with urfave/negroni#158.

The results.txt below was unscientifically generated on my 2014 MacBook Pro while also running a bunch of other stuff 🎉.

fmt_tmpl_test.go

package negronitest

import (
	"bytes"
	"html/template"
	"io/ioutil"
	"log"
	"testing"
	"time"
)

var (
	l    = log.New(ioutil.Discard, "x", 0)
	tmpl = template.Must(template.New("log").Parse("{{.StartTime}} | {{.Status}} | \t {{.Duration}} | {{.Hostname}} | {{.Method}} {{.Path}}\n"))
)

func withPrintf(start time.Time) bool {
	l.Printf("%v | %v | \t %v | %v | %v %v", start.Format(time.RFC3339), 200, time.Since(start), "some.host.example.com", "GET", "/wat")
	return true
}

func withTemplateExecute(start time.Time) bool {
	buf := &bytes.Buffer{}
	err := tmpl.Execute(buf, map[string]interface{}{
		"StartTime": start,
		"Status":    200,
		"Duration":  time.Since(start),
		"Hostname":  "some.host.example.com",
		"Method":    "GET",
		"Path":      "/wat",
	})
	if err != nil {
		panic(err)
	}
	l.Print(buf.String())
	return true
}

func BenchmarkPrintf(b *testing.B) {
	start := time.Now()

	for i := 0; i < b.N; i++ {
		ok := withPrintf(start)
		if !ok {
			panic("NOT OK")
		}
	}
}

func BenchmarkTemplateExecute(b *testing.B) {
	start := time.Now()

	for i := 0; i < b.N; i++ {
		ok := withTemplateExecute(start)
		if !ok {
			panic("NOT OK")
		}
	}
}

Makefile

test:
	go test -v -bench=. -benchtime=30s 2>&1 | tee results.txt

results.txt

testing: warning: no tests to run
BenchmarkPrintf-8            	30000000	      1345 ns/op
BenchmarkTemplateExecute-8   	 3000000	     12508 ns/op
PASS
ok  	_/Users/me/Downloads/negronitest	91.805s