Proposal: remove our usage of log::log_enabled! using a global Targets in ore

[guswynn]

(This is primarily aimed at @benesch)

The way that log::log_enabled! (and my soon-to-be-landed tracing::enabled!) work with "per-layer filtering" in tracing means that they return true if ANY layer in the subscriber stack returns true. For enabling rdkafka debug mode, we want to check if only the fmt layer is enabled for the rdkafka target. The way we currently work around this is by cloning the fmt layer's target filter onto all our tracing layers. My understanding is that a primary reason we have seen regressions in the past is because of

materialize/src/dataflow/src/source/kafka.rs

Line 539 in d10ac1e

if log::log_enabled!(target: "librdkafka", log::Level::Debug) {

accidentally being enabled.

I suggested tokio-rs/tracing#1889 to the tracing team to create a version of enabled! that returned false if ANY of the layers were disabled, but instead they suggested that I just keep a copy of my Targets layer around and query that.

So I propose we do the following:

• I implement this api: guswynn/tracing@4890c81#diff-c190c4f696381edb3ee10b89ceb505f047616fd2478ce3eb0d24868e356b74c8R341, which I have confirmed will be merged by the tracing folks
• We add a static FMT_FILTER: once_cell::OnceCell<Targets> global into ore
• materialized main clones the fmt layer's Targets and called OnceCell::set with it
• We replace the log_enabled! lines with FMT_FILTER.get().map(|t| t.enabled_for("rdkafka", tracing::Level::DEBUG)).unwrap_or(false);
• We bypass https://github.com/fede1024/rust-rdkafka/blob/master/src/config.rs#L288-L298 in rdkafka by using the https://docs.rs/rdkafka/latest/rdkafka/config/struct.ClientConfig.html#method.set_log_level to set it correctly using the same global
• We then can remove the target filter from the Metrics layer (and in the future, dont worry about the console layer, and the opentel layer)

I think we can ALSO optionally add global EnvFilter if we really want field-level filtering, but EnvFilter only works globally, for special debugging scenarios.

Alternatives

• We do nothing, and leave the filters on all layers
  • The tokio-console layer SHOULD already filter out spans that aren't from tokio, so it MAY work as we want it to, but I have not tested how this interacts with enabled!
• We come up with some other way to communicate the debug state to rdkafka

[benesch]

Do we not want the default enabled! behavior? Like, if the console is enabled, don't we in theory want to enable librdkafka's debug logs so that librdkafka shows up? Very willing to believe that I'm missing something.

[benesch]

Oh, I think I see. Setting debug=true in librdkafka is expensive because it causes a lot of extra string formatting internally, yeah? And since librdkafka is in C, the tracing magic of deferring string formatting doesn't apply. So we're looking to special case the heck out of librdkafka's debug logs.

Rather than trying to back this information out via globals and the enabled! macro, how about we add a librdkafka_debug: bool to the dataflow server configuration? And then the materialized main function can do whatever tracing-related logic it wants to determine whether that bool should be true or false.

I think downstream in rust-rdkafka it still makes sense to use the enabled! macro here, yeah? Since most folks won't have a MetricsRecorderLayer that's observing events at all levels.

[guswynn]

@benesch piping that value through seems fine to me!

So the new plan is:

• I implement this api: guswynn/tracing@4890c81#diff-c190c4f696381edb3ee10b89ceb505f047616fd2478ce3eb0d24868e356b74c8R341, which I have confirmed will be merged by the tracing folks
• we pipefmt_layer_targets.enabled_for("rdkafka", tracing::Level::DEBUG) through in the dataflow layer
• We bypass https://github.com/fede1024/rust-rdkafka/blob/master/src/config.rs#L288-L298 in rdkafka by using the docs.rs/rdkafka/latest/rdkafka/config/struct.ClientConfig.html#method.set_log_level to set it correctly using the same piped-through value
• We then can remove the target filter from the Metrics layer (and in the future, dont worry about the console layer, and the opentel layer)

and then we also separately do the rdkafka cleanup by adding a tracing feature which:

• uses tracing instead of log
• switch to tracing::enabled!
• remove MzClientContext

(i already have a local commit with most of this)

[guswynn]

I think we will need to pipe through a tracing::Level instead of a boolean, but thats just finer details

[benesch]

Yeah, that sounds right to me!!

[guswynn]

rdkafka side: fede1024/rust-rdkafka#440

[guswynn]

working on the second part: guswynn@cdafa32 requires a lot of piping values through, posting here so people can see my WIP