refactor(log): remove workaround for logging issue

Also renames `opts.log_level` to `opts.log` for internal use.

src/lib.rs

@@ -75,6 +75,9 @@ pub mod opts;
 pub mod tasks;
 pub mod utils;
 
+/// The unique identifier of the up application on the system.
+pub const UP_BUNDLE_ID: &str = "co.fahn.up";
+
 /// Run `up_rs` with provided [Opts][] struct.
 ///
 /// # Errors

src/main.rs

@@ -14,9 +14,13 @@
 #![allow(clippy::implicit_return, clippy::missing_docs_in_private_items)]
 
 use camino::Utf8PathBuf;
+use chrono::SecondsFormat;
+use color_eyre::eyre::eyre;
+use color_eyre::eyre::Context;
 use color_eyre::eyre::Result;
+use color_eyre::Section;
+use color_eyre::SectionExt;
 use std::env;
-use std::fs::File;
 use std::sync::Arc;
 use std::time::Duration;
 use std::time::Instant;
@@ -33,6 +37,8 @@ use tracing_subscriber::prelude::*;
 use tracing_subscriber::util::SubscriberInitExt;
 use up_rs::log;
 use up_rs::opts::Opts;
+use up_rs::utils::errors::log_error;
+use up_rs::utils::files;
 
 /// Env vars to avoid printing when we log the current environment.
 const IGNORED_ENV_VARS: [&str; 1] = [
@@ -48,9 +54,7 @@ fn main() -> Result<()> {
 
     let mut opts = up_rs::opts::parse();
 
-    let (log_path, level_filter) = set_up_logging(&opts);
-
-    color_eyre::config::HookBuilder::default()
+    color_eyre::config::HookBuilder::new()
         // Avoids printing these lines when up fails:
         // ```
         // Backtrace omitted. Run with RUST_BACKTRACE=1 environment variable to display it.
@@ -59,15 +63,21 @@ fn main() -> Result<()> {
         .display_env_section(false)
         .install()?;
 
-    // If we set a log filter, save that filter back to the log option.
-    // This allows us to run `up -l up=trace`, and get back a `trace` variable we can use in
-    // `Opts::debug_logging_enabled()`.
-    if let Some(filter) = level_filter {
-        opts.log_level = filter.to_string();
-    }
+    let log_path = match set_up_logging(&opts) {
+        Ok((log_path, level_filter)) => {
+            // If we set a log filter, save that filter back to the log option.
+            // This allows us to run `up -l up=trace`, and get back a `trace` variable we can use
+            // to check log levels later in the application.
+            opts.log = level_filter.to_string();
+            Some(log_path)
+        }
+        Err(e) => {
+            eprintln!(" WARN Failed to set up logging.{err}", err = log_error(&e));
+            None
+        }
+    };
 
     trace!("Starting up.");
-    debug!("Writing full logs to {log_path}",);
 
     trace!("Received args: {opts:#?}");
     trace!(
@@ -77,7 +87,13 @@ fn main() -> Result<()> {
             .collect::<Vec<_>>()
     );
 
-    up_rs::run(opts)?;
+    let mut result = up_rs::run(opts);
+
+    if let Some(log_path) = log_path {
+        result = result.with_section(|| format!("{log_path}").header("Log file:"));
+    }
+
+    result?;
 
     // No need to log the time we took to run by default unless it actually took some time.
     let now_elapsed = now.elapsed();
@@ -93,7 +109,7 @@ fn main() -> Result<()> {
 
 /// Set up logging to stderr and to a temp file path.
 /// Returns the log level filter chosen by the user if available, and the path to the log file.
-fn set_up_logging(opts: &Opts) -> (Utf8PathBuf, Option<LevelFilter>) {
+fn set_up_logging(opts: &Opts) -> Result<(Utf8PathBuf, LevelFilter)> {
     let indicatif_layer = IndicatifLayer::new();
 
     let stderr_log = tracing_subscriber::fmt::layer()
@@ -102,27 +118,38 @@ fn set_up_logging(opts: &Opts) -> (Utf8PathBuf, Option<LevelFilter>) {
         .without_time()
         .with_writer(indicatif_layer.get_stderr_writer());
 
-    let (log_path, log_file) = get_log_file_and_path(opts);
-    let log_file_setup = log_file.is_some();
+    // Logs go to e.g. ~/Library/Logs/co.fahn.up/up_2024-04-26T11_22_24.834348Z.log
+    let log_path = files::log_dir()?.join(format!(
+        "up_{}.log",
+        opts.start_time
+            .to_rfc3339_opts(SecondsFormat::AutoSi, true)
+            // : is not an allowed filename character in Finder.
+            .replace(':', "_")
+    ));
+
+    let log_file = files::create(&log_path, None).wrap_err("Failed to create log file.")?;
 
     let stderr_envfilter = EnvFilter::builder()
         .with_default_directive(LevelFilter::INFO.into())
-        .parse_lossy(&opts.log_level);
-    let log_filter = stderr_envfilter.max_level_hint();
+        .parse_lossy(&opts.log);
+    let log_filter = stderr_envfilter.max_level_hint().ok_or_else(|| {
+        eyre!(
+            "Failed to work out the max level hint for {}",
+            &opts.log,
+        )
+    })?;
 
     let file_envfilter = EnvFilter::builder()
         .with_default_directive(LevelFilter::TRACE.into())
         .parse_lossy("up=trace");
 
-    let file_log = log_file.map(|log_file| {
-        tracing_subscriber::fmt::layer()
-            .with_writer(Arc::new(log_file))
-            .with_target(true)
-            .with_file(true)
-            .with_line_number(true)
-            .pretty()
-            .with_ansi(false)
-    });
+    let file_log = tracing_subscriber::fmt::layer()
+        .with_writer(Arc::new(log_file))
+        .with_target(true)
+        .with_file(true)
+        .with_line_number(true)
+        .pretty()
+        .with_ansi(false);
 
     // Always log to stderr, also log to a file if we can successfully set that up.
     tracing_subscriber::registry()
@@ -134,37 +161,7 @@ fn set_up_logging(opts: &Opts) -> (Utf8PathBuf, Option<LevelFilter>) {
         .with(ErrorLayer::default())
         .init();
 
-    if log_file_setup {
-        debug!("Writing trace logs to {log_path:?}");
-    } else {
-        warn!("Failed to set up logging to a file");
-    };
-
-    (log_path, log_filter)
-}
+    debug!("Writing trace logs to {log_path:?}");
 
-/// Get the path to the default log file, and create that file.
-fn get_log_file_and_path(opts: &Opts) -> (Utf8PathBuf, Option<File>) {
-    // TODO(gib): if this function tries to do any logging, or returns a Result, and file logging
-    // doesn't get set up properly, then it seems to break stderr logging as well. Test by running
-    // `cargo build && TMPDIR=/dev/null target/debug/up build`. We don't see the `warn!()`
-    // in `set_up_logging()`.
-    // Probably https://github.com/yaahc/color-eyre/issues/110
-
-    let log_dir = opts.temp_dir.join("logs");
-    let log_path = log_dir.join(format!("up-rs_{}.log", opts.start_time.to_rfc3339()));
-
-    // Can't use files::create_dir_all() wrapper as it uses logging.
-    if let Err(e) = std::fs::create_dir_all(&log_dir) {
-        eprintln!(" WARN Failed to create log directory {log_dir}.\n  Error: {e:?}");
-        return (log_path, None);
-    }
-    let log_file = match File::create(&log_path) {
-        Ok(log_file) => log_file,
-        Err(e) => {
-            eprintln!(" WARN failed to create log file {log_path}:\n  Error: {e}");
-            return (log_path, None);
-        }
-    };
-    (log_path, Some(log_file))
+    Ok((log_path, log_filter))
 }

src/opts.rs

@@ -64,9 +64,10 @@ pub struct Opts {
         long,
         short = 'l',
         default_value = "up=info,up_rs=info",
-        env = "RUST_LOG"
+        env = "RUST_LOG",
+        alias = "log_level"
     )]
-    pub log_level: String,
+    pub log: String,
 
     /**
     Temporary directory to use for logs, fifos, and other intermediate artifacts.

src/tasks/task.rs

@@ -105,8 +105,8 @@ pub struct TaskConfig {
     /// This will allow all subtasks that up executes in this iteration.
     #[serde(default = "default_false")]
     pub needs_sudo: bool,
-    // This field must be the last one in this struct in order for the yaml serializer in the generate functions
-    // to be able to serialise it properly.
+    // This field must be the last one in this struct in order for the yaml serializer in the
+    // generate functions to be able to serialise it properly.
     /// Set of data provided to the Run library.
     #[serde(skip_serializing_if = "Option::is_none")]
     // schemars doesn't have built-in support for YAML values, but it does have support for

src/utils.rs

@@ -1,6 +1,7 @@
 //! General-use utility functions.
 
-pub(crate) mod files;
+pub mod errors;
+pub mod files;
 pub(crate) mod log;
 pub(crate) mod mac;
 pub(crate) mod user;

src/utils/errors.rs

@@ -0,0 +1,13 @@
+//! Utilities for manipulating eyre errors.
+
+use std::fmt::Debug;
+
+/// Format an error into a nice way to show it in a log message.
+/// e.g.
+///
+/// ```text
+/// trace!("Action failed.{}", log_error(&e));
+/// ```
+pub fn log_error(e: &impl Debug) -> String {
+    format!("\n  Error: {e:?}")
+}

src/utils/files.rs

@@ -1,12 +1,16 @@
 //! Utilities for dealing with files, including wrappers around `std::fs` APIs.
 
 use crate::errors::UpError;
+use crate::UP_BUNDLE_ID;
 use camino::Utf8Path;
 use camino::Utf8PathBuf;
 use color_eyre::eyre::eyre;
 use color_eyre::eyre::Context;
 use color_eyre::Result;
 use std::fs;
+use std::fs::File;
+use std::fs::OpenOptions;
+use std::os::unix::fs::OpenOptionsExt;
 use tracing::trace;
 use tracing::warn;
 
@@ -31,6 +35,17 @@ pub fn home_dir() -> Result<Utf8PathBuf> {
     Ok(home_dir)
 }
 
+/// The directory to which we write log files.
+pub fn log_dir() -> Result<Utf8PathBuf> {
+    Ok(home_dir()?.join("Library/Logs").join(UP_BUNDLE_ID))
+}
+
+/// Get a parent path or provide a useful error message.
+pub(crate) fn parent(path: &Utf8Path) -> Result<&Utf8Path> {
+    path.parent()
+        .ok_or_else(|| eyre!("Didn't expect path {path} to be the root directory."))
+}
+
 /// Convert a std path to a `Utf8Path`. We should be able to use `Utf8Path::try_from()`, but get
 /// compiler errors.
 pub fn to_utf8_path(path: &std::path::Path) -> Result<&Utf8Path> {
@@ -56,6 +71,24 @@ pub fn remove_broken_symlink(path: &Utf8Path) -> Result<(), UpError> {
     Ok(())
 }
 
+/// Ensure that a file exists with the specified permissions, creating it and its parent directories
+/// as needed.
+pub fn create(file_path: &Utf8Path, mode: Option<u32>) -> Result<File> {
+    trace!("Ensuring file exists: {file_path}");
+    create_dir_all(parent(file_path)?)?;
+    let mode = mode.unwrap_or(0o666);
+
+    let file = OpenOptions::new()
+        .write(true)
+        .create(true)
+        // This mode is only set if the file didn't exist.
+        .mode(mode)
+        .open(file_path)
+        .wrap_err_with(|| eyre!("Failed to create file at {file_path}"))?;
+
+    Ok(file)
+}
+
 /// Same as `std::fs::create_dir_all()` but with a better error message.
 pub fn create_dir_all(path: impl AsRef<Utf8Path>) -> Result<()> {
     let path = path.as_ref();