From 35a0588102b222ff9bf6de643830800fffce8780 Mon Sep 17 00:00:00 2001 From: Ronak Date: Wed, 23 Feb 2022 13:26:19 +0530 Subject: [PATCH 1/8] chore: adding late event timer metrics --- .../jaeger/JaegerSpanNormalizer.java | 32 ++++++++++++++++++- 1 file changed, 31 insertions(+), 1 deletion(-) diff --git a/span-normalizer/span-normalizer/src/main/java/org/hypertrace/core/spannormalizer/jaeger/JaegerSpanNormalizer.java b/span-normalizer/span-normalizer/src/main/java/org/hypertrace/core/spannormalizer/jaeger/JaegerSpanNormalizer.java index e3b490544..28059e040 100644 --- a/span-normalizer/span-normalizer/src/main/java/org/hypertrace/core/spannormalizer/jaeger/JaegerSpanNormalizer.java +++ b/span-normalizer/span-normalizer/src/main/java/org/hypertrace/core/spannormalizer/jaeger/JaegerSpanNormalizer.java @@ -3,6 +3,7 @@ import static org.hypertrace.core.datamodel.shared.AvroBuilderCache.fastNewBuilder; import com.google.protobuf.ProtocolStringList; +import com.google.protobuf.Timestamp; import com.google.protobuf.util.Timestamps; import com.typesafe.config.Config; import io.jaegertracing.api_v2.JaegerSpanInternalModel; @@ -21,6 +22,7 @@ import java.util.concurrent.Callable; import java.util.concurrent.ConcurrentHashMap; import java.util.concurrent.ConcurrentMap; +import java.util.concurrent.TimeUnit; import java.util.stream.Collectors; import javax.annotation.Nonnull; import javax.annotation.Nullable; @@ -63,6 +65,11 @@ public class JaegerSpanNormalizer { private final JaegerResourceNormalizer resourceNormalizer = new JaegerResourceNormalizer(); private final TenantIdHandler tenantIdHandler; + // measure the span's start time and its processing time + private static final String DELAY_IN_SPAN_PROCESSED_TIME_METRIC = "span.processed.delay.time"; + private final ConcurrentMap tenantToDelayInSpanProcessedTimer = + new ConcurrentHashMap<>(); + public static JaegerSpanNormalizer get(Config config) { if (INSTANCE == null) { synchronized (JaegerSpanNormalizer.class) { @@ -102,9 +109,22 @@ public RawSpan convert(String tenantId, Span jaegerSpan) throws Exception { private Callable getRawSpanNormalizerCallable( Span jaegerSpan, Map spanTags, String tenantId) { return () -> { + long spanProcessedTime = System.currentTimeMillis(); + long spanStartTime = Timestamps.toMillis(jaegerSpan.getStartTime()); + Builder rawSpanBuilder = fastNewBuilder(RawSpan.Builder.class); rawSpanBuilder.setCustomerId(tenantId); rawSpanBuilder.setTraceId(jaegerSpan.getTraceId().asReadOnlyByteBuffer()); + + // register timer per tenant + tenantToSpanNormalizationTimer + .computeIfAbsent( + tenantId, + tenant -> + PlatformMetricsRegistry.registerTimer( + DELAY_IN_SPAN_PROCESSED_TIME_METRIC, Map.of("tenantId", tenant))) + .record(spanProcessedTime - spanStartTime, TimeUnit.MILLISECONDS); + // Build Event Event event = buildEvent( @@ -113,7 +133,7 @@ private Callable getRawSpanNormalizerCallable( spanTags, tenantIdHandler.getTenantIdProvider().getTenantIdTagKey()); rawSpanBuilder.setEvent(event); - rawSpanBuilder.setReceivedTimeMillis(System.currentTimeMillis()); + rawSpanBuilder.setReceivedTimeMillis(spanProcessedTime); resourceNormalizer .normalize(jaegerSpan, tenantIdHandler.getTenantIdProvider().getTenantIdTagKey()) .ifPresent(rawSpanBuilder::setResource); @@ -123,6 +143,16 @@ private Callable getRawSpanNormalizerCallable( if (LOG.isDebugEnabled()) { logSpanConversion(jaegerSpan, rawSpan); } + + // register and update timer per tenant + tenantToSpanNormalizationTimer + .computeIfAbsent( + tenantId, + tenant -> + PlatformMetricsRegistry.registerTimer( + DELAY_IN_SPAN_PROCESSED_TIME_METRIC, Map.of("tenantId", tenant))) + .record(spanProcessedTime - spanStartTime, TimeUnit.MILLISECONDS); + return rawSpan; }; } From 5f26b6282d6406c6bb41055ac4f5666d2da02c26 Mon Sep 17 00:00:00 2001 From: Ronak Date: Wed, 23 Feb 2022 14:54:39 +0530 Subject: [PATCH 2/8] fixed the spotless issue --- .../jaeger/JaegerSpanNormalizer.java | 19 ++++++------------- .../jaeger/JaegerSpanNormalizerTest.java | 6 ++++++ 2 files changed, 12 insertions(+), 13 deletions(-) diff --git a/span-normalizer/span-normalizer/src/main/java/org/hypertrace/core/spannormalizer/jaeger/JaegerSpanNormalizer.java b/span-normalizer/span-normalizer/src/main/java/org/hypertrace/core/spannormalizer/jaeger/JaegerSpanNormalizer.java index 28059e040..51c7dcc46 100644 --- a/span-normalizer/span-normalizer/src/main/java/org/hypertrace/core/spannormalizer/jaeger/JaegerSpanNormalizer.java +++ b/span-normalizer/span-normalizer/src/main/java/org/hypertrace/core/spannormalizer/jaeger/JaegerSpanNormalizer.java @@ -3,7 +3,6 @@ import static org.hypertrace.core.datamodel.shared.AvroBuilderCache.fastNewBuilder; import com.google.protobuf.ProtocolStringList; -import com.google.protobuf.Timestamp; import com.google.protobuf.util.Timestamps; import com.typesafe.config.Config; import io.jaegertracing.api_v2.JaegerSpanInternalModel; @@ -89,6 +88,10 @@ public Timer getSpanNormalizationTimer(String tenantId) { return tenantToSpanNormalizationTimer.get(tenantId); } + public Timer getSpanDelayInSpanProcessedTimer(String tenantId) { + return tenantToDelayInSpanProcessedTimer.get(tenantId); + } + @Nullable public RawSpan convert(String tenantId, Span jaegerSpan) throws Exception { Map tags = @@ -115,16 +118,6 @@ private Callable getRawSpanNormalizerCallable( Builder rawSpanBuilder = fastNewBuilder(RawSpan.Builder.class); rawSpanBuilder.setCustomerId(tenantId); rawSpanBuilder.setTraceId(jaegerSpan.getTraceId().asReadOnlyByteBuffer()); - - // register timer per tenant - tenantToSpanNormalizationTimer - .computeIfAbsent( - tenantId, - tenant -> - PlatformMetricsRegistry.registerTimer( - DELAY_IN_SPAN_PROCESSED_TIME_METRIC, Map.of("tenantId", tenant))) - .record(spanProcessedTime - spanStartTime, TimeUnit.MILLISECONDS); - // Build Event Event event = buildEvent( @@ -145,12 +138,12 @@ private Callable getRawSpanNormalizerCallable( } // register and update timer per tenant - tenantToSpanNormalizationTimer + tenantToDelayInSpanProcessedTimer .computeIfAbsent( tenantId, tenant -> PlatformMetricsRegistry.registerTimer( - DELAY_IN_SPAN_PROCESSED_TIME_METRIC, Map.of("tenantId", tenant))) + DELAY_IN_SPAN_PROCESSED_TIME_METRIC, Map.of("tenantId", tenant), true)) .record(spanProcessedTime - spanStartTime, TimeUnit.MILLISECONDS); return rawSpan; diff --git a/span-normalizer/span-normalizer/src/test/java/org/hypertrace/core/spannormalizer/jaeger/JaegerSpanNormalizerTest.java b/span-normalizer/span-normalizer/src/test/java/org/hypertrace/core/spannormalizer/jaeger/JaegerSpanNormalizerTest.java index 4020d1af3..70aef98b6 100644 --- a/span-normalizer/span-normalizer/src/test/java/org/hypertrace/core/spannormalizer/jaeger/JaegerSpanNormalizerTest.java +++ b/span-normalizer/span-normalizer/src/test/java/org/hypertrace/core/spannormalizer/jaeger/JaegerSpanNormalizerTest.java @@ -219,6 +219,12 @@ public void testServiceNameNotAddedToEvent() throws Exception { // Assert that metrics are collected. Assertions.assertEquals(1, timer.count()); + + Timer timer1 = normalizer.getSpanDelayInSpanProcessedTimer(tenantId); + Assertions.assertNotNull(timer1); + + // Assert that metrics are collected. + Assertions.assertEquals(1, timer1.count()); } @Test From 398e80280021c707b09eea75317447c7e8cb275c Mon Sep 17 00:00:00 2001 From: Ronak Date: Wed, 23 Feb 2022 14:58:57 +0530 Subject: [PATCH 3/8] rename the function name --- .../core/spannormalizer/jaeger/JaegerSpanNormalizer.java | 2 +- .../core/spannormalizer/jaeger/JaegerSpanNormalizerTest.java | 2 +- 2 files changed, 2 insertions(+), 2 deletions(-) diff --git a/span-normalizer/span-normalizer/src/main/java/org/hypertrace/core/spannormalizer/jaeger/JaegerSpanNormalizer.java b/span-normalizer/span-normalizer/src/main/java/org/hypertrace/core/spannormalizer/jaeger/JaegerSpanNormalizer.java index 51c7dcc46..9fbd57a2c 100644 --- a/span-normalizer/span-normalizer/src/main/java/org/hypertrace/core/spannormalizer/jaeger/JaegerSpanNormalizer.java +++ b/span-normalizer/span-normalizer/src/main/java/org/hypertrace/core/spannormalizer/jaeger/JaegerSpanNormalizer.java @@ -88,7 +88,7 @@ public Timer getSpanNormalizationTimer(String tenantId) { return tenantToSpanNormalizationTimer.get(tenantId); } - public Timer getSpanDelayInSpanProcessedTimer(String tenantId) { + public Timer getDelayInSpanProcessedTimer(String tenantId) { return tenantToDelayInSpanProcessedTimer.get(tenantId); } diff --git a/span-normalizer/span-normalizer/src/test/java/org/hypertrace/core/spannormalizer/jaeger/JaegerSpanNormalizerTest.java b/span-normalizer/span-normalizer/src/test/java/org/hypertrace/core/spannormalizer/jaeger/JaegerSpanNormalizerTest.java index 70aef98b6..16dedf83e 100644 --- a/span-normalizer/span-normalizer/src/test/java/org/hypertrace/core/spannormalizer/jaeger/JaegerSpanNormalizerTest.java +++ b/span-normalizer/span-normalizer/src/test/java/org/hypertrace/core/spannormalizer/jaeger/JaegerSpanNormalizerTest.java @@ -220,7 +220,7 @@ public void testServiceNameNotAddedToEvent() throws Exception { // Assert that metrics are collected. Assertions.assertEquals(1, timer.count()); - Timer timer1 = normalizer.getSpanDelayInSpanProcessedTimer(tenantId); + Timer timer1 = normalizer.getDelayInSpanProcessedTimer(tenantId); Assertions.assertNotNull(timer1); // Assert that metrics are collected. From a66dbda04cab9062d3f06c741985cb30f2e38904 Mon Sep 17 00:00:00 2001 From: Ronak Date: Wed, 23 Feb 2022 15:26:47 +0530 Subject: [PATCH 4/8] wrap the difference around math.abs --- .../core/spannormalizer/jaeger/JaegerSpanNormalizer.java | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/span-normalizer/span-normalizer/src/main/java/org/hypertrace/core/spannormalizer/jaeger/JaegerSpanNormalizer.java b/span-normalizer/span-normalizer/src/main/java/org/hypertrace/core/spannormalizer/jaeger/JaegerSpanNormalizer.java index 9fbd57a2c..b49585e52 100644 --- a/span-normalizer/span-normalizer/src/main/java/org/hypertrace/core/spannormalizer/jaeger/JaegerSpanNormalizer.java +++ b/span-normalizer/span-normalizer/src/main/java/org/hypertrace/core/spannormalizer/jaeger/JaegerSpanNormalizer.java @@ -138,14 +138,14 @@ private Callable getRawSpanNormalizerCallable( } // register and update timer per tenant + // its uses absolute value to take care if any clock skewness too. tenantToDelayInSpanProcessedTimer .computeIfAbsent( tenantId, tenant -> PlatformMetricsRegistry.registerTimer( DELAY_IN_SPAN_PROCESSED_TIME_METRIC, Map.of("tenantId", tenant), true)) - .record(spanProcessedTime - spanStartTime, TimeUnit.MILLISECONDS); - + .record(Math.abs(spanProcessedTime - spanStartTime), TimeUnit.MILLISECONDS); return rawSpan; }; } From a788bab3c7d4a32ed994a5169e33f02b06a95199 Mon Sep 17 00:00:00 2001 From: Ronak Date: Wed, 23 Feb 2022 16:01:22 +0530 Subject: [PATCH 5/8] addressed comments --- .../core/spannormalizer/jaeger/JaegerSpanNormalizer.java | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/span-normalizer/span-normalizer/src/main/java/org/hypertrace/core/spannormalizer/jaeger/JaegerSpanNormalizer.java b/span-normalizer/span-normalizer/src/main/java/org/hypertrace/core/spannormalizer/jaeger/JaegerSpanNormalizer.java index b49585e52..66956cdae 100644 --- a/span-normalizer/span-normalizer/src/main/java/org/hypertrace/core/spannormalizer/jaeger/JaegerSpanNormalizer.java +++ b/span-normalizer/span-normalizer/src/main/java/org/hypertrace/core/spannormalizer/jaeger/JaegerSpanNormalizer.java @@ -64,8 +64,8 @@ public class JaegerSpanNormalizer { private final JaegerResourceNormalizer resourceNormalizer = new JaegerResourceNormalizer(); private final TenantIdHandler tenantIdHandler; - // measure the span's start time and its processing time - private static final String DELAY_IN_SPAN_PROCESSED_TIME_METRIC = "span.processed.delay.time"; + // measure the difference between span's start time and its processing tim + private static final String SPAN_PROCESSING_DELAY_TIME_METRIC = "span.processing.delay.time"; private final ConcurrentMap tenantToDelayInSpanProcessedTimer = new ConcurrentHashMap<>(); @@ -138,13 +138,13 @@ private Callable getRawSpanNormalizerCallable( } // register and update timer per tenant - // its uses absolute value to take care if any clock skewness too. + // it uses absolute value to take care of any clock skewness too. tenantToDelayInSpanProcessedTimer .computeIfAbsent( tenantId, tenant -> PlatformMetricsRegistry.registerTimer( - DELAY_IN_SPAN_PROCESSED_TIME_METRIC, Map.of("tenantId", tenant), true)) + SPAN_PROCESSING_DELAY_TIME_METRIC, Map.of("tenantId", tenant), true)) .record(Math.abs(spanProcessedTime - spanStartTime), TimeUnit.MILLISECONDS); return rawSpan; }; From e3e3a21f830ee3664d0ef9cc9f6365d94097ee25 Mon Sep 17 00:00:00 2001 From: Ronak Date: Wed, 23 Feb 2022 16:04:26 +0530 Subject: [PATCH 6/8] fixed typo issue in last commit --- .../core/spannormalizer/jaeger/JaegerSpanNormalizer.java | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/span-normalizer/span-normalizer/src/main/java/org/hypertrace/core/spannormalizer/jaeger/JaegerSpanNormalizer.java b/span-normalizer/span-normalizer/src/main/java/org/hypertrace/core/spannormalizer/jaeger/JaegerSpanNormalizer.java index 66956cdae..ccfa51fa9 100644 --- a/span-normalizer/span-normalizer/src/main/java/org/hypertrace/core/spannormalizer/jaeger/JaegerSpanNormalizer.java +++ b/span-normalizer/span-normalizer/src/main/java/org/hypertrace/core/spannormalizer/jaeger/JaegerSpanNormalizer.java @@ -64,7 +64,7 @@ public class JaegerSpanNormalizer { private final JaegerResourceNormalizer resourceNormalizer = new JaegerResourceNormalizer(); private final TenantIdHandler tenantIdHandler; - // measure the difference between span's start time and its processing tim + // measure the difference between span's start time and its processing time private static final String SPAN_PROCESSING_DELAY_TIME_METRIC = "span.processing.delay.time"; private final ConcurrentMap tenantToDelayInSpanProcessedTimer = new ConcurrentHashMap<>(); From 5f05a99aa649f72fd9af262ad195c5b0082031d3 Mon Sep 17 00:00:00 2001 From: Ronak Date: Wed, 23 Feb 2022 17:39:50 +0530 Subject: [PATCH 7/8] address comments --- .../core/spannormalizer/jaeger/JaegerSpanNormalizer.java | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/span-normalizer/span-normalizer/src/main/java/org/hypertrace/core/spannormalizer/jaeger/JaegerSpanNormalizer.java b/span-normalizer/span-normalizer/src/main/java/org/hypertrace/core/spannormalizer/jaeger/JaegerSpanNormalizer.java index ccfa51fa9..d1050f704 100644 --- a/span-normalizer/span-normalizer/src/main/java/org/hypertrace/core/spannormalizer/jaeger/JaegerSpanNormalizer.java +++ b/span-normalizer/span-normalizer/src/main/java/org/hypertrace/core/spannormalizer/jaeger/JaegerSpanNormalizer.java @@ -144,7 +144,7 @@ private Callable getRawSpanNormalizerCallable( tenantId, tenant -> PlatformMetricsRegistry.registerTimer( - SPAN_PROCESSING_DELAY_TIME_METRIC, Map.of("tenantId", tenant), true)) + SPAN_PROCESSING_DELAY_TIME_METRIC, Map.of("tenantId", tenant))) .record(Math.abs(spanProcessedTime - spanStartTime), TimeUnit.MILLISECONDS); return rawSpan; }; From 97327989d090e2c6f53131bbfc23317a175293e8 Mon Sep 17 00:00:00 2001 From: Ronak Date: Wed, 23 Feb 2022 19:13:03 +0530 Subject: [PATCH 8/8] addressed further minor comments --- .../spannormalizer/jaeger/JaegerSpanNormalizer.java | 12 ++++++------ .../jaeger/JaegerSpanPreProcessor.java | 2 ++ .../jaeger/JaegerSpanNormalizerTest.java | 2 +- 3 files changed, 9 insertions(+), 7 deletions(-) diff --git a/span-normalizer/span-normalizer/src/main/java/org/hypertrace/core/spannormalizer/jaeger/JaegerSpanNormalizer.java b/span-normalizer/span-normalizer/src/main/java/org/hypertrace/core/spannormalizer/jaeger/JaegerSpanNormalizer.java index d1050f704..cb8a8909e 100644 --- a/span-normalizer/span-normalizer/src/main/java/org/hypertrace/core/spannormalizer/jaeger/JaegerSpanNormalizer.java +++ b/span-normalizer/span-normalizer/src/main/java/org/hypertrace/core/spannormalizer/jaeger/JaegerSpanNormalizer.java @@ -65,8 +65,8 @@ public class JaegerSpanNormalizer { private final TenantIdHandler tenantIdHandler; // measure the difference between span's start time and its processing time - private static final String SPAN_PROCESSING_DELAY_TIME_METRIC = "span.processing.delay.time"; - private final ConcurrentMap tenantToDelayInSpanProcessedTimer = + private static final String SPAN_ARRIVAL_DELAY = "span.arrival.delay"; + private final ConcurrentMap tenantToSpanArrivalDelayTimer = new ConcurrentHashMap<>(); public static JaegerSpanNormalizer get(Config config) { @@ -88,8 +88,8 @@ public Timer getSpanNormalizationTimer(String tenantId) { return tenantToSpanNormalizationTimer.get(tenantId); } - public Timer getDelayInSpanProcessedTimer(String tenantId) { - return tenantToDelayInSpanProcessedTimer.get(tenantId); + public Timer getSpanArrivalDelayTimer(String tenantId) { + return tenantToSpanArrivalDelayTimer.get(tenantId); } @Nullable @@ -139,12 +139,12 @@ private Callable getRawSpanNormalizerCallable( // register and update timer per tenant // it uses absolute value to take care of any clock skewness too. - tenantToDelayInSpanProcessedTimer + tenantToSpanArrivalDelayTimer .computeIfAbsent( tenantId, tenant -> PlatformMetricsRegistry.registerTimer( - SPAN_PROCESSING_DELAY_TIME_METRIC, Map.of("tenantId", tenant))) + SPAN_ARRIVAL_DELAY, Map.of("tenantId", tenant))) .record(Math.abs(spanProcessedTime - spanStartTime), TimeUnit.MILLISECONDS); return rawSpan; }; diff --git a/span-normalizer/span-normalizer/src/main/java/org/hypertrace/core/spannormalizer/jaeger/JaegerSpanPreProcessor.java b/span-normalizer/span-normalizer/src/main/java/org/hypertrace/core/spannormalizer/jaeger/JaegerSpanPreProcessor.java index 4a1d1b500..56d46ad5a 100644 --- a/span-normalizer/span-normalizer/src/main/java/org/hypertrace/core/spannormalizer/jaeger/JaegerSpanPreProcessor.java +++ b/span-normalizer/span-normalizer/src/main/java/org/hypertrace/core/spannormalizer/jaeger/JaegerSpanPreProcessor.java @@ -112,6 +112,8 @@ PreProcessedSpan preProcessSpan(Span span) { return null; } + // should drop late span + return new PreProcessedSpan(tenantId, span); } diff --git a/span-normalizer/span-normalizer/src/test/java/org/hypertrace/core/spannormalizer/jaeger/JaegerSpanNormalizerTest.java b/span-normalizer/span-normalizer/src/test/java/org/hypertrace/core/spannormalizer/jaeger/JaegerSpanNormalizerTest.java index 16dedf83e..7d170015e 100644 --- a/span-normalizer/span-normalizer/src/test/java/org/hypertrace/core/spannormalizer/jaeger/JaegerSpanNormalizerTest.java +++ b/span-normalizer/span-normalizer/src/test/java/org/hypertrace/core/spannormalizer/jaeger/JaegerSpanNormalizerTest.java @@ -220,7 +220,7 @@ public void testServiceNameNotAddedToEvent() throws Exception { // Assert that metrics are collected. Assertions.assertEquals(1, timer.count()); - Timer timer1 = normalizer.getDelayInSpanProcessedTimer(tenantId); + Timer timer1 = normalizer.getSpanArrivalDelayTimer(tenantId); Assertions.assertNotNull(timer1); // Assert that metrics are collected.