server: write pebble log messages to storage channel

[renatolabs]

Previously, when setting up the server, the pebble engine would be initialized with Pebble's default logger. The reason for this is that the pebble initialization code calls EnsureDefaults on the configuration options before checking if the options.Logger is nil/unset. At that point, it will never be unset, as EnsureDefaults will set the logger to pebble.DefaultLogger if it was not previously set.

This change overwrites the pebble logger if its found to be the DefaultLogger. We never want to use pebble's DefaultLogger in CRDB as that would mean pebble would use the standard library log package, making every message emitted by Pebble to be treated as INFO level messages, regardless of severity (including log.Fatal calls).

Related to #83079.

Fixes #72683.
Fixes #90483.

Release note: None.

[cockroach-teamcity]

This change is 

[renatolabs]

cockroach.log before:

(nothing)

cockroach.log after:

F221021 19:42:58.902679 625530 3@pebble/internal/base/filenames.go:167 ⋮ [n1,s1,pebble] 915  ‹13314777078855381451.sst›:
F221021 19:42:58.902679 625530 3@pebble/internal/base/filenames.go:167 ⋮ [n1,s1,pebble] 915 +open ‹/mnt/data1/cockroach/13314777078855381451.sst›: no such file or directory
F221021 19:42:58.902679 625530 3@pebble/internal/base/filenames.go:167 ⋮ [n1,s1,pebble] 915 +directory contains 2910 files, 13 unknown, 2889 tables, 3 logs, 2 manifests
F221021 19:42:58.902679 625530 3@pebble/internal/base/filenames.go:167 ⋮ [n1,s1,pebble] 915 !goroutine 625530 [running]:

<stracktrace dumps>

[renatolabs]

Another approach to fix the issue would be to move the log initialization code so that it sits before the EnsureDefaults() call. I chose to keep the log setup logic where it is because: 1. It stays near other cfg.Opts-related code; and 2. Makes it explicit we never want pebble.DefaultLogger.

That said, I'm open to moving the code around if that's deemed to be more appropriate.

[joshimhoff]

My initial thought was this was a test-only bug, but based on this bug fix, does this affect production CRDB too?

If it is NOT a test-only bug, then I bet it is a regression that only affects certain CRDB versions, etc., since we use pebble logs all the time in production. Is that correct? If it is, when was the regression introduced, at least in terms of major versions?

Also, want to mark this PR as fixing #90483?

[renatolabs]

does this affect production CRDB too?

Yes, it affects production CRDB too.

only affects certain CRDB versions, etc., since we use pebble logs all the time in production. Is that correct?

It seems like this has been the case for some time. The pebble.log logs that you are probably familiar with are event logs; these are set to the appropriate channel:

cockroach/pkg/storage/pebble.go

Lines 918 to 924 in 62175c9

	cfg.Opts.EventListener = pebble.TeeEventListener(
	pebble.MakeLoggingEventListener(pebbleLogger{
	ctx: logCtx,
	depth: 2, // skip over the EventListener stack frame
	}),
	p.makeMetricEtcEventListener(ctx),
	)

[joshimhoff]

It seems like this has been the case for some time. The pebble.log logs that you are probably familiar with are event logs.

Ah! Nice. Great find then.

[knz]

nice 💯

[knz]

nice 💯

This might be the fix to #72683. Can you check?

[renatolabs]

nice 💯

This might be the fix to #72683. Can you check?

This change does fix that issue. The log message reported there is now displayed as below. Commit and PR messages updated to reflect that.

I221025 15:46:11.127184 5156 3@pebble/ingest.go:763 ⋮ [n2,s2,pebble] 184  ingest failed to remove original file: invalid argument
I221025 15:46:11.127453 5156 3@pebble/ingest.go:763 ⋮ [n2,s2,pebble] 185  ingest failed to remove original file: invalid argument
I221025 15:46:11.127458 5156 3@pebble/ingest.go:763 ⋮ [n2,s2,pebble] 186  ingest failed to remove original file: invalid argument

TFTR!

[renatolabs]

bors r=knz

[craig]

Build failed (retrying...):

• Bazel Essential CI (Cockroach)

[craig]

Build failed (retrying...):

• Bazel Essential CI (Cockroach)

[craig]

Build succeeded:

• Bazel Essential CI (Cockroach)