set the end time after the body was streamed

awslabs · Dec 6, 2023 · 9f57517 · 9f57517
1 parent 5769bd5
commit 9f57517
Show file tree

Hide file tree

Showing 7 changed files with 31 additions and 11 deletions.
diff --git 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
@@ -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
@@ -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
@@ -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
@@ -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
@@ -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
@@ -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};