ziflex/lecho

Existing zerolog instance is not reflected with full functionality

andygrunwald opened this issue · 2 comments

First of all, thanks for this middleware!

While providing an exsiting zerolog instance to lecho, it seems that the functionality is not fully used:
When using

output := zerolog.ConsoleWriter{Out: os.Stdout, TimeFormat: time.RFC3339}
logger := zerolog.New(output).With().Timestamp().Logger()

The following output is producted

2021-03-22T08:09:42+01:00 INF booting foo=true
2021-03-22T08:09:42+01:00 ??? {"message":"⇨ http server started on [::]:8282"}

If you apply a HTTP handler to the echo framework and make a HTTP call, it outputs:

2021-03-22T08:09:16+01:00 ??? {"level":"info","id":"mISgzePvkoXF02jSSNdiAn8Ns2IBjfvX","remote_ip":"3.135.189.179","host":"8dc74f618941.ngrok.io","method":"GET","uri":"/favicon.ico","user_agent":"Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/88.0.4324.150 Safari/537.36","status":404,"referer":"","error":"code=404, message=Not Found","latency":0.139483,"latency_human":"139.483µs","bytes_in":"0","bytes_out":"24"}

A few things are not reflected:

  • level is part of the message, rather then after the timestamp (see ???)
  • No default level is provided (see "http server started" message)
  • Request information is still in json format rather than as single logging attributes

Is it a mistake from my side or a (valid) limitation of this library?
Thank you @ziflex!

Code to reproduce

package main

import (
	"os"
	"time"

	"github.com/labstack/echo/v4"
	"github.com/rs/zerolog"
	"github.com/ziflex/lecho/v2"
)

func main() {
	output := zerolog.ConsoleWriter{Out: os.Stdout, TimeFormat: time.RFC3339}
	logger := zerolog.New(output).With().Timestamp().Logger()

	logger.Info().Bool("foo", true).Msg("booting")

	e := echo.New()
	e.HideBanner = true

	lechoLogger := lecho.New(logger)
	e.Logger = lechoLogger

	e.Use(lecho.Middleware(lecho.Config{
		Logger: lechoLogger,
	}))

	e.Start(":8282")
}

Hey, thanks for using lecho!

First of all, if you want to use lecho with preconfigured instance of zerolog, you should use lecho.From method instead.

Second, the reason why you are getting ??? is that echo calls a given Logger without a status (by using its output). Maybe we should use default level for that?

I will update lecho.New to avoid such confusion in the future.

Hey @ziflex,
thanks for the response and for pointing me in the right direction of lecho.From.
Now it works as expected like

2021-03-28T18:43:31+02:00 INF  bytes_in=0 bytes_out=11797 host=ID.ngrok.io id=rb1qN0Mq7GyIykif1vUhJsuovaaeEsEn latency=22.833632 latency_human=22.833632ms method=GET referer=https://ID.ngrok.io/url remote_ip=ipv6 status=200 uri=uri user_agent="Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/89.0.4389.90 Safari/537.36"

Just for reference (and others), the change for lecho.New was applied in 5b04e50
Thanks a lot for taking care!

About the log level ???, I created a PR in the echo framework: labstack/echo#1826
Let us see what comes out of this.

In my opinion, this issue can be closed. Please reopen, if you think differently.
Thanks again!