From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: from firstgate.proxmox.com (firstgate.proxmox.com [212.224.123.68]) (using TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits) key-exchange X25519 server-signature RSA-PSS (2048 bits)) (No client certificate requested) by lists.proxmox.com (Postfix) with ESMTPS id E89799E9C4 for ; Thu, 2 Nov 2023 15:58:04 +0100 (CET) Received: from firstgate.proxmox.com (localhost [127.0.0.1]) by firstgate.proxmox.com (Proxmox) with ESMTP id CAAF912E83 for ; Thu, 2 Nov 2023 15:58:04 +0100 (CET) Received: from proxmox-new.maurer-it.com (proxmox-new.maurer-it.com [94.136.29.106]) (using TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits) key-exchange X25519 server-signature RSA-PSS (2048 bits) server-digest SHA256) (No client certificate requested) by firstgate.proxmox.com (Proxmox) with ESMTPS for ; Thu, 2 Nov 2023 15:58:03 +0100 (CET) Received: from proxmox-new.maurer-it.com (localhost.localdomain [127.0.0.1]) by proxmox-new.maurer-it.com (Proxmox) with ESMTP id 90B8543C4E for ; Thu, 2 Nov 2023 15:58:03 +0100 (CET) Message-ID: Date: Thu, 2 Nov 2023 15:58:02 +0100 MIME-Version: 1.0 User-Agent: Mozilla Thunderbird To: Wolfgang Bumiller Cc: pbs-devel@lists.proxmox.com References: <20231025135325.198073-1-g.goller@proxmox.com> <20231025135325.198073-3-g.goller@proxmox.com> Content-Language: en-US From: Gabriel Goller In-Reply-To: Content-Type: text/plain; charset=UTF-8; format=flowed Content-Transfer-Encoding: 7bit X-SPAM-LEVEL: Spam detection results: 0 AWL -0.273 Adjusted score from AWL reputation of From: address BAYES_00 -1.9 Bayes spam probability is 0 to 1% DMARC_MISSING 0.1 Missing DMARC policy KAM_DMARC_STATUS 0.01 Test Rule for DKIM or SPF Failure with Strict Alignment SPF_HELO_NONE 0.001 SPF: HELO does not publish an SPF Record SPF_PASS -0.001 SPF: sender matches SPF record T_SCC_BODY_TEXT_LINE -0.01 - Subject: Re: [pbs-devel] [RFC proxmox v2 2/2] proxmox-log: added tracing infra X-BeenThere: pbs-devel@lists.proxmox.com X-Mailman-Version: 2.1.29 Precedence: list List-Id: Proxmox Backup Server development discussion List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Thu, 02 Nov 2023 14:58:05 -0000 Thanks for the review! On 11/2/23 14:43, Wolfgang Bumiller wrote: > [..] >> + >> +impl Layer 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>, > AFAICT you only have locks which are shortlived to set/clear/check this > value. > For such a thing you can use `Arc` 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>) -> WorkerTaskFilter { >> + WorkerTaskFilter { in_worker_task } >> + } >> +} >> + >> +impl LookupSpan<'a>> Filter 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! > [..]