From 3bd44657557c58f70a8cfcf93bc9e1c2a9b22d20 Mon Sep 17 00:00:00 2001 From: Clint Checketts Date: Sat, 11 Nov 2017 19:51:22 -0700 Subject: [PATCH 1/2] Create TracingTimer that leverages OpenTracing --- micrometer-core/build.gradle | 5 + .../io/micrometer/core/instrument/Timer.java | 2 +- .../core/instrument/TracingTimer.java | 124 ++++++++++++++++++ .../core/instrument/TracingTimerTest.java | 65 +++++++++ 4 files changed, 195 insertions(+), 1 deletion(-) create mode 100644 micrometer-core/src/main/java/io/micrometer/core/instrument/TracingTimer.java create mode 100644 micrometer-core/src/test/java/io/micrometer/core/instrument/TracingTimerTest.java diff --git a/micrometer-core/build.gradle b/micrometer-core/build.gradle index 3423c48a57..3885d798aa 100644 --- a/micrometer-core/build.gradle +++ b/micrometer-core/build.gradle @@ -36,6 +36,11 @@ dependencies { compile 'com.squareup.okhttp3:okhttp:3.9.0',optional + //tracing + compile 'io.opentracing:opentracing-api:0.30.0', optional + testCompile 'io.opentracing:opentracing-mock:0.30.0' + testCompile 'io.opentracing:opentracing-util:0.30.0' + testCompile 'io.projectreactor:reactor-test:3.1.0.RELEASE' testCompile 'io.projectreactor.ipc:reactor-netty:0.7.1.RELEASE' diff --git a/micrometer-core/src/main/java/io/micrometer/core/instrument/Timer.java b/micrometer-core/src/main/java/io/micrometer/core/instrument/Timer.java index 5455b2acf8..7b67711aac 100644 --- a/micrometer-core/src/main/java/io/micrometer/core/instrument/Timer.java +++ b/micrometer-core/src/main/java/io/micrometer/core/instrument/Timer.java @@ -143,7 +143,7 @@ class Builder { private String description; private final HistogramConfig.Builder histogramConfigBuilder; - private Builder(String name) { + Builder(String name) { this.name = name; this.histogramConfigBuilder = new HistogramConfig.Builder(); minimumExpectedValue(Duration.ofMillis(1)); diff --git a/micrometer-core/src/main/java/io/micrometer/core/instrument/TracingTimer.java b/micrometer-core/src/main/java/io/micrometer/core/instrument/TracingTimer.java new file mode 100644 index 0000000000..13160eecfc --- /dev/null +++ b/micrometer-core/src/main/java/io/micrometer/core/instrument/TracingTimer.java @@ -0,0 +1,124 @@ +/** + * Copyright 2017 Pivotal Software, Inc. + *

+ * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + *

+ * http://www.apache.org/licenses/LICENSE-2.0 + *

+ * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ +package io.micrometer.core.instrument; + +import io.opentracing.ActiveSpan; +import io.opentracing.Tracer; + +import java.util.concurrent.Callable; +import java.util.concurrent.TimeUnit; +import java.util.function.Supplier; + +public class TracingTimer implements Timer{ + + static Builder builder(String name, Tracer tracer) { + return new Builder(name, tracer); + } + + static class Builder extends Timer.Builder{ + private final Tracer tracer; + + Builder(String name, Tracer tracer) { + super(name); + this.tracer = tracer; + } + + @Override + public Timer register(MeterRegistry registry) { + return new TracingTimer(super.register(registry), tracer); + } + } + + private final Timer delegate; + private final Tracer tracer; + + TracingTimer(Timer delegate, Tracer tracer) { + this.delegate = delegate; + this.tracer = tracer; + } + + private ActiveSpan createSpan() { + Tracer.SpanBuilder spanBuilder = tracer.buildSpan(getId().getName()); + getId().getTags().forEach(t -> spanBuilder.withTag(t.getKey(), t.getValue())); + return spanBuilder.startActive(); + } + + + @Override + public T record(Supplier f) { + try(@SuppressWarnings("unused") ActiveSpan span = createSpan()){ + return delegate.record(f); + } + } + + @Override + public T recordCallable(Callable f) throws Exception { + try(@SuppressWarnings("unused") ActiveSpan span = createSpan()) { + return delegate.recordCallable(f); + } + } + + @Override + public void record(Runnable f) { + try(@SuppressWarnings("unused") ActiveSpan span = createSpan()) { + delegate.record(f); + } + } + + @Override + public Callable wrap(Callable f) { + return () -> { + try(@SuppressWarnings("unused") ActiveSpan span = createSpan()) { + return delegate.wrap(f).call(); + } + }; + } + + @Override + public void record(long amount, TimeUnit unit) { + delegate.record(amount, unit); + } + + @Override + public long count() { + return delegate.count(); + } + + @Override + public double totalTime(TimeUnit unit) { + return delegate.totalTime(unit); + } + + @Override + public double max(TimeUnit unit) { + return delegate.max(unit); + } + + @Override + public double percentile(double percentile, TimeUnit unit) { + return delegate.percentile(percentile, unit); + } + + @Override + public double histogramCountAtValue(long valueNanos) { + return delegate.histogramCountAtValue(valueNanos); + } + + @Override + public Id getId() { + return delegate.getId(); + } +} diff --git a/micrometer-core/src/test/java/io/micrometer/core/instrument/TracingTimerTest.java b/micrometer-core/src/test/java/io/micrometer/core/instrument/TracingTimerTest.java new file mode 100644 index 0000000000..066b49857e --- /dev/null +++ b/micrometer-core/src/test/java/io/micrometer/core/instrument/TracingTimerTest.java @@ -0,0 +1,65 @@ +/** + * Copyright 2017 Pivotal Software, Inc. + *

+ * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + *

+ * http://www.apache.org/licenses/LICENSE-2.0 + *

+ * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ +package io.micrometer.core.instrument; + +import io.micrometer.core.instrument.simple.SimpleMeterRegistry; +import io.opentracing.mock.MockSpan; +import io.opentracing.mock.MockTracer; +import io.opentracing.util.ThreadLocalActiveSpanSource; +import org.junit.jupiter.api.BeforeEach; +import org.junit.jupiter.api.Test; + +import java.util.List; + +import static org.assertj.core.api.Assertions.assertThat; + +class TracingTimerTest { + + private MockTracer tracer; + private SimpleMeterRegistry registry; + + @BeforeEach + void setup(){ + tracer = new MockTracer(new ThreadLocalActiveSpanSource(), MockTracer.Propagator.TEXT_MAP); + registry = new SimpleMeterRegistry(); + registry.config().commonTags("commonTag1", "commonVal1"); + } + + @Test + void tracingTimer() { + TracingTimer.builder("trace.outer.timer", tracer).tags("testTag1","testVal1").register(registry).record(() -> { + TracingTimer.builder("trace.inner.timer", tracer).tags("testTag2","testVal2").register(registry).record(() -> { + //Nothing to do here + }); + }); + + List mockSpans = tracer.finishedSpans(); + assertThat(mockSpans).hasSize(2); + + MockSpan innerSpan = mockSpans.get(0); + assertThat(innerSpan.operationName()).isEqualTo("trace.inner.timer"); + assertThat(innerSpan.tags().get("commonTag1")).describedAs("Common tags are applied").isEqualTo("commonVal1"); + assertThat(innerSpan.parentId()).isEqualTo(2L); + + MockSpan outerSpan = mockSpans.get(1); + assertThat(outerSpan.operationName()).isEqualTo("trace.outer.timer"); + assertThat(outerSpan.tags()).hasSize(2); + assertThat(outerSpan.tags().get("testTag1")).isEqualTo("testVal1"); + + + } + +} From 91b3a6b40a55caff373134774e29f3b79b0f33b8 Mon Sep 17 00:00:00 2001 From: Clint Checketts Date: Fri, 1 Dec 2017 07:22:45 -0700 Subject: [PATCH 2/2] Add opencensus tracing --- micrometer-core/build.gradle | 2 + .../io/micrometer/core/instrument/Timer.java | 2 +- .../instrument/tracing/OpenCensusTimer.java | 133 ++++++++++++++++++ .../OpenTracingTimer.java} | 22 ++- .../tracing/OpenCensusTimerTest.java | 93 ++++++++++++ .../OpenTracingTimerTest.java} | 10 +- 6 files changed, 248 insertions(+), 14 deletions(-) create mode 100644 micrometer-core/src/main/java/io/micrometer/core/instrument/tracing/OpenCensusTimer.java rename micrometer-core/src/main/java/io/micrometer/core/instrument/{TracingTimer.java => tracing/OpenTracingTimer.java} (80%) create mode 100644 micrometer-core/src/test/java/io/micrometer/core/instrument/tracing/OpenCensusTimerTest.java rename micrometer-core/src/test/java/io/micrometer/core/instrument/{TracingTimerTest.java => tracing/OpenTracingTimerTest.java} (86%) diff --git a/micrometer-core/build.gradle b/micrometer-core/build.gradle index 3885d798aa..0971554690 100644 --- a/micrometer-core/build.gradle +++ b/micrometer-core/build.gradle @@ -37,6 +37,8 @@ dependencies { compile 'com.squareup.okhttp3:okhttp:3.9.0',optional //tracing + compile 'io.opencensus:opencensus-api:0.9.1', optional + testCompile 'io.opencensus:opencensus-impl:0.9.1' compile 'io.opentracing:opentracing-api:0.30.0', optional testCompile 'io.opentracing:opentracing-mock:0.30.0' testCompile 'io.opentracing:opentracing-util:0.30.0' diff --git a/micrometer-core/src/main/java/io/micrometer/core/instrument/Timer.java b/micrometer-core/src/main/java/io/micrometer/core/instrument/Timer.java index 7b67711aac..08da42a0f9 100644 --- a/micrometer-core/src/main/java/io/micrometer/core/instrument/Timer.java +++ b/micrometer-core/src/main/java/io/micrometer/core/instrument/Timer.java @@ -143,7 +143,7 @@ class Builder { private String description; private final HistogramConfig.Builder histogramConfigBuilder; - Builder(String name) { + protected Builder(String name) { this.name = name; this.histogramConfigBuilder = new HistogramConfig.Builder(); minimumExpectedValue(Duration.ofMillis(1)); diff --git a/micrometer-core/src/main/java/io/micrometer/core/instrument/tracing/OpenCensusTimer.java b/micrometer-core/src/main/java/io/micrometer/core/instrument/tracing/OpenCensusTimer.java new file mode 100644 index 0000000000..75d2ae4433 --- /dev/null +++ b/micrometer-core/src/main/java/io/micrometer/core/instrument/tracing/OpenCensusTimer.java @@ -0,0 +1,133 @@ +/** + * Copyright 2017 Pivotal Software, Inc. + *

+ * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + *

+ * http://www.apache.org/licenses/LICENSE-2.0 + *

+ * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ +package io.micrometer.core.instrument.tracing; + +import io.micrometer.core.instrument.HistogramSnapshot; +import io.micrometer.core.instrument.MeterRegistry; +import io.micrometer.core.instrument.Timer; +import io.opencensus.common.Scope; +import io.opencensus.trace.AttributeValue; +import io.opencensus.trace.Tracer; + +import java.util.concurrent.Callable; +import java.util.concurrent.TimeUnit; +import java.util.function.Supplier; + +public class OpenCensusTimer implements Timer { + + public static Builder builder(String name, Tracer tracer) { + return new Builder(name, tracer); + } + + public static class Builder extends Timer.Builder{ + private final Tracer tracer; + + Builder(String name, Tracer tracer) { + super(name); + this.tracer = tracer; + } + + @Override + public OpenCensusTimer register(MeterRegistry registry) { + return new OpenCensusTimer(super.register(registry), tracer); + } + } + + private final Timer delegate; + private final Tracer tracer; + + OpenCensusTimer(Timer delegate, Tracer tracer) { + this.delegate = delegate; + this.tracer = tracer; + } + + private Scope createSpan() { + Scope spanBuilder = tracer.spanBuilder(getId().getName()).startScopedSpan(); + getId().getTags().forEach(t -> tracer.getCurrentSpan().putAttribute(t.getKey(), AttributeValue.stringAttributeValue(t.getValue()))); + return spanBuilder; + } + + + @Override + public T record(Supplier f) { + try(@SuppressWarnings("unused") Scope span = createSpan()){ + return delegate.record(f); + } + } + + @Override + public T recordCallable(Callable f) throws Exception { + try(@SuppressWarnings("unused") Scope span = createSpan()) { + return delegate.recordCallable(f); + } + } + + @Override + public void record(Runnable f) { + try(@SuppressWarnings("unused") Scope span = createSpan()) { + delegate.record(f); + } + } + + @Override + public Callable wrap(Callable f) { + return () -> { + try(@SuppressWarnings("unused") Scope span = createSpan()) { + return delegate.wrap(f).call(); + } + }; + } + + @Override + public void record(long amount, TimeUnit unit) { + delegate.record(amount, unit); + } + + @Override + public long count() { + return delegate.count(); + } + + @Override + public double totalTime(TimeUnit unit) { + return delegate.totalTime(unit); + } + + @Override + public double max(TimeUnit unit) { + return delegate.max(unit); + } + + @Override + public double percentile(double percentile, TimeUnit unit) { + return delegate.percentile(percentile, unit); + } + + @Override + public double histogramCountAtValue(long valueNanos) { + return delegate.histogramCountAtValue(valueNanos); + } + + @Override + public HistogramSnapshot takeSnapshot(boolean supportsAggregablePercentiles) { + return delegate.takeSnapshot(supportsAggregablePercentiles); + } + + @Override + public Id getId() { + return delegate.getId(); + } +} diff --git a/micrometer-core/src/main/java/io/micrometer/core/instrument/TracingTimer.java b/micrometer-core/src/main/java/io/micrometer/core/instrument/tracing/OpenTracingTimer.java similarity index 80% rename from micrometer-core/src/main/java/io/micrometer/core/instrument/TracingTimer.java rename to micrometer-core/src/main/java/io/micrometer/core/instrument/tracing/OpenTracingTimer.java index 13160eecfc..e5326de431 100644 --- a/micrometer-core/src/main/java/io/micrometer/core/instrument/TracingTimer.java +++ b/micrometer-core/src/main/java/io/micrometer/core/instrument/tracing/OpenTracingTimer.java @@ -13,8 +13,11 @@ * See the License for the specific language governing permissions and * limitations under the License. */ -package io.micrometer.core.instrument; +package io.micrometer.core.instrument.tracing; +import io.micrometer.core.instrument.HistogramSnapshot; +import io.micrometer.core.instrument.MeterRegistry; +import io.micrometer.core.instrument.Timer; import io.opentracing.ActiveSpan; import io.opentracing.Tracer; @@ -22,13 +25,13 @@ import java.util.concurrent.TimeUnit; import java.util.function.Supplier; -public class TracingTimer implements Timer{ +public class OpenTracingTimer implements Timer { - static Builder builder(String name, Tracer tracer) { + public static Builder builder(String name, Tracer tracer) { return new Builder(name, tracer); } - static class Builder extends Timer.Builder{ + public static class Builder extends Timer.Builder{ private final Tracer tracer; Builder(String name, Tracer tracer) { @@ -37,15 +40,15 @@ static class Builder extends Timer.Builder{ } @Override - public Timer register(MeterRegistry registry) { - return new TracingTimer(super.register(registry), tracer); + public OpenTracingTimer register(MeterRegistry registry) { + return new OpenTracingTimer(super.register(registry), tracer); } } private final Timer delegate; private final Tracer tracer; - TracingTimer(Timer delegate, Tracer tracer) { + OpenTracingTimer(Timer delegate, Tracer tracer) { this.delegate = delegate; this.tracer = tracer; } @@ -117,6 +120,11 @@ public double histogramCountAtValue(long valueNanos) { return delegate.histogramCountAtValue(valueNanos); } + @Override + public HistogramSnapshot takeSnapshot(boolean supportsAggregablePercentiles) { + return delegate.takeSnapshot(supportsAggregablePercentiles); + } + @Override public Id getId() { return delegate.getId(); diff --git a/micrometer-core/src/test/java/io/micrometer/core/instrument/tracing/OpenCensusTimerTest.java b/micrometer-core/src/test/java/io/micrometer/core/instrument/tracing/OpenCensusTimerTest.java new file mode 100644 index 0000000000..5f6db8e48e --- /dev/null +++ b/micrometer-core/src/test/java/io/micrometer/core/instrument/tracing/OpenCensusTimerTest.java @@ -0,0 +1,93 @@ +package io.micrometer.core.instrument.tracing; + +import io.micrometer.core.instrument.simple.SimpleMeterRegistry; +import io.opencensus.trace.AttributeValue; +import io.opencensus.trace.Tracer; +import io.opencensus.trace.Tracing; +import io.opencensus.trace.config.TraceParams; +import io.opencensus.trace.export.SpanData; +import io.opencensus.trace.export.SpanExporter; +import io.opencensus.trace.samplers.Samplers; +import org.junit.jupiter.api.AfterEach; +import org.junit.jupiter.api.BeforeEach; +import org.junit.jupiter.api.Test; + +import java.time.Duration; +import java.util.ArrayList; +import java.util.Collection; +import java.util.List; + +import static org.assertj.core.api.Assertions.assertThat; + +class OpenCensusTimerTest { + + private Tracer tracer; + private SimpleMeterRegistry registry; + private ArrayList exportedSpans; + + @BeforeEach + void setup(){ + tracer = Tracing.getTracer(); + registry = new SimpleMeterRegistry(); + registry.config().commonTags("commonTag1", "commonVal1"); + + exportedSpans = new ArrayList<>(); + Tracing.getTraceConfig().updateActiveTraceParams(TraceParams.DEFAULT.toBuilder().setSampler(Samplers.probabilitySampler(1.0)).build()); + Tracing.getExportComponent().getSpanExporter().registerHandler("test", new SpanExporter.Handler() { + @Override + public void export(Collection spanDataList) { + exportedSpans.addAll(spanDataList); + } + }); + } + + @AfterEach + void cleanup(){ + Tracing.getExportComponent().getSpanExporter().unregisterHandler("test"); + } + + @Test + void tracingTimer() throws InterruptedException { + + + OpenCensusTimer.builder("trace.outer.timer", tracer).tags("testTag1","testVal1").register(registry).record(() -> { + OpenCensusTimer.builder("trace.inner.timer", tracer).tags("testTag2","testVal2").register(registry).record(() -> { + //Nothing to do here + }); + }); + + registry.getMeters(); + + waitForSpans(Duration.ofSeconds(5), 2); + + SpanData innerSpan = exportedSpans.get(0); + SpanData outerSpan = exportedSpans.get(1); + assertThat(innerSpan.getName()).isEqualTo("trace.inner.timer"); + assertThat(innerSpan.getAttributes().getAttributeMap().get("commonTag1")).describedAs("Common tags are applied").isEqualTo(AttributeValue.stringAttributeValue("commonVal1")); + assertThat(innerSpan.getParentSpanId()).isNotNull(); + + + assertThat(outerSpan.getName()).isEqualTo("trace.outer.timer"); + assertThat(outerSpan.getAttributes().getAttributeMap()).hasSize(2); + assertThat(outerSpan.getAttributes().getAttributeMap().get("testTag1")).isEqualTo(AttributeValue.stringAttributeValue("testVal1")); + assertThat(outerSpan.getParentSpanId()).isNull(); + } + + private void waitForSpans(Duration duration, int spanCount) { + long endTime = System.currentTimeMillis() + duration.toMillis(); + while(endTime > System.currentTimeMillis()) { + if (exportedSpans.size() == spanCount) { + return; + } + try { + Thread.sleep(100L); + } catch (InterruptedException e) { + //ignored + } + } + throw new AssertionError("Expected spans of "+spanCount+" not found after waiting "+duration.toMillis()+"ms Spans Found:"+exportedSpans.size()); + } + + + +} diff --git a/micrometer-core/src/test/java/io/micrometer/core/instrument/TracingTimerTest.java b/micrometer-core/src/test/java/io/micrometer/core/instrument/tracing/OpenTracingTimerTest.java similarity index 86% rename from micrometer-core/src/test/java/io/micrometer/core/instrument/TracingTimerTest.java rename to micrometer-core/src/test/java/io/micrometer/core/instrument/tracing/OpenTracingTimerTest.java index 066b49857e..b04c56840f 100644 --- a/micrometer-core/src/test/java/io/micrometer/core/instrument/TracingTimerTest.java +++ b/micrometer-core/src/test/java/io/micrometer/core/instrument/tracing/OpenTracingTimerTest.java @@ -13,7 +13,7 @@ * See the License for the specific language governing permissions and * limitations under the License. */ -package io.micrometer.core.instrument; +package io.micrometer.core.instrument.tracing; import io.micrometer.core.instrument.simple.SimpleMeterRegistry; import io.opentracing.mock.MockSpan; @@ -26,7 +26,7 @@ import static org.assertj.core.api.Assertions.assertThat; -class TracingTimerTest { +class OpenTracingTimerTest { private MockTracer tracer; private SimpleMeterRegistry registry; @@ -40,8 +40,8 @@ void setup(){ @Test void tracingTimer() { - TracingTimer.builder("trace.outer.timer", tracer).tags("testTag1","testVal1").register(registry).record(() -> { - TracingTimer.builder("trace.inner.timer", tracer).tags("testTag2","testVal2").register(registry).record(() -> { + OpenTracingTimer.builder("trace.outer.timer", tracer).tags("testTag1","testVal1").register(registry).record(() -> { + OpenTracingTimer.builder("trace.inner.timer", tracer).tags("testTag2","testVal2").register(registry).record(() -> { //Nothing to do here }); }); @@ -58,8 +58,6 @@ void tracingTimer() { assertThat(outerSpan.operationName()).isEqualTo("trace.outer.timer"); assertThat(outerSpan.tags()).hasSize(2); assertThat(outerSpan.tags().get("testTag1")).isEqualTo("testVal1"); - - } }