Logger backends

[novln]

Hello,

This Pull Request add a new Metrics middleware in order to close the #55.
It require a MetricsHandler which will be used as an events/metrics receiver.

If the user want to use another logging backend, it just have to implement the previous interface.

Example:

func main() {
  r := chi.NewRouter()
  ...
  r.Use(middleware.Metrics(LogrusAdapter{}))
  ...
}

However, while trying to keep compatibility with the v1 version, I think some refactoring for middleware/recoverer.go are required.

Cheers,

[VojtechVitek]

Why do you call it Metrics? This is just a Logger, isn't it?

[novln]

Hello,

It's a terminology choice in order to separate what the data is (a metric) with how it's handled (with a logger).

For example, depending of your use case, you may use this middleware to expose these metrics on one of these "backends":

• NSQ Producer
• RabbitMQ Queue
• Telegraf (InfluxDB) Plugin
• Prometheus Exporter

With these examples, is Logger still make sense ? I was trying to "use" a more generic terms (Metrics) for this purpose. (However, a Logger use these metrics)

Nevertheless, If the contributors team isn't conviced by this opinionated design, I can update this Pull Request with the terminology that you prefer.

[VojtechVitek]

I feel like Metrics is more specific word for the application data/metrics (where data would contain session, user_id, ip, referer, user_agent, context etc.), not just the Request/Response data.

@pkieltyka thoughts?

[VojtechVitek]

btw: We need to keep the old Logger interface the same. For stable API.

func Logger(next http.Handler) http.Handler

[pkieltyka]

yea, I agree with @VojtechVitek that the name Metrics is more about instrumentation metrics and less about application logs going to different backends.

[novln]

Ok, so for the terminology, do we agree to rename Metric as LogEntry and Metrics as NewLogger ?

Also, for the MetricsHandler interface, what do you prefer between:

• LogAppender with a Append method.
• LogHandler with a Write method.

Thank you.

[pkieltyka]

Nice, I like these suggestions, LogEntry, NewLogger and I prefer LogAppender/Append -- @VojtechVitek ?

[pkieltyka]

thanks for the PR @november-eleven, there is definitely some good stuff in here and I feel we're close.

I'd like to find a different name than Metric, more like LogBackend etc., or LogPipe .. something like that.

But first, can you give a quick example how this could be used with different backends? ie. is it like ..

// something that comes to mind
func router() http.Handler {
  logger := middleware.NewLogger(
    middleware.DefaultLoggerBackend,
    myCustomPrometheusLoggerBackend{},
  )

  r := chi.NewRouter()
  r.Use(logger)
  r.Get("/", ...)
}

[novln]

Oh, I haven't thought about the "multiple backends" use-case.

If we assume that the declaration of each routes are defined in the same thread in order to avoid race condition, then (with a little modification) you could use the NewLogger like these two examples:

func router() http.Handler {
  logger := middleware.NewLogger(
    middleware.DefaultLoggerBackend,
    myCustomPrometheusLoggerBackend{},
  )

  r := chi.NewRouter()
  r.Use(logger)
  r.Get("/", ...)
}

or

func router() http.Handler {
  r := chi.NewRouter()
  r.Use(middleware.NewLogger(middleware.DefaultLoggerBackend))
  r.Use(middleware.NewLogger(myCustomPrometheusLoggerBackend{}))
  r.Get("/", ...)
}

However, if a third Logger is required for a sub group:

r.Group("articles", func(r chi.Router) {

  r.Use(middleware.NewLogger(AnotherLoggerForArticles{}))
  r.Get("/", paginate, listArticles)
  r.Post("/", createArticle)

  r.Group("/:articleID", func(r chi.Router) {
    r.Use(ArticleCtx)
    r.Get("/", getArticle)
    r.Put("/", updateArticle)
    r.Delete("/", deleteArticle)
  })

})

The implementation I have in mind wouldn't work, and wrapping another writerProxy on top of a writerProxy (and so on...) may induce a great latency, a huge complexity and/or a poor performance. I haven't tested this case but it already seem shaky...

For these reasons, I would be inclined to think that this middleware should define only once, one or multiple backend. (So, it would be your example).

[pkieltyka]

@november-eleven yea, I was also thinking about the performance implications. For some, the trade-off may be negligible, but we should still consider the API design in regards to performance. It's pretty easy to support multiple backends in a single call..

func NewLogger(logAppenders ...LogAppender) { ... } it would return a single middleware that captures the data and calls out to a slice of appenders

[pkieltyka]

if someone felt so inclined, they could split the logger middlewares like in your example, which I think looks a bit cleaner, but has some performance penalties that aren't worth it.

[novln]

Hello,

I've played a little with boom and chi and I think I've found a good trade-off with the API design (which enable the "split" use-case defined in my third examples) and performances.

If you prefer, I can submit a new pull request with a more appropriate branch name and a squashed commit. However, it will lose this discussion history...

Cheers,

[pkieltyka]

Sure, submit another PR and we can always reference the discussion here as needed. Also, boom tests are good, but it's also important to write go bench tests to determine number of allocs and ops to figure out memory and cpu pressure of the code

[novln]

Yeah, you're right. I've added some primary benchmark for this purpose, so if you have any feedback: don't hesitate. Also, don't merge it yet, I would like to add some testing too :)
Besides, I've located two allocations per logger layer. I'll work on it later with a new pull request...

BenchmarkLoggerWithoutMiddleware-4                   3000000           423 ns/op         352 B/op          3 allocs/op
BenchmarkLoggerWithOneAppender-4                     2000000           846 ns/op         472 B/op          5 allocs/op
BenchmarkLoggerWithMultipleAppenders-4               2000000           994 ns/op         472 B/op          5 allocs/op
BenchmarkLoggerWithMultipleLayers-4                  2000000           806 ns/op         387 B/op          5 allocs/op
BenchmarkLoggerWithMultipleLayersAndAppenders-4      1000000          1711 ns/op         512 B/op          7 allocs/op

To finish on a good note, I've run some benchmark on several router (Echo, Gin and LARS for instance) with and without logger (note: output on stdout was disabled, measuring my terminal has no value). With go1.7-rc1, chi as a pretty good review/ranking.

BenchmarkChiWithoutLogger-4      5000000           364 ns/op         352 B/op          3 allocs/op
BenchmarkChiWithLogger-4         2000000           762 ns/op         472 B/op          5 allocs/op
BenchmarkEchoWithoutLogger-4    20000000            73.1 ns/op         0 B/op          0 allocs/op
BenchmarkEchoWithLogger-4        2000000           869 ns/op         224 B/op          8 allocs/op
BenchmarkGinWithoutLogger-4      3000000           569 ns/op         464 B/op          4 allocs/op
BenchmarkGinWithLogger-4         2000000           779 ns/op         496 B/op          5 allocs/op
BenchmarkLarsWithoutLogger-4    20000000            98.6 ns/op         0 B/op          0 allocs/op
BenchmarkLarsWithLogger-4       10000000           156 ns/op           0 B/op          0 allocs/op

Cheers,

[novln]

Hello,

I think this will be my final commit for this Pull Request because I won't be available for the time being...
If it's look good for you, I will create a new pull request with a squashed commit.

Cheers,

[pkieltyka]

@november-eleven this is awesome, thank you. I'm going to dive in deeper on this as I get to the final details and step of v2

[pkieltyka]

@november-eleven thanks so much for your work on this! What's great about the new context support in net/http, this logger is framework-agnostic and will technically work as any stdlib net/lib http middleware. After giving it some thought, I think the first version of chi v2, I'd like to keep super minimal and it would be better if you move this PR into its own middleware package. For example, github.com/november-eleven/logpiper or in the github.com/goware org which we put a lot of other middleware's if you'd like. Let me know if you do it, and I'll link to it from our README.

[novln]

Hello,

Ok I understand. I would prefer to have access to the goware organizations so others (including you) could contribute more easily to this middleware.

Cheers,

[pkieltyka]

done!

[VojtechVitek]

@november-eleven I reviewed this PR too. There is some really good code!

However, after some considerations, I also feel like we should keep the default logger middleware as simple as possible and it should just write to STDOUT in respect to Docker, syslog etc. Even though multiple backend is certainly good idea, I don't think that LogEntry struct would be flexible enough, since one cannot store custom values into it - for example data from the Context chain (go1.7's r.Context()), ie. session, user_id and other app-specific data/metrics.

goware Org would be a perfect place for this :)

Anyway, thank you again for your PR, we really appreciate it!