[pbs-devel] [RFC proxmox-backup 0/2] Tasklog rewrite with tracing

[Gabriel Goller]

On 10/23/23 16:33, Thomas Lamprecht wrote:

> [..]
> - if in worker task:
>    - log info and higher to worker task log
>    - mirror error level to syslog too
>
> - if not in worker task:
>    - log warnings and higher to syslog
>
> It's slightly magic, but fit our reality quite well.
>
> For forcing other logs, or a debug level, to a target too, one then
> could provide environment variables, or an API command-socket command
> for a dynamic change of max-level to log – especially the latter is
> a bit orthogonal to this and should be done later.
Yes, sounds good! I should be able to implement this.
> semi-related: I didn't check the series in detail, so sorry if already
> answered there, but how's the story for logging specific spans?
>
> As logging levels are normally rather coarse, especially on complex
> tasks one can have a log going on, and so it can be helpful to, e.g.,
> enable debug logging only for some specific "topics", especially if
> one is debugging an issue that a user faces, but one cannot (easily)
> reproduce themselves. But, I guess that is unrelated from your current
> work here, or did you already think about that?
>
> (the place I'd want something like that the most is pmxcfs, as there
> you can currently only decide if you want very sparse information or
> every detail times ten for about every file operation happening, very
> frustrating)
Hmm this is a tricky one... With the current RFC this is only possible by
reloading a specific layer (syslog or task_log) using another log-level (and
thus we need to pass a reload-handle around, which is not optimal).

But, if this is frequent, we could add another layer (conveniently called
debug_layer or something) that is only active inside a span with a specific
name and prints all levels to syslog. This layer would only be used when
debugging and shouldn't impact runtime performance that much (although I
will check this).

So you would basically wrap your critical code with a span:

fn super_long_function_with_critical_stuff() {
     let span_guard = tracing::span!(Level::INFO, "debug").entered();
     // other code that emits logs
     // the `span_guard` will be dropped at the end and the span will end
     // we can also end the span manually using `span.exit()`
}

We then have a special layer, that will check if the log is in a span
with name 'debug' and will write to syslog without checking the
max log level.