Skip to content

edac: Fix printf-style formatting in slog call - #3759

Open
at-blacknight wants to merge 1 commit into
prometheus:masterfrom
at-blacknight:fix-edac-slog
Open

edac: Fix printf-style formatting in slog call#3759
at-blacknight wants to merge 1 commit into
prometheus:masterfrom
at-blacknight:fix-edac-slog

Conversation

@at-blacknight

Copy link
Copy Markdown

@SuperQ — small follow-up to #3734.

That PR converted the ch*_ue_count error return into a debug log, and the fmt.Errorf format string came across with it. slog does no formatting, so the verbs are logged literally and the arguments after the message are consumed as key/value pairs:

level=DEBUG source=edac_linux.go:204 msg="couldn't get ue_count for controller/csrow/channel %s/%s/%s: %w" collector=edac 0=2 0="open /sys/devices/system/edac/mc/mc0/csrow2/ch0_ue_count: no such file or directory"

controllerNumber became a key with csrowNumber as its value, and channelNumber became a second key with the error as its value, so the controller/csrow/channel the message meant to report are no longer readable and the record carries 0 twice. Where the controller and channel numbers differ the second key is named after the channel instead, so the key set changes from one iteration to the next. Under --log.format=json that is an object with a repeated key, and parsers silently drop one of the values.

%w compounds it: that is an fmt.Errorf directive, not a valid Printf verb.

After:

level=DEBUG source=edac_linux.go:204 msg="couldn't get ue_count" collector=edac controller=0 csrow=2 channel=0 err="open /sys/devices/system/edac/mc/mc0/csrow2/ch0_ue_count: no such file or directory"

Reproduces on the existing fixtures: mc0/csrow2 has ch0_ce_count but no ch0_ue_count, so running with --log.level=debug against collector/fixtures/sys hits the branch. Present in v1.12.1 and on master. Metric output is unchanged — 20 node_edac series before and after, identical — and gofmt, go vet and end-to-end-test.sh are clean.

On why CI didn't catch it, in case it's useful: go vet's slog analyzer only fires when a key-position argument isn't a string or the arguments don't pair up, and here the count is even and all three are strings, so the call looks well formed to it. The e2e test does execute this line with debug logging enabled, but only diffs the metrics output. I have a small go/ast test that rejects Printf verbs in slog messages across the collector package — happy to raise it separately if you'd want it, equally happy to leave it.

The Debug call added in prometheus#3734 passes printf verbs and positional arguments to
slog, which does not format them. The format string is logged verbatim and the
arguments are consumed as key/value pairs, so controller and channel numbers
become attribute keys: a duplicate key when the two are equal, and otherwise a
key whose name changes on every iteration. Under --log.format=json that is an
object with a repeated key, and parsers silently drop one of the values. The
csrow number and the error, the two things worth reading, are the only parts
that survive, and they appear as values of meaningless keys.

%w compounds it: that is an fmt.Errorf directive and not a valid Printf verb,
left behind when the error return this replaced was converted to a log line.

Pass the values as named attributes instead. Metric output is unchanged.

Signed-off-by: Adam Butler <github@at-blacknight.com>
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.

1 participant