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

Add SlogSink support to funcr #241

Merged
merged 11 commits into from
Dec 8, 2023
Merged

Add SlogSink support to funcr #241

merged 11 commits into from
Dec 8, 2023

Conversation

thockin
Copy link
Contributor

@thockin thockin commented Dec 1, 2023

See commits for comments. This unearthed at least 3 bugs.

funcr now passes all but one of the slog tests (that being the timestamp one).

Copy link
Contributor

@pohly pohly left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Looks good to me, but I've not tried to really understand all implementation details in funcr.

sloghandler.go Outdated Show resolved Hide resolved
@thockin
Copy link
Contributor Author

thockin commented Dec 4, 2023

Yeah, I don't expect you to dig into funcr too deeply. Mostly I was interested in your take on the changes to TestFuncrHandler() - specifically that the exceptions list is now reduced to just 1.

It feels like that SHOULD be in the funcr subdir, but we also use testSlog to test slogSink ?

@thockin
Copy link
Contributor Author

thockin commented Dec 4, 2023

As I stare at slogr_test, I am a little confused - testSlogSink seems like a copy of slogSink - why?

@thockin
Copy link
Contributor Author

thockin commented Dec 4, 2023

I pushed another commit - please look at the "Get rid of testSlogSink" and tell me if it is wrong?

@thockin
Copy link
Contributor Author

thockin commented Dec 4, 2023

I pushed on more commit, moving slogtests to a helper and funcr tests to funcr.

@thockin thockin force-pushed the master branch 2 times, most recently from d7be8c5 to 76cc254 Compare December 4, 2023 22:29
@pohly
Copy link
Contributor

pohly commented Dec 5, 2023

One observation: because we are now testing only with a logr.Sink which is also a logr.SlogSink, we lose coverage of those code paths that bridge slog with "traditional" logr backends. This primarily shows up in sloghandler.go (97.9% percent before, now 53.2%).

To restore full coverage, we would have to define a logr.LogSink which uses the funcr formatter without providing the logr.SlogSink interface.

@thockin
Copy link
Contributor Author

thockin commented Dec 5, 2023

What would you say to having an internal trivial implementation which is basically discard but not nil? We could have one which supports SlogSink and one which does not.

I guess that is testLogSink...

@thockin
Copy link
Contributor Author

thockin commented Dec 5, 2023

Are we generating a coverage report for PRs?

@pohly
Copy link
Contributor

pohly commented Dec 5, 2023

What would you say to having an internal trivial implementation which is basically discard but not nil?

For slogtest.TestHandler, that test sink would have to produce valid JSON. I can suggest a solution tomorrow.

Are we generating a coverage report for PRs?

No. I was testing locally because I wanted to understand whether moving the testing around had an effect. There's an effect of the PR, it's just because for another reason.


//
// slogSink wrapper of discard
//
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Did you learn anything from these benchmarks? I'm just curious.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I learned that funcr with JSON is more than 2x faster than slog's JSON handler, but has more allocs. And that the slogSink (wrapper) path is (as expected) low overhead.

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I did a similar comparison between slog's JSON handler and zap (kubernetes/kubernetes@9100c3c). Slog was slower, so there was no justification for switching from zap to slog as backend in Kubernetes.

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

While I have your attention (sorry, couldn't resist 😁 ), could you perhaps review the PR in Kubernetes that this commit came from? The dependency update is in another pending PR, that's the only reason it's WIP.

@thockin
Copy link
Contributor Author

thockin commented Dec 5, 2023

I am cooking something wrt test impls and coverage.

@thockin
Copy link
Contributor Author

thockin commented Dec 5, 2023

I have an extra commit in flight, but opinion wanted.

I can make slogHandler do groups properly, but it would store them itself and bypass calling sink.WithValues() . It would come close to passing slog tests, though. Worthwhile? Or just leave it with things like a.b=<value> ?

@thockin
Copy link
Contributor Author

thockin commented Dec 6, 2023

OK, I added a big commit. It makes sloghandler pass almost all of the slog tests wrt WithGroup and WithAttrs, at the cost of bypassing the LogSink.WithValues. It's not yet safe - maps get copied and then mutated nor have I really looked at performance. It needs maps in order to get groups right, and that makes me sad (expensive, loses ordering).

I could abandon the maps part and just go back to dot-prefixes (simpler, won't pass as many slog tests but maybe OK?). Opinion wanted.

@pohly
Copy link
Contributor

pohly commented Dec 6, 2023

I can make slogHandler do groups properly, but it would store them itself and bypass calling sink.WithValues() . It would come close to passing slog tests, though. Worthwhile? Or just leave it with things like a.b= ?

I prefer to keep slogHandler as simple as possible, i.e. use a.b=<value> for those sinks which don't implement SlogSink. There are other things that sinks should support if they care about being used with slog, like special slog values, so eventually either a sink supports slog and SlogSink or it should be replaced with something else. Once we are at that point, the additional complexity in slogHandler won't be needed.

@thockin
Copy link
Contributor Author

thockin commented Dec 6, 2023

After having done it, I think I agree. Though the testing is satisfying :)

@thockin
Copy link
Contributor Author

thockin commented Dec 6, 2023

One last thought: as it is, with prefixes, someone who calls:

slogger.Info("msg", slog.Group("g", "k", "v"))

gets a different result than:

slogger.WithGroup("g", Info("msg", "k", "v"))

It's {"g": { "k": "v"}} in the first and {"g.k": "v"} in the second.

@pohly
Copy link
Contributor

pohly commented Dec 6, 2023

One last thought: as it is, with prefixes, someone who calls:

slogger.Info("msg", slog.Group("g", "k", "v"))
[...]
It's {"g": { "k": "v"}} in the first

Is that perhaps because slogHandler is passing the parameter down into a sink which partially supports slog, as in "I can handle slog.Group, but I don't implement the full logr.SlogSink"?

I can see how this happens with a simple test sink based on funcr. I think "real" sinks will fully support slog, then the WithGroup case will also work.

@thockin thockin force-pushed the master branch 2 times, most recently from c6e67c9 to 0dd6551 Compare December 6, 2023 17:36
@thockin
Copy link
Contributor Author

thockin commented Dec 6, 2023

I pushed now with a much simpler change to sloghandler, coverage is restored, tests are cleaner (IMO). PTAL.

context_slog_test.go Outdated Show resolved Hide resolved
context_slog_test.go Outdated Show resolved Hide resolved
context_slog_test.go Outdated Show resolved Hide resolved
context_slog_test.go Outdated Show resolved Hide resolved
context_test.go Outdated Show resolved Hide resolved
uses: actions/setup-go@v4
with:
go-version: '>=1.21.0'
cache: false
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I agree that we should cover the new code with linting. I don't think it's worth to lint also with older Go because the non-slog code isn't that complex and going away at some point.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

i cant tell if you are agreeing with me or want a change?

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I agree with you.

if attr.Key != "" {
kvList = append(kvList, l.addGroupPrefix(attr.Key), attr.Value.Resolve().Any())
}
kvList = attrToKVs(attr, l.groupPrefix, kvList)
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think this code change deserves to be a separate commit with a description of why it is made. Right now it is in "Clean up slog testing and restore coverage" which doesn't tell me why sloghandler.go needs to be changed.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I can either a) break this last commit to a PR which applies AFTER this PR (rebasing it is tedious and it has a lot of deps on other commits); or b) beef up the comments.

I'll do B now and you can decide if you prefer A.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

pushed

sloghandler.go Show resolved Hide resolved
@thockin
Copy link
Contributor Author

thockin commented Dec 7, 2023

pushed with small changes, will look at splitting sloghandler to a new PR or beefing up comments.

// and other details of slog.
func attrToKVs(attr slog.Attr, groupPrefix string, kvList []any) []any {
attrVal := attr.Value.Resolve()
if attrVal.Kind() == slog.KindGroup {
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I suppose this is the "retools sloghandler to handle slog Attrs a bit better" part.

Looks okay to me now. Let's rebase and then merge it without further refactoring (your plan B).

@thockin
Copy link
Contributor Author

thockin commented Dec 8, 2023

rebased and pushed

@pohly pohly merged commit d55b4e2 into go-logr:master Dec 8, 2023
14 checks passed
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.

None yet

2 participants