diff --git a/library/src/android.rs b/library/src/android.rs index 823a561..54a8258 100644 --- a/library/src/android.rs +++ b/library/src/android.rs @@ -3,10 +3,6 @@ use std::fs; use std::io::{Cursor, Read}; use std::path::{Path, PathBuf}; -// -#[cfg(test)] -use std::println as debug; // Workaround to use println! for logs. - use crate::InitError; /// This function is a hack for Android. Android passes an array of paths, the @@ -138,9 +134,9 @@ fn find_and_open_lib(apks_dir: &Path, lib_name: &str) -> anyhow::Result anyhow::Result Result -#[cfg(test)] -use std::{println as info, println as error}; // Workaround to use println! for logs. - use self::c_file::CFileProvder; mod c_file; @@ -118,7 +114,7 @@ where F: FnOnce() -> Result, { f().unwrap_or_else(|e| { - error!("Error {}: {:?}", context, e); + shorebird_error!("Error {}: {:?}", context, e); error_result }) } @@ -226,7 +222,7 @@ pub extern "C" fn shorebird_check_for_update() -> bool { #[no_mangle] pub extern "C" fn shorebird_update() { log_on_error( - || updater::update().map(|result| info!("Update result: {}", result)), + || updater::update().map(|result| shorebird_info!("Update result: {}", result)), "downloading update", (), ); diff --git a/library/src/cache/disk_io.rs b/library/src/cache/disk_io.rs index e8cb427..cb086c2 100644 --- a/library/src/cache/disk_io.rs +++ b/library/src/cache/disk_io.rs @@ -6,16 +6,12 @@ use std::{ path::Path, }; -// https://stackoverflow.com/questions/67087597/is-it-possible-to-use-rusts-log-info-for-tests -#[cfg(test)] -use std::println as debug; // Workaround to use println! for logs. - pub fn write(serializable: &S, path: &P) -> anyhow::Result<()> where S: ?Sized + Serialize, P: AsRef, { - debug!("Writing to {:?}", path.as_ref()); + shorebird_debug!("Writing to {:?}", path.as_ref()); let path_as_ref = path.as_ref(); let containing_dir = path_as_ref @@ -38,7 +34,7 @@ where D: DeserializeOwned, P: AsRef, { - debug!("Reading from {:?}", path.as_ref()); + shorebird_debug!("Reading from {:?}", path.as_ref()); let path_as_ref = path.as_ref(); if !path_as_ref.exists() { diff --git a/library/src/cache/patch_manager.rs b/library/src/cache/patch_manager.rs index 7cfa351..d1861ee 100644 --- a/library/src/cache/patch_manager.rs +++ b/library/src/cache/patch_manager.rs @@ -12,10 +12,6 @@ use mockall::automock; #[cfg(test)] use tempdir::TempDir; -// https://stackoverflow.com/questions/67087597/is-it-possible-to-use-rusts-log-info-for-tests -#[cfg(test)] -use std::{println as info, println as error, println as debug}; // Workaround to use println! for logs. - const PATCHES_DIR_NAME: &str = "patches"; const PATCHES_STATE_FILE_NAME: &str = "patches_state.json"; const PATCH_ARTIFACT_FILENAME: &str = "dlc.vmcode"; @@ -166,7 +162,7 @@ impl PatchManager { match disk_io::read(&path) { Ok(maybe_state) => maybe_state, Err(e) => { - debug!( + shorebird_debug!( "Failed to load patches state from {}: {}", path.display(), e @@ -240,7 +236,7 @@ impl PatchManager { let patch_hash = signing::hash_file(&artifact_path)?; signing::check_signature(&patch_hash, &signature, public_key)?; } else { - info!("No public key provided, skipping signature verification"); + shorebird_info!("No public key provided, skipping signature verification"); } Ok(()) @@ -249,15 +245,15 @@ impl PatchManager { fn delete_patch_artifacts(&mut self, patch_number: usize) -> Result<()> { let patch_dir = self.patch_dir(patch_number); if !patch_dir.exists() { - debug!("Patch {} not installed, nothing to delete", patch_number); + shorebird_debug!("Patch {} not installed, nothing to delete", patch_number); return Ok(()); } - info!("Deleting patch artifacts for patch {}", patch_number); + shorebird_info!("Deleting patch artifacts for patch {}", patch_number); std::fs::remove_dir_all(&patch_dir) .map_err(|e| { - error!("Failed to delete patch dir {}: {}", patch_dir.display(), e); + shorebird_error!("Failed to delete patch dir {}: {}", patch_dir.display(), e); e }) .with_context(|| format!("Failed to delete patch dir {}", &patch_dir.display())) @@ -315,7 +311,7 @@ impl PatchManager { } Ok(_) => {} Err(e) => { - error!( + shorebird_error!( "Failed to parse patch number from patches directory entry, deleting: {}", e ); @@ -395,12 +391,13 @@ impl ManagePatches for PatchManager { }; if let Err(e) = self.validate_patch_is_bootable(&next_boot_patch) { - error!("Patch {} is not bootable: {}", next_boot_patch.number, e); + shorebird_error!("Patch {} is not bootable: {}", next_boot_patch.number, e); if let Err(e) = self.try_fall_back_from_patch(next_boot_patch.number) { - error!( + shorebird_error!( "Failed to fall back from next_boot_patch {}: {}", - next_boot_patch.number, e + next_boot_patch.number, + e ); } } @@ -440,9 +437,10 @@ impl ManagePatches for PatchManager { self.patches_state.currently_booting_patch = None; self.patches_state.last_booted_patch = Some(boot_patch.clone()); if let Err(e) = self.delete_patch_artifacts_older_than(boot_patch.number) { - error!( + shorebird_error!( "Failed to delete patch artifacts older than {}: {}", - boot_patch.number, e + boot_patch.number, + e ); } self.save_patches_state() @@ -495,7 +493,7 @@ impl PatchManager { .path() .join(format!("patch{}.vmcode", patch_number)); std::fs::write(file_path, patch_number.to_string().repeat(patch_number)).unwrap(); - info!( + shorebird_info!( "Adding patch {} with contents {} hash {} at {}", patch_number, patch_number.to_string().repeat(patch_number), diff --git a/library/src/cache/signing.rs b/library/src/cache/signing.rs index d812737..b8a95b0 100644 --- a/library/src/cache/signing.rs +++ b/library/src/cache/signing.rs @@ -1,9 +1,6 @@ use anyhow::{bail, Context, Result}; use base64::Engine; use std::path::Path; -// https://stackoverflow.com/questions/67087597/is-it-possible-to-use-rusts-log-info-for-tests -#[cfg(test)] -use std::{println as info, println as debug, println as error}; // Workaround to use println! for logs. /// Reads the file at `path` and returns the SHA-256 hash of its contents as a String. pub fn hash_file>(path: P) -> Result { @@ -29,9 +26,9 @@ pub fn hash_file>(path: P) -> Result { /// See https://docs.rs/ring/latest/ring/signature/index.html#signing-and-verifying-with-rsa-pkcs1-15-padding /// for more information. pub fn check_signature(message: &str, signature: &str, public_key: &str) -> Result<()> { - debug!("Message is {}", message); - debug!("Public key is {:?}", public_key); - debug!("Signature is {}", signature); + shorebird_debug!("Message is {}", message); + shorebird_debug!("Public key is {:?}", public_key); + shorebird_debug!("Signature is {}", signature); let public_key_bytes = base64::prelude::BASE64_STANDARD .decode(public_key) @@ -44,16 +41,16 @@ pub fn check_signature(message: &str, signature: &str, public_key: &str) -> Resu .decode(signature) .map_err(|e| anyhow::Error::msg(format!("Failed to decode signature: {:?}", e)))?; - info!("Verifying patch signature..."); + shorebird_info!("Verifying patch signature..."); match public_key.verify(message.as_bytes(), &decoded_sig) { Ok(_) => { - info!("Patch signature is valid"); + shorebird_info!("Patch signature is valid"); Ok(()) } Err(_) => { // The error provided by `verify` is (by design) not helpful, so we ignore it. // See https://docs.rs/ring/latest/ring/error/struct.Unspecified.html - error!("Patch signature is invalid"); + shorebird_error!("Patch signature is invalid"); bail!("Patch signature is invalid") } } diff --git a/library/src/cache/updater_state.rs b/library/src/cache/updater_state.rs index 0930b48..459b33c 100644 --- a/library/src/cache/updater_state.rs +++ b/library/src/cache/updater_state.rs @@ -12,10 +12,6 @@ use serde::{Deserialize, Serialize}; use crate::events::PatchEvent; -// https://stackoverflow.com/questions/67087597/is-it-possible-to-use-rusts-log-info-for-tests -#[cfg(test)] -use std::{println as info, println as warn}; // Workaround to use println! for logs. - use super::patch_manager::{ManagePatches, PatchManager}; use super::{disk_io, PatchInfo}; @@ -104,7 +100,7 @@ impl UpdaterState { patch_public_key, ); if let Err(e) = state.save() { - warn!("Error saving state {:?}, ignoring.", e); + shorebird_warn!("Error saving state {:?}, ignoring.", e); } state } @@ -118,9 +114,10 @@ impl UpdaterState { match load_result { Ok(mut loaded) => { if loaded.serialized_state.release_version != release_version { - info!( + shorebird_info!( "release_version changed {} -> {}, creating new state", - loaded.serialized_state.release_version, release_version + loaded.serialized_state.release_version, + release_version ); let _ = loaded.patch_manager.reset(); return Self::create_new_and_save( @@ -133,7 +130,7 @@ impl UpdaterState { } Err(e) => { if !is_file_not_found(&e) { - info!("No existing state file found: {:#}, creating new state.", e); + shorebird_info!("No existing state file found: {:#}, creating new state.", e); } Self::create_new_and_save(storage_dir, release_version, patch_public_key) } diff --git a/library/src/config.rs b/library/src/config.rs index df073bf..d60b2a8 100644 --- a/library/src/config.rs +++ b/library/src/config.rs @@ -10,10 +10,6 @@ use anyhow::{bail, Result}; use once_cell::sync::OnceCell; use std::sync::Mutex; -// https://stackoverflow.com/questions/67087597/is-it-possible-to-use-rusts-log-info-for-tests -#[cfg(test)] -use std::println as debug; // Workaround to use println! for logs. - // cbindgen looks for const, ignore these so it doesn't warn about them. /// cbindgen:ignore @@ -132,7 +128,7 @@ pub fn set_config( file_provider, patch_public_key: yaml.patch_public_key.to_owned(), }; - debug!("Updater configured with: {:?}", new_config); + shorebird_debug!("Updater configured with: {:?}", new_config); *config = Some(new_config); Ok(()) diff --git a/library/src/lib.rs b/library/src/lib.rs index 9b331d2..85ecf9e 100644 --- a/library/src/lib.rs +++ b/library/src/lib.rs @@ -1,6 +1,9 @@ // This is a required file for rust libraries which declares what files are // part of the library and what interfaces are public from the library. +#[macro_use] +mod logging_macros; + // Declare that the c_api.rs file exists and is a public sub-namespace. // C doesn't care about the namespaces, but Rust does. pub mod c_api; @@ -25,10 +28,5 @@ mod test_utils; // Take all public items from the updater namespace and make them public. pub use self::updater::*; -#[cfg(not(test))] -// Exposes error!(), info!(), etc macros. -#[macro_use] -extern crate log; - #[cfg(test)] extern crate tempdir; diff --git a/library/src/logging.rs b/library/src/logging.rs index 81ab745..7d801e7 100644 --- a/library/src/logging.rs +++ b/library/src/logging.rs @@ -8,7 +8,7 @@ pub fn init_logging() { .with_tag("flutter") .with_max_level(log::LevelFilter::Info), ); - debug!("Logging initialized"); + shorebird_debug!("Logging initialized"); } #[cfg(target_os = "ios")] @@ -17,8 +17,8 @@ pub fn init_logging() { .level_filter(log::LevelFilter::Info) .init(); match init_result { - Ok(_) => debug!("Logging initialized"), - Err(e) => error!("Failed to initialize logging: {}", e), + Ok(_) => shorebird_debug!("Logging initialized"), + Err(e) => shorebird_error!("Failed to initialize logging: {}", e), } } diff --git a/library/src/logging_macros.rs b/library/src/logging_macros.rs new file mode 100644 index 0000000..4c7653e --- /dev/null +++ b/library/src/logging_macros.rs @@ -0,0 +1,72 @@ +// Wrappers around crate::log's logging functions that prepend "[shorebird]" to the log message. +// +// See https://stackoverflow.com/questions/67087597/is-it-possible-to-use-rusts-log-info-for-tests +// for the rationale behind the use of the #[cfg(test)] attribute. + +#[cfg(test)] +#[macro_export] +macro_rules! shorebird_info { + ($fmt:expr $(, $($arg:tt)*)?) => { + println!(concat!("[shorebird] ", $fmt), $($($arg)*)?) + }; +} + +#[cfg(not(test))] +#[macro_export] +macro_rules! shorebird_info { + // shorebird_info!("a {} event", "log") + ($fmt:expr $(, $($arg:tt)*)?) => { + log::info!(concat!("[shorebird] ", $fmt), $($($arg)*)?) + }; +} + +#[cfg(test)] +#[macro_export] +macro_rules! shorebird_debug { + ($fmt:expr $(, $($arg:tt)*)?) => { + println!(concat!("[shorebird] ", $fmt), $($($arg)*)?) + }; +} + +#[cfg(not(test))] +#[macro_export] +macro_rules! shorebird_debug { + // shorebird_debug!("a {} event", "log") + ($fmt:expr $(, $($arg:tt)*)?) => { + log::debug!(concat!("[shorebird] ", $fmt), $($($arg)*)?) + }; +} + +#[cfg(test)] +#[macro_export] +macro_rules! shorebird_warn { + ($fmt:expr $(, $($arg:tt)*)?) => { + println!(concat!("[shorebird] ", $fmt), $($($arg)*)?) + }; +} + +#[cfg(not(test))] +#[macro_export] +macro_rules! shorebird_warn { + // shorebird_warn!("a {} event", "log") + ($fmt:expr $(, $($arg:tt)*)?) => { + log::warn!(concat!("[shorebird] ", $fmt), $($($arg)*)?) + }; +} + +#[cfg(test)] +#[macro_export] +macro_rules! shorebird_error { + ($fmt:expr $(, $($arg:tt)*)?) => { + println!(concat!("[shorebird] ", $fmt), $($($arg)*)?) + }; +} + +#[cfg(not(test))] +#[macro_export] +macro_rules! shorebird_error { + // shorebird_error!("a {} event", "log") + ($fmt:expr $(, $($arg:tt)*)?) => { + log::error!(concat!("[shorebird] ", $fmt), $($($arg)*)?) + }; +} diff --git a/library/src/network.rs b/library/src/network.rs index 9b18ba3..859e97b 100644 --- a/library/src/network.rs +++ b/library/src/network.rs @@ -11,10 +11,6 @@ use std::string::ToString; use crate::config::{current_arch, current_platform, UpdateConfig}; use crate::events::PatchEvent; -// https://stackoverflow.com/questions/67087597/is-it-possible-to-use-rusts-log-info-for-tests -#[cfg(test)] -use std::{println as info, println as debug}; // Workaround to use println! for logs. - pub fn patches_check_url(base_url: &str) -> String { format!("{base_url}/api/v1/patches/check") } @@ -63,11 +59,11 @@ pub fn patch_check_request_default( url: &str, request: PatchCheckRequest, ) -> anyhow::Result { - info!("Sending patch check request: {:?}", request); + shorebird_info!("Sending patch check request: {:?}", request); let client = reqwest::blocking::Client::new(); let result = client.post(url).json(&request).send(); let response = handle_network_result(result)?.json()?; - debug!("Patch check response: {:?}", response); + shorebird_debug!("Patch check response: {:?}", response); Ok(response) } @@ -230,18 +226,18 @@ pub fn download_to_path( url: &str, path: &Path, ) -> anyhow::Result<()> { - debug!("Downloading patch from: {}", url); + shorebird_debug!("Downloading patch from: {}", url); // Download the file at the given url to the given path. let download_file_hook = network_hooks.download_file_fn; let bytes = download_file_hook(url)?; // Ensure the download directory exists. if let Some(parent) = path.parent() { - debug!("Creating download directory: {:?}", parent); + shorebird_debug!("Creating download directory: {:?}", parent); std::fs::create_dir_all(parent) .with_context(|| format!("create_dir_all failed for {}", parent.display()))?; } - debug!("Writing download to: {:?}", path); + shorebird_debug!("Writing download to: {:?}", path); let mut file = File::create(path)?; file.write_all(&bytes)?; Ok(()) diff --git a/library/src/updater.rs b/library/src/updater.rs index 3598454..3893d94 100644 --- a/library/src/updater.rs +++ b/library/src/updater.rs @@ -16,10 +16,6 @@ use crate::network::{download_to_path, patches_check_url, NetworkHooks, PatchChe use crate::updater_lock::{with_updater_thread_lock, UpdaterLockState}; use crate::yaml::YamlConfig; -// https://stackoverflow.com/questions/67087597/is-it-possible-to-use-rusts-log-info-for-tests -#[cfg(test)] -use std::{println as info, println as error, println as debug}; // Workaround to use println! for logs. - #[cfg(test)] // Expose testing_reset_config for integration tests. pub use crate::config::testing_reset_config; @@ -190,7 +186,7 @@ pub fn init( .map_err(|err| InitError::InvalidArgument("yaml".to_string(), err.to_string()))?; let libapp_path = libapp_path_from_settings(&app_config.original_libapp_paths)?; - debug!("libapp_path: {:?}", libapp_path); + shorebird_debug!("libapp_path: {:?}", libapp_path); let set_config_result = set_config( app_config, file_provider, @@ -236,7 +232,7 @@ pub fn handle_prior_boot_failure_if_necessary() -> Result<(), InitError> { Ok(()) }) .map_err(|e| { - error!("Failed to clean up after a failed patch: {:?}", e); + shorebird_error!("Failed to clean up after a failed patch: {:?}", e); InitError::FailedToCleanUpFailedPatch }) } @@ -258,7 +254,7 @@ pub fn check_for_update() -> anyhow::Result { })?; let response = request_fn(&url, request)?; - debug!("Patch check response: {:?}", response); + shorebird_debug!("Patch check response: {:?}", response); if let Some(patch) = response.patch { match should_install_patch(patch.number)? { @@ -300,7 +296,7 @@ fn check_hash(path: &Path, expected_string: &str) -> anyhow::Result<()> { hex::encode(hash) ); } - debug!("Hash match: {:?}", path); + shorebird_debug!("Hash match: {:?}", path); Ok(()) } @@ -349,7 +345,7 @@ fn update_internal(_: &UpdaterLockState) -> anyhow::Result { for event in events { let result = crate::network::send_patch_event(event, &config); if let Err(err) = result { - error!("Failed to report event: {:?}", err); + shorebird_error!("Failed to report event: {:?}", err); } } let request = with_mut_state(|state| { @@ -357,7 +353,7 @@ fn update_internal(_: &UpdaterLockState) -> anyhow::Result { // loaded the state now, but that's OK for now. let result = state.clear_events(); if let Err(err) = result { - error!("Failed to clear events: {:?}", err); + shorebird_error!("Failed to clear events: {:?}", err); } // Update our outer state with the new state. Ok(PatchCheckRequest::new(&config)) @@ -366,13 +362,13 @@ fn update_internal(_: &UpdaterLockState) -> anyhow::Result { // Check for update. let patch_check_request_fn = &(config.network_hooks.patch_check_request_fn); let response = patch_check_request_fn(&patches_check_url(&config.base_url), request)?; - info!("Patch check response: {:?}", response); + shorebird_info!("Patch check response: {:?}", response); with_mut_state(|state| { if let Some(rolled_back_patches) = response.rolled_back_patch_numbers { if !rolled_back_patches.is_empty() { for patch_number in rolled_back_patches { - info!("Attempting uninstall of patch {}...", patch_number); + shorebird_info!("Attempting uninstall of patch {}...", patch_number); state.uninstall_patch(patch_number)?; } } @@ -421,7 +417,7 @@ fn update_internal(_: &UpdaterLockState) -> anyhow::Result { }; // Move/state update should be "atomic" (it isn't today). state.install_patch(&patch_info, &patch.hash, patch.hash_signature.as_deref())?; - info!( + shorebird_info!( "Patch {} successfully downloaded. It will be launched when the app next restarts.", patch.number ); @@ -430,7 +426,7 @@ fn update_internal(_: &UpdaterLockState) -> anyhow::Result { let event = PatchEvent::new(&config, EventType::PatchDownload, patch.number, None); let report_result = crate::network::send_patch_event(event, &config); if let Err(err) = report_result { - error!("Failed to report patch download: {:?}", err); + shorebird_error!("Failed to report patch download: {:?}", err); } }); @@ -445,7 +441,7 @@ fn should_install_patch(patch_number: usize) -> Result Result anyhow::Result<()> { // do so because the semantics have changed: // current is now "last successfully booted patch" // next is now "patch to boot next" - info!("Reporting launch start."); + shorebird_info!("Reporting launch start."); with_mut_state(|state| { if let Some(next_boot_patch) = state.next_boot_patch() { @@ -551,7 +547,7 @@ pub fn report_launch_start() -> anyhow::Result<()> { /// Report that the current active path failed to launch. /// This will mark the patch as bad and activate the next best patch. pub fn report_launch_failure() -> anyhow::Result<()> { - info!("Reporting failed launch."); + shorebird_info!("Reporting failed launch."); with_config(|config| { let mut state = UpdaterState::load_or_new_on_error( @@ -567,7 +563,7 @@ pub fn report_launch_failure() -> anyhow::Result<()> { // even if we fail to mark this one as bad (because it was already bad). let mark_result = state.record_boot_failure_for_patch(patch.number); if mark_result.is_err() { - error!("Failed to mark patch as bad: {:?}", mark_result); + shorebird_error!("Failed to mark patch as bad: {:?}", mark_result); } let event = PatchEvent::new( config, @@ -588,7 +584,7 @@ pub fn report_launch_failure() -> anyhow::Result<()> { } pub fn report_launch_success() -> anyhow::Result<()> { - info!("Reporting successful launch."); + shorebird_info!("Reporting successful launch."); with_config(|config| { // We can tell the UpdaterState that we have successfully booted from the "next" patch @@ -634,7 +630,7 @@ pub fn report_launch_success() -> anyhow::Result<()> { ); let report_result = crate::network::send_patch_event(event, &config_copy); if let Err(err) = report_result { - error!("Failed to report successful patch install: {:?}", err); + shorebird_error!("Failed to report successful patch install: {:?}", err); } }); @@ -651,11 +647,11 @@ pub fn start_update_thread() { let status = match result { Ok(status) => status, Err(err) => { - error!("Update failed: {:?}", err); + shorebird_error!("Update failed: {:?}", err); UpdateStatus::UpdateHadError } }; - info!("Update thread finished with status: {}", status); + shorebird_info!("Update thread finished with status: {}", status); }); }