Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Add timestamp in logs (also) on libtelio side #1035

Merged
merged 1 commit into from
Dec 18, 2024
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
Empty file added .unreleased/log_time_in_telio
Empty file.
1 change: 1 addition & 0 deletions Cargo.lock

Some generated files are not rendered by default. Learn more about how customized files appear on GitHub.

1 change: 1 addition & 0 deletions Cargo.toml
Original file line number Diff line number Diff line change
Expand Up @@ -62,6 +62,7 @@ telio-wg.workspace = true
once_cell.workspace = true
nat-detect.workspace = true
smart-default.workspace = true
time.workspace = true

[target.'cfg(target_os = "android")'.dependencies]
jni = "0.19"
Expand Down
1 change: 1 addition & 0 deletions nat-lab/tests/uniffi/libtelio_remote.py
Original file line number Diff line number Diff line change
Expand Up @@ -84,6 +84,7 @@ def __init__(self, daemon, logfile):
self._libtelio = None
self._event_cb = TelioEventCbImpl()
self._logger_cb = TelioLoggerCbImpl(logfile)
libtelio.add_timestamps_to_logs()
libtelio.set_global_logger(libtelio.TelioLogLevel.DEBUG, self._logger_cb)

def shutdown(self):
Expand Down
8 changes: 7 additions & 1 deletion src/ffi.rs
Original file line number Diff line number Diff line change
Expand Up @@ -20,7 +20,7 @@ use std::{
time::Duration,
};

use self::{logging::LOGGER_STOPPER, types::*};
use self::{logging::LOGGER_STOPPER, logging::TIMESTAMPS_IN_LOGS, types::*};
use crate::device::{Device, DeviceConfig, Result as DevResult};
use telio_model::{
config::{Config, ConfigParseError},
Expand Down Expand Up @@ -81,6 +81,12 @@ pub fn unset_global_logger() {
LOGGER_STOPPER.stop();
}

/// Enable timestamps in logs generated by libtelio.
/// When enabled host application doesn't need to add timestamps in the logging callback.
pub fn add_timestamps_to_logs() {
TIMESTAMPS_IN_LOGS.store(true, std::sync::atomic::Ordering::Relaxed);
}

/// Get default recommended adapter type for platform.
pub fn get_default_adapter() -> TelioAdapterType {
AdapterType::default().into()
Expand Down
25 changes: 20 additions & 5 deletions src/ffi/logging.rs
Original file line number Diff line number Diff line change
Expand Up @@ -2,12 +2,12 @@ use std::{
io::{self, ErrorKind},
str::from_utf8,
sync::{
atomic::AtomicUsize,
atomic::{AtomicBool, AtomicUsize},
mpsc::{sync_channel, RecvError, SyncSender},
Arc, Barrier, Mutex,
},
thread::Builder,
time::Instant,
time::{Instant, SystemTime},
};

use once_cell::sync::Lazy;
Expand All @@ -28,6 +28,7 @@ pub const ASYNC_CHANNEL_CLOSED_MSG: &str = "Async channel explicitly closed";
static DROPPED_LOGS: AtomicUsize = AtomicUsize::new(0);
static DROPPED_LOGS_LAST_CHECKED_VALUE: AtomicUsize = AtomicUsize::new(0);
pub static LOGGER_STOPPER: LoggerStopper = LoggerStopper::new();
pub static TIMESTAMPS_IN_LOGS: AtomicBool = AtomicBool::new(false);

pub struct LoggerStopper {
sender: parking_lot::Mutex<Option<SyncSender<LogMessage>>>,
Expand Down Expand Up @@ -189,7 +190,11 @@ impl io::Write for FfiCallbackWriter {
// In both cases there is nothing to do when it happens.
if self
.log_sender
.try_send(LogMessage::Message(self.level, filtered_msg))
.try_send(LogMessage::Message(
self.level,
filtered_msg,
SystemTime::now(),
))
.is_err()
{
DROPPED_LOGS.fetch_add(1, std::sync::atomic::Ordering::Relaxed);
Expand Down Expand Up @@ -246,7 +251,7 @@ fn filter_log_message(msg: String) -> Option<String> {
}

enum LogMessage {
Message(TelioLogLevel, String),
Message(TelioLogLevel, String, SystemTime),
Quit(Arc<Barrier>),
}

Expand All @@ -258,7 +263,17 @@ fn start_async_logger(cb: Box<dyn TelioLoggerCb>, buffer_size: usize) -> SyncSen
let _ = cb.log(TelioLogLevel::Debug, START_ASYNC_LOGGER_MSG.to_owned());
loop {
match receiver.recv() {
Ok(LogMessage::Message(level, msg)) => {
Ok(LogMessage::Message(level, msg, timestamp)) => {
let msg = if TIMESTAMPS_IN_LOGS.load(std::sync::atomic::Ordering::Relaxed) {
tomaszklak marked this conversation as resolved.
Show resolved Hide resolved
let timestamp: time::OffsetDateTime = timestamp.into();
let timestamp: String = timestamp
.format(&time::format_description::well_known::Rfc3339)
.unwrap_or_else(|_| timestamp.to_string());
format!("{timestamp} {msg}")
} else {
msg
};

let _ = cb.log(level, msg);
}
Ok(LogMessage::Quit(barrier)) => {
Expand Down
3 changes: 3 additions & 0 deletions src/libtelio.udl
Original file line number Diff line number Diff line change
Expand Up @@ -191,6 +191,9 @@ namespace telio {
/// Utility function to create a `Config` object from a json-string
[Throws=TelioError]
Config deserialize_meshnet_config(string cfg_str);

/// For testing only - embeds timestamps into generated logs
void add_timestamps_to_logs();
};

interface Telio {
Expand Down
Loading