From 3f14fdc62d12124dd4365c401c6ec4f2baac5522 Mon Sep 17 00:00:00 2001
From: neuronull <9162534+neuronull@users.noreply.github.com>
Date: Mon, 22 Sep 2025 09:56:23 -0600
Subject: [PATCH] [BEEEP][PM-255518] Use tracing for improved observability
(#16321)
* [BEEEP][PM-255518] Use tracing for improved observability
* feedback dani-garcia: use DefaultVisitor
* set default log level
* convert printlns in objc crate
* convert printlns in autotype crate
* convert printlns in autostart crate
* convert printlns in core/password crate
* convert printlns in core/biometric crate
* convert printlns in napi crate
* convert log usage in macos provider crate
* convert existing log macros to tracing
* fix the cargo.toml sort lint errors
* Revert "fix the cargo.toml sort lint errors"
This reverts commit fd149ab697d37ea8fc9c22db8f96684fc99bf2d8.
* fix the sort lint using correct cargo sort version
* feedback coltonhurst: more comments/clarity on behavior
* revert changes to ssh_agent
---
apps/desktop/desktop_native/Cargo.lock | 81 ++++++++++-
apps/desktop/desktop_native/Cargo.toml | 2 +
.../desktop_native/autotype/Cargo.toml | 1 +
.../desktop_native/autotype/src/windows.rs | 3 +-
.../bitwarden_chromium_importer/Cargo.toml | 1 -
apps/desktop/desktop_native/core/Cargo.toml | 2 +-
.../core/src/autostart/linux.rs | 9 +-
.../desktop_native/core/src/biometric/unix.rs | 3 +-
.../desktop_native/core/src/ipc/client.rs | 8 +-
.../desktop_native/core/src/ipc/server.rs | 14 +-
.../desktop_native/core/src/password/unix.rs | 14 +-
.../desktop_native/macos_provider/Cargo.toml | 1 +
.../desktop_native/macos_provider/src/lib.rs | 10 +-
apps/desktop/desktop_native/napi/Cargo.toml | 3 +-
apps/desktop/desktop_native/napi/src/lib.rs | 135 +++++++++++++-----
apps/desktop/desktop_native/objc/Cargo.toml | 1 +
apps/desktop/desktop_native/objc/src/lib.rs | 11 +-
17 files changed, 226 insertions(+), 73 deletions(-)
diff --git a/apps/desktop/desktop_native/Cargo.lock b/apps/desktop/desktop_native/Cargo.lock
index ae96de067d..e3b1b0e034 100644
--- a/apps/desktop/desktop_native/Cargo.lock
+++ b/apps/desktop/desktop_native/Cargo.lock
@@ -342,6 +342,7 @@ checksum = "ace50bade8e6234aa140d9a2f552bbee1db4d353f69b8217bc503490fc1a9f26"
name = "autotype"
version = "0.0.0"
dependencies = [
+ "tracing",
"windows 0.61.1",
"windows-core 0.61.0",
]
@@ -448,7 +449,6 @@ dependencies = [
"cbc",
"hex",
"homedir",
- "log",
"oo7",
"pbkdf2",
"rand 0.9.1",
@@ -903,7 +903,6 @@ dependencies = [
"interprocess",
"keytar",
"libc",
- "log",
"oo7",
"pin-project",
"pkcs8",
@@ -922,6 +921,7 @@ dependencies = [
"tokio",
"tokio-stream",
"tokio-util",
+ "tracing",
"typenum",
"widestring",
"windows 0.61.1",
@@ -941,7 +941,6 @@ dependencies = [
"bitwarden_chromium_importer",
"desktop_core",
"hex",
- "log",
"napi",
"napi-build",
"napi-derive",
@@ -950,6 +949,8 @@ dependencies = [
"tokio",
"tokio-stream",
"tokio-util",
+ "tracing",
+ "tracing-subscriber",
"windows-registry",
"windows_plugin_authenticator",
]
@@ -964,6 +965,7 @@ dependencies = [
"glob",
"thiserror 2.0.12",
"tokio",
+ "tracing",
]
[[package]]
@@ -1796,9 +1798,19 @@ dependencies = [
"serde_json",
"tokio",
"tokio-util",
+ "tracing",
"uniffi",
]
+[[package]]
+name = "matchers"
+version = "0.2.0"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "d1525a2a28c7f4fa0fc98bb91ae755d1e2d1505079e05539e35bc876b5d65ae9"
+dependencies = [
+ "regex-automata",
+]
+
[[package]]
name = "md-5"
version = "0.10.6"
@@ -1968,6 +1980,15 @@ dependencies = [
"winapi",
]
+[[package]]
+name = "nu-ansi-term"
+version = "0.50.1"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "d4a28e057d01f97e61255210fcff094d74ed0466038633e95017f5beb68e4399"
+dependencies = [
+ "windows-sys 0.52.0",
+]
+
[[package]]
name = "num"
version = "0.4.3"
@@ -2971,6 +2992,15 @@ dependencies = [
"digest",
]
+[[package]]
+name = "sharded-slab"
+version = "0.1.7"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "f40ca3c46823713e0d4209592e8d6e826aa57e928f09752619fc696c499637f6"
+dependencies = [
+ "lazy_static",
+]
+
[[package]]
name = "shlex"
version = "1.3.0"
@@ -3239,6 +3269,15 @@ dependencies = [
"syn",
]
+[[package]]
+name = "thread_local"
+version = "1.1.9"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "f60246a4944f24f6e018aa17cdeffb7818b76356965d03b07d6a9886e8962185"
+dependencies = [
+ "cfg-if",
+]
+
[[package]]
name = "time"
version = "0.3.41"
@@ -3391,6 +3430,36 @@ source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "e672c95779cf947c5311f83787af4fa8fffd12fb27e4993211a84bdfd9610f9c"
dependencies = [
"once_cell",
+ "valuable",
+]
+
+[[package]]
+name = "tracing-log"
+version = "0.2.0"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "ee855f1f400bd0e5c02d150ae5de3840039a3f54b025156404e34c23c03f47c3"
+dependencies = [
+ "log",
+ "once_cell",
+ "tracing-core",
+]
+
+[[package]]
+name = "tracing-subscriber"
+version = "0.3.20"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "2054a14f5307d601f88daf0553e1cbf472acc4f2c51afab632431cdcd72124d5"
+dependencies = [
+ "matchers",
+ "nu-ansi-term",
+ "once_cell",
+ "regex-automata",
+ "sharded-slab",
+ "smallvec",
+ "thread_local",
+ "tracing",
+ "tracing-core",
+ "tracing-log",
]
[[package]]
@@ -3611,6 +3680,12 @@ version = "0.2.2"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "06abde3611657adf66d383f00b093d7faecc7fa57071cce2578660c9f1010821"
+[[package]]
+name = "valuable"
+version = "0.1.1"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "ba73ea9cf16a25df0c8caa16c51acb937d5712a8429db78a3ee29d5dcacd3a65"
+
[[package]]
name = "vcpkg"
version = "0.2.15"
diff --git a/apps/desktop/desktop_native/Cargo.toml b/apps/desktop/desktop_native/Cargo.toml
index 3edbd1b389..b8f582f43d 100644
--- a/apps/desktop/desktop_native/Cargo.toml
+++ b/apps/desktop/desktop_native/Cargo.toml
@@ -62,6 +62,8 @@ thiserror = "=2.0.12"
tokio = "=1.45.0"
tokio-stream = "=0.1.15"
tokio-util = "=0.7.13"
+tracing = "=0.1.41"
+tracing-subscriber = { version = "=0.3.20", features = ["fmt", "env-filter"] }
typenum = "=1.18.0"
uniffi = "=0.28.3"
widestring = "=1.2.0"
diff --git a/apps/desktop/desktop_native/autotype/Cargo.toml b/apps/desktop/desktop_native/autotype/Cargo.toml
index de026a3ddd..ceccd0c890 100644
--- a/apps/desktop/desktop_native/autotype/Cargo.toml
+++ b/apps/desktop/desktop_native/autotype/Cargo.toml
@@ -6,6 +6,7 @@ edition.workspace = true
publish.workspace = true
[target.'cfg(windows)'.dependencies]
+tracing.workspace = true
windows = { workspace = true, features = [
"Win32_UI_Input_KeyboardAndMouse",
"Win32_UI_WindowsAndMessaging",
diff --git a/apps/desktop/desktop_native/autotype/src/windows.rs b/apps/desktop/desktop_native/autotype/src/windows.rs
index 57770ba1d4..f1f9bee7f6 100644
--- a/apps/desktop/desktop_native/autotype/src/windows.rs
+++ b/apps/desktop/desktop_native/autotype/src/windows.rs
@@ -1,6 +1,7 @@
use std::ffi::OsString;
use std::os::windows::ffi::OsStringExt;
+use tracing::debug;
use windows::Win32::Foundation::{GetLastError, HWND};
use windows::Win32::UI::Input::KeyboardAndMouse::{
SendInput, INPUT, INPUT_0, INPUT_KEYBOARD, KEYBDINPUT, KEYEVENTF_KEYUP, KEYEVENTF_UNICODE,
@@ -187,7 +188,7 @@ fn send_input(inputs: Vec) -> Result<(), ()> {
let insert_count = unsafe { SendInput(&inputs, std::mem::size_of::() as i32) };
let e = unsafe { GetLastError().to_hresult().message() };
- println!("type_input() called, GetLastError() is: {:?}", e);
+ debug!("type_input() called, GetLastError() is: {:?}", e);
if insert_count == 0 {
return Err(()); // input was blocked by another thread
diff --git a/apps/desktop/desktop_native/bitwarden_chromium_importer/Cargo.toml b/apps/desktop/desktop_native/bitwarden_chromium_importer/Cargo.toml
index 8512ed1b31..b7289c4860 100644
--- a/apps/desktop/desktop_native/bitwarden_chromium_importer/Cargo.toml
+++ b/apps/desktop/desktop_native/bitwarden_chromium_importer/Cargo.toml
@@ -14,7 +14,6 @@ base64 = { workspace = true }
cbc = { workspace = true, features = ["alloc"] }
hex = { workspace = true }
homedir = { workspace = true }
-log = { workspace = true }
pbkdf2 = "=0.12.2"
rand = { workspace = true }
rusqlite = { version = "=0.35.0", features = ["bundled"] }
diff --git a/apps/desktop/desktop_native/core/Cargo.toml b/apps/desktop/desktop_native/core/Cargo.toml
index 3aedf90613..36e1a85abc 100644
--- a/apps/desktop/desktop_native/core/Cargo.toml
+++ b/apps/desktop/desktop_native/core/Cargo.toml
@@ -31,7 +31,6 @@ ed25519 = { workspace = true, features = ["pkcs8"] }
futures = { workspace = true }
homedir = { workspace = true }
interprocess = { workspace = true, features = ["tokio"] }
-log = { workspace = true }
pin-project = { workspace = true }
pkcs8 = { workspace = true, features = ["alloc", "encryption", "pem"] }
rand = { workspace = true }
@@ -52,6 +51,7 @@ thiserror = { workspace = true }
tokio = { workspace = true, features = ["io-util", "sync", "macros", "net"] }
tokio-stream = { workspace = true, features = ["net"] }
tokio-util = { workspace = true, features = ["codec"] }
+tracing = { workspace = true }
typenum = { workspace = true }
zeroizing-alloc = { workspace = true }
diff --git a/apps/desktop/desktop_native/core/src/autostart/linux.rs b/apps/desktop/desktop_native/core/src/autostart/linux.rs
index 1fd02a6ea5..b89ba80f71 100644
--- a/apps/desktop/desktop_native/core/src/autostart/linux.rs
+++ b/apps/desktop/desktop_native/core/src/autostart/linux.rs
@@ -1,5 +1,6 @@
use anyhow::Result;
use ashpd::desktop::background::Background;
+use tracing::{error, info};
pub async fn set_autostart(autostart: bool, params: Vec) -> Result<()> {
let request = if params.is_empty() {
@@ -10,11 +11,15 @@ pub async fn set_autostart(autostart: bool, params: Vec) -> Result<()> {
match request.send().await.and_then(|r| r.response()) {
Ok(response) => {
- println!("[ASHPD] Autostart enabled: {:?}", response);
+ info!(
+ response = ?response,
+ "[ASHPD] Autostart enabled");
Ok(())
}
Err(err) => {
- println!("[ASHPD] Error enabling autostart: {}", err);
+ error!(
+ error = %err,
+ "[ASHPD] Error enabling autostart");
Err(anyhow::anyhow!("error enabling autostart {}", err))
}
}
diff --git a/apps/desktop/desktop_native/core/src/biometric/unix.rs b/apps/desktop/desktop_native/core/src/biometric/unix.rs
index 60392adc9d..0f6ff8f33d 100644
--- a/apps/desktop/desktop_native/core/src/biometric/unix.rs
+++ b/apps/desktop/desktop_native/core/src/biometric/unix.rs
@@ -4,6 +4,7 @@ use anyhow::Result;
use base64::Engine;
use rand::RngCore;
use sha2::{Digest, Sha256};
+use tracing::error;
use crate::biometric::{base64_engine, KeyMaterial, OsDerivedKey};
use zbus::Connection;
@@ -35,7 +36,7 @@ impl super::BiometricTrait for Biometric {
match result {
Ok(result) => Ok(result.is_authorized),
Err(e) => {
- println!("polkit biometric error: {:?}", e);
+ error!( error = %e, "polkit biometric error");
Ok(false)
}
}
diff --git a/apps/desktop/desktop_native/core/src/ipc/client.rs b/apps/desktop/desktop_native/core/src/ipc/client.rs
index 6c4ca0a605..45b19e72bb 100644
--- a/apps/desktop/desktop_native/core/src/ipc/client.rs
+++ b/apps/desktop/desktop_native/core/src/ipc/client.rs
@@ -5,21 +5,21 @@ use interprocess::local_socket::{
tokio::{prelude::*, Stream},
GenericFilePath, ToFsName,
};
-use log::{error, info};
+use tracing::{error, info};
pub async fn connect(
path: PathBuf,
send: tokio::sync::mpsc::Sender,
mut recv: tokio::sync::mpsc::Receiver,
) -> Result<(), Box> {
- info!("Attempting to connect to {}", path.display());
+ info!(?path, "Attempting to connect");
let name = path.as_os_str().to_fs_name::()?;
let conn = Stream::connect(name).await?;
let mut conn = crate::ipc::internal_ipc_codec(conn);
- info!("Connected to {}", path.display());
+ info!(?path, "Connected");
// This `connected` and the latter `disconnected` messages are the only ones that
// are sent from the Rust IPC code and not just forwarded from the desktop app.
@@ -46,7 +46,7 @@ pub async fn connect(
res = conn.next() => {
match res {
Some(Err(e)) => {
- error!("Error reading from IPC server: {e}");
+ error!(error = %e, "Error reading from IPC server");
break;
}
None => {
diff --git a/apps/desktop/desktop_native/core/src/ipc/server.rs b/apps/desktop/desktop_native/core/src/ipc/server.rs
index a1c77e7ab1..2762a832ac 100644
--- a/apps/desktop/desktop_native/core/src/ipc/server.rs
+++ b/apps/desktop/desktop_native/core/src/ipc/server.rs
@@ -7,12 +7,12 @@ use futures::{SinkExt, StreamExt, TryFutureExt};
use anyhow::Result;
use interprocess::local_socket::{tokio::prelude::*, GenericFilePath, ListenerOptions};
-use log::{error, info};
use tokio::{
io::{AsyncRead, AsyncWrite},
sync::{broadcast, mpsc},
};
use tokio_util::sync::CancellationToken;
+use tracing::{error, info};
use super::MESSAGE_CHANNEL_BUFFER;
@@ -143,11 +143,11 @@ async fn listen_incoming(
client_id
);
tokio::spawn(future.map_err(|e| {
- error!("Error handling connection: {}", e)
+ error!(error = %e, "Error handling connection")
}));
},
Err(e) => {
- error!("Error accepting connection: {}", e);
+ error!(error = %e, "Error accepting connection");
break;
},
}
@@ -176,7 +176,7 @@ async fn handle_connection(
loop {
tokio::select! {
_ = cancel_token.cancelled() => {
- info!("Client {client_id} cancelled.");
+ info!(client_id, "Client cancelled.");
break;
},
@@ -187,7 +187,7 @@ async fn handle_connection(
client_stream.send(msg.into()).await?;
},
Err(e) => {
- info!("Error reading message: {}", e);
+ error!(error = %e, "Error reading message");
break;
}
}
@@ -199,7 +199,7 @@ async fn handle_connection(
result = client_stream.next() => {
match result {
Some(Err(e)) => {
- info!("Error reading from client {client_id}: {e}");
+ error!(client_id, error = %e, "Error reading from client");
client_to_server_send.send(Message {
client_id,
@@ -209,7 +209,7 @@ async fn handle_connection(
break;
},
None => {
- info!("Client {client_id} disconnected.");
+ info!(client_id, "Client disconnected.");
client_to_server_send.send(Message {
client_id,
diff --git a/apps/desktop/desktop_native/core/src/password/unix.rs b/apps/desktop/desktop_native/core/src/password/unix.rs
index 0b1c59e772..b7595dca28 100644
--- a/apps/desktop/desktop_native/core/src/password/unix.rs
+++ b/apps/desktop/desktop_native/core/src/password/unix.rs
@@ -2,6 +2,7 @@ use crate::password::PASSWORD_NOT_FOUND;
use anyhow::{anyhow, Result};
use oo7::dbus::{self};
use std::collections::HashMap;
+use tracing::info;
pub async fn get_password(service: &str, account: &str) -> Result {
match get_password_new(service, account).await {
@@ -27,7 +28,7 @@ async fn get_password_new(service: &str, account: &str) -> Result {
// forces to read via secret service; remvove after 2025.03
async fn get_password_legacy(service: &str, account: &str) -> Result {
- println!("falling back to get legacy {} {}", service, account);
+ info!("falling back to get legacy {} {}", service, account);
let svc = dbus::Service::new().await?;
let collection = svc.default_collection().await?;
let keyring = oo7::Keyring::DBus(collection);
@@ -38,10 +39,7 @@ async fn get_password_legacy(service: &str, account: &str) -> Result {
match res {
Some(res) => {
let secret = res.secret().await?;
- println!(
- "deleting legacy secret service entry {} {}",
- service, account
- );
+ info!(service, account, "deleting legacy secret service entry",);
keyring.delete(&attributes).await?;
let secret_string = String::from_utf8(secret.to_vec())?;
set_password(service, account, &secret_string).await?;
@@ -77,7 +75,7 @@ pub async fn delete_password(service: &str, account: &str) -> Result<()> {
// seems to happen because we call [delete_password] many times when a forced
// de-auth occurs to clean up old keys.
if is_locked().await? {
- println!("skipping deletion of old keys. OS keyring is locked.");
+ info!("skipping deletion of old keys. OS keyring is locked.");
return Ok(());
}
@@ -105,11 +103,11 @@ pub async fn is_locked() -> Result {
if let Some(item) = items.first() {
return match item.is_locked().await {
Ok(is_locked) => {
- println!("OS keyring is locked = {is_locked}");
+ info!(is_locked, "OS keyring");
Ok(is_locked)
}
Err(_) => {
- println!("OS keyring is unlocked");
+ info!("OS keyring is unlocked");
Ok(false)
}
};
diff --git a/apps/desktop/desktop_native/macos_provider/Cargo.toml b/apps/desktop/desktop_native/macos_provider/Cargo.toml
index a48aadb5b9..9f042209b0 100644
--- a/apps/desktop/desktop_native/macos_provider/Cargo.toml
+++ b/apps/desktop/desktop_native/macos_provider/Cargo.toml
@@ -21,6 +21,7 @@ serde = { workspace = true, features = ["derive"] }
serde_json = { workspace = true }
tokio = { workspace = true, features = ["sync"] }
tokio-util = { workspace = true }
+tracing = { workspace = true }
uniffi = { workspace = true, features = ["cli"] }
[target.'cfg(target_os = "macos")'.dependencies]
diff --git a/apps/desktop/desktop_native/macos_provider/src/lib.rs b/apps/desktop/desktop_native/macos_provider/src/lib.rs
index 9872468643..ded133bcb5 100644
--- a/apps/desktop/desktop_native/macos_provider/src/lib.rs
+++ b/apps/desktop/desktop_native/macos_provider/src/lib.rs
@@ -7,8 +7,8 @@ use std::{
};
use futures::FutureExt;
-use log::{error, info};
use serde::{de::DeserializeOwned, Deserialize, Serialize};
+use tracing::{error, info};
uniffi::setup_scaffolding!();
@@ -114,21 +114,21 @@ impl MacOSProviderClient {
match value {
Ok(value) => {
if let Err(e) = cb.complete(value) {
- error!("Error deserializing message: {e}");
+ error!(error = %e, "Error deserializing message");
}
}
Err(e) => {
- error!("Error processing message: {e:?}");
+ error!(error = ?e, "Error processing message");
cb.error(e)
}
}
}
None => {
- error!("No callback found for sequence number: {sequence_number}")
+ error!(sequence_number, "No callback found for sequence number")
}
},
Err(e) => {
- error!("Error deserializing message: {e}");
+ error!(error = %e, "Error deserializing message");
}
};
}
diff --git a/apps/desktop/desktop_native/napi/Cargo.toml b/apps/desktop/desktop_native/napi/Cargo.toml
index 9e8404ea8d..5e2e42b463 100644
--- a/apps/desktop/desktop_native/napi/Cargo.toml
+++ b/apps/desktop/desktop_native/napi/Cargo.toml
@@ -20,7 +20,6 @@ base64 = { workspace = true }
bitwarden_chromium_importer = { path = "../bitwarden_chromium_importer" }
desktop_core = { path = "../core" }
hex = { workspace = true }
-log = { workspace = true }
napi = { workspace = true, features = ["async"] }
napi-derive = { workspace = true }
serde = { workspace = true, features = ["derive"] }
@@ -28,6 +27,8 @@ serde_json = { workspace = true }
tokio = { workspace = true }
tokio-stream = { workspace = true }
tokio-util = { workspace = true }
+tracing = { workspace = true }
+tracing-subscriber = { workspace = true }
[target.'cfg(windows)'.dependencies]
windows-registry = { workspace = true }
diff --git a/apps/desktop/desktop_native/napi/src/lib.rs b/apps/desktop/desktop_native/napi/src/lib.rs
index 0e5cdc838d..4731166852 100644
--- a/apps/desktop/desktop_native/napi/src/lib.rs
+++ b/apps/desktop/desktop_native/napi/src/lib.rs
@@ -175,6 +175,7 @@ pub mod sshagent {
threadsafe_function::{ErrorStrategy::CalleeHandled, ThreadsafeFunction},
};
use tokio::{self, sync::Mutex};
+ use tracing::error;
#[napi]
pub struct SshAgentState {
@@ -242,7 +243,7 @@ pub mod sshagent {
.expect("should be able to send auth response to agent");
}
Err(e) => {
- println!("[SSH Agent Native Module] calling UI callback promise was rejected: {e}");
+ error!(error = %e, "Calling UI callback promise was rejected");
let _ = auth_response_tx_arc
.lock()
.await
@@ -251,7 +252,7 @@ pub mod sshagent {
}
},
Err(e) => {
- println!("[SSH Agent Native Module] calling UI callback could not create promise: {e}");
+ error!(error = %e, "Calling UI callback could not create promise");
let _ = auth_response_tx_arc
.lock()
.await
@@ -513,6 +514,7 @@ pub mod autofill {
ErrorStrategy, ThreadsafeFunction, ThreadsafeFunctionCallMode,
};
use serde::{de::DeserializeOwned, Deserialize, Serialize};
+ use tracing::error;
#[napi]
pub async fn run_command(value: String) -> napi::Result {
@@ -668,7 +670,7 @@ pub mod autofill {
MessageType::Connected | MessageType::Disconnected => continue,
MessageType::Message => {
let Some(message) = message else {
- println!("[ERROR] Message is empty");
+ error!("Message is empty");
continue;
};
@@ -686,7 +688,7 @@ pub mod autofill {
continue;
}
Err(e) => {
- println!("[ERROR] Error deserializing message1: {e}");
+ error!(error = %e, "Error deserializing message1");
}
}
@@ -705,7 +707,7 @@ pub mod autofill {
continue;
}
Err(e) => {
- println!("[ERROR] Error deserializing message1: {e}");
+ error!(error = %e, "Error deserializing message1");
}
}
@@ -722,11 +724,11 @@ pub mod autofill {
continue;
}
Err(e) => {
- println!("[ERROR] Error deserializing message2: {e}");
+ error!(error = %e, "Error deserializing message2");
}
}
- println!("[ERROR] Received an unknown message2: {message:?}");
+ error!(message, "Received an unknown message2");
}
}
}
@@ -823,11 +825,28 @@ pub mod passkey_authenticator {
#[napi]
pub mod logging {
- use log::{Level, Metadata, Record};
+ //! `logging` is the interface between the native desktop's usage of the `tracing` crate
+ //! for logging, to intercept events and write to the JS space.
+ //!
+ //! # Example
+ //!
+ //! [Elec] 14:34:03.517 › [NAPI] [INFO] desktop_core::ssh_agent::platform_ssh_agent: Starting SSH Agent server {socket=/Users/foo/.bitwarden-ssh-agent.sock}
+
+ use std::fmt::Write;
+ use std::sync::OnceLock;
+
use napi::threadsafe_function::{
ErrorStrategy::CalleeHandled, ThreadsafeFunction, ThreadsafeFunctionCallMode,
};
- use std::sync::OnceLock;
+ use tracing::Level;
+ use tracing_subscriber::fmt::format::{DefaultVisitor, Writer};
+ use tracing_subscriber::{
+ filter::{EnvFilter, LevelFilter},
+ layer::SubscriberExt,
+ util::SubscriberInitExt,
+ Layer,
+ };
+
struct JsLogger(OnceLock>);
static JS_LOGGER: JsLogger = JsLogger(OnceLock::new());
@@ -840,42 +859,86 @@ pub mod logging {
Error,
}
- impl From for LogLevel {
- fn from(level: Level) -> Self {
- match level {
- Level::Trace => LogLevel::Trace,
- Level::Debug => LogLevel::Debug,
- Level::Info => LogLevel::Info,
- Level::Warn => LogLevel::Warn,
- Level::Error => LogLevel::Error,
+ impl From<&Level> for LogLevel {
+ fn from(level: &Level) -> Self {
+ match *level {
+ Level::TRACE => LogLevel::Trace,
+ Level::DEBUG => LogLevel::Debug,
+ Level::INFO => LogLevel::Info,
+ Level::WARN => LogLevel::Warn,
+ Level::ERROR => LogLevel::Error,
}
}
}
+ // JsLayer lets us intercept events and write them to the JS Logger.
+ struct JsLayer;
+
+ impl Layer for JsLayer
+ where
+ S: tracing::Subscriber,
+ {
+ // This function builds a log message buffer from the event data and
+ // calls the JS logger with it.
+ //
+ // For example, this log call:
+ //
+ // ```
+ // mod supreme {
+ // mod module {
+ // let foo = "bar";
+ // info!(best_variable_name = %foo, "Foo done it again.");
+ // }
+ // }
+ // ```
+ //
+ // , results in the following string:
+ //
+ // [INFO] supreme::module: Foo done it again. {best_variable_name=bar}
+ fn on_event(
+ &self,
+ event: &tracing::Event<'_>,
+ _ctx: tracing_subscriber::layer::Context<'_, S>,
+ ) {
+ let mut buffer = String::new();
+
+ // create the preamble text that precedes the message and vars. e.g.:
+ // [INFO] desktop_core::ssh_agent::platform_ssh_agent:
+ let level = event.metadata().level().as_str();
+ let module_path = event.metadata().module_path().unwrap_or_default();
+
+ write!(&mut buffer, "[{level}] {module_path}:")
+ .expect("Failed to write tracing event to buffer");
+
+ let writer = Writer::new(&mut buffer);
+
+ // DefaultVisitor adds the message and variables to the buffer
+ let mut visitor = DefaultVisitor::new(writer, false);
+ event.record(&mut visitor);
+
+ let msg = (event.metadata().level().into(), buffer);
+
+ if let Some(logger) = JS_LOGGER.0.get() {
+ let _ = logger.call(Ok(msg), ThreadsafeFunctionCallMode::NonBlocking);
+ };
+ }
+ }
+
#[napi]
pub fn init_napi_log(js_log_fn: ThreadsafeFunction<(LogLevel, String), CalleeHandled>) {
let _ = JS_LOGGER.0.set(js_log_fn);
- let _ = log::set_logger(&JS_LOGGER);
- log::set_max_level(log::LevelFilter::Debug);
- }
- impl log::Log for JsLogger {
- fn enabled(&self, metadata: &Metadata) -> bool {
- metadata.level() <= log::max_level()
- }
+ let filter = EnvFilter::builder()
+ // set the default log level to INFO.
+ .with_default_directive(LevelFilter::INFO.into())
+ // parse directives from the RUST_LOG environment variable,
+ // overriding the default directive for matching targets.
+ .from_env_lossy();
- fn log(&self, record: &Record) {
- if !self.enabled(record.metadata()) {
- return;
- }
- let Some(logger) = self.0.get() else {
- return;
- };
- let msg = (record.level().into(), record.args().to_string());
- let _ = logger.call(Ok(msg), ThreadsafeFunctionCallMode::NonBlocking);
- }
-
- fn flush(&self) {}
+ tracing_subscriber::registry()
+ .with(filter)
+ .with(JsLayer)
+ .init();
}
}
diff --git a/apps/desktop/desktop_native/objc/Cargo.toml b/apps/desktop/desktop_native/objc/Cargo.toml
index 76843f3efd..fc8910bddd 100644
--- a/apps/desktop/desktop_native/objc/Cargo.toml
+++ b/apps/desktop/desktop_native/objc/Cargo.toml
@@ -12,6 +12,7 @@ default = []
anyhow = { workspace = true }
thiserror = { workspace = true }
tokio = { workspace = true }
+tracing = { workspace = true }
[target.'cfg(target_os = "macos")'.dependencies]
core-foundation = "=0.10.1"
diff --git a/apps/desktop/desktop_native/objc/src/lib.rs b/apps/desktop/desktop_native/objc/src/lib.rs
index 60e48760da..eaa9f66669 100644
--- a/apps/desktop/desktop_native/objc/src/lib.rs
+++ b/apps/desktop/desktop_native/objc/src/lib.rs
@@ -66,6 +66,8 @@ impl Drop for ObjCString {
mod objc {
use std::os::raw::c_void;
+ use tracing::error;
+
use super::*;
unsafe extern "C" {
@@ -79,8 +81,9 @@ mod objc {
let value: String = match value.try_into() {
Ok(value) => value,
Err(e) => {
- println!(
- "Error: Failed to convert ObjCString to Rust string during commandReturn: {e}"
+ error!(
+ error = %e,
+ "Error: Failed to convert ObjCString to Rust string during commandReturn"
);
return false;
@@ -90,7 +93,9 @@ mod objc {
match context.send(value) {
Ok(_) => 0,
Err(e) => {
- println!("Error: Failed to return ObjCString from ObjC code to Rust code: {e}");
+ error!(
+ error = %e,
+ "Error: Failed to return ObjCString from ObjC code to Rust code");
return false;
}