improve some error logs

...in particular, pass the error as a tracing param rather than directly
in the main error message. The new behavior is nicer with e.g.
OpenTelemetry.

server/base/clock.rs

@@ -99,7 +99,7 @@ impl Clocks for RealClocks {
     fn sleep(&self, how_long: Duration) {
         match how_long.to_std() {
             Ok(d) => thread::sleep(d),
-            Err(e) => warn!("Invalid duration {:?}: {}", how_long, e),
+            Err(err) => warn!(%err, "invalid duration {:?}", how_long),
         };
     }
 

server/db/check.rs

@@ -43,7 +43,7 @@ pub fn run(conn: &mut rusqlite::Connection, opts: &Options) -> Result<i32, Error
             if e == "ok" {
                 continue;
             }
-            error!("{}", e);
+            error!(err = %e, "sqlite integrity error");
             printed_error = true;
         }
     }

server/db/db.rs

@@ -2322,7 +2322,7 @@ impl<C: Clocks + Clone> Drop for Database<C> {
         }
         if let Some(m) = self.db.take() {
             if let Err(e) = m.into_inner().unwrap().flush(&self.clocks, "drop") {
-                error!("Final database flush failed: {}", e);
+                error!(err = %e.chain(), "final database flush failed");
             }
         }
     }
@@ -2358,7 +2358,7 @@ impl<C: Clocks + Clone> Database<C> {
             let open_uuid = SqlUuid(Uuid::new_v4());
             let boot_uuid = match get_boot_uuid() {
                 Err(e) => {
-                    warn!("Unable to get boot uuid: {}", e);
+                    warn!(err = %e.chain(), "unable to get boot uuid");
                     None
                 }
                 Ok(id) => id.map(SqlUuid),

server/db/dir/mod.rs

@@ -95,8 +95,8 @@ impl std::os::unix::io::AsRawFd for Fd {
 
 impl Drop for Fd {
     fn drop(&mut self) {
-        if let Err(e) = nix::unistd::close(self.0) {
-            warn!("Unable to close sample file dir: {}", e);
+        if let Err(err) = nix::unistd::close(self.0) {
+            warn!(%err, "unable to close sample file dir");
         }
     }
 }
@@ -236,9 +236,10 @@ impl SampleFileDir {
             bail!(
                 Internal,
                 msg(
-                    "metadata mismatch: {e}.\nexpected:\n{expected_meta:#?}\n\nactual:\n\
+                    "metadata mismatch\nexpected:\n{expected_meta:#?}\n\nactual:\n\
                     {dir_meta:#?}",
                 ),
+                source(e),
             );
         }
         if expected_meta.in_progress_open.is_some() {

server/db/upgrade/v4_to_v5.rs

@@ -44,7 +44,8 @@ fn maybe_upgrade_meta(dir: &dir::Fd, db_meta: &schema::DirMeta) -> Result<bool,
     if let Err(e) = dir::SampleFileDir::check_consistent(db_meta, &dir_meta) {
         bail!(
             FailedPrecondition,
-            msg("inconsistent db_meta={db_meta:?} dir_meta={dir_meta:?}: {e}"),
+            msg("inconsistent db_meta={db_meta:?} dir_meta={dir_meta:?}"),
+            source(e),
         );
     }
     let mut f = crate::fs::openat(

server/db/writer.rs

@@ -176,7 +176,7 @@ where
         let snd = snd.clone();
         move || {
             if let Err(err) = snd.send(SyncerCommand::DatabaseFlushed) {
-                warn!(%err, "Unable to notify syncer for dir {}", dir_id);
+                warn!(%err, "unable to notify syncer for dir {}", dir_id);
             }
         }
     }));
@@ -403,9 +403,9 @@ impl<C: Clocks + Clone> Syncer<C, Arc<dir::SampleFileDir>> {
             // Try to delete files; retain ones in `garbage` that don't exist.
             let mut errors = 0;
             for &id in &garbage {
-                if let Err(e) = self.dir.unlink_file(id) {
-                    if e != nix::Error::ENOENT {
-                        warn!("dir: Unable to unlink {}: {}", id, e);
+                if let Err(err) = self.dir.unlink_file(id) {
+                    if err != nix::Error::ENOENT {
+                        warn!(%err, "dir: unable to unlink {}", id);
                         errors += 1;
                     }
                 }
@@ -1199,8 +1199,8 @@ mod tests {
         tdb.db.lock().on_flush(Box::new({
             let snd = syncer_tx.clone();
             move || {
-                if let Err(e) = snd.send(super::SyncerCommand::DatabaseFlushed) {
-                    warn!("Unable to notify syncer for dir {} of flush: {}", dir_id, e);
+                if let Err(err) = snd.send(super::SyncerCommand::DatabaseFlushed) {
+                    warn!(%err, "unable to notify syncer for dir {} of flush", dir_id);
                 }
             }
         }));

server/src/cmds/config/cameras.rs

@@ -397,7 +397,7 @@ fn confirm_deletion(siv: &mut Cursive, db: &Arc<db::Database>, id: i32, to_delet
         }
         if let Err(e) = lower_retention(db, zero_limits) {
             siv.add_layer(
-                views::Dialog::text(format!("Unable to delete recordings: {e}"))
+                views::Dialog::text(format!("Unable to delete recordings: {}", e.chain()))
                     .title("Error")
                     .dismiss_button("Abort"),
             );
@@ -433,7 +433,7 @@ fn actually_delete(siv: &mut Cursive, db: &Arc<db::Database>, id: i32) {
     };
     if let Err(e) = result {
         siv.add_layer(
-            views::Dialog::text(format!("Unable to delete camera: {e}"))
+            views::Dialog::text(format!("Unable to delete camera: {}", e.chain()))
                 .title("Error")
                 .dismiss_button("Abort"),
         );

server/src/cmds/config/dirs.rs

@@ -51,7 +51,7 @@ fn update_limits_inner(model: &Model) -> Result<(), Error> {
 fn update_limits(model: &Model, siv: &mut Cursive) {
     if let Err(e) = update_limits_inner(model) {
         siv.add_layer(
-            views::Dialog::text(format!("Unable to update limits: {e}"))
+            views::Dialog::text(format!("Unable to update limits: {}", e.chain()))
                 .dismiss_button("Back")
                 .title("Error"),
         );
@@ -142,7 +142,7 @@ fn actually_delete(model: &RefCell<Model>, siv: &mut Cursive) {
     }
     if let Err(e) = writer::lower_retention(&model.db, model.dir_id, &new_limits[..]) {
         siv.add_layer(
-            views::Dialog::text(format!("Unable to delete excess video: {e}"))
+            views::Dialog::text(format!("Unable to delete excess video: {}", e.chain()))
                 .title("Error")
                 .dismiss_button("Abort"),
         );
@@ -282,9 +282,13 @@ fn add_dir_dialog(db: &Arc<db::Database>, siv: &mut Cursive) {
 fn add_dir(db: &Arc<db::Database>, siv: &mut Cursive, path: &Path) {
     if let Err(e) = db.lock().add_sample_file_dir(path.to_owned()) {
         siv.add_layer(
-            views::Dialog::text(format!("Unable to add path {}: {}", path.display(), e))
-                .dismiss_button("Back")
-                .title("Error"),
+            views::Dialog::text(format!(
+                "Unable to add path {}: {}",
+                path.display(),
+                e.chain()
+            ))
+            .dismiss_button("Back")
+            .title("Error"),
         );
         return;
     }
@@ -312,7 +316,7 @@ fn delete_dir_dialog(db: &Arc<db::Database>, siv: &mut Cursive, dir_id: i32) {
 fn delete_dir(db: &Arc<db::Database>, siv: &mut Cursive, dir_id: i32) {
     if let Err(e) = db.lock().delete_sample_file_dir(dir_id) {
         siv.add_layer(
-            views::Dialog::text(format!("Unable to delete dir id {dir_id}: {e}"))
+            views::Dialog::text(format!("Unable to delete dir id {dir_id}: {}", e.chain()))
                 .dismiss_button("Back")
                 .title("Error"),
         );

server/src/cmds/config/users.rs

@@ -6,7 +6,6 @@ use cursive::traits::{Nameable, Resizable};
 use cursive::views;
 use cursive::Cursive;
 use std::sync::Arc;
-use tracing::info;
 
 /// Builds a `UserChange` from an active `edit_user_dialog`.
 fn get_change(
@@ -48,7 +47,6 @@ fn get_change(
         ),
     ] {
         **b = siv.find_name::<views::Checkbox>(id).unwrap().is_checked();
-        info!("{}: {}", id, **b);
     }
     change
 }
@@ -61,7 +59,7 @@ fn press_edit(siv: &mut Cursive, db: &Arc<db::Database>, id: Option<i32>, pw: Pa
     };
     if let Err(e) = result {
         siv.add_layer(
-            views::Dialog::text(format!("Unable to apply change: {e}"))
+            views::Dialog::text(format!("Unable to apply change: {}", e.chain()))
                 .title("Error")
                 .dismiss_button("Abort"),
         );
@@ -94,7 +92,7 @@ fn actually_delete(siv: &mut Cursive, db: &Arc<db::Database>, id: i32) {
     };
     if let Err(e) = result {
         siv.add_layer(
-            views::Dialog::text(format!("Unable to delete user: {e}"))
+            views::Dialog::text(format!("Unable to delete user: {}", e.chain()))
                 .title("Error")
                 .dismiss_button("Abort"),
         );

server/src/cmds/run/mod.rs

@@ -439,8 +439,8 @@ async fn inner(
 
     info!("Waiting for TEARDOWN requests to complete.");
     for g in session_groups_by_camera.values() {
-        if let Err(e) = g.await_teardown().await {
-            error!("{}", e);
+        if let Err(err) = g.await_teardown().await {
+            error!(%err, "teardown failed");
         }
     }
 

server/src/main.rs

@@ -94,7 +94,7 @@ fn main() {
 
     match args.run() {
         Err(e) => {
-            error!("exiting due to error: {}", e.chain());
+            error!(err = %e.chain(), "exiting due to error");
             ::std::process::exit(1);
         }
         Ok(rv) => {

server/src/web/mod.rs

@@ -638,13 +638,13 @@ impl Service {
                         }),
                     })
                 }
-                Err(e) if e.kind() == base::ErrorKind::Unauthenticated => {
+                Err(err) if err.kind() == base::ErrorKind::Unauthenticated => {
                     // Log the specific reason this session is unauthenticated.
                     // Don't let the API client see it, as it may have a
                     // revocation reason that isn't for their eyes.
-                    warn!("Session authentication failed: {e}");
+                    warn!(err = %err.chain(), "session authentication failed");
                 }
-                Err(e) => return Err(e),
+                Err(err) => return Err(err),
             };
         }