[pbs-devel] applied: [PATCH v3] worker_task: write result message manually, bypassing tracing

[Wolfgang Bumiller]

applied, but modified the commit message to point to the affected
crates

On Tue, Feb 18, 2025 at 05:55:03PM +0100, Gabriel Goller wrote:
> The workertasks currently get their status from parsing the log
> messages in the task-log file. The problem is that if these messages are
> filtered – which is now possible using the PBS_LOG env variable – some
> workertasks will end up with a "stopped: unknown" status. This is not
> desirable so write the message manually to the workertask file and
> bypass tracing.
> 
> This way we are guaranteed that, regardless of the max logging level the
> user sets, the final message (and status) is written.
> 
> Signed-off-by: Gabriel Goller <g.goller at proxmox.com>
> ---
> 
> Changelog:
> v3, thanks @Wobu:
>  * move function to LogContext get the LogContext in the worker_task
>    module.
> v2:
>  * remove jank (detect workertask failure based on return value instead
>    of message)
> 
> 
>  proxmox-log/src/lib.rs                 | 10 ++++++++++
>  proxmox-rest-server/src/worker_task.rs | 16 ++++++++++++++--
>  2 files changed, 24 insertions(+), 2 deletions(-)
> 
> diff --git a/proxmox-log/src/lib.rs b/proxmox-log/src/lib.rs
> index 8c74e42b618d..0362b2ba36d6 100644
> --- a/proxmox-log/src/lib.rs
> +++ b/proxmox-log/src/lib.rs
> @@ -129,6 +129,15 @@ impl LogContext {
>      pub fn state(&self) -> &Arc<Mutex<FileLogState>> {
>          &self.logger
>      }
> +
> +    /// Log directly to the underlying FileLogger, without going through tracing.
> +    ///
> +    /// Using this function we can guarantee that a log message will be in the tasklog file,
> +    /// regardless of the tracing layers/filters.
> +    pub fn log_unfiltered(&self, msg: &str) {
> +        let mut logger = self.logger.lock().unwrap();
> +        logger.logger.log(msg);
> +    }
>  }
>  
>  fn journald_or_stderr_layer<S>() -> Box<dyn tracing_subscriber::Layer<S> + Send + Sync>
> @@ -191,3 +200,4 @@ pub fn init_cli_logger(
>      LogTracer::init_with_filter(log_level.as_log())?;
>      Ok(())
>  }
> +
> diff --git a/proxmox-rest-server/src/worker_task.rs b/proxmox-rest-server/src/worker_task.rs
> index 24e2676e69c7..5f45365f00e2 100644
> --- a/proxmox-rest-server/src/worker_task.rs
> +++ b/proxmox-rest-server/src/worker_task.rs
> @@ -14,7 +14,7 @@ use serde::{Deserialize, Serialize};
>  use serde_json::{json, Value};
>  use tokio::signal::unix::SignalKind;
>  use tokio::sync::{oneshot, watch};
> -use tracing::{info, warn};
> +use tracing::{error, info, warn};
>  
>  use proxmox_daemon::command_socket::CommandSocket;
>  use proxmox_lang::try_block;
> @@ -1025,7 +1025,19 @@ impl WorkerTask {
>      /// Log task result, remove task from running list
>      pub fn log_result(&self, result: &Result<(), Error>) {
>          let state = self.create_state(result);
> -        self.log_message(state.result_text());
> +
> +        // Write the result manually to the workertask file. We don't want to filter or process
> +        // this message by the logging system. This also guarantees the result message will be in
> +        // the file, regardless of the logging level.
> +        match LogContext::current() {
> +            Some(context) => {
> +                context.log_unfiltered(&state.result_text());
> +                if result.is_err() {
> +                    eprintln!("{}", &state.result_text());
> +                }
> +            },
> +            None => error!("error writing task result to the tasklog"),
> +        }
>  
>          WORKER_TASK_LIST.lock().unwrap().remove(&self.upid.task_id);
>          // this wants to access WORKER_TASK_LIST, so we need to drop the lock above
> -- 
> 2.39.5