From e58678da4eee1c3f844c80e6ac0a4df8aadacca5 Mon Sep 17 00:00:00 2001 From: Yang Wang Date: Mon, 5 Aug 2024 09:40:27 +1000 Subject: [PATCH] Use higher precision time so that 0 can represent missing data (#111554) The time computation uses 0 to represent missing value. In #111502, we lowered the precision from micros to ms. For requests that completed under 1 ms, their time metric are now considered missing. This PR fixes it by raising the precision to nanoseconds which is the native resolution of the s3 time metric and lower it to ms only for recording the metric. Resolves: #111549 Resolves: #111550 --- .../repositories/s3/S3BlobStore.java | 25 +++++++++++-------- 1 file changed, 14 insertions(+), 11 deletions(-) diff --git a/modules/repository-s3/src/main/java/org/elasticsearch/repositories/s3/S3BlobStore.java b/modules/repository-s3/src/main/java/org/elasticsearch/repositories/s3/S3BlobStore.java index fbf4767bd3e99..03605d50750f0 100644 --- a/modules/repository-s3/src/main/java/org/elasticsearch/repositories/s3/S3BlobStore.java +++ b/modules/repository-s3/src/main/java/org/elasticsearch/repositories/s3/S3BlobStore.java @@ -224,11 +224,13 @@ private void maybeRecordHttpRequestTime(Request request) { return; } - final long totalTimeInMillis = getTotalTimeInMillis(requestTimesIncludingRetries); - if (totalTimeInMillis == 0) { + final long totalTimeInNanos = getTotalTimeInNanos(requestTimesIncludingRetries); + if (totalTimeInNanos == 0) { logger.warn("Expected HttpRequestTime to be tracked for request [{}] but found no count.", request); } else { - s3RepositoriesMetrics.common().httpRequestTimeInMillisHistogram().record(totalTimeInMillis, attributes); + s3RepositoriesMetrics.common() + .httpRequestTimeInMillisHistogram() + .record(TimeUnit.NANOSECONDS.toMillis(totalTimeInNanos), attributes); } } @@ -271,19 +273,20 @@ private static long getCountForMetric(TimingInfo info, AWSRequestMetrics.Field f } } - private static long getTotalTimeInMillis(List requestTimesIncludingRetries) { - // Here we calculate the timing in Milliseconds for the sum of the individual subMeasurements with the goal of deriving the TTFB - // (time to first byte). We calculate the time in millis for later use with an APM style counter (exposed as a long), rather than - // using the default double exposed by getTimeTakenMillisIfKnown(). We don't need sub-millisecond precision. So no need perform - // the data type castings. - long totalTimeInMillis = 0; + private static long getTotalTimeInNanos(List requestTimesIncludingRetries) { + // Here we calculate the timing in Nanoseconds for the sum of the individual subMeasurements with the goal of deriving the TTFB + // (time to first byte). We use high precision time here to tell from the case when request time metric is missing (0). + // The time is converted to milliseconds for later use with an APM style counter (exposed as a long), rather than using the + // default double exposed by getTimeTakenMillisIfKnown(). + // We don't need sub-millisecond precision. So no need perform the data type castings. + long totalTimeInNanos = 0; for (TimingInfo timingInfo : requestTimesIncludingRetries) { var endTimeInNanos = timingInfo.getEndTimeNanoIfKnown(); if (endTimeInNanos != null) { - totalTimeInMillis += TimeUnit.NANOSECONDS.toMillis(endTimeInNanos - timingInfo.getStartTimeNano()); + totalTimeInNanos += endTimeInNanos - timingInfo.getStartTimeNano(); } } - return totalTimeInMillis; + return totalTimeInNanos; } @Override