From d86241724b76c2c1cb1497305d12fd78e4441a19 Mon Sep 17 00:00:00 2001 From: Daniel Carl Jones Date: Wed, 6 Dec 2023 14:21:02 +0000 Subject: [PATCH 1/2] Add CRT error to underlying request log entries Signed-off-by: Daniel Carl Jones --- mountpoint-s3-client/src/s3_crt_client.rs | 9 +++++---- 1 file changed, 5 insertions(+), 4 deletions(-) diff --git a/mountpoint-s3-client/src/s3_crt_client.rs b/mountpoint-s3-client/src/s3_crt_client.rs index e993ee8d2..ce54d5239 100644 --- a/mountpoint-s3-client/src/s3_crt_client.rs +++ b/mountpoint-s3-client/src/s3_crt_client.rs @@ -449,6 +449,7 @@ impl S3CrtClientInner { let http_status = metrics.status_code().unwrap_or(-1); let request_failure = !(200..299).contains(&http_status); + let crt_error = Some(metrics.error()).filter(|e| e.is_err()); let request_type = request_type_to_metrics_string(metrics.request_type()); let request_id = metrics.request_id().unwrap_or_else(|| "".into()); let duration = metrics.total_duration(); @@ -458,12 +459,12 @@ impl S3CrtClientInner { let log_level = status_code_to_log_level(http_status); let message = if request_failure { - "request failed" + "CRT request failed" } else { - "request finished" + "CRT request finished" }; - event!(log_level, %request_type, http_status, ?range, ?duration, ?ttfb, %request_id, "{}", message); - trace!(detailed_metrics=?metrics, "request completed"); + event!(log_level, %request_type, ?crt_error, http_status, ?range, ?duration, ?ttfb, %request_id, "{}", message); + trace!(detailed_metrics=?metrics, "CRT request completed"); let op = span_telemetry.metadata().map(|m| m.name()).unwrap_or("unknown"); if let Some(ttfb) = ttfb { From 0f8118c8e239639e18a40bc9fb74ad54c74fd780 Mon Sep 17 00:00:00 2001 From: Daniel Carl Jones Date: Thu, 7 Dec 2023 09:41:35 +0000 Subject: [PATCH 2/2] Move all CRT request logging to debug even on error Signed-off-by: Daniel Carl Jones --- mountpoint-s3-client/src/s3_crt_client.rs | 10 ++++------ 1 file changed, 4 insertions(+), 6 deletions(-) diff --git a/mountpoint-s3-client/src/s3_crt_client.rs b/mountpoint-s3-client/src/s3_crt_client.rs index ce54d5239..d1216e36c 100644 --- a/mountpoint-s3-client/src/s3_crt_client.rs +++ b/mountpoint-s3-client/src/s3_crt_client.rs @@ -447,8 +447,8 @@ impl S3CrtClientInner { .on_telemetry(move |metrics| { let _guard = span_telemetry.enter(); - let http_status = metrics.status_code().unwrap_or(-1); - let request_failure = !(200..299).contains(&http_status); + let http_status = metrics.status_code(); + let request_failure = http_status.map(|status| !(200..299).contains(&status)).unwrap_or(true); let crt_error = Some(metrics.error()).filter(|e| e.is_err()); let request_type = request_type_to_metrics_string(metrics.request_type()); let request_id = metrics.request_id().unwrap_or_else(|| "".into()); @@ -456,14 +456,12 @@ impl S3CrtClientInner { let ttfb = metrics.time_to_first_byte(); let range = metrics.response_headers().and_then(|headers| extract_range_header(&headers)); - let log_level = status_code_to_log_level(http_status); - let message = if request_failure { "CRT request failed" } else { "CRT request finished" }; - event!(log_level, %request_type, ?crt_error, http_status, ?range, ?duration, ?ttfb, %request_id, "{}", message); + debug!(%request_type, ?crt_error, http_status, ?range, ?duration, ?ttfb, %request_id, "{}", message); trace!(detailed_metrics=?metrics, "CRT request completed"); let op = span_telemetry.metadata().map(|m| m.name()).unwrap_or("unknown"); @@ -473,7 +471,7 @@ impl S3CrtClientInner { metrics::histogram!("s3.requests.total_latency_us", duration.as_micros() as f64, "op" => op, "type" => request_type); metrics::counter!("s3.requests", 1, "op" => op, "type" => request_type); if request_failure { - metrics::counter!("s3.requests.failures", 1, "op" => op, "type" => request_type, "status" => format!("{http_status}")); + metrics::counter!("s3.requests.failures", 1, "op" => op, "type" => request_type, "status" => http_status.unwrap_or(-1).to_string()); } }) .on_headers(move |headers, response_status| {