proxmox-log: add tracing infrastructure

Add the `proxmox_log` crate which includes the new logging infra.
Export the `init_logger` function, which creates the `tracing` logger
that includes the default subscriber and two layer.

The first layer comes from the tracing-journald crate and logs
everything that does not come from a worker-task/thread to the syslog.
The second layer filters the exact opposite and writes the logs into the
corresponding task-log file.

Reviewed-by: Lukas Wagner <l.wagner@proxmox.com>
Tested-by: Lukas Wagner <l.wagner@proxmox.com>
Signed-off-by: Gabriel Goller <g.goller@proxmox.com>
This commit is contained in:
Gabriel Goller 2024-07-09 16:20:10 +02:00 committed by Wolfgang Bumiller
parent f1920d9b94
commit 0550659cd1
9 changed files with 368 additions and 0 deletions

View File

@ -19,6 +19,7 @@ members = [
"proxmox-io",
"proxmox-lang",
"proxmox-ldap",
"proxmox-log",
"proxmox-login",
"proxmox-metrics",
"proxmox-network-api",
@ -104,6 +105,10 @@ tokio = "1.6"
tokio-openssl = "0.6.1"
tokio-stream = "0.1.0"
tower-service = "0.3.0"
tracing = "0.1"
tracing-journald = "0.3.0"
tracing-log = { version = "0.1.3", default-features = false }
tracing-subscriber = "0.3.16"
url = "2.2"
walkdir = "2"
webauthn-rs = "0.3"
@ -121,6 +126,7 @@ proxmox-http-error = { version = "0.1.0", path = "proxmox-http-error" }
proxmox-human-byte = { version = "0.1.0", path = "proxmox-human-byte" }
proxmox-io = { version = "1.1.0", path = "proxmox-io" }
proxmox-lang = { version = "1.3", path = "proxmox-lang" }
proxmox-log= { version = "0.1.0", path = "proxmox-log" }
proxmox-login = { version = "0.1.0", path = "proxmox-login" }
proxmox-product-config = { version = "0.2.0", path = "proxmox-product-config" }
proxmox-config-digest = { version = "0.1.0", path = "proxmox-config-digest" }

23
proxmox-log/Cargo.toml Normal file
View File

@ -0,0 +1,23 @@
[package]
name = "proxmox-log"
version = "0.1.0"
authors.workspace = true
edition.workspace = true
license.workspace = true
repository.workspace = true
description = "Logging infrastructure for proxmox"
exclude.workspace = true
[dependencies]
anyhow.workspace = true
nix.workspace = true
log.workspace = true
tracing.workspace = true
tracing-journald.workspace = true
tracing-subscriber.workspace = true
tracing-log = { workspace = true, features = ["std"] }
tokio = { workspace = true, features = ["rt-multi-thread"] }
proxmox-time.workspace = true
proxmox-sys.workspace = true

View File

@ -0,0 +1,5 @@
rust-proxmox-log (0.1.0-3) UNRELEASED; urgency=medium
* Initial release
-- Gabriel Goller <ggoller@luna.proxmox.com> Wed, 11 Oct 2023 15:13:58 +0200

View File

@ -0,0 +1,52 @@
Source: rust-proxmox-log
Section: rust
Priority: optional
Build-Depends: debhelper (>= 12),
dh-cargo (>= 25),
cargo:native <!nocheck>,
rustc:native <!nocheck>,
libstd-rust-dev <!nocheck>,
librust-anyhow-1+default-dev <!nocheck>,
librust-log-0.4+default-dev (>= 0.4.17-~~) <!nocheck>,
librust-nix-0.26+default-dev (>= 0.26.1-~~) <!nocheck>,
librust-proxmox-sys-0.5+default-dev (>= 0.5.1-~~) <!nocheck>,
librust-proxmox-time-1+default-dev (>= 1.1.6-~~) <!nocheck>,
librust-tracing-journald-0.3+default-dev <!nocheck>
librust-tokio-1+default-dev (>= 1.6-~~) <!nocheck>,
librust-tokio-1+rt-multi-thread-dev (>= 1.6-~~) <!nocheck>,
librust-tracing-0.1+default-dev <!nocheck>,
librust-tracing-log-0.1-dev (>= 0.1.3-~~) <!nocheck>,
librust-tracing-subscriber-0.3+default-dev (>= 0.3.16-~~) <!nocheck>
Maintainer: Proxmox Support Team <support@proxmox.com>
Standards-Version: 4.6.2
Vcs-Git: git://git.proxmox.com/git/proxmox.git
Vcs-Browser: https://git.proxmox.com/?p=proxmox.git
X-Cargo-Crate: proxmox-log
Rules-Requires-Root: no
Package: librust-proxmox-log-dev
Architecture: any
Multi-Arch: same
Depends:
${misc:Depends},
librust-anyhow-1+default-dev,
librust-log-0.4+default-dev (>= 0.4.17-~~),
librust-nix-0.26+default-dev (>= 0.26.1-~~),
librust-proxmox-sys-0.5+default-dev (>= 0.5.1-~~),
librust-proxmox-time-1+default-dev (>= 1.1.6-~~),
librust-tracing-journald-0.3+default-dev,
librust-tokio-1+default-dev (>= 1.6-~~),
librust-tokio-1+rt-multi-thread-dev (>= 1.6-~~),
librust-tracing-0.1+default-dev,
librust-tracing-log-0.1-dev (>= 0.1.3-~~),
librust-tracing-subscriber-0.3+default-dev (>= 0.3.16-~~)
Provides:
librust-proxmox-log+default-dev (= ${binary:Version}),
librust-proxmox-log-0-dev (= ${binary:Version}),
librust-proxmox-log-0+default-dev (= ${binary:Version}),
librust-proxmox-log-0.1-dev (= ${binary:Version}),
librust-proxmox-log-0.1+default-dev (= ${binary:Version}),
librust-proxmox-log-0.1.0-dev (= ${binary:Version}),
librust-proxmox-log-0.1.0+default-dev (= ${binary:Version})
Description: Logging infrastructure for proxmox - Rust source code
Source code for Debianized Rust crate "proxmox-log"

View File

@ -0,0 +1,18 @@
Format: https://www.debian.org/doc/packaging-manuals/copyright-format/1.0/
Files:
*
Copyright: 2019 - 2024 Proxmox Server Solutions GmbH <support@proxmox.com>
License: AGPL-3.0-or-later
This program is free software: you can redistribute it and/or modify it under
the terms of the GNU Affero General Public License as published by the Free
Software Foundation, either version 3 of the License, or (at your option) any
later version.
.
This program is distributed in the hope that it will be useful, but WITHOUT
ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or FITNESS
FOR A PARTICULAR PURPOSE. See the GNU Affero General Public License for more
details.
.
You should have received a copy of the GNU Affero General Public License along
with this program. If not, see <https://www.gnu.org/licenses/>.

View File

@ -0,0 +1,7 @@
overlay = "."
crate_src_path = ".."
maintainer = "Proxmox Support Team <support@proxmox.com>"
[source]
vcs_git = "git://git.proxmox.com/git/proxmox.git"
vcs_browser = "https://git.proxmox.com/?p=proxmox.git"

View File

@ -0,0 +1,151 @@
use std::io::Write;
use anyhow::Error;
use nix::fcntl::OFlag;
use proxmox_sys::fs::{atomic_open_or_create_file, CreateOptions};
/// Options to control the behavior of a [FileLogger] instance
#[derive(Default)]
pub struct FileLogOptions {
/// Open underlying log file in append mode, useful when multiple concurrent processes
/// want to log to the same file (e.g., HTTP access log). Note that it is only atomic
/// for writes smaller than the PIPE_BUF (4k on Linux).
/// Inside the same process you may need to still use an mutex, for shared access.
pub append: bool,
/// Open underlying log file as readable
pub read: bool,
/// If set, ensure that the file is newly created or error out if already existing.
pub exclusive: bool,
/// Duplicate logged messages to STDOUT, like tee
pub to_stdout: bool,
/// Prefix messages logged to the file with the current local time as RFC 3339
pub prefix_time: bool,
/// File owner/group and mode
pub file_opts: CreateOptions,
}
/// Log messages with optional automatically added timestamps into files
///
/// #### Example:
/// ```
/// # use anyhow::{bail, format_err, Error};
/// use proxmox_log::{flog, FileLogger, FileLogOptions};
///
/// # std::fs::remove_file("test.log");
/// let options = FileLogOptions {
/// to_stdout: true,
/// exclusive: true,
/// ..Default::default()
/// };
/// let mut log = FileLogger::new("test.log", options).unwrap();
/// flog!(log, "A simple log: {}", "Hello!");
/// # std::fs::remove_file("test.log");
/// ```
pub struct FileLogger {
file: std::fs::File,
file_name: std::path::PathBuf,
options: FileLogOptions,
}
/// Log messages to [FileLogger] - ``println`` like macro
#[macro_export]
macro_rules! flog {
($log:expr, $($arg:tt)*) => ({
$log.log(format!($($arg)*));
})
}
impl FileLogger {
/// Create a new FileLogger. This opens the specified file and
/// stores a file descriptor.
pub fn new<P: AsRef<std::path::Path>>(
file_name: P,
options: FileLogOptions,
) -> Result<Self, Error> {
let file = Self::open(&file_name, &options)?;
let file_name: std::path::PathBuf = file_name.as_ref().to_path_buf();
Ok(Self {
file,
file_name,
options,
})
}
/// Reopen logfile.
pub fn reopen(&mut self) -> Result<&Self, Error> {
let file = Self::open(&self.file_name, &self.options)?;
self.file = file;
Ok(self)
}
fn open<P: AsRef<std::path::Path>>(
file_name: P,
options: &FileLogOptions,
) -> Result<std::fs::File, Error> {
let mut flags = OFlag::O_CLOEXEC;
if options.read {
flags |= OFlag::O_RDWR;
} else {
flags |= OFlag::O_WRONLY;
}
if options.append {
flags |= OFlag::O_APPEND;
}
if options.exclusive {
flags |= OFlag::O_EXCL;
}
let file =
atomic_open_or_create_file(&file_name, flags, &[], options.file_opts.clone(), false)?;
Ok(file)
}
/// Writes `msg` to the logfile with a timestamp and to stdout if
/// specified.
pub fn log<S: AsRef<str>>(&mut self, msg: S) {
let msg = msg.as_ref();
if self.options.to_stdout {
let mut stdout = std::io::stdout();
let _ = stdout.write_all(msg.as_bytes());
let _ = stdout.write_all(b"\n");
}
let line = if self.options.prefix_time {
let now = proxmox_time::epoch_i64();
let rfc3339 = match proxmox_time::epoch_to_rfc3339(now) {
Ok(rfc3339) => rfc3339,
Err(_) => "1970-01-01T00:00:00Z".into(), // for safety, should really not happen!
};
format!("{rfc3339}: {msg}\n")
} else {
format!("{msg}\n")
};
// Note: we ignore the potential error here because log methods
// shouldn't panic. We also can't log an error, because that
// would lead to recursion.
let _ = self.file.write_all(line.as_bytes());
}
}
impl std::io::Write for FileLogger {
fn write(&mut self, buf: &[u8]) -> Result<usize, std::io::Error> {
if self.options.to_stdout {
let _ = std::io::stdout().write(buf);
}
self.file.write(buf)
}
fn flush(&mut self) -> Result<(), std::io::Error> {
if self.options.to_stdout {
let _ = std::io::stdout().flush();
}
self.file.flush()
}
}

48
proxmox-log/src/lib.rs Normal file
View File

@ -0,0 +1,48 @@
use std::{
cell::{Cell, RefCell},
env,
};
use tracing::Level;
use tracing_log::{AsLog, LogTracer};
use tracing_subscriber::filter::{filter_fn, LevelFilter};
use tracing_subscriber::prelude::*;
use tasklog_layer::TasklogLayer;
mod file_logger;
pub use file_logger::{FileLogOptions, FileLogger};
mod tasklog_layer;
tokio::task_local! {
pub static LOGGER: RefCell<FileLogger>;
pub static WARN_COUNTER: Cell<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(
tracing_journald::layer()
.expect("Unable to open syslog")
.with_filter(log_level)
.with_filter(filter_fn(|metadata| {
LOGGER.try_with(|_| {}).is_err() || *metadata.level() == Level::ERROR
})),
)
.with(TasklogLayer {}.with_filter(log_level));
tracing::subscriber::set_global_default(registry)?;
LogTracer::init_with_filter(log_level.as_log())?;
Ok(())
}

View File

@ -0,0 +1,58 @@
use std::fmt::Write as _;
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 TasklogLayer;
impl<S: Subscriber> Layer<S> for TasklogLayer {
fn on_event(&self, event: &Event<'_>, _ctx: Context<'_, S>) {
let _result = LOGGER.try_with(|logger| {
let mut buf = String::new();
event.record(&mut EventVisitor::new(&mut buf));
let level = event.metadata().level();
log_to_file(&mut logger.borrow_mut(), level, &buf);
});
}
}
fn log_to_file(logger: &mut FileLogger, level: &Level, buf: &String) {
match *level {
Level::ERROR | Level::WARN => {
WARN_COUNTER.with(|counter| {
counter.set(counter.get() + 1);
});
logger.log(buf);
}
Level::INFO => logger.log(buf),
Level::DEBUG => logger.log(format!("DEBUG: {buf}")),
Level::TRACE => logger.log(format!("TRACE: {buf}")),
};
}
struct EventVisitor<'a> {
buf: &'a mut String,
}
impl<'a> EventVisitor<'a> {
fn new(buf: &'a mut String) -> Self {
Self { buf }
}
}
impl Visit for EventVisitor<'_> {
fn record_debug(&mut self, field: &Field, value: &dyn std::fmt::Debug) {
if field.name() == "message" {
let _ = write!(self.buf, "{value:?}");
}
}
}