diff --git a/include/aws/s3/private/s3_util.h b/include/aws/s3/private/s3_util.h index 3162313c7..a490df2a2 100644 --- a/include/aws/s3/private/s3_util.h +++ b/include/aws/s3/private/s3_util.h @@ -290,7 +290,8 @@ AWS_S3_API void aws_s3_request_finish_up_metrics_synced( struct aws_s3_request *request, struct aws_s3_meta_request *meta_request, - int error_code); + int error_code, + bool record_end); AWS_EXTERN_C_END diff --git a/source/s3_auto_ranged_get.c b/source/s3_auto_ranged_get.c index 7eb6d179d..c950ea527 100644 --- a/source/s3_auto_ranged_get.c +++ b/source/s3_auto_ranged_get.c @@ -673,6 +673,7 @@ static void s_s3_auto_ranged_get_request_finished( /* BEGIN CRITICAL SECTION */ { aws_s3_meta_request_lock_synced_data(meta_request); + bool record_end = true; /* If the object range was found, then record it. */ if (found_object_size) { @@ -722,6 +723,9 @@ static void s_s3_auto_ranged_get_request_finished( } aws_s3_meta_request_stream_response_body_synced(meta_request, request); + /* The body of the request is queued to be streamed, don't record the end timestamp for the request + * yet. */ + record_end = false; AWS_LOGF_DEBUG( AWS_LS_S3_META_REQUEST, @@ -756,7 +760,7 @@ static void s_s3_auto_ranged_get_request_finished( meta_request->synced_data.finish_result.validation_algorithm = request->validation_algorithm; } } - aws_s3_request_finish_up_metrics_synced(request, meta_request, error_code); + aws_s3_request_finish_up_metrics_synced(request, meta_request, error_code, record_end); aws_s3_meta_request_unlock_synced_data(meta_request); } diff --git a/source/s3_auto_ranged_put.c b/source/s3_auto_ranged_put.c index 63fec4088..462a0700d 100644 --- a/source/s3_auto_ranged_put.c +++ b/source/s3_auto_ranged_put.c @@ -1622,7 +1622,7 @@ static void s_s3_auto_ranged_put_request_finished( } break; } - aws_s3_request_finish_up_metrics_synced(request, meta_request, error_code); + aws_s3_request_finish_up_metrics_synced(request, meta_request, error_code, true /*record_end*/); aws_s3_meta_request_unlock_synced_data(meta_request); } diff --git a/source/s3_copy_object.c b/source/s3_copy_object.c index a1f32733a..a4b4aa0d4 100644 --- a/source/s3_copy_object.c +++ b/source/s3_copy_object.c @@ -805,7 +805,7 @@ static void s_s3_copy_object_request_finished( } } - aws_s3_request_finish_up_metrics_synced(request, meta_request, error_code); + aws_s3_request_finish_up_metrics_synced(request, meta_request, error_code, true /*record_end*/); aws_s3_meta_request_unlock_synced_data(meta_request); } diff --git a/source/s3_default_meta_request.c b/source/s3_default_meta_request.c index 15292e804..c00f70b5c 100644 --- a/source/s3_default_meta_request.c +++ b/source/s3_default_meta_request.c @@ -401,6 +401,7 @@ static void s_s3_meta_request_default_request_finished( meta_request_default->synced_data.cached_response_status = request->send_data.response_status; meta_request_default->synced_data.request_completed = true; meta_request_default->synced_data.request_error_code = error_code; + bool record_end = true; if (error_code == AWS_ERROR_SUCCESS) { /* Send progress_callback for delivery on io_event_loop thread. @@ -423,10 +424,13 @@ static void s_s3_meta_request_default_request_finished( } aws_s3_meta_request_stream_response_body_synced(meta_request, request); + /* The body of the request is queued to be streamed, don't record the end timestamp for the request + * yet. */ + record_end = false; } else { aws_s3_meta_request_set_fail_synced(meta_request, request, error_code); } - aws_s3_request_finish_up_metrics_synced(request, meta_request, error_code); + aws_s3_request_finish_up_metrics_synced(request, meta_request, error_code, record_end); aws_s3_meta_request_unlock_synced_data(meta_request); } diff --git a/source/s3_meta_request.c b/source/s3_meta_request.c index e29c76331..1b0363ccb 100644 --- a/source/s3_meta_request.c +++ b/source/s3_meta_request.c @@ -1744,9 +1744,16 @@ static void s_s3_meta_request_event_delivery_task(struct aws_task *task, void *a } break; case AWS_S3_META_REQUEST_EVENT_TELEMETRY: { + struct aws_s3_request_metrics *metric = event.u.telemetry.metrics; AWS_FATAL_ASSERT(meta_request->telemetry_callback != NULL); - AWS_FATAL_ASSERT(event.u.telemetry.metrics != NULL); - meta_request->telemetry_callback(meta_request, event.u.telemetry.metrics, meta_request->user_data); + AWS_FATAL_ASSERT(metric != NULL); + + if (metric->time_metrics.end_timestamp_ns == -1) { + aws_high_res_clock_get_ticks((uint64_t *)&metric->time_metrics.end_timestamp_ns); + metric->time_metrics.total_duration_ns = + metric->time_metrics.end_timestamp_ns - metric->time_metrics.start_timestamp_ns; + } + meta_request->telemetry_callback(meta_request, metric, meta_request->user_data); event.u.telemetry.metrics = aws_s3_request_metrics_release(event.u.telemetry.metrics); } break; diff --git a/source/s3_util.c b/source/s3_util.c index 051d6cbf2..21400bd72 100644 --- a/source/s3_util.c +++ b/source/s3_util.c @@ -630,16 +630,20 @@ int aws_s3_crt_error_code_from_server_error_code_string(struct aws_byte_cursor e void aws_s3_request_finish_up_metrics_synced( struct aws_s3_request *request, struct aws_s3_meta_request *meta_request, - int error_code) { + int error_code, + bool record_end) { AWS_PRECONDITION(meta_request); AWS_PRECONDITION(request); if (request->send_data.metrics != NULL) { /* Request is done, complete the metrics for the request now. */ struct aws_s3_request_metrics *metric = request->send_data.metrics; - aws_high_res_clock_get_ticks((uint64_t *)&metric->time_metrics.end_timestamp_ns); - metric->time_metrics.total_duration_ns = - metric->time_metrics.end_timestamp_ns - metric->time_metrics.start_timestamp_ns; + metric->crt_info_metrics.error_code = error_code; + if (record_end) { + aws_high_res_clock_get_ticks((uint64_t *)&metric->time_metrics.end_timestamp_ns); + metric->time_metrics.total_duration_ns = + metric->time_metrics.end_timestamp_ns - metric->time_metrics.start_timestamp_ns; + } if (meta_request->telemetry_callback != NULL) { struct aws_s3_meta_request_event event = {.type = AWS_S3_META_REQUEST_EVENT_TELEMETRY};