[pbs-devel] [RFC proxmox v2 2/2] proxmox-log: added tracing infra

[Gabriel Goller]

Thanks for the review!

On 11/2/23 14:43, Wolfgang Bumiller wrote:
> [..]
>> +
>> +impl<S: Subscriber> Layer<S> for FilelogLayer {
>> +    fn on_event(&self, event: &Event<'_>, _ctx: Context<'_, S>) {
>> +        let mut buf = String::new();
>> +
>> +        event.record(&mut EventVisitor::new(&mut buf));
> I'd argue the above 2 lines should be part of the closure below,
> otherwise in the error case you just produce a string to throw away.
I Agree!
>> +
>> +        let logger_exists = LOGGER.try_with(|logger| {
>> +            log_to_file(&mut logger.borrow_mut(), event.metadata().level(), buf);
>> +        });
>> +        if let Err(e) = logger_exists {
>> +            error!(
> Is it wise to call log functions from within log handlers? ;-)
Hmm, yes this could be tricky...
How do we want to handle this anyway? We could panic here, but that 
seems a bit
harsh. Logging with `eprintln` is also an option, but a quite useless 
one tbh.
>> [..]
>> +pub struct WorkerTaskFilter {
>> +    in_worker_task: Arc<Mutex<bool>>,
> AFAICT you only have locks which are shortlived to set/clear/check this
> value.
> For such a thing you can use `Arc<AtomicBool>` and get rid of all the
> error handling.
Ooh, this makes it a lot easier, thanks for the heads up!I think we 
should be alright by just using `Ordering::Relaxed` everywhere, right?
>> +}
>> +
>> +impl WorkerTaskFilter {
>> +    pub fn new(in_worker_task: Arc<Mutex<bool>>) -> WorkerTaskFilter {
>> +        WorkerTaskFilter { in_worker_task }
>> +    }
>> +}
>> +
>> +impl<S: Subscriber + for<'a> LookupSpan<'a>> Filter<S> for WorkerTaskFilter {
>> +    fn on_enter(&self, id: &span::Id, ctx: Context<'_, S>) {
>> +        let metadata = ctx.metadata(id);
>> +        if let Some(m) = metadata {
>> +            if m.name() == "worker_task" {
> I'm not so happy with this.
> Now each time we poll a worker task we go through this layer system
> which uses string comparison to know whether we're currently in a worker
> task, for something that is actually rather static in the code.
> I'd much prefer a simply custom `Future` wrapping the worker task's
> future and setting this flag for the duration of the `poll()` method.
Ok, but the `Future` wrapper would only work for the task, right?
So we would need to keep the `span` version (or come up with
something different) for the thread use-case and then again have a
lot of `if (thread) { do this } else if (task) { do this }` stuff, which 
I don't
really like.
What we could do is have another `tokio::task_local!()` thingy, which 
contains a bool 'log_to_tasklog'. Then have another `scope` and 
`sync_scope` around the worker logic (So we would substitute the span 
stuff with another TLS).
> This just seems like a whole lot of overhead we don't need for such
> simple functionality. Also, the `on_enter` and `on_exit` methods make it
> look like you could easily enter and exit this type of span, but that's
> not the case. `on_exit` always stores `false`, so nested spans
> temporarily disabling and enabling the worker task log would just end up
> with a messed up state (this would need to be a counter...).
Right, I would need a counter here..
>> [..]
>> +
>> +impl Visit for EventVisitor<'_> {
>> +    fn record_debug(&mut self, field: &Field, value: &dyn fmt::Debug) {
>> +        if field.name() == "message" {
>> +            self.buf.push_str(&format!("{:?}", value));
> String implements fmt::Write. You can
>
>      use std::fmt::Write as _;
>      let _ = write!(state.buf, "{value:?}");
>
> it's possible for this to be more efficient since it does not enforce
> the creation of a separate allocated string.

Thanks!

> [..]