1
0
mirror of https://github.com/bitwarden/browser synced 2026-02-26 01:23:24 +00:00

Replace dbg_log with tracing::debug (#17251)

We already configure tracing to only be enabled in debug so there is no need to wrap it with a macro
This commit is contained in:
Oscar Hinton
2025-11-06 15:48:19 +01:00
committed by GitHub
parent 30af9425d8
commit 78d1eb9bed
6 changed files with 34 additions and 49 deletions

View File

@@ -620,7 +620,6 @@ dependencies = [
"sha1",
"tokio",
"tracing",
"tracing-subscriber",
"verifysign",
"windows 0.61.1",
]

View File

@@ -1,6 +1,5 @@
// Enable this to log to a file. The way this executable is used, it's not easy to debug and the stdout gets lost.
// This is intended for development time only. All the logging is wrapped in `dbg_log!`` macro that compiles to
// no-op when logging is disabled. This is needed to avoid any sensitive data being logged in production.
// This is intended for development time only.
pub(crate) const ENABLE_DEVELOPER_LOGGING: bool = false;
pub(crate) const LOG_FILENAME: &str = "c:\\path\\to\\log.txt"; // This is an example filename, replace it with you own

View File

@@ -17,17 +17,16 @@ use windows::{
};
use super::impersonate::{start_impersonating, stop_impersonating};
use crate::dbg_log;
//
// Base64
//
pub(crate) fn decode_base64(data_base64: &str) -> Result<Vec<u8>> {
dbg_log!("Decoding base64 data: {}", data_base64);
debug!("Decoding base64 data: {}", data_base64);
let data = general_purpose::STANDARD.decode(data_base64).map_err(|e| {
dbg_log!("Failed to decode base64: {}", e);
debug!("Failed to decode base64: {}", e);
e
})?;
@@ -46,7 +45,7 @@ pub(crate) fn decrypt_with_dpapi_as_system(encrypted: &[u8]) -> Result<Vec<u8>>
// Impersonate a SYSTEM process to be able to decrypt data encrypted for the machine
let system_token = start_impersonating()?;
defer! {
dbg_log!("Stopping impersonation");
debug!("Stopping impersonation");
_ = stop_impersonating(system_token);
}
@@ -55,7 +54,7 @@ pub(crate) fn decrypt_with_dpapi_as_system(encrypted: &[u8]) -> Result<Vec<u8>>
pub(crate) fn decrypt_with_dpapi_as_user(encrypted: &[u8], expect_appb: bool) -> Result<Vec<u8>> {
let system_decrypted = decrypt_with_dpapi(encrypted, expect_appb)?;
dbg_log!(
debug!(
"Decrypted data with SYSTEM {} bytes",
system_decrypted.len()
);
@@ -66,7 +65,7 @@ pub(crate) fn decrypt_with_dpapi_as_user(encrypted: &[u8], expect_appb: bool) ->
fn decrypt_with_dpapi(data: &[u8], expect_appb: bool) -> Result<Vec<u8>> {
if expect_appb && (data.len() < 5 || !data.starts_with(b"APPB")) {
const ERR_MSG: &str = "Ciphertext is too short or does not start with 'APPB'";
dbg_log!("{}", ERR_MSG);
debug!("{}", ERR_MSG);
return Err(anyhow!(ERR_MSG));
}
@@ -101,7 +100,7 @@ fn decrypt_with_dpapi(data: &[u8], expect_appb: bool) -> Result<Vec<u8>> {
Ok(decrypted)
} else {
dbg_log!("CryptUnprotectData failed");
debug!("CryptUnprotectData failed");
Err(anyhow!("CryptUnprotectData failed"))
}
}
@@ -231,7 +230,7 @@ fn decrypt_abe_key_blob_chrome_cng(blob: &[u8]) -> Result<Vec<u8>> {
let decrypted_aes_key: Vec<u8> = {
let system_token = start_impersonating()?;
defer! {
dbg_log!("Stopping impersonation");
debug!("Stopping impersonation");
_ = stop_impersonating(system_token);
}
decrypt_with_cng(&encrypted_aes_key)?

View File

@@ -1,5 +1,6 @@
use anyhow::{anyhow, Result};
use sysinfo::System;
use tracing::debug;
use windows::{
core::BOOL,
Wdk::System::SystemServices::SE_DEBUG_PRIVILEGE,
@@ -14,7 +15,6 @@ use windows::{
};
use super::config::SYSTEM_PROCESS_NAMES;
use crate::dbg_log;
#[link(name = "ntdll")]
unsafe extern "system" {
@@ -37,7 +37,7 @@ pub(crate) fn start_impersonating() -> Result<HANDLE> {
unsafe {
ImpersonateLoggedOnUser(token)?;
};
dbg_log!("Impersonating system process '{}' (PID: {})", name, pid);
debug!("Impersonating system process '{}' (PID: {})", name, pid);
Ok(token)
}
@@ -56,10 +56,9 @@ fn find_system_process_with_token(
for (pid, name) in pids {
match get_system_token_from_pid(pid) {
Err(_) => {
dbg_log!(
debug!(
"Failed to open process handle '{}' (PID: {}), skipping",
name,
pid
name, pid
);
continue;
}
@@ -120,20 +119,20 @@ fn get_process_handle(pid: u32) -> Result<HANDLE> {
fn enable_debug_privilege() -> Result<()> {
let mut previous_value = BOOL(0);
let status = unsafe {
dbg_log!("Setting SE_DEBUG_PRIVILEGE to 1 via RtlAdjustPrivilege");
debug!("Setting SE_DEBUG_PRIVILEGE to 1 via RtlAdjustPrivilege");
RtlAdjustPrivilege(SE_DEBUG_PRIVILEGE, BOOL(1), BOOL(0), &mut previous_value)
};
match status {
STATUS_SUCCESS => {
dbg_log!(
debug!(
"SE_DEBUG_PRIVILEGE set to 1, was {} before",
previous_value.as_bool()
);
Ok(())
}
_ => {
dbg_log!("RtlAdjustPrivilege failed with status: 0x{:X}", status.0);
debug!("RtlAdjustPrivilege failed with status: 0x{:X}", status.0);
Err(anyhow!("Failed to adjust privilege"))
}
}

View File

@@ -5,16 +5,6 @@ use tracing_subscriber::{
use super::config::{ENABLE_DEVELOPER_LOGGING, LOG_FILENAME};
// Macro wrapper around debug! that compiles to no-op when ENABLE_DEVELOPER_LOGGING is false
#[macro_export]
macro_rules! dbg_log {
($($arg:tt)*) => {
if $crate::windows::config::ENABLE_DEVELOPER_LOGGING {
tracing::debug!($($arg)*);
}
};
}
pub(crate) fn init_logging() {
if ENABLE_DEVELOPER_LOGGING {
// We only log to a file. It's impossible to see stdout/stderr when this exe is launched from ShellExecuteW.

View File

@@ -12,7 +12,7 @@ use tokio::{
net::windows::named_pipe::{ClientOptions, NamedPipeClient},
time,
};
use tracing::error;
use tracing::{debug, error};
use windows::Win32::{
Foundation::{CloseHandle, ERROR_PIPE_BUSY, HANDLE},
System::{
@@ -35,7 +35,6 @@ use super::{
},
log::init_logging,
};
use crate::dbg_log;
#[derive(Parser)]
#[command(name = "bitwarden_chromium_import_helper")]
@@ -50,14 +49,14 @@ async fn open_pipe_client(pipe_name: &'static str) -> Result<NamedPipeClient> {
for _ in 0..max_attempts {
match ClientOptions::new().open(pipe_name) {
Ok(client) => {
dbg_log!("Successfully connected to the pipe!");
debug!("Successfully connected to the pipe!");
return Ok(client);
}
Err(e) if e.raw_os_error() == Some(ERROR_PIPE_BUSY.0 as i32) => {
dbg_log!("Pipe is busy, retrying in 50ms...");
debug!("Pipe is busy, retrying in 50ms...");
}
Err(e) => {
dbg_log!("Failed to connect to pipe: {}", &e);
debug!("Failed to connect to pipe: {}", &e);
return Err(e.into());
}
}
@@ -96,15 +95,15 @@ fn get_named_pipe_server_pid(client: &NamedPipeClient) -> Result<u32> {
}
fn resolve_process_executable_path(pid: u32) -> Result<PathBuf> {
dbg_log!("Resolving process executable path for PID {}", pid);
debug!("Resolving process executable path for PID {}", pid);
// Open the process handle
let hprocess = unsafe { OpenProcess(PROCESS_QUERY_LIMITED_INFORMATION, false, pid) }?;
dbg_log!("Opened process handle for PID {}", pid);
debug!("Opened process handle for PID {}", pid);
// Close when no longer needed
defer! {
dbg_log!("Closing process handle for PID {}", pid);
debug!("Closing process handle for PID {}", pid);
unsafe {
_ = CloseHandle(hprocess);
}
@@ -120,7 +119,7 @@ fn resolve_process_executable_path(pid: u32) -> Result<PathBuf> {
&mut exe_name_length,
)
}?;
dbg_log!(
debug!(
"QueryFullProcessImageNameW returned {} bytes",
exe_name_length
);
@@ -147,25 +146,25 @@ async fn open_and_validate_pipe_server(pipe_name: &'static str) -> Result<NamedP
if ENABLE_SERVER_SIGNATURE_VALIDATION {
let server_pid = get_named_pipe_server_pid(&client)?;
dbg_log!("Connected to pipe server PID {}", server_pid);
debug!("Connected to pipe server PID {}", server_pid);
// Validate the server end process signature
let exe_path = resolve_process_executable_path(server_pid)?;
dbg_log!("Pipe server executable path: {}", exe_path.display());
debug!("Pipe server executable path: {}", exe_path.display());
if !verify_signature(&exe_path)? {
return Err(anyhow!("Pipe server signature is not valid"));
}
dbg_log!("Pipe server signature verified for PID {}", server_pid);
debug!("Pipe server signature verified for PID {}", server_pid);
}
Ok(client)
}
fn run() -> Result<String> {
dbg_log!("Starting bitwarden_chromium_import_helper.exe");
debug!("Starting bitwarden_chromium_import_helper.exe");
let args = Args::try_parse()?;
@@ -173,31 +172,31 @@ fn run() -> Result<String> {
return Err(anyhow!("Expected to run with admin privileges"));
}
dbg_log!("Running as ADMINISTRATOR");
debug!("Running as ADMINISTRATOR");
let encrypted = decode_base64(&args.encrypted)?;
dbg_log!(
debug!(
"Decoded encrypted data [{}] {:?}",
encrypted.len(),
encrypted
);
let system_decrypted = decrypt_with_dpapi_as_system(&encrypted)?;
dbg_log!(
debug!(
"Decrypted data with DPAPI as SYSTEM {} {:?}",
system_decrypted.len(),
system_decrypted
);
let user_decrypted = decrypt_with_dpapi_as_user(&system_decrypted, false)?;
dbg_log!(
debug!(
"Decrypted data with DPAPI as USER {} {:?}",
user_decrypted.len(),
user_decrypted
);
let key = decode_abe_key_blob(&user_decrypted)?;
dbg_log!("Decoded ABE key blob {} {:?}", key.len(), key);
debug!("Decoded ABE key blob {} {:?}", key.len(), key);
Ok(encode_base64(&key))
}
@@ -218,11 +217,11 @@ pub(crate) async fn main() {
match run() {
Ok(system_decrypted_base64) => {
dbg_log!("Sending response back to user");
debug!("Sending response back to user");
let _ = send_to_user(&mut client, &system_decrypted_base64).await;
}
Err(e) => {
dbg_log!("Error: {}", e);
debug!("Error: {}", e);
send_error_to_user(&mut client, &format!("{}", e)).await;
}
}