From mboxrd@z Thu Jan  1 00:00:00 1970
Return-Path: <l.wagner@proxmox.com>
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 05BD2B4264
 for <pbs-devel@lists.proxmox.com>; Fri,  1 Dec 2023 10:56:50 +0100 (CET)
Received: from firstgate.proxmox.com (localhost [127.0.0.1])
 by firstgate.proxmox.com (Proxmox) with ESMTP id D971214C08
 for <pbs-devel@lists.proxmox.com>; Fri,  1 Dec 2023 10:56:49 +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 <pbs-devel@lists.proxmox.com>; Fri,  1 Dec 2023 10:56:49 +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 24CF24356D
 for <pbs-devel@lists.proxmox.com>; Fri,  1 Dec 2023 10:56:48 +0100 (CET)
Message-ID: <48fb398e-d7d4-4e7b-a313-057953b82aca@proxmox.com>
Date: Fri, 1 Dec 2023 10:56:47 +0100
MIME-Version: 1.0
User-Agent: Mozilla Thunderbird
Content-Language: de-AT, en-US
To: Proxmox Backup Server development discussion
 <pbs-devel@lists.proxmox.com>, Gabriel Goller <g.goller@proxmox.com>
References: <20231103112849.71953-1-g.goller@proxmox.com>
 <20231103112849.71953-2-g.goller@proxmox.com>
From: Lukas Wagner <l.wagner@proxmox.com>
Cc: Wolfgang Bumiller <w.bumiller@proxmox.com>
In-Reply-To: <20231103112849.71953-2-g.goller@proxmox.com>
Content-Type: text/plain; charset=UTF-8; format=flowed
Content-Transfer-Encoding: 7bit
X-SPAM-LEVEL: Spam detection results:  0
 AWL -0.008 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 -
 URIBL_BLOCKED 0.001 ADMINISTRATOR NOTICE: The query to URIBL was blocked. See
 http://wiki.apache.org/spamassassin/DnsBlocklists#dnsbl-block for more
 information. [lib.rs]
Subject: Re: [pbs-devel] [PATCH proxmox 1/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
 <pbs-devel.lists.proxmox.com>
List-Unsubscribe: <https://lists.proxmox.com/cgi-bin/mailman/options/pbs-devel>, 
 <mailto:pbs-devel-request@lists.proxmox.com?subject=unsubscribe>
List-Archive: <http://lists.proxmox.com/pipermail/pbs-devel/>
List-Post: <mailto:pbs-devel@lists.proxmox.com>
List-Help: <mailto:pbs-devel-request@lists.proxmox.com?subject=help>
List-Subscribe: <https://lists.proxmox.com/cgi-bin/mailman/listinfo/pbs-devel>, 
 <mailto:pbs-devel-request@lists.proxmox.com?subject=subscribe>
X-List-Received-Date: Fri, 01 Dec 2023 09:56:50 -0000

Hello,
I'm currently evaluating how this crate could be used from the
proxmox-perl-rs bindings.

The status quo there is that we initialize an envlogger, but that leads 
to the problem that logs are only visible for tasks, since envlogger 
does log to stdout (or was it stderr?).
To differentiate between 'daemon context' and 'fork worker context' we 
obviously cannot rely on a tokio task-local var there.
Maybe it would make sense to have an alternative mode (gated via 
feature-flags) with a static flag, which is then set in 
RestEnvironment::fork_worker via a setter?
The dependency on tokio should then also be feature-gated, since we 
don't want to have to pull in tokio as a dep for proxmox-perl-rs yet.

@Wolfgang what do you think about this?


On 11/3/23 12:28, Gabriel Goller wrote:
> diff --git a/proxmox-log/src/lib.rs b/proxmox-log/src/lib.rs
> new file mode 100644
> index 0000000..15fa22d
> --- /dev/null
> +++ b/proxmox-log/src/lib.rs
> @@ -0,0 +1,34 @@
> +use std::{cell::RefCell, env};
> +use syslog_tasklog_layer::SyslogAndTasklogLayer;
> +use tracing_log::{AsLog, LogTracer};
> +use tracing_subscriber::filter::LevelFilter;
> +use tracing_subscriber::prelude::*;
> +
> +mod file_logger;
> +pub use file_logger::{FileLogOptions, FileLogger};
> +
> +mod syslog_tasklog_layer;
> +
> +tokio::task_local! {
> +    pub static LOGGER: RefCell<FileLogger>;
> +    pub static WARN_COUNTER: RefCell<u64>;
> +}



> +
> +pub fn init_logger(
> +    env_var_name: &str,
> +    default_log_level: LevelFilter,
> +    application_name: &str,
> +) -> Result<(), anyhow::Error> {
> +    let mut log_level = default_log_level;
> +    if let Ok(v) = env::var(env_var_name) {
> +        if let Ok(l) = v.parse::<LevelFilter>() {
> +            log_level = l;
> +        }
> +    }
> +    let registry = tracing_subscriber::registry()
> +        .with(SyslogAndTasklogLayer::new(application_name.to_string()).with_filter(log_level));
> +
> +    tracing::subscriber::set_global_default(registry)?;
> +    LogTracer::init_with_filter(log_level.as_log())?;
> +    Ok(())
> +}
> diff --git a/proxmox-log/src/syslog_tasklog_layer.rs b/proxmox-log/src/syslog_tasklog_layer.rs
> new file mode 100644
> index 0000000..344a514
> --- /dev/null
> +++ b/proxmox-log/src/syslog_tasklog_layer.rs
> @@ -0,0 +1,106 @@
> +use std::fmt::Write as _;
> +use std::sync::Arc;
> +use std::sync::Mutex;
> +
> +use syslog::{Formatter3164, LoggerBackend};
> +use tracing::field::Field;
> +use tracing::field::Visit;
> +use tracing::Event;
> +use tracing::Level;
> +use tracing::Subscriber;
> +use tracing_subscriber::layer::Context;
> +use tracing_subscriber::Layer;
> +
> +use crate::FileLogger;
> +use crate::LOGGER;
> +use crate::WARN_COUNTER;
> +
> +pub struct SyslogAndTasklogLayer {
> +    syslog_logger: Arc<Mutex<syslog::Logger<LoggerBackend, Formatter3164>>>,
> +}
> +
> +impl SyslogAndTasklogLayer {
> +    pub fn new(application_name: String) -> Self {
> +        let formatter = Formatter3164 {
> +            facility: syslog::Facility::LOG_DAEMON,
> +            process: application_name,
> +            ..Formatter3164::default()
> +        };
> +
> +        // we panic here if we can't initialize the syslogger
> +        let logger = syslog::unix(formatter)
> +            .map_err(|e| {
> +                anyhow::Error::new(std::io::Error::new(
> +                    std::io::ErrorKind::Other,
> +                    e.description(),
> +                ))
> +            })
> +            .unwrap();
> +
> +        let logger = Arc::new(Mutex::new(logger));
> +
> +        Self {
> +            syslog_logger: logger,
> +        }
> +    }
> +}
> +
> +impl<S: Subscriber> Layer<S> for SyslogAndTasklogLayer {
> +    fn on_event(&self, event: &Event<'_>, _ctx: Context<'_, S>) {
> +        let mut buf = String::new();
> +        event.record(&mut EventVisitor::new(&mut buf));
> +        let level = event.metadata().level();
> +
> +        let result = LOGGER.try_with(|logger| {
> +            log_to_file(&mut logger.borrow_mut(), level, &buf);
> +        });
> +        if result.is_err() || *level == Level::ERROR {
                                                      ^
Shouldn't this be configurable?
Or, alternatively would it make sense of drop this comparison and only 
rely on the env var (e.g. PBS_LOG)?

> +            log_to_syslog(&mut self.syslog_logger.lock().unwrap(), level, &buf);
> +        }
> +    }
> +}
> +
> +fn log_to_syslog(
> +    logger: &mut syslog::Logger<LoggerBackend, Formatter3164>,
> +    level: &Level,
> +    buf: &String,
> +) {
(...)

-- 
- Lukas