chore!: adopt log/slog, remove go-kit/log #14906

tjhop · 2024-09-15T15:44:38Z

This commit updates Prometheus to adopt stdlib's log/slog package in
favor of go-kit/log. As part of converting to use slog, several other
related changes are required to get prometheus working, including:

removed unused logging util func RateLimit()
forward ported the util/logging/Deduper logging by implementing a small custom slog.Handler that does the deduping before chaining log calls to the underlying real slog.Logger
move some of the json file logging functionality to use prom/common package functionality
refactored some of the new json file logging for scraping
changes to promql.QueryLogger interface to swap out logging methods for relevant slog sugar wrappers
updated lots of tests that used/replicated custom logging functionality, attempting to keep the logical goal of the tests consistent after the transition
added a healthy amount of if logger == nil { $makeLogger } type conditional checks amongst various functions where none were provided -- old code that used the go-kit/log.Logger interface had several places where there were nil references when trying to use functions like With() to add keyvals on the new *slog.Logger type

tjhop · 2024-09-15T15:46:01Z

@SuperQ if you don't mind taking a look when you have time as well, I'd appreciate it!

And sorry all for the massive change set 😅

tjhop · 2024-09-15T15:48:10Z

Opening as draft for now so it's known that there's work in progress -- still need to fix up tests around the custom query log testing that's done in cmd/prometheus/query_log_test.go, but I believe that should cover most things.

It builds and has been running well for me in my testing so far; feedback welcome!

bboreham

Sterling stuff! Thanks for doing this; some initial comments below.
(I only read about 25% of the PR, so far)

cmd/prometheus/main.go

bboreham · 2024-09-22T17:19:47Z

cmd/prometheus/main.go

-	// Above level 6, the k8s client would log bearer tokens in clear-text.
-	klog.ClampLevel(6)


Seem to have lost this line.

So ClampLevel() isn't a native klog function, but rather a function from the library prometheus replaces klog with:
https://github.com/prometheus/prometheus/blob/main/go.mod#L210-L213
https://pkg.go.dev/github.com/simonpasquier/klog-gokit#ClampLevel
https://pkg.go.dev/github.com/simonpasquier/klog-gokit/v3#ClampLevel

A similar change was made to the prometheus operator when they switched to slog:
https://github.com/prometheus-operator/prometheus-operator/pull/6902/files#diff-33ef32bf6c23acb95f5902d7097b7a1d5128ca061167ec0716715b0b9eeaa5f6L147
https://github.com/prometheus-operator/prometheus-operator/pull/6902/files#diff-3a86c514d2d3f52dc7235e0444e3a2c54960795d7e73cecb131b876ce306442bL67-L69

To the best of my current understanding, this is intentional

bboreham · 2024-09-22T17:19:54Z

cmd/prometheus/main.go

-	// Above level 6, the k8s client would log bearer tokens in clear-text.
-	klog.ClampLevel(6)
-	klog.SetLogger(log.With(logger, "component", "k8s_client_runtime"))
-	klogv2.ClampLevel(6)


And this one.

Same response as the other one -- though I do need to double check and see if/where we still need klog v1 in prometheus to see about creating SetSlogLogger() type redirect func like there is in klogv2 upstream

yea, we still have v1 things in discovery, I took inspiration from klog's upstream v1/v2 coexistence docs and implemented a small wrapper to redirect klogv1 calls to klogv2, and since klogv2 is already redirected to log/slog, that should mean both flavors of klog end up in slog in the end

cmd/prometheus/main.go

bboreham · 2024-09-22T17:22:12Z

cmd/prometheus/main.go

-		log.With(logger, "component", "scrape manager"),
-		func(s string) (log.Logger, error) { return logging.NewJSONFileLogger(s) },
+		logger.With("component", "scrape manager"),
+		func(s string) (*logging.JSONFileLogger, error) { return logging.NewJSONFileLogger(s) },


Should this return a more abstract interface type?

I can be convinced of the usefulness there.

The previous "raison d'être" for the json file logger, as far as I can tell, was to satisfy the promql.QueryLogger interface:
https://github.com/prometheus/prometheus/pull/14906/files#diff-ad2761bb162a2f12326b18f2714ef54f4cd476cfe3388f77b2b20c5ff82e4faaL127-L130

Does that feel more appropriate for our usage here?

cmd/prometheus/main.go

@ArthurSens

Simple convenience function to return an slog.Logger that writes to io.Discard. Originally suggested by @ArthurSens [here](prometheus#686 (comment)), and requested again by @bboreham [here](prometheus/prometheus#14906 (comment)). As Bryan points out in the comment, there's 147 instances where a discard logger is needed, so a consistent utility function to manage them seems helpful. Signed-off-by: TJ Hoplock <t.hoplock@gmail.com>

tjhop · 2024-09-27T21:02:09Z

@bboreham I believe this is ready for a re-review. I've rebased on current upstream main, incorporated fixes for some of the feedback provided so far, and go tests working locally.

Things work locally using go workspaces, but as I mention in the updated PR description, this requires functionality in 2 PRs that haven't made their way to an upstream release yet in prometheus/common. Because of this, test failures should be expected as things fail to compile for obvious reasons.

@ArthurSens

Simple convenience function to return an slog.Logger that writes to io.Discard. Originally suggested by @ArthurSens [here](#686 (comment)), and requested again by @bboreham [here](prometheus/prometheus#14906 (comment)). As Bryan points out in the comment, there's 147 instances where a discard logger is needed, so a consistent utility function to manage them seems helpful. Signed-off-by: TJ Hoplock <t.hoplock@gmail.com>

bboreham · 2024-09-29T07:42:57Z

Pin to a commit in go.mod ?

tjhop · 2024-09-29T13:36:25Z

Pin to a commit in go.mod ?

Sure, I can do that. I'd prefer not to do that at merge time, but happy to do that for now at least.

tjhop · 2024-09-30T16:17:37Z

All lights are green (after pinning prometheus/common to commit) 🙃

SuperQ · 2024-09-30T16:33:10Z

I plan to cut a prometheus/common tag after prometheus/common#700.

tjhop · 2024-10-01T14:03:36Z

Bumped prometheus/common to v0.60.0, rebased to solve a merge conflict, squashed commits, and updated commit description to match current state 👍

roidelapluie · 2024-10-01T14:47:22Z

I approve this but I would appreciate if we do not have the full path to source file

roidelapluie · 2024-10-01T14:54:51Z

time=2024-10-01T16:54:36.703+02:00 level=INFO source=/home/roidelapluie/dev/prometheus/cmd/prometheus/main.go:1363 msg="Notifier manager stopped"

didn't we go for ts ?

SuperQ · 2024-10-04T08:12:22Z

@roidelapluie It looks like you merged a broken change into this PR. 😕

tjhop · 2024-10-04T19:42:28Z

resolved another merge conflict and fixed up go mods that got messed up earlier

roidelapluie · 2024-10-07T12:23:15Z

Needs a rebase, but I will merge asap once this is fixed

roidelapluie

Mmh, I see slog does not return error, but we sill moved query logger to slog?

tjhop · 2024-10-07T13:35:12Z

Mmh, I see slog does not return error, but we sill moved query logger to slog?

Yes, so far we've been operating with the goal of "full slog adoption" as much as possible. The QueryLogger interface has been updated to match the slog sugar logger methods available, the difference being that With() on the query logger does not return a new logger but rather updates the querylogger's internal logger.

I had some similar thoughts. Do you have any thoughts/opinions?

roidelapluie · 2024-10-07T13:49:59Z

Let's merge for now ?

roidelapluie · 2024-10-07T13:57:05Z

I would have prefered not to change the QueryLogger and ScrapeFailure loggers but no strong opinion

tjhop · 2024-10-07T14:31:49Z

I'm game for merge. Like @SuperQ had mentioned a ways above, let's get it in and iterate on improvements 👍

SuperQ · 2024-10-07T14:47:06Z

@roidelapluie As far as I remember looking at the go-kit/log code, the Log() interface swallowed all errors anyway and always returned nil. I think it was only there for internal use or something like that. This is why we added an exception to golangci-lint configs to ignore errcheck issues.

Which reminds me, @tjhop , you can remove this from the .golanci.yml

      # Never check for logger errors.
      - (github.com/go-kit/log.Logger).Log

tjhop · 2024-10-07T16:05:47Z

Which reminds me, @tjhop , you can remove this from the .golanci.yml

Woops, I had it in there at one point, must've lost in one of the recent rebases. Thanks!

tjhop · 2024-10-07T19:13:34Z

Did a thorough self-review and see a few other spots to tidy up, will get things better cleaned up

For: prometheus#14355 This commit updates Prometheus to adopt stdlib's log/slog package in favor of go-kit/log. As part of converting to use slog, several other related changes are required to get prometheus working, including: - removed unused logging util func `RateLimit()` - forward ported the util/logging/Deduper logging by implementing a small custom slog.Handler that does the deduping before chaining log calls to the underlying real slog.Logger - move some of the json file logging functionality to use prom/common package functionality - refactored some of the new json file logging for scraping - changes to promql.QueryLogger interface to swap out logging methods for relevant slog sugar wrappers - updated lots of tests that used/replicated custom logging functionality, attempting to keep the logical goal of the tests consistent after the transition - added a healthy amount of `if logger == nil { $makeLogger }` type conditional checks amongst various functions where none were provided -- old code that used the go-kit/log.Logger interface had several places where there were nil references when trying to use functions like `With()` to add keyvals on the new *slog.Logger type Signed-off-by: TJ Hoplock <t.hoplock@gmail.com>

SuperQ

Lets gooooooooooooooooo

Resolves: prometheus#15433 When I converted prometheus to use slog in prometheus#14906, I update both the `QueryLogger` interface, as well as how the log calls to the `QueryLogger` were built up in `promql.Engine.exec()`. The backing logger for the `QueryLogger` in the engine is a `util/logging.JSONFileLogger`, and it's implementation of the `With()` method updates the logger the logger in place with the new keyvals added onto the underlying `slog.Logger`, which means they get inherited onto everything after. All subsequent calls to `With()`, even in later queries, would continue to then append on more and more keyvals for the various params and fields built up in the logger. In turn, this causes unbounded growth of the logger, leading to increased memory usage, and in at least one report was the likely cause of an OOM kill. More information can be found in the issue and the linked slack thread. This commit does a few things: - It was referenced in feedback in prometheus#14906 that it would've been better to not change the `QueryLogger` interface if possible, this PR proposes changes that bring it closer to alignment with the pre-3.0 `QueryLogger` interface contract - reverts `promql.Engine.exec()`'s usage of the query logger to the pattern of building up an array of args to pass at once to the end log call. Avoiding the repetitious calls to `.With()` are what resolve the issue with the logger growth/memory usage. - updates the scrape failure logger to use the update `QueryLogger` methods in the contract. - updates tests accordingly - cleans up unused methods Builds and passes tests successfully. Tested locally and confirmed I could no longer reproduce the issue/it resolved the issue. Signed-off-by: TJ Hoplock <t.hoplock@gmail.com>

Resolves: prometheus#15433 When I converted prometheus to use slog in prometheus#14906, I update both the `QueryLogger` interface, as well as how the log calls to the `QueryLogger` were built up in `promql.Engine.exec()`. The backing logger for the `QueryLogger` in the engine is a `util/logging.JSONFileLogger`, and it's implementation of the `With()` method updates the logger the logger in place with the new keyvals added onto the underlying slog.Logger, which means they get inherited onto everything after. All subsequent calls to `With()`, even in later queries, would continue to then append on more and more keyvals for the various params and fields built up in the logger. In turn, this causes unbounded growth of the logger, leading to increased memory usage, and in at least one report was the likely cause of an OOM kill. More information can be found in the issue and the linked slack thread. This commit does a few things: - It was referenced in feedback in prometheus#14906 that it would've been better to not change the `QueryLogger` interface if possible, this PR proposes changes that bring it closer to alignment with the pre-3.0 `QueryLogger` interface contract - reverts `promql.Engine.exec()`'s usage of the query logger to the pattern of building up an array of args to pass at once to the end log call. Avoiding the repetitious calls to `.With()` are what resolve the issue with the logger growth/memory usage. - updates the scrape failure logger to use the update `QueryLogger` methods in the contract. - updates tests accordingly - cleans up unused methods Builds and passes tests successfully. Tested locally and confirmed I could no longer reproduce the issue/it resolved the issue. Signed-off-by: TJ Hoplock <t.hoplock@gmail.com>

bboreham reviewed Sep 22, 2024

View reviewed changes

tjhop mentioned this pull request Sep 27, 2024

feat: add promslog.NewNopLogger() convenience func prometheus/common#697

Merged

tjhop force-pushed the chore/3.0-adopt-slog branch 2 times, most recently from cf7de3e to b49314d Compare September 27, 2024 20:58

tjhop marked this pull request as ready for review September 27, 2024 20:59

tjhop requested review from dgl, roidelapluie, jesusvazquez, brancz, cstyan, bwplotka and tomwilkie as code owners September 27, 2024 20:59

tjhop force-pushed the chore/3.0-adopt-slog branch 2 times, most recently from 9a3c98a to d52d7f5 Compare September 29, 2024 13:46

tjhop requested a review from aknuds1 as a code owner September 29, 2024 14:27

tjhop force-pushed the chore/3.0-adopt-slog branch 2 times, most recently from 7bee14c to a09e3bc Compare September 29, 2024 15:57

tjhop force-pushed the chore/3.0-adopt-slog branch from 29fdeef to 3cd8b74 Compare October 1, 2024 14:01

tjhop dismissed SuperQ’s stale review via 46e9d4c October 4, 2024 19:41

tjhop force-pushed the chore/3.0-adopt-slog branch from 9e6c03e to 46e9d4c Compare October 4, 2024 19:41

tjhop force-pushed the chore/3.0-adopt-slog branch from 46e9d4c to c025769 Compare October 4, 2024 19:45

tjhop force-pushed the chore/3.0-adopt-slog branch from c025769 to 509638c Compare October 7, 2024 13:14

roidelapluie previously approved these changes Oct 7, 2024

View reviewed changes

roidelapluie reviewed Oct 7, 2024

View reviewed changes

tjhop dismissed roidelapluie’s stale review via 98af38d October 7, 2024 16:07

tjhop force-pushed the chore/3.0-adopt-slog branch from 509638c to 98af38d Compare October 7, 2024 16:07

SuperQ previously approved these changes Oct 7, 2024

View reviewed changes

tjhop dismissed SuperQ’s stale review via 6ebfbd2 October 7, 2024 20:00

tjhop force-pushed the chore/3.0-adopt-slog branch from 98af38d to 6ebfbd2 Compare October 7, 2024 20:00

SuperQ approved these changes Oct 7, 2024

View reviewed changes

SuperQ merged commit 805954d into prometheus:main Oct 7, 2024
26 checks passed

tjhop mentioned this pull request Oct 8, 2024

Replace go-kit/log with log/slog #14355

Closed

tjhop mentioned this pull request Nov 21, 2024

fix!: stop unbounded memory usage from query log #15434

Merged

yeya24 mentioned this pull request Dec 1, 2024

Switch to slog thanos-io/promql-engine#497

Merged

tjhop mentioned this pull request Dec 6, 2024

chore(deps): bump github.com/prometheus/common from 0.60.0 to 0.61.0 and use version.PrometheusUserAgent #15540

Draft

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

chore!: adopt log/slog, remove go-kit/log #14906

chore!: adopt log/slog, remove go-kit/log #14906

tjhop commented Sep 15, 2024 •

edited

Loading

tjhop commented Sep 15, 2024

tjhop commented Sep 15, 2024

bboreham left a comment

bboreham Sep 22, 2024

tjhop Sep 27, 2024

bboreham Sep 22, 2024

tjhop Sep 27, 2024

tjhop Sep 27, 2024

bboreham Sep 22, 2024

tjhop Sep 27, 2024

tjhop commented Sep 27, 2024

bboreham commented Sep 29, 2024

tjhop commented Sep 29, 2024

tjhop commented Sep 30, 2024

SuperQ commented Sep 30, 2024

tjhop commented Oct 1, 2024

roidelapluie commented Oct 1, 2024

roidelapluie commented Oct 1, 2024

SuperQ commented Oct 4, 2024

tjhop commented Oct 4, 2024

roidelapluie commented Oct 7, 2024

roidelapluie left a comment

tjhop commented Oct 7, 2024

roidelapluie commented Oct 7, 2024

roidelapluie commented Oct 7, 2024

tjhop commented Oct 7, 2024

SuperQ commented Oct 7, 2024

tjhop commented Oct 7, 2024

tjhop commented Oct 7, 2024

SuperQ left a comment

		// Above level 6, the k8s client would log bearer tokens in clear-text.
		klog.ClampLevel(6)

chore!: adopt log/slog, remove go-kit/log #14906

chore!: adopt log/slog, remove go-kit/log #14906

Conversation

tjhop commented Sep 15, 2024 • edited Loading

tjhop commented Sep 15, 2024

tjhop commented Sep 15, 2024

bboreham left a comment

Choose a reason for hiding this comment

bboreham Sep 22, 2024

Choose a reason for hiding this comment

tjhop Sep 27, 2024

Choose a reason for hiding this comment

bboreham Sep 22, 2024

Choose a reason for hiding this comment

tjhop Sep 27, 2024

Choose a reason for hiding this comment

tjhop Sep 27, 2024

Choose a reason for hiding this comment

bboreham Sep 22, 2024

Choose a reason for hiding this comment

tjhop Sep 27, 2024

Choose a reason for hiding this comment

tjhop commented Sep 27, 2024

bboreham commented Sep 29, 2024

tjhop commented Sep 29, 2024

tjhop commented Sep 30, 2024

SuperQ commented Sep 30, 2024

tjhop commented Oct 1, 2024

roidelapluie commented Oct 1, 2024

roidelapluie commented Oct 1, 2024

SuperQ commented Oct 4, 2024

tjhop commented Oct 4, 2024

roidelapluie commented Oct 7, 2024

roidelapluie left a comment

Choose a reason for hiding this comment

tjhop commented Oct 7, 2024

roidelapluie commented Oct 7, 2024

roidelapluie commented Oct 7, 2024

tjhop commented Oct 7, 2024

SuperQ commented Oct 7, 2024

tjhop commented Oct 7, 2024

tjhop commented Oct 7, 2024

SuperQ left a comment

Choose a reason for hiding this comment

tjhop commented Sep 15, 2024 •

edited

Loading