pkg/util/log: introduce fluent.sink.conn.errors metric to log package

[abarganier]

Logging is a critical subsystem within CRDB, but as things
are today, we have very little observability into logging
itself. For starters, we have no metrics in the logging
package at all!

This makes it difficult to observe things within the log
package. For example, if a fluent-server log sink fails
to connect to FluentBit, how can we tell? We get some STDOUT
message, but that's about it.

It's time to get some metrics into the log package.

Doing so is a bit of a tricky dance, because pretty much every
package in CRDB imports the logging package, meaning you
almost always get a circular dependency when trying to make
use of any library within pkg/util/log. Therefore, this PR
injects metrics functionality into the logging package.
It does so via a new interface called LogMetrics with
functions that enable its users to modify metrics.

The implementation of the interface can live elsewhere,
such as the metrics package itself, whe circular dependencies
aren't such a pain. We can then inject the implementation
into the log package.

With all that plumbing done, the PR also introduces a new metric,
fluent.sink.conn.errors representing fluentbit connection errors
whenever a fluent-server log sink fails to establish a connection.

We can see the metric represented below in a test, where no
fluent-server was running for a moment, before starting it.
Note that the connection errors level off once the server was
started:

Release note (ops change): This patch introduces the counter
metric fluent.sink.conn.errors to the CockroachDB tsdb,
which is exposed to /_status/vars clients as
fluent_sink_conn_errors. The metric is incremented whenever
a fluent-server log sink fails to establish a connection to
the log sink pointed to by the address for the sink in the
provided log config.

Epic: CC-9681

Addresses: #102753

[cockroach-teamcity]

This change is 

[knz]

My main feedback concerns the structure of the new package and the ownership of the registry (1st and 2nd commit). The rest checks out.

Reviewed 5 of 5 files at r1, 12 of 12 files at r2, 5 of 5 files at r3, 1 of 1 files at r4, all commit messages.
Reviewable status: complete! 0 of 0 LGTMs obtained (waiting on @abarganier and @dhartunian)

---

pkg/cli/demo.go line 235 at r3 (raw file):

			// decide how to enable logging.
			serverCfg.Stores.Specs = nil
			logMetrics := metric.NewLogMetricsRegistry()

I believe this change should be moved form the 3rd commit to the 2nd commit.

---

pkg/server/tenant.go line 651 at r3 (raw file):

		lr, ok := r.(*metric.Registry)
		if !ok {
			panic(fmt.Sprintf("unexpected type for LogMetrics registry: %T", r))

panic(errors.AssertionFailedf(...))

---

pkg/util/log/flags.go line 93 at r2 (raw file):

//
// The returned logShutdownFn can be used to gracefully shut down logging facilities.
func ApplyConfig(config logconfig.Config, metrics LogMetrics) (logShutdownFn func(), err error) {

I don't love this change.

It seems to me that the (new) logmetrics package should instantiate the registry in a init function as a singleton, inject it into the log package only once (with a specific function just for that purpose).

Then the cli/start code would retrieve a reference to that singleton for passing to the server initialization.

(I am especially concerned by CLI unit tests that call start repeatedly. I don't think we want each iteration of the unit test to create a new metric registry.)

---

pkg/util/metric/log_metrics.go line 11 at r1 (raw file):

// licenses/APL.txt.

package metric

my preference would be to have the log metrics defined in a sub-package of log, e.g. util/log/logmetrics.
This way someone who is exploring the code around logging gets a "full picture" from the sub-directory tree.

---

pkg/util/metric/log_metrics.go line 68 at r1 (raw file):

	l.mu.Lock()
	defer l.mu.Unlock()
	if counter, ok := l.mu.counters[metric]; ok {

It seems to me that if the metric does not exist, the program should crash -- it would be an implementation bug.
Maybe a panic? panic(errors.AssertionFailedf(...))

[abarganier]

Thanks for the feedback, it was very helpful. RFAL!

Reviewable status: complete! 0 of 0 LGTMs obtained (waiting on @dhartunian and @knz)

---

pkg/server/tenant.go line 651 at r3 (raw file):

Previously, knz (Raphael 'kena' Poss) wrote…

panic(errors.AssertionFailedf(...))

Ack, but no longer needed as we don't need to worry about this case anymore 😌

---

pkg/cli/demo.go line 235 at r3 (raw file):

Previously, knz (Raphael 'kena' Poss) wrote…

I believe this change should be moved form the 3rd commit to the 2nd commit.

Ack - no longer relevant as this entire init process has been greatly simplified thanks to your other comment 🙂

---

pkg/util/log/flags.go line 93 at r2 (raw file):

Previously, knz (Raphael 'kena' Poss) wrote…

I don't love this change.

It seems to me that the (new) logmetrics package should instantiate the registry in a init function as a singleton, inject it into the log package only once (with a specific function just for that purpose).

Then the cli/start code would retrieve a reference to that singleton for passing to the server initialization.

(I am especially concerned by CLI unit tests that call start repeatedly. I don't think we want each iteration of the unit test to create a new metric registry.)

Thanks for this advice, I somehow felt the entire thing was still too brittle.

Using an init function made everything much simpler & we no longer have to worry about nil log metrics.

I ended up adding an init to the MetricsRecorder file for this, since the new logmetrics package isn't imported many places otherwise. LMK if you think there's a better place for this.

---

pkg/util/metric/log_metrics.go line 11 at r1 (raw file):

Previously, knz (Raphael 'kena' Poss) wrote…

my preference would be to have the log metrics defined in a sub-package of log, e.g. util/log/logmetrics.
This way someone who is exploring the code around logging gets a "full picture" from the sub-directory tree.

Done.

---

pkg/util/metric/log_metrics.go line 68 at r1 (raw file):

Previously, knz (Raphael 'kena' Poss) wrote…

It seems to me that if the metric does not exist, the program should crash -- it would be an implementation bug.
Maybe a panic? panic(errors.AssertionFailedf(...))

Agreed & Done.

[knz]

Reviewed 4 of 23 files at r5, 2 of 16 files at r6, 4 of 17 files at r7, 14 of 14 files at r8, all commit messages.
Reviewable status: complete! 0 of 0 LGTMs obtained (waiting on @abarganier and @dhartunian)

---

pkg/server/server.go line 1844 at r8 (raw file):

	// Grab the log metrics registry.
	r := log.LogMetricsRegistry()

nit: you could retrieve the registry directly with the right type (*metric.Registry) if you put the accessor in package logmetrics instead.

---

pkg/server/tenant.go line 646 at r8 (raw file):

	// Grab the log metrics registry.
	r := log.LogMetricsRegistry()

ditto

---

pkg/server/status/recorder.go line 134 at r8 (raw file):

		nodeRegistry *metric.Registry
		// logRegistry contains the global metrics registry used by the logging
		// package. NB: code paths exist where this registry is never initialized,

nit: pls provide an example of such code path.

---

pkg/server/status/recorder.go line 159 at r8 (raw file):

	// The logmetrics package is not imported by much, meaning
	// that its own init function is not a reliable place to initialize
	// log metrics. Being that the recorder is the primary user of

I disagree. you can use

import (
   _ ".../util/log/logmetrics"
)

at the top of this file, and you'd get the right behavior.

---

pkg/server/status/recorder.go line 254 at r8 (raw file):

			nodeReg.AddLabel("node_id", strconv.Itoa(int(desc.NodeID)))
			if !mr.hasLabel(logReg.GetLabels(), "node_id") {
				logReg.AddLabel("node_id", strconv.Itoa(int(desc.NodeID)))

This does not work for me. The log metric registry should be read-only.

If we have multiple in-memory servers running one after the other (e.g. think about multiple go tests in one package), the logic here would make the first one "win" the right to get its node_id in there. The others that then access the log package afterwards would not have "their" node_id in there and the person looking at the log output would be utterly confused

Is there a way to have the counters in the singleton in logmetrics, and the labels in an object that's different in each serveR?

---

pkg/util/log/clog.go line 115 at r8 (raw file):

}

// LogMetricsRegistry returns the metrics registry used by

As explained above, you can put this accessor in logmetrics. The Set function below can remain here.

[abarganier]

Again, great feedback. I've made some changes, PTAL!

Reviewable status: complete! 0 of 0 LGTMs obtained (waiting on @dhartunian and @knz)

---

pkg/server/server.go line 1844 at r8 (raw file):

Previously, knz (Raphael 'kena' Poss) wrote…

nit: you could retrieve the registry directly with the right type (*metric.Registry) if you put the accessor in package logmetrics instead.

Thanks for the tip, this worked well and cleaned up the interface. Done.

---

pkg/server/tenant.go line 646 at r8 (raw file):

Previously, knz (Raphael 'kena' Poss) wrote…

ditto

Done.

---

pkg/server/status/recorder.go line 134 at r8 (raw file):

Previously, knz (Raphael 'kena' Poss) wrote…

nit: pls provide an example of such code path.

Ah, this was leftovers that I missed/forgot to remove. No such case exists anymore, since the recorder imports pkg/util/log/logmetrics, which ensures initialization.

Removed.

---

pkg/server/status/recorder.go line 159 at r8 (raw file):

Previously, knz (Raphael 'kena' Poss) wrote…

I disagree. you can use

import (
   _ ".../util/log/logmetrics"
)

at the top of this file, and you'd get the right behavior.

Thanks for this, it worked nicely. Done.

---

pkg/server/status/recorder.go line 254 at r8 (raw file):

Previously, knz (Raphael 'kena' Poss) wrote…

This does not work for me. The log metric registry should be read-only.

If we have multiple in-memory servers running one after the other (e.g. think about multiple go tests in one package), the logic here would make the first one "win" the right to get its node_id in there. The others that then access the log package afterwards would not have "their" node_id in there and the person looking at the log output would be utterly confused

Is there a way to have the counters in the singleton in logmetrics, and the labels in an object that's different in each serveR?

Good point, thank you for bringing this up.

What we can do is export a function from the package, logmetrics.NewRegistry(), that adds the same singleton counters to a fresh registry per-server. This way, each server can add its own labels without anything colliding.

I've implemented this and found it worked nicely during testing. LMK your thoughts.

---

pkg/util/log/clog.go line 115 at r8 (raw file):

Previously, knz (Raphael 'kena' Poss) wrote…

As explained above, you can put this accessor in logmetrics. The Set function below can remain here.

Done, great tip! Thanks.

[knz]

Reviewed 7 of 14 files at r9, 2 of 3 files at r10, 5 of 5 files at r11, 1 of 1 files at r12, all commit messages.
Reviewable status: complete! 0 of 0 LGTMs obtained (waiting on @dhartunian)

[abarganier]

TFTR!

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)