zerolog icon indicating copy to clipboard operation
zerolog copied to clipboard

Caller confusion when using caller multiple times

Open sruehl opened this issue 1 year ago • 2 comments

when using the .Caller like this

package main

import (
	"github.com/rs/zerolog"
	"github.com/rs/zerolog/log"
)

func main() {
	logger := log.With().Caller().Logger()
	logger.Info().Msg("Should be 10")
	UtilSomething(logger)
	logger.Info().Str("field1", "left").Str("field1", "right").Msg("Test")
}

func UtilSomething(logger zerolog.Logger) {
	logger.Info().Caller(1).Msg("Should be 11")
}

src: https://go.dev/play/p/nyLsISEzVhV we are getting this output:

{"level":"info","time":"2009-11-10T23:00:00Z","caller":"/tmp/sandbox2691989628/prog.go:10","message":"Should be 10"}
{"level":"info","caller":"/tmp/sandbox2691989628/prog.go:11","time":"2009-11-10T23:00:00Z","caller":"/tmp/sandbox2691989628/prog.go:16","message":"Should be 11"}
{"level":"info","field1":"left","field1":"right","time":"2009-11-10T23:00:00Z","caller":"/tmp/sandbox2691989628/prog.go:12","message":"Test"}

Program exited.

as you can see the second skip set in the UtilSomething funktion is getting put to the right and therefore when collapsing using the wrong line number. Is that a issue in zerolog or a missunderstanding how to use the API for such a case?

sruehl avatar Feb 15 '24 15:02 sruehl

And for clarification: The first .Caller() is set on the root logger to always display caller lines and the second one is used in util functions to get the right line number.

sruehl avatar Feb 15 '24 15:02 sruehl

or in other words, it seems like the order is wrong for caller (ref https://github.com/rs/zerolog/issues/40#issuecomment-371180715)

sruehl avatar Feb 15 '24 17:02 sruehl