Skip to content

Commit 5e836f8

Browse files
radekchannableradekchannable
committed
Consistently pass errors as fields of type &dyn Error to tracing::error!
Previously, many tracing::error! calls formatted the error as part of the message, but this loses information about the error's source chain.
1 parent c239da7 commit 5e836f8

10 files changed

Lines changed: 61 additions & 15 deletions

File tree

‎opsqueue/app/main.rs‎

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -4,9 +4,9 @@ use opentelemetry_otlp::SpanExporter;
44
use opentelemetry_resource_detectors::HostResourceDetector;
55
use opentelemetry_resource_detectors::{OsResourceDetector, ProcessResourceDetector};
66
use opentelemetry_sdk::trace::{RandomIdGenerator, Sampler, SdkTracerProvider};
7+
use opsqueue::tracing::as_dyn_error;
78
use opsqueue::{common::submission::db::periodically_cleanup_old, config::Config, prometheus};
89
use std::{
9-
error::Error,
1010
sync::{Arc, atomic::AtomicBool},
1111
time::Duration,
1212
};
@@ -104,7 +104,7 @@ pub async fn async_main() {
104104
res = tokio::signal::ctrl_c() => {
105105
match res {
106106
Ok(()) => tracing::warn!("Received Ctrl-C signal"),
107-
Err(ref err) => tracing::error!(error = err as &dyn Error, "Error while waiting for Ctrl-C signal"),
107+
Err(ref err) => tracing::error!(error = as_dyn_error(err), "Error while waiting for Ctrl-C signal"),
108108
}
109109
},
110110
};

‎opsqueue/src/common/submission.rs‎

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -276,6 +276,7 @@ impl Submission {
276276

277277
#[cfg(feature = "server-logic")]
278278
pub mod db {
279+
use crate::tracing::as_dyn_error;
279280
use crate::{
280281
common::{
281282
MaxSubmissions, StrategicMetadataMap,
@@ -1179,7 +1180,7 @@ pub mod db {
11791180
}
11801181
.await;
11811182
if let Err(e) = res {
1182-
tracing::error!("Error during periodic cleanup: {}", e);
1183+
tracing::error!(error = as_dyn_error(&e), "Error during periodic cleanup");
11831184
}
11841185
tokio::time::sleep(PERIODIC_CLEANUP_INTERVAL).await;
11851186
}

‎opsqueue/src/consumer/client.rs‎

Lines changed: 4 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -1,6 +1,6 @@
1+
use crate::tracing::as_dyn_error;
12
use std::{
23
collections::HashMap,
3-
error::Error,
44
str::FromStr,
55
sync::{
66
Arc,
@@ -356,7 +356,7 @@ impl Client {
356356
break;
357357
}
358358
Some(Err(e)) => {
359-
tracing::error!("Opsqueue consumer client background task closing, reason: {e}");
359+
tracing::error!(error = as_dyn_error(&e), "Opsqueue consumer client background task closing, reason");
360360
break;
361361
},
362362
Some(Ok(msg)) => {
@@ -389,7 +389,7 @@ impl Client {
389389
failure: "Requester disappeared".into(),
390390
},
391391
).await else { continue; };
392-
tracing::error!(error = &internal_error as &dyn Error, chunk_id = ?chunk_id, "Failed to return unhandled reservation to server");
392+
tracing::error!(error = as_dyn_error(&internal_error), chunk_id = ?chunk_id, "Failed to return unhandled reservation to server");
393393
}
394394
},
395395
}
@@ -416,7 +416,7 @@ impl Client {
416416
failure: "Reservation expired".into(),
417417
},
418418
).await else { continue; };
419-
tracing::error!(error = &internal_error as &dyn Error, chunk_id = ?chunk_id, "Failed to return expired reservation to server");
419+
tracing::error!(error = as_dyn_error(&internal_error), chunk_id = ?chunk_id, "Failed to return expired reservation to server");
420420
},
421421
}
422422
}

‎opsqueue/src/consumer/server/conn.rs‎

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -1,3 +1,4 @@
1+
use crate::tracing::as_dyn_error;
12
use std::{
23
sync::{
34
Arc,
@@ -216,7 +217,7 @@ impl ConsumerConn {
216217
.await;
217218
match chunks_or_err {
218219
Err(e) => {
219-
tracing::error!("Failed to reserve chunks: {}", e);
220+
tracing::error!(error = as_dyn_error(&e), "Failed to reserve chunks");
220221
match e {
221222
// In the unlikely event of a DatabaseError,
222223
// this is not the client's fault but _our_ fault.

‎opsqueue/src/consumer/server/mod.rs‎

Lines changed: 7 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -1,3 +1,4 @@
1+
use crate::tracing::{anyhow_as_dyn_error, as_dyn_error};
12
use std::{
23
collections::HashSet,
34
sync::{Arc, Mutex},
@@ -124,7 +125,8 @@ async fn ws_accept_handler(
124125
Ok(()) => {}
125126
Err(e) if e.is_internal_error() => {
126127
tracing::error!(
127-
"Closed websocket connection because of internal error, details: {e:?}"
128+
error = as_dyn_error(&e),
129+
"Closed websocket connection because of internal error"
128130
);
129131
}
130132
Err(e) => {
@@ -298,7 +300,10 @@ impl Completer {
298300
.await;
299301
match res {
300302
Ok(()) => {}
301-
Err(err) => tracing::error!("Error in chunk completer: {err}"),
303+
Err(err) => tracing::error!(
304+
error = anyhow_as_dyn_error(&err),
305+
"Error in chunk completer"
306+
),
302307
}
303308
}
304309
}

‎opsqueue/src/db/mod.rs‎

Lines changed: 6 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -53,6 +53,7 @@
5353
//! # Ok (()) }
5454
//! ```
5555
56+
use crate::tracing::as_dyn_error;
5657
use std::{marker::PhantomData, num::NonZero, time::Duration};
5758

5859
use futures::future::BoxFuture;
@@ -215,8 +216,11 @@ impl DBPools {
215216
})
216217
.await
217218
.is_ok(),
218-
Err(error) => {
219-
tracing::error!("DB unhealthy; could not acquire DB connection: {error:?}");
219+
Err(err) => {
220+
tracing::error!(
221+
error = as_dyn_error(&err),
222+
"DB unhealthy; could not acquire DB connection"
223+
);
220224
false
221225
}
222226
}

‎opsqueue/src/producer/server.rs‎

Lines changed: 5 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -4,6 +4,7 @@ use crate::common::errors::E::{L, R};
44
use crate::common::submission::{self, SubmissionId};
55
use crate::common::{MaxSubmissions, StrategicMetadataMap};
66
use crate::db::{self, DBPools};
7+
use crate::tracing::anyhow_as_dyn_error;
78
use axum::extract;
89
use axum::extract::{Path, State};
910
use axum::http::StatusCode;
@@ -90,7 +91,10 @@ struct ServerError(anyhow::Error);
9091

9192
impl IntoResponse for ServerError {
9293
fn into_response(self) -> Response {
93-
tracing::error!("Producer Server Error {:?}", self.0);
94+
tracing::error!(
95+
error = anyhow_as_dyn_error(&self.0),
96+
"Producer Server Error"
97+
);
9498

9599
(
96100
StatusCode::INTERNAL_SERVER_ERROR,

‎opsqueue/src/prometheus.rs‎

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -13,6 +13,7 @@ use axum_prometheus::{
1313
use tokio_util::sync::CancellationToken;
1414

1515
use crate::db::DBPools;
16+
use crate::tracing::anyhow_as_dyn_error;
1617

1718
pub const SUBMISSIONS_TOTAL_COUNTER: &str = "submissions_total_count";
1819
pub const SUBMISSIONS_COMPLETED_COUNTER: &str = "submissions_completed_count";
@@ -233,7 +234,7 @@ pub async fn periodically_calculate_scaling_metrics(
233234
() = cancellation_token.cancelled() => break,
234235
() = tokio::time::sleep(METRICS_INTERVAL) => {
235236
if let Err(e) = calculate_scaling_metrics(db_pool).await {
236-
tracing::error!("Error calculating scaling metrics: {}", e);
237+
tracing::error!(error = anyhow_as_dyn_error(&e), "Error calculating scaling metrics");
237238
}
238239
}
239240
}

‎opsqueue/src/server.rs‎

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -1,4 +1,5 @@
11
//! Defines the HTTP endpoints that are used by both the `producer` and `consumer` APIs
2+
use crate::tracing::as_dyn_error;
23
use std::{
34
any::Any,
45
mem,
@@ -72,7 +73,7 @@ pub async fn serve_producer_and_consumer(
7273
Ok(())
7374
})
7475
.retry(retry_policy())
75-
.notify(|e, d| tracing::error!("Error when binding server address: {e:?}, retrying in {d:?}"))
76+
.notify(|e, d| tracing::error!(error = as_dyn_error(e), "Error when binding server address, retrying in {d:?}"))
7677
.await.inspect_err(|_|{
7778
// Drop the pipe after the server start retries have been exhausted. This ensures that the
7879
// parent process can safely block on reading from the pipe.

‎opsqueue/src/tracing.rs‎

Lines changed: 29 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -4,6 +4,7 @@ use opentelemetry::{Context, propagation::TextMapCompositePropagator};
44
use opentelemetry_http::{HeaderExtractor, HeaderInjector};
55
use opentelemetry_sdk::propagation::{BaggagePropagator, TraceContextPropagator};
66
use rustc_hash::FxHashMap;
7+
use std::error::Error;
78

89
#[must_use]
910
pub fn context_from_headers(headers: &http::HeaderMap) -> Context {
@@ -57,3 +58,31 @@ pub fn propagator() -> TextMapCompositePropagator {
5758
Box::new(TraceContextPropagator::new()),
5859
])
5960
}
61+
62+
/// Convenient function for converting an error into `dyn Error` for tracing.
63+
///
64+
/// When logging an error, convert the error to `dyn Error` using this function
65+
/// and assign it to the `error` field, rather than displaying the error, so
66+
/// that the source chain of the error is preserved.
67+
///
68+
/// ```ignore
69+
/// // Good:
70+
/// tracing::error!(error = as_dyn_error(e), "operation failed");
71+
///
72+
/// // Bad:
73+
/// tracing::error!("operation failed: {e}");
74+
/// tracing::error!(error = %e, "operation failed");
75+
/// ```
76+
pub fn as_dyn_error<T>(err: &T) -> &(dyn 'static + Error)
77+
where
78+
T: 'static + Error,
79+
{
80+
err
81+
}
82+
83+
/// [`anyhow::Error`] does not implement [`Error`], so this function is
84+
/// separate from [`as_dyn_error`].
85+
#[must_use]
86+
pub fn anyhow_as_dyn_error(err: &anyhow::Error) -> &(dyn 'static + Error) {
87+
err.as_ref()
88+
}

0 commit comments

Comments
 (0)