add more metrics to request

Author: DmitriyMusatkin

include/aws/s3/private/s3_request.h

@@ -70,6 +70,26 @@ struct aws_s3_request_metrics {
         /* The time duration for the request from start signing to finish signing (sign_end_timestamp_ns -
          * sign_start_timestamp_ns). When sign_end_timestamp_ns is 0, means data not available. */
         int64_t signing_duration_ns;
+
+        /* The time stamp when the request started to acquire memory. -1 means data not
+         * available. Timestamp are from `aws_high_res_clock_get_ticks` */
+        int64_t mem_acquire_start_timestamp_ns;
+        /* The time stamp when the response to acquire memory. -1 means data not
+         * available. Timestamp are from `aws_high_res_clock_get_ticks` */
+        int64_t mem_acquire_end_timestamp_ns;
+        /* The time duration for the request from start mem acquire to finish mem acquire (mem_acquire_end_timestamp_ns
+         * - mem_acquire_start_timestamp_ns). When sign_end_timestamp_ns is 0, means data not available. */
+        int64_t mem_acquire_duration_ns;
+
+        /* The time stamp when the request started to be delivered (i.e. on body callback is invoked or write to file
+         * initiated). -1 means data not available. Timestamp are from `aws_high_res_clock_get_ticks` */
+        int64_t deliver_start_timestamp_ns;
+        /* The time stamp when the response finished to be delivered. -1 means data not
+         * available. Timestamp are from `aws_high_res_clock_get_ticks` */
+        int64_t deliver_end_timestamp_ns;
+        /* The time duration for the request from start of delivery to finish of delivery (deliver_end_timestamp_ns -
+         * deliver_start_timestamp_ns). When deliver_duration_ns is 0, means data not available. */
+        int64_t deliver_duration_ns;
     } time_metrics;
 
     struct {

source/s3_client.c

@@ -1850,6 +1850,14 @@ static void s_on_pool_buffer_reserved(void *user_data) {
     struct aws_s3_meta_request *meta_request = request->meta_request;
     AWS_PRECONDITION(meta_request);
 
+    if (request->send_data.metrics) {
+        struct aws_s3_request_metrics *metric = request->send_data.metrics;
+        aws_high_res_clock_get_ticks((uint64_t *)&metric->time_metrics.mem_acquire_end_timestamp_ns);
+        AWS_ASSERT(metric->time_metrics.mem_acquire_start_timestamp_ns != 0);
+        metric->time_metrics.mem_acquire_duration_ns =
+            metric->time_metrics.mem_acquire_end_timestamp_ns - metric->time_metrics.mem_acquire_start_timestamp_ns;
+    }
+
     struct aws_future_s3_buffer_ticket *future_ticket = payload->buffer_future;
 
     int error_code = aws_future_s3_buffer_ticket_get_error(future_ticket);
@@ -1889,10 +1897,19 @@ void s_acquire_mem_and_prepare_request(
     void *user_data) {
 
     if (request->ticket == NULL && request->should_allocate_buffer_from_pool) {
+
+        if (request->send_data.metrics) {
+            struct aws_s3_request_metrics *metric = request->send_data.metrics;
+            aws_high_res_clock_get_ticks((uint64_t *)&metric->time_metrics.mem_acquire_start_timestamp_ns);
+        }
+
         struct aws_allocator *allocator = request->allocator;
         struct aws_s3_meta_request *meta_request = request->meta_request;
         struct aws_s3_buffer_pool_reserve_meta meta = {
-            .client = client, .meta_request = meta_request, .size = meta_request->part_size};
+            .client = client,
+            .meta_request = meta_request,
+            .size = meta_request->part_size,
+        };
 
         struct aws_s3_reserve_memory_payload *payload =
             aws_mem_calloc(allocator, 1, sizeof(struct aws_s3_reserve_memory_payload));

source/s3_meta_request.c

@@ -1933,6 +1933,11 @@ static void s_s3_meta_request_event_delivery_task(struct aws_task *task, void *a
                         }
                     }
                     if (error_code == AWS_ERROR_SUCCESS) {
+                        if (request->send_data.metrics) {
+                            struct aws_s3_request_metrics *metric = request->send_data.metrics;
+                            aws_high_res_clock_get_ticks((uint64_t *)&metric->time_metrics.deliver_start_timestamp_ns);
+                        }
+
                         if (meta_request->recv_file) {
                             /* Write the data directly to the file. No need to seek, since the event will always be
                              * delivered with the right order. */
@@ -1978,6 +1983,14 @@ static void s_s3_meta_request_event_delivery_task(struct aws_task *task, void *a
                                 error_code,
                                 aws_error_str(error_code));
                         }
+
+                        if (request->send_data.metrics) {
+                            struct aws_s3_request_metrics *metric = request->send_data.metrics;
+                            aws_high_res_clock_get_ticks((uint64_t *)&metric->time_metrics.deliver_end_timestamp_ns);
+                            AWS_ASSERT(metric->time_metrics.deliver_start_timestamp_ns != 0);
+                            metric->time_metrics.deliver_duration_ns = metric->time_metrics.deliver_end_timestamp_ns -
+                                                                       metric->time_metrics.deliver_start_timestamp_ns;
+                        }
                     }
                 }
                 aws_atomic_fetch_sub(&client->stats.num_requests_streaming_response, 1);

source/s3_request.c

@@ -192,6 +192,12 @@ struct aws_s3_request_metrics *aws_s3_request_metrics_new(
     metrics->time_metrics.sign_start_timestamp_ns = -1;
     metrics->time_metrics.sign_end_timestamp_ns = -1;
     metrics->time_metrics.signing_duration_ns = -1;
+    metrics->time_metrics.mem_acquire_start_timestamp_ns = -1;
+    metrics->time_metrics.mem_acquire_end_timestamp_ns = -1;
+    metrics->time_metrics.mem_acquire_duration_ns = -1;
+    metrics->time_metrics.deliver_start_timestamp_ns = -1;
+    metrics->time_metrics.deliver_end_timestamp_ns = -1;
+    metrics->time_metrics.deliver_duration_ns = -1;
 
     metrics->req_resp_info_metrics.response_status = -1;