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.
This commit is contained in:
Scott Lamb 2023-08-03 15:42:41 -05:00
parent 9d07d24bc7
commit b9db9c11cc
12 changed files with 36 additions and 32 deletions

View File

@ -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),
};
}

View File

@ -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;
}
}

View File

@ -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),

View File

@ -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() {

View File

@ -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(

View File

@ -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);
}
}
}));

View File

@ -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"),
);

View File

@ -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"),
);

View File

@ -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"),
);

View File

@ -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");
}
}

View File

@ -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) => {

View File

@ -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),
};
}