commit 1a97d3faa33f9afa737897bbca0ecb41ca42126f
parent 196f5a77d9d8cc04099a7506f1c33dc2b3f92e73
Author: Antoine A <>
Date: Thu, 23 Jan 2025 17:30:50 +0100
common: improve logging
Diffstat:
12 files changed, 152 insertions(+), 64 deletions(-)
diff --git a/Cargo.lock b/Cargo.lock
@@ -1400,6 +1400,7 @@ dependencies = [
"portable-atomic",
"portable-atomic-util",
"serde",
+ "windows-sys 0.59.0",
]
[[package]]
@@ -1670,9 +1671,9 @@ dependencies = [
[[package]]
name = "openssl-probe"
-version = "0.1.5"
+version = "0.1.6"
source = "registry+https://github.com/rust-lang/crates.io-index"
-checksum = "ff011a302c396a5197692431fc1948019154afc178baf7d8e37367442a4601cf"
+checksum = "d05e27ee213611ffe7d6348b942e8f942b37114c00cc03cec254295a4a17852e"
[[package]]
name = "openssl-sys"
@@ -2584,7 +2585,9 @@ dependencies = [
"sqlx",
"tempfile",
"thiserror 2.0.11",
+ "tokio",
"tracing",
+ "tracing-subscriber",
"url",
]
@@ -2921,9 +2924,9 @@ checksum = "5c1cb5db39152898a79168971543b1cb5020dff7fe43c8dc468b0885f5e29df5"
[[package]]
name = "unicode-ident"
-version = "1.0.14"
+version = "1.0.15"
source = "registry+https://github.com/rust-lang/crates.io-index"
-checksum = "adb9e6ca4f869e1180728b7950e35922a7fc6397f7b641499e8f3ef06e50dc83"
+checksum = "11cd88e12b17c6494200a9c1b683a04fcac9573ed74cd1b62aeb2727c5592243"
[[package]]
name = "unicode-normalization"
diff --git a/Cargo.toml b/Cargo.toml
@@ -24,9 +24,9 @@ fastrand = "2.2"
tracing = "0.1"
tracing-subscriber = "0.3"
clap = { version = "4.5", features = ["derive"] }
-jiff = { version = "0.1", default-features = false, features = ["std"] }
+jiff = { version = "0.1", default-features = false, features = ["tz-system"] }
tempfile = "3.15"
taler-common = { path = "common/taler-common" }
taler-api = { path = "common/taler-api" }
test-utils = { path = "common/test-utils" }
-anyhow = "1"
-\ No newline at end of file
+anyhow = "1"
diff --git a/common/taler-api/Cargo.toml b/common/taler-api/Cargo.toml
@@ -15,7 +15,7 @@ sqlx = { workspace = true, features = [
http-body-util = "0.1.2"
libdeflater = "1.22.0"
ed25519-dalek = { version = "2.1.1", default-features = false }
-tokio = { workspace = true, features = ["rt-multi-thread", "macros", "signal"] }
+tokio = { workspace = true, features = ["signal"] }
serde.workspace = true
tracing.workspace = true
tracing-subscriber.workspace = true
diff --git a/common/taler-api/src/error.rs b/common/taler-api/src/error.rs
@@ -98,7 +98,7 @@ impl From<serde_path_to_error::Error<serde_json::Error>> for ApiError {
impl IntoResponse for ApiError {
fn into_response(self) -> Response {
if let Some(log) = self.log.as_deref().or(self.hint.as_deref()) {
- tracing::error!("{log}");
+ tracing::error!(target: "api", "{log}");
}
let status_code = self.status.unwrap_or_else(|| {
let (status_code, _) = self.code.metadata();
diff --git a/common/taler-api/src/lib.rs b/common/taler-api/src/lib.rs
@@ -137,13 +137,13 @@ impl Serve {
// Check if systemd is passing a socket
let mut listenfd = ListenFd::from_env();
if let Ok(Some(unix)) = listenfd.take_unix_listener(0) {
- info!(
+ info!(target: "api",
"Server listening on activated unix socket {:?}",
unix.local_addr()
);
Ok(Listener::Unix(UnixListener::from_std(unix)?))
} else if let Ok(Some(tcp)) = listenfd.take_tcp_listener(0) {
- info!(
+ info!(target: "api",
"Server listening on activated TCP socket {:?}",
tcp.local_addr()
);
@@ -151,12 +151,12 @@ impl Serve {
} else {
match self {
Serve::Tcp(socket_addr) => {
- info!("Server listening on {socket_addr}");
+ info!(target: "api", "Server listening on {socket_addr}");
let listener = std::net::TcpListener::bind(socket_addr)?;
Ok(Listener::Tcp(TcpListener::from_std(listener)?))
}
Serve::Unix { path, permission } => {
- info!(
+ info!(target: "api",
"Server listening on unxis domain socket {path} {:o}",
permission.mode()
);
@@ -218,7 +218,7 @@ pub async fn server(
}
}
- info!("Server stopped");
+ info!(target: "api", "Server stopped");
Ok(())
}
@@ -285,7 +285,7 @@ async fn logger_middleware(request: Request, next: Next) -> Response {
let response = next.run(request).await;
let elapsed = now.elapsed();
// TODO log error message
- info!(
+ info!(target: "api",
"{} {request_info} {}ms",
response.status(),
elapsed.as_millis()
diff --git a/common/taler-api/src/notification.rs b/common/taler-api/src/notification.rs
@@ -31,7 +31,7 @@ macro_rules! notification_listener {
listener.listen_all([$($channel,)*]).await?;
loop {
while let Some(notification) = listener.try_recv().await? {
- tracing::debug!(
+ tracing::debug!(target: "db-watcher",
"db notification: {} - {}",
notification.channel(),
notification.payload()
diff --git a/common/taler-common/Cargo.toml b/common/taler-common/Cargo.toml
@@ -20,7 +20,9 @@ fastrand.workspace = true
tracing.workspace = true
clap.workspace = true
anyhow.workspace = true
-sqlx = { workspace = true, features = ["macros"] }
+tracing-subscriber.workspace = true
+tokio = { workspace = true, features = ["rt-multi-thread"] }
+sqlx = { workspace = true, features = ["macros", "postgres"] }
[dev-dependencies]
criterion.workspace = true
diff --git a/common/taler-common/src/config.rs b/common/taler-common/src/config.rs
@@ -157,19 +157,21 @@ pub mod parser {
match entry {
Ok(entry) => self.parse_file(&entry.path(), 0)?,
Err(err) => {
- warn!("{}", io_err("read base config directory", &cfg_dir, err));
+ warn!(target: "config", "{}", io_err("read base config directory", &cfg_dir, err));
}
}
}
}
- Err(err) => warn!("{}", io_err("read base config directory", &cfg_dir, err)),
+ Err(err) => {
+ warn!(target: "config", "{}", io_err("read base config directory", &cfg_dir, err))
+ }
}
Ok(())
}
fn parse_file(&mut self, src: &Path, depth: u8) -> Result<(), ParserErr> {
- trace!("load file at '{}'", src.to_string_lossy());
+ trace!(target: "config", "load file at '{}'", src.to_string_lossy());
match std::fs::File::open(src) {
Ok(file) => self.parse(BufReader::new(file), src, depth + 1),
Err(e) => Err(io_err("read config", src, e)),
@@ -246,7 +248,7 @@ pub mod parser {
if let Err(e) = tmp.parse_file(src, depth) {
if let ParserErr::IO(_, path, err) = e {
- warn!("{}", io_err("read secrets", path, err))
+ warn!(target: "config", "{}", io_err("read secrets", path, err))
} else {
return Err(e);
}
@@ -257,7 +259,7 @@ pub mod parser {
.or_default()
.extend(secret_section);
} else {
- warn!("{}", line_err(format!("Configuration file at '{}' loaded with @inline-secret@ does not contain section '{section}' ", file), src, num));
+ warn!(target: "config", "{}", line_err(format!("Configuration file at '{}' loaded with @inline-secret@ does not contain section '{section}' ", file), src, num));
}
}
unknown => {
diff --git a/common/taler-common/src/lib.rs b/common/taler-common/src/lib.rs
@@ -14,6 +14,13 @@
TALER; see the file COPYING. If not, see <http://www.gnu.org/licenses/>
*/
+use std::{future::Future, path::PathBuf};
+
+use config::{parser::ConfigSource, Config};
+use log::TalerTime;
+use tracing::{error, Level};
+use tracing_subscriber::{util::SubscriberInitExt as _, FmtSubscriber};
+
pub mod api_common;
pub mod api_params;
pub mod api_wire;
@@ -21,4 +28,54 @@ pub mod cli;
pub mod config;
pub mod error_code;
pub mod json_file;
+mod log;
pub mod types;
+
+#[derive(clap::Parser, Debug, Clone)]
+pub struct CommonArgs {
+ /// Specifies the configuration file
+ #[clap(long, short)]
+ #[arg(global = true)]
+ config: Option<PathBuf>,
+
+ /// Configure logging to use LOGLEVEL
+ #[clap(long, short('L'))]
+ #[arg(global = true)]
+ log: Option<tracing::Level>,
+}
+
+pub fn taler_main<F: Future<Output = Result<(), anyhow::Error>>>(
+ src: ConfigSource,
+ args: CommonArgs,
+ app: impl FnOnce(Config) -> F,
+) {
+ // Setup logger
+ let level = args.log.unwrap_or(Level::INFO);
+ FmtSubscriber::builder()
+ .with_timer(TalerTime::new())
+ .with_max_level(level)
+ .with_writer(std::io::stderr)
+ .finish()
+ .init();
+
+ let cfg = match Config::from_file(src, args.config) {
+ Ok(cfg) => cfg,
+ Err(err) => {
+ error!(target: "config", "{}", err);
+ std::process::exit(1);
+ }
+ };
+
+ // Setup async runtime
+ let runtime = tokio::runtime::Builder::new_multi_thread()
+ .enable_all()
+ .build()
+ .unwrap();
+
+ // Run app
+ let result = runtime.block_on(app(cfg));
+ if let Err(err) = result {
+ error!(target: "cli", "{}", err);
+ std::process::exit(1);
+ }
+}
diff --git a/common/taler-common/src/log.rs b/common/taler-common/src/log.rs
@@ -0,0 +1,55 @@
+/*
+ This file is part of TALER
+ Copyright (C) 2025 Taler Systems SA
+
+ TALER 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, or (at your option) any later version.
+
+ TALER 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
+ TALER; see the file COPYING. If not, see <http://www.gnu.org/licenses/>
+*/
+
+use jiff::{fmt::StdFmtWrite, tz::TimeZone, Timestamp};
+use tracing_subscriber::fmt::time::FormatTime;
+
+pub struct TalerTime {
+ zone: Option<TimeZone>,
+}
+
+impl TalerTime {
+ pub fn new() -> Self {
+ let zone = if std::env::var_os("JOURNAL_STREAM").is_some() {
+ None
+ } else {
+ Some(match TimeZone::try_system() {
+ Ok(z) => z,
+ Err(e) => {
+ eprintln!("could not fetch system time zone, default to UTC: {e}");
+ TimeZone::UTC
+ }
+ })
+ };
+ Self { zone }
+ }
+}
+
+impl FormatTime for TalerTime {
+ fn format_time(&self, w: &mut tracing_subscriber::fmt::format::Writer<'_>) -> std::fmt::Result {
+ if let Some(zone) = &self.zone {
+ let timestamp = Timestamp::now();
+ let (offset, _, _) = zone.to_offset(timestamp);
+ jiff::fmt::temporal::DateTimePrinter::new()
+ .precision(Some(6))
+ .separator(b'T')
+ .print_timestamp_with_offset(×tamp, offset, StdFmtWrite(w))
+ .map_err(|_| std::fmt::Error)?;
+ // TODO remove : in offset
+ }
+ Ok(())
+ }
+}
diff --git a/common/test-utils/src/lib.rs b/common/test-utils/src/lib.rs
@@ -70,7 +70,7 @@ async fn db_pool() -> PgPool {
.expect("pg pool")
}
-const TEST_TRACING_LEVEL: tracing::Level = Level::WARN;
+const TEST_TRACING_LEVEL: tracing::Level = Level::INFO;
fn setup_tracing() {
FmtSubscriber::builder()
diff --git a/wire-gateway/magnet-bank/src/main.rs b/wire-gateway/magnet-bank/src/main.rs
@@ -14,7 +14,7 @@
TALER; see the file COPYING. If not, see <http://www.gnu.org/licenses/>
*/
-use std::{future::Future, path::PathBuf, sync::Arc};
+use std::sync::Arc;
use clap::Parser;
use magnet_bank::{
@@ -31,23 +31,16 @@ use sqlx::PgPool;
use taler_common::{
cli::ConfigCmd,
config::{parser::ConfigSource, Config},
+ taler_main,
types::payto::{payto, Payto},
+ CommonArgs,
};
-use tracing::{error, Level};
-use tracing_subscriber::{util::SubscriberInitExt as _, FmtSubscriber};
#[derive(clap::Parser, Debug)]
#[command(version, about, long_about = None)]
struct Args {
- /// Specifies the configuration file
- #[clap(long, short)]
- #[arg(global = true)]
- config: Option<PathBuf>,
-
- /// Configure logging to use LOGLEVEL
- #[clap(long, short('L'))]
- #[arg(global = true)]
- log: Option<tracing::Level>,
+ #[clap(flatten)]
+ common: CommonArgs,
#[command(subcommand)]
cmd: Command,
@@ -79,34 +72,7 @@ enum Command {
Dev(DevCmd),
}
-fn setup(level: Option<tracing::Level>, app: impl Future<Output = Result<(), anyhow::Error>>) {
- // Setup logger
- let level = level.unwrap_or(Level::INFO);
- FmtSubscriber::builder()
- .with_max_level(level)
- .with_writer(std::io::stderr)
- .finish()
- .init();
-
- // Setup async runtime
- let runtime = tokio::runtime::Builder::new_multi_thread()
- .enable_all()
- .build()
- .unwrap();
-
- // Run app
- let result = runtime.block_on(app);
- if let Err(err) = result {
- error!("{}", err);
- std::process::exit(1);
- }
-}
-
-async fn app(args: Args) -> anyhow::Result<()> {
- let source = ConfigSource::new("magnet-bank", "magnet-bank", "magnet-bank");
-
- let cfg = Config::from_file(source, args.config)?;
-
+async fn app(args: Args, cfg: Config) -> anyhow::Result<()> {
match args.cmd {
Command::Setup { reset } => {
let cfg = MagnetConfig::parse(&cfg)?;
@@ -159,5 +125,9 @@ async fn app(args: Args) -> anyhow::Result<()> {
fn main() {
let args = Args::parse();
- setup(args.log, app(args));
+ taler_main(
+ ConfigSource::new("magnet-bank", "magnet-bank", "magnet-bank"),
+ args.common.clone(),
+ |cfg| async move { app(args, cfg).await },
+ );
}
