Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Fix handling of printing caller with Write, Print, and Printf. #315

Merged
merged 8 commits into from
May 13, 2021

Conversation

zelch
Copy link
Contributor

@zelch zelch commented May 6, 2021

This fixes #243, as well as the identical issue around Print and Printf calls in both zerolog and zerolog/log.

With these changes, we now get correct caller data in all those cases.

@rs
Copy link
Owner

rs commented May 6, 2021

This is not thread safe.

@zelch
Copy link
Contributor Author

zelch commented May 6, 2021

Indeed, it's not even safe for a single OS thread but multiple goroutines, I'm a bit annoyed with myself for failing to even think about the concurrent case.

I think I see how to do it more correctly, but the initial thought on that is uglier than I'd like.

I'll follow up in a few days when I've had time to play with a couple of different options.

@rs
Copy link
Owner

rs commented May 6, 2021

If write is called concurrently (it's often the case with a logger), the counter will be arbitrary incremented. You can't write a global variable from a logger method. The best way to fix that would be to add a method on event to customized a skip frame delta for the message.

@zelch
Copy link
Contributor Author

zelch commented May 6, 2021

I have just such a change working, but it will likely be tomorrow or the day after that I have the time to finalize it.

Zephaniah E. Loss-Cutler-Hull added 3 commits May 6, 2021 15:44
This indicates that, for this event, we should skip an additional
specified number of frames.

This is cumulative, calling it twice for the same event will add both
numbers together, and this is in addition to any skip frame settings set
through the context, or globally.

The indended purpose is for wrappers to Msg or Msgf, so that the actual
caller is always printed correctly.
This allows us to use the correct caller when using these 3 functions.
These now use CallerSkipFrame, this means that they can no longer pass
down to the Logger.Print/Printf functions.

As such, we now use Logger.Debug() to get an event, call
CallerSkipFrame, and then use either .Msg or .Msgf to print the message.

But we get correct caller logs, and this is essentially the same thing
that Logger.Print and Logger.Printf are doing.
@zelch
Copy link
Contributor Author

zelch commented May 6, 2021

Alright, the rework in the force-push should be significantly better in regards to thread (and basic concurrency) safety.

Obvious, if multiple goroutines are trying to use the same Event, we have problems, but I'm pretty sure that we have many other problems in that case as well.

log.go Outdated Show resolved Hide resolved
log.go Outdated Show resolved Hide resolved
log.go Outdated Show resolved Hide resolved
event.go Outdated Show resolved Hide resolved
Zephaniah E. Loss-Cutler-Hull added 3 commits May 6, 2021 23:32
Code review request.
This didn't even compile.  Another reminder that a quick change while
tired is never a good idea.
@zelch zelch requested a review from rs May 7, 2021 06:36
event.go Outdated Show resolved Hide resolved
log.go Outdated Show resolved Hide resolved
Zephaniah E. Loss-Cutler-Hull added 2 commits May 10, 2021 12:53
We were ignoring the argument, oops.
A ever so slight misunderstanding of the code review request.
@zelch zelch requested a review from rs May 12, 2021 15:53
@rs rs merged commit 4de2fcc into rs:master May 13, 2021
@Zenithar

This comment has been minimized.

@zelch
Copy link
Contributor Author

zelch commented Jun 18, 2021

For any undetermined reason, I have e nil in

That's reasonable, I was going to say that it seems somewhat insane to try and do anything with a nil Event, except most of the other functions that work on Event check for nil, so we should as well.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

log.Logger.Write() writes wrong "caller" information (wrong frame skip count)
3 participants