diff --git a/NOTICE b/NOTICE index c874b88bc9..6d545fc64d 100644 --- a/NOTICE +++ b/NOTICE @@ -359,3 +359,48 @@ WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN THE SOFTWARE. ############################################################################### +This product includes code from HdrHistogram, dual-licensed under CC0 and BSD 2-Clause License + +The code in this repository code was Written by Gil Tene, Michael Barker, +and Matt Warren, and released to the public domain, as explained at +http://creativecommons.org/publicdomain/zero/1.0/ + +For users of this code who wish to consume it under the "BSD" license +rather than under the public domain or CC0 contribution text mentioned +above, the code found under this directory is *also* provided under the +following license (commonly referred to as the BSD 2-Clause License). This +license does not detract from the above stated release of the code into +the public domain, and simply represents an additional license granted by +the Author. + +----------------------------------------------------------------------------- +** Beginning of "BSD 2-Clause License" text. ** + + Copyright (c) 2012, 2013, 2014, 2015, 2016 Gil Tene + Copyright (c) 2014 Michael Barker + Copyright (c) 2014 Matt Warren + All rights reserved. + + Redistribution and use in source and binary forms, with or without + modification, are permitted provided that the following conditions are met: + + 1. Redistributions of source code must retain the above copyright notice, + this list of conditions and the following disclaimer. + + 2. Redistributions in binary form must reproduce the above copyright notice, + this list of conditions and the following disclaimer in the documentation + and/or other materials provided with the distribution. + + THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS "AS IS" + AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE + IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE + ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT HOLDER OR CONTRIBUTORS BE + LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR + CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF + SUBSTITUTE GOODS OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS + INTERRUPTION) HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN + CONTRACT, STRICT LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) + ARISING IN ANY WAY OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF + THE POSSIBILITY OF SUCH DAMAGE. + +############################################################################### diff --git a/apm-agent-benchmarks/src/main/java/co/elastic/apm/agent/benchmark/ElasticApmContinuousBenchmark.java b/apm-agent-benchmarks/src/main/java/co/elastic/apm/agent/benchmark/ElasticApmContinuousBenchmark.java index 72be26a84b..fc3b1f8010 100644 --- a/apm-agent-benchmarks/src/main/java/co/elastic/apm/agent/benchmark/ElasticApmContinuousBenchmark.java +++ b/apm-agent-benchmarks/src/main/java/co/elastic/apm/agent/benchmark/ElasticApmContinuousBenchmark.java @@ -150,6 +150,7 @@ public void setUp(Blackhole blackhole) { @TearDown public void tearDown() throws ExecutionException, InterruptedException { + Thread.sleep(1000); tracer.getReporter().flush().get(); server.stop(); System.out.println("Reported: " + tracer.getReporter().getReported()); diff --git a/apm-agent-core/pom.xml b/apm-agent-core/pom.xml index b44ca48524..f60004af2f 100644 --- a/apm-agent-core/pom.xml +++ b/apm-agent-core/pom.xml @@ -92,6 +92,11 @@ byte-buddy ${version.byte-buddy} + + org.hdrhistogram + HdrHistogram + 2.1.11 + com.squareup.okhttp3 diff --git a/apm-agent-core/src/main/java/co/elastic/apm/agent/impl/ElasticApmTracer.java b/apm-agent-core/src/main/java/co/elastic/apm/agent/impl/ElasticApmTracer.java index bfae4f0784..62c78e8552 100644 --- a/apm-agent-core/src/main/java/co/elastic/apm/agent/impl/ElasticApmTracer.java +++ b/apm-agent-core/src/main/java/co/elastic/apm/agent/impl/ElasticApmTracer.java @@ -11,9 +11,9 @@ * 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 @@ -399,7 +399,7 @@ public void endSpan(Span span) { if (span.isSampled() && !span.isDiscard()) { long spanFramesMinDurationMs = stacktraceConfiguration.getSpanFramesMinDurationMs(); if (spanFramesMinDurationMs != 0 && span.isSampled()) { - if (span.getDuration() >= spanFramesMinDurationMs) { + if (span.getDurationMs() >= spanFramesMinDurationMs) { span.withStacktrace(new Throwable()); } } diff --git a/apm-agent-core/src/main/java/co/elastic/apm/agent/impl/async/SpanInScopeCallableWrapper.java b/apm-agent-core/src/main/java/co/elastic/apm/agent/impl/async/SpanInScopeCallableWrapper.java index 3a62b98099..b5c7c34efa 100644 --- a/apm-agent-core/src/main/java/co/elastic/apm/agent/impl/async/SpanInScopeCallableWrapper.java +++ b/apm-agent-core/src/main/java/co/elastic/apm/agent/impl/async/SpanInScopeCallableWrapper.java @@ -11,9 +11,9 @@ * 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 diff --git a/apm-agent-core/src/main/java/co/elastic/apm/agent/impl/async/SpanInScopeRunnableWrapper.java b/apm-agent-core/src/main/java/co/elastic/apm/agent/impl/async/SpanInScopeRunnableWrapper.java index 7f69da5a4f..0c90f53b56 100644 --- a/apm-agent-core/src/main/java/co/elastic/apm/agent/impl/async/SpanInScopeRunnableWrapper.java +++ b/apm-agent-core/src/main/java/co/elastic/apm/agent/impl/async/SpanInScopeRunnableWrapper.java @@ -11,9 +11,9 @@ * 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 diff --git a/apm-agent-core/src/main/java/co/elastic/apm/agent/impl/transaction/AbstractSpan.java b/apm-agent-core/src/main/java/co/elastic/apm/agent/impl/transaction/AbstractSpan.java index 2f604e205c..ee8e39f9df 100644 --- a/apm-agent-core/src/main/java/co/elastic/apm/agent/impl/transaction/AbstractSpan.java +++ b/apm-agent-core/src/main/java/co/elastic/apm/agent/impl/transaction/AbstractSpan.java @@ -11,9 +11,9 @@ * 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 @@ -26,6 +26,9 @@ import co.elastic.apm.agent.impl.ElasticApmTracer; import co.elastic.apm.agent.impl.context.AbstractContext; +import co.elastic.apm.agent.matcher.WildcardMatcher; +import co.elastic.apm.agent.objectpool.Recyclable; +import co.elastic.apm.agent.report.ReporterConfiguration; import org.slf4j.Logger; import org.slf4j.LoggerFactory; @@ -33,6 +36,7 @@ import java.util.concurrent.Callable; import java.util.concurrent.TimeUnit; import java.util.concurrent.atomic.AtomicInteger; +import java.util.concurrent.atomic.AtomicLong; public abstract class AbstractSpan extends TraceContextHolder { private static final Logger logger = LoggerFactory.getLogger(AbstractSpan.class); @@ -43,13 +47,12 @@ public abstract class AbstractSpan extends TraceContextH * Generic designation of a transaction in the scope of a single service (eg: 'GET /users/:id') */ protected final StringBuilder name = new StringBuilder(); + protected final boolean collectBreakdownMetrics; private long timestamp; - /** - * How long the transaction took to complete, in ms with 3 decimal points - * (Required) - */ - protected double duration; + // in microseconds + protected long duration; + private ChildDurationTimer childDurations = new ChildDurationTimer(); protected AtomicInteger references = new AtomicInteger(); protected volatile boolean finished = true; @@ -57,9 +60,64 @@ public int getReferenceCount() { return references.get(); } + private static class ChildDurationTimer implements Recyclable { + + private AtomicInteger activeChildren = new AtomicInteger(); + private AtomicLong start = new AtomicLong(); + private AtomicLong duration = new AtomicLong(); + + /** + * Starts the timer if it has not been started already. + * + * @param startTimestamp + */ + void onChildStart(long startTimestamp) { + if (activeChildren.incrementAndGet() == 1) { + start.set(startTimestamp); + } + } + + /** + * Stops the timer and increments the duration if no other direct children are still running + * @param endTimestamp + */ + void onChildEnd(long endTimestamp) { + if (activeChildren.decrementAndGet() == 0) { + incrementDuration(endTimestamp); + } + } + + /** + * Stops the timer and increments the duration even if there are direct children which are still running + * + * @param endTimestamp + */ + void onSpanEnd(long endTimestamp) { + if (activeChildren.getAndSet(0) != 0) { + incrementDuration(endTimestamp); + } + } + + private void incrementDuration(long epochMicros) { + duration.addAndGet(epochMicros - start.get()); + } + + @Override + public void resetState() { + activeChildren.set(0); + start.set(0); + duration.set(0); + } + + public long getDuration() { + return duration.get(); + } + } + public AbstractSpan(ElasticApmTracer tracer) { super(tracer); traceContext = TraceContext.with64BitId(this.tracer); + collectBreakdownMetrics = !WildcardMatcher.isAnyMatch(tracer.getConfig(ReporterConfiguration.class).getDisableMetrics(), "span.self_time"); } public boolean isReferenced() { @@ -67,13 +125,20 @@ public boolean isReferenced() { } /** - * How long the transaction took to complete, in ms with 3 decimal points - * (Required) + * How long the transaction took to complete, in µs */ - public double getDuration() { + public long getDuration() { return duration; } + public long getSelfDuration() { + return duration - childDurations.getDuration(); + } + + public double getDurationMs() { + return duration / AbstractSpan.MS_IN_MICROS; + } + /** * Generic designation of a transaction in the scope of a single service (eg: 'GET /users/:id') */ @@ -124,6 +189,7 @@ public void resetState() { timestamp = 0; duration = 0; traceContext.resetState(); + childDurations.resetState(); references.set(0); } @@ -177,20 +243,23 @@ public void end() { public final void end(long epochMicros) { if (!finished) { - this.duration = (epochMicros - timestamp) / AbstractSpan.MS_IN_MICROS; + this.duration = (epochMicros - timestamp); if (name.length() == 0) { name.append("unnamed"); } - doEnd(epochMicros); - // has to be set last so doEnd callbacks don't think it has already been finished + childDurations.onSpanEnd(epochMicros); + beforeEnd(epochMicros); this.finished = true; + afterEnd(); } else { logger.warn("End has already been called: {}", this); assert false; } } - protected abstract void doEnd(long epochMicros); + protected abstract void beforeEnd(long epochMicros); + + protected abstract void afterEnd(); @Override public boolean isChildOf(TraceContextHolder other) { @@ -242,6 +311,18 @@ public void setStartTimestamp(long epochMicros) { timestamp = epochMicros; } + void onChildStart(long epochMicros) { + if (collectBreakdownMetrics) { + childDurations.onChildStart(epochMicros); + } + } + + void onChildEnd(long epochMicros) { + if (collectBreakdownMetrics) { + childDurations.onChildEnd(epochMicros); + } + } + public void incrementReferences() { references.incrementAndGet(); if (logger.isDebugEnabled()) { diff --git a/apm-agent-core/src/main/java/co/elastic/apm/agent/impl/transaction/Span.java b/apm-agent-core/src/main/java/co/elastic/apm/agent/impl/transaction/Span.java index bc24e17c36..1d856dc01b 100644 --- a/apm-agent-core/src/main/java/co/elastic/apm/agent/impl/transaction/Span.java +++ b/apm-agent-core/src/main/java/co/elastic/apm/agent/impl/transaction/Span.java @@ -11,9 +11,9 @@ * 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 @@ -77,12 +77,10 @@ public Span start(TraceContext.ChildContextCreator childContextCreator, T if (parentContext instanceof Transaction) { this.transaction = (Transaction) parentContext; this.parent = this.transaction; - this.parent.incrementReferences(); } else if (parentContext instanceof Span) { final Span parentSpan = (Span) parentContext; this.parent = parentSpan; this.transaction = parentSpan.transaction; - this.parent.incrementReferences(); } if (dropped) { traceContext.setRecorded(false); @@ -103,6 +101,15 @@ public Span start(TraceContext.ChildContextCreator childContextCreator, T return this; } + @Override + protected void onAfterStart() { + super.onAfterStart(); + if (parent != null) { + this.parent.incrementReferences(); + this.parent.onChildStart(getTimestamp()); + } + } + /** * Any other arbitrary data captured by the agent, optionally provided by the user */ @@ -188,7 +195,7 @@ public String getAction() { } @Override - public void doEnd(long epochMicros) { + public void beforeEnd(long epochMicros) { if (logger.isDebugEnabled()) { logger.debug("} endSpan {}", this); if (logger.isTraceEnabled()) { @@ -198,9 +205,17 @@ public void doEnd(long epochMicros) { if (type == null) { type = "custom"; } + if (transaction != null) { + transaction.incrementTimer(type, subtype, getSelfDuration()); + } if (parent != null) { + parent.onChildEnd(epochMicros); parent.decrementReferences(); } + } + + @Override + protected void afterEnd() { this.tracer.endSpan(this); } diff --git a/apm-agent-core/src/main/java/co/elastic/apm/agent/impl/transaction/Transaction.java b/apm-agent-core/src/main/java/co/elastic/apm/agent/impl/transaction/Transaction.java index ee17725aa1..5ad7bae80e 100644 --- a/apm-agent-core/src/main/java/co/elastic/apm/agent/impl/transaction/Transaction.java +++ b/apm-agent-core/src/main/java/co/elastic/apm/agent/impl/transaction/Transaction.java @@ -11,9 +11,9 @@ * 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 @@ -27,10 +27,16 @@ import co.elastic.apm.agent.impl.ElasticApmTracer; import co.elastic.apm.agent.impl.context.TransactionContext; import co.elastic.apm.agent.impl.sampling.Sampler; +import co.elastic.apm.agent.metrics.Labels; +import co.elastic.apm.agent.metrics.MetricRegistry; +import co.elastic.apm.agent.metrics.Timer; +import co.elastic.apm.agent.util.KeyListConcurrentHashMap; +import org.HdrHistogram.WriterReaderPhaser; import org.slf4j.Logger; import org.slf4j.LoggerFactory; import javax.annotation.Nullable; +import java.util.List; /** * Data captured by an agent representing an event occurring in a monitored service @@ -38,6 +44,12 @@ public class Transaction extends AbstractSpan { private static final Logger logger = LoggerFactory.getLogger(Transaction.class); + private static final ThreadLocal labelsThreadLocal = new ThreadLocal() { + @Override + protected Labels.Mutable initialValue() { + return Labels.Mutable.of(); + } + }; public static final String TYPE_REQUEST = "request"; @@ -48,6 +60,17 @@ public class Transaction extends AbstractSpan { */ private final TransactionContext context = new TransactionContext(); private final SpanCount spanCount = new SpanCount(); + /** + * type: subtype: timer + *

+ * This map is not cleared when the transaction is recycled. + * Instead, it accumulates span types and subtypes over time. + * When tracking the metrics, the timers are reset and only those with a count > 0 are examined. + * That is done in order to minimize {@link java.util.Map.Entry} garbage. + *

+ */ + private final KeyListConcurrentHashMap> timerBySpanTypeAndSubtype = new KeyListConcurrentHashMap<>(); + private final WriterReaderPhaser phaser = new WriterReaderPhaser(); /** * The result of the transaction. HTTP status code for HTTP-related transactions. @@ -150,7 +173,7 @@ public void setUser(String id, String email, String username) { } @Override - public void doEnd(long epochMicros) { + public void beforeEnd(long epochMicros) { if (!isSampled()) { context.resetState(); } @@ -158,6 +181,12 @@ public void doEnd(long epochMicros) { type = "custom"; } context.onTransactionEnd(); + incrementTimer("app", null, getSelfDuration()); + } + + @Override + protected void afterEnd() { + trackMetrics(); this.tracer.endTransaction(this); } @@ -165,6 +194,10 @@ public SpanCount getSpanCount() { return spanCount; } + public KeyListConcurrentHashMap> getTimerBySpanTypeAndSubtype() { + return timerBySpanTypeAndSubtype; + } + @Override public void resetState() { super.resetState(); @@ -173,6 +206,7 @@ public void resetState() { spanCount.resetState(); noop = false; type = null; + // don't clear timerBySpanTypeAndSubtype map (see field-level javadoc) } public boolean isNoop() { @@ -223,4 +257,86 @@ public void incrementReferences() { protected void recycle() { tracer.recycle(this); } + + void incrementTimer(@Nullable String type, @Nullable String subtype, long duration) { + long criticalValueAtEnter = phaser.writerCriticalSectionEnter(); + try { + if (!collectBreakdownMetrics || type == null || finished) { + return; + } + if (subtype == null) { + subtype = ""; + } + KeyListConcurrentHashMap timersBySubtype = timerBySpanTypeAndSubtype.get(type); + if (timersBySubtype == null) { + timersBySubtype = new KeyListConcurrentHashMap<>(); + KeyListConcurrentHashMap racyMap = timerBySpanTypeAndSubtype.putIfAbsent(type, timersBySubtype); + if (racyMap != null) { + timersBySubtype = racyMap; + } + } + Timer timer = timersBySubtype.get(subtype); + if (timer == null) { + timer = new Timer(); + Timer racyTimer = timersBySubtype.putIfAbsent(subtype, timer); + if (racyTimer != null) { + timer = racyTimer; + } + } + timer.update(duration); + if (finished) { + // in case end()->trackMetrics() has been called concurrently + // don't leak timers + timer.resetState(); + } + } finally { + phaser.writerCriticalSectionExit(criticalValueAtEnter); + } + } + + private void trackMetrics() { + try { + phaser.readerLock(); + phaser.flipPhase(); + // timers are guaranteed to be stable now + // - no concurrent updates possible as finished is true + // - no other thread is running the incrementTimer method, + // as flipPhase only returns when all threads have exited that method + + final String type = getType(); + if (type == null) { + return; + } + final Labels.Mutable labels = labelsThreadLocal.get(); + labels.resetState(); + labels.transactionName(name).transactionType(type); + final MetricRegistry metricRegistry = tracer.getMetricRegistry(); + long criticalValueAtEnter = metricRegistry.writerCriticalSectionEnter(); + try { + metricRegistry.updateTimer("transaction.duration", labels, getDuration()); + if (collectBreakdownMetrics) { + metricRegistry.incrementCounter("transaction.breakdown.count", labels); + List types = timerBySpanTypeAndSubtype.keyList(); + for (int i = 0; i < types.size(); i++) { + String spanType = types.get(i); + KeyListConcurrentHashMap timerBySubtype = timerBySpanTypeAndSubtype.get(spanType); + List subtypes = timerBySubtype.keyList(); + for (int j = 0; j < subtypes.size(); j++) { + String subtype = subtypes.get(j); + final Timer timer = timerBySubtype.get(subtype); + if (timer.getCount() > 0) { + labels.spanType(spanType).spanSubType(!subtype.equals("") ? subtype : null); + metricRegistry.updateTimer("span.self_time", labels, timer.getTotalTimeUs(), timer.getCount()); + timer.resetState(); + } + } + } + } + } finally { + metricRegistry.writerCriticalSectionExit(criticalValueAtEnter); + } + } finally { + phaser.readerUnlock(); + } + } } diff --git a/apm-agent-core/src/main/java/co/elastic/apm/agent/metrics/Labels.java b/apm-agent-core/src/main/java/co/elastic/apm/agent/metrics/Labels.java new file mode 100644 index 0000000000..163d978931 --- /dev/null +++ b/apm-agent-core/src/main/java/co/elastic/apm/agent/metrics/Labels.java @@ -0,0 +1,374 @@ +/*- + * #%L + * Elastic APM Java agent + * %% + * Copyright (C) 2018 - 2019 Elastic and contributors + * %% + * Licensed to Elasticsearch B.V. under one or more contributor + * license agreements. See the NOTICE file distributed with + * this work for additional information regarding copyright + * ownership. Elasticsearch B.V. licenses this file to you 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. + * #L% + */ +package co.elastic.apm.agent.metrics; + +import co.elastic.apm.agent.objectpool.Recyclable; + +import javax.annotation.Nullable; +import java.util.ArrayList; +import java.util.Collections; +import java.util.List; +import java.util.Map; +import java.util.Objects; + +/** + * Labels are key/value pairs and relate to ECS labels. + * However, there are also top-level labels which are not nested under the {@code labels} object, + * for example {@link #getTransactionName()}, {@link #getTransactionType()}, {@link #getSpanType()} and {@link #getSpanSubType()}. + *

+ * Metrics are structured into multiple {@link MetricSet}s. + * For each distinct combination of {@link Labels}, there is one {@link MetricSet}. + *

+ *

+ * Labels allow for {@link CharSequence}s as a value, + * thus avoiding allocations for {@code transaction.name.toString()} when tracking breakdown metrics for a transaction. + * Iterations over the labels also don't allocate an Iterator, in contrast to {@code Map.entrySet().iterator()}. + *

+ */ +public interface Labels { + + Labels EMPTY = Labels.Immutable.empty(); + + @Nullable + CharSequence getTransactionName(); + + @Nullable + String getTransactionType(); + + @Nullable + String getSpanType(); + + @Nullable + String getSpanSubType(); + + List getKeys(); + + List getValues(); + + boolean isEmpty(); + + int size(); + + String getKey(int i); + + CharSequence getValue(int i); + + Labels.Immutable immutableCopy(); + + abstract class AbstractBase implements Labels { + protected final List keys; + protected final List values; + + AbstractBase(List keys, List values) { + this.keys = keys; + this.values = values; + } + + public List getKeys() { + return keys; + } + + public List getValues() { + return values; + } + + public boolean isEmpty() { + return keys.isEmpty() && getTransactionName() == null && getTransactionType() == null && getSpanType() == null; + } + + public int size() { + return keys.size(); + } + + public String getKey(int i) { + return keys.get(i); + } + + public CharSequence getValue(int i) { + return values.get(i); + } + + @Override + public boolean equals(Object o) { + if (this == o) return true; + if (!(o instanceof Labels)) return false; + AbstractBase labels = (AbstractBase) o; + return Objects.equals(getSpanType(), labels.getSpanType()) && + Objects.equals(getTransactionType(), labels.getTransactionType()) && + contentEquals(getTransactionName(), labels.getTransactionName()) && + keys.equals(labels.keys) && + isEqual(values, labels.values); + } + + @Override + public int hashCode() { + int h = 0; + for (int i = 0; i < values.size(); i++) { + h = 31 * h + hashEntryAt(i); + } + h = 31 * h + hash(getTransactionName()); + h = 31 * h + (getTransactionType() != null ? getTransactionType().hashCode() : 0); + h = 31 * h + (getSpanType() != null ? getSpanType().hashCode() : 0); + return h; + } + + @Override + public String toString() { + StringBuilder sb = new StringBuilder(); + for (int i = 0; i < keys.size(); i++) { + if (i > 0) { + sb.append(", "); + } + sb.append(keys.get(i)).append("=").append(values.get(i)); + + } + return sb.toString(); + } + + private int hashEntryAt(int i) { + return keys.get(i).hashCode() * 31 + hash(values.get(i)); + } + + private static boolean isEqual(List values, List otherValues) { + if (values.size() != otherValues.size()) { + return false; + } + for (int i = 0; i < values.size(); i++) { + if (!contentEquals(values.get(i), otherValues.get(i))) { + return false; + } + } + return true; + } + + private static boolean contentEquals(@Nullable CharSequence cs1, @Nullable CharSequence cs2) { + if (cs1 == null || cs2 == null) { + return cs1 == cs2; + } + if (cs1 instanceof String) { + return ((String) cs1).contentEquals(cs2); + } else if (cs2 instanceof String) { + return ((String) cs2).contentEquals(cs1); + } else { + if (cs1.length() == cs2.length()) { + for (int i = 0; i < cs1.length(); i++) { + if (cs1.charAt(i) != cs2.charAt(i)) { + return false; + } + } + return true; + } + } + return false; + } + + static int hash(@Nullable CharSequence cs) { + if (cs == null) { + return 0; + } + // this is safe as the hash code calculation is well defined + // (see javadoc for String.hashCode()) + if (cs instanceof String) return cs.hashCode(); + int h = 0; + for (int i = 0; i < cs.length(); i++) { + h = 31 * h + cs.charAt(i); + } + return h; + } + } + + class Mutable extends AbstractBase implements Recyclable { + + @Nullable + private CharSequence transactionName; + @Nullable + private String transactionType; + @Nullable + private String spanType; + @Nullable + private String spanSubType; + + private Mutable() { + super(new ArrayList(), new ArrayList()); + } + + public static Mutable of() { + return new Mutable(); + } + + public static Mutable of(String key, CharSequence value) { + final Mutable labels = new Mutable(); + labels.add(key, value); + return labels; + } + + public static Mutable of(Map labelMap) { + Mutable labels = new Mutable(); + for (Map.Entry entry : labelMap.entrySet()) { + labels.add(entry.getKey(), entry.getValue()); + } + return labels; + } + + public Labels add(String key, CharSequence value) { + keys.add(key); + values.add(value); + return this; + } + + public Labels.Mutable transactionName(@Nullable CharSequence transactionName) { + this.transactionName = transactionName; + return this; + } + + public Labels.Mutable transactionType(@Nullable String transactionType) { + this.transactionType = transactionType; + return this; + } + + public Labels.Mutable spanType(@Nullable String spanType) { + this.spanType = spanType; + return this; + } + + public Labels.Mutable spanSubType(@Nullable String subtype) { + this.spanSubType = subtype; + return this; + } + + @Nullable + public CharSequence getTransactionName() { + return transactionName; + } + + @Nullable + public String getTransactionType() { + return transactionType; + } + + @Nullable + public String getSpanType() { + return spanType; + } + + @Override + @Nullable + public String getSpanSubType() { + return spanSubType; + } + + public Labels.Immutable immutableCopy() { + return new Immutable(this); + } + + @Override + public void resetState() { + keys.clear(); + values.clear(); + transactionName = null; + transactionType = null; + spanType = null; + } + } + + /** + * An immutable implementation of the {@link Labels} interface + *

+ * To publish a copy of {@link Mutable} in a thread-safe manner, + * all properties need to be final. + * That's why we can't share the exact same class. + *

+ */ + class Immutable extends AbstractBase { + private static final Labels.Immutable EMPTY = new Mutable().immutableCopy(); + + private final int hash; + @Nullable + private final String transactionName; + @Nullable + private final String transactionType; + @Nullable + private final String spanType; + @Nullable + private final String spanSubType; + + public Immutable(Labels labels) { + super(new ArrayList<>(labels.getKeys()), copy(labels.getValues())); + final CharSequence transactionName = labels.getTransactionName(); + this.transactionName = transactionName != null ? transactionName.toString() : null; + this.transactionType = labels.getTransactionType(); + this.spanType = labels.getSpanType(); + this.spanSubType = labels.getSpanSubType(); + this.hash = labels.hashCode(); + } + + private static List copy(List values) { + List immutableValues = new ArrayList<>(values.size()); + for (int i = 0; i < values.size(); i++) { + immutableValues.add(values.get(i).toString()); + } + return immutableValues; + } + + public static Labels.Immutable empty() { + return EMPTY; + } + + @Override + public int hashCode() { + return hash; + } + + @Nullable + @Override + public String getTransactionName() { + return transactionName; + } + + @Nullable + @Override + public String getTransactionType() { + return transactionType; + } + + @Nullable + @Override + public String getSpanType() { + return spanType; + } + + @Override + @Nullable + public String getSpanSubType() { + return spanSubType; + } + + @Override + public Labels.Immutable immutableCopy() { + return this; + } + } + +} diff --git a/apm-agent-core/src/main/java/co/elastic/apm/agent/metrics/MetricRegistry.java b/apm-agent-core/src/main/java/co/elastic/apm/agent/metrics/MetricRegistry.java index c81cc7592d..07d3929945 100644 --- a/apm-agent-core/src/main/java/co/elastic/apm/agent/metrics/MetricRegistry.java +++ b/apm-agent-core/src/main/java/co/elastic/apm/agent/metrics/MetricRegistry.java @@ -11,9 +11,9 @@ * 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 @@ -26,7 +26,12 @@ import co.elastic.apm.agent.matcher.WildcardMatcher; import co.elastic.apm.agent.report.ReporterConfiguration; +import org.HdrHistogram.WriterReaderPhaser; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; +import javax.annotation.Nonnull; +import javax.annotation.Nullable; import java.util.Map; import java.util.concurrent.ConcurrentHashMap; import java.util.concurrent.ConcurrentMap; @@ -40,55 +45,64 @@ */ public class MetricRegistry { + private static final Logger logger = LoggerFactory.getLogger(MetricRegistry.class); + private static final int METRIC_SET_LIMIT = 1000; + private final WriterReaderPhaser phaser = new WriterReaderPhaser(); + private final ReporterConfiguration config; /** - * Groups {@link MetricSet}s by their unique tags. + * Groups {@link MetricSet}s by their unique labels. */ - private final ConcurrentMap, MetricSet> metricSets = new ConcurrentHashMap<>(); - private final ReporterConfiguration config; + private volatile ConcurrentMap activeMetricSets = new ConcurrentHashMap<>(); + private ConcurrentMap inactiveMetricSets = new ConcurrentHashMap<>(); + /** + * Final and thus stable references to the two different metric sets. + * See {@link #getOrCreateMetricSet(Labels)} + */ + private final ConcurrentMap metricSets1 = activeMetricSets, metricSets2 = inactiveMetricSets; public MetricRegistry(ReporterConfiguration config) { this.config = config; } /** - * Same as {@link #add(String, Map, DoubleSupplier)} but only adds the metric + * Same as {@link #add(String, Labels, DoubleSupplier)} but only adds the metric * if the {@link DoubleSupplier} does not return {@link Double#NaN} * * @param name the name of the metric - * @param tags tags for the metric. + * @param labels labels for the metric. * Tags can be used to create different graphs based for each value of a specific tag name, using a terms aggregation. - * Note that there will be a {@link MetricSet} created for each distinct set of tags. + * Note that there will be a {@link MetricSet} created for each distinct set of labels. * @param metric this supplier will be called for every reporting cycle * ({@link co.elastic.apm.agent.report.ReporterConfiguration#metricsInterval metrics_interval)}) - * @see #add(String, Map, DoubleSupplier) + * @see #add(String, Labels, DoubleSupplier) */ - public void addUnlessNan(String name, Map tags, DoubleSupplier metric) { + public void addUnlessNan(String name, Labels labels, DoubleSupplier metric) { if (isDisabled(name)) { return; } if (!Double.isNaN(metric.get())) { - add(name, tags, metric); + add(name, labels, metric); } } /** - * Same as {@link #add(String, Map, DoubleSupplier)} but only adds the metric + * Same as {@link #add(String, Labels, DoubleSupplier)} but only adds the metric * if the {@link DoubleSupplier} returns a positive number or zero. * * @param name the name of the metric - * @param tags tags for the metric. + * @param labels labels for the metric. * Tags can be used to create different graphs based for each value of a specific tag name, using a terms aggregation. - * Note that there will be a {@link MetricSet} created for each distinct set of tags. + * Note that there will be a {@link MetricSet} created for each distinct set of labels. * @param metric this supplier will be called for every reporting cycle * ({@link co.elastic.apm.agent.report.ReporterConfiguration#metricsInterval metrics_interval)}) - * @see #add(String, Map, DoubleSupplier) + * @see #add(String, Labels, DoubleSupplier) */ - public void addUnlessNegative(String name, Map tags, DoubleSupplier metric) { + public void addUnlessNegative(String name, Labels labels, DoubleSupplier metric) { if (isDisabled(name)) { return; } if (metric.get() >= 0) { - add(name, tags, metric); + add(name, labels, metric); } } @@ -96,37 +110,138 @@ public void addUnlessNegative(String name, Map tags, DoubleSuppl * Adds a gauge to the metric registry. * * @param name the name of the metric - * @param tags tags for the metric. + * @param labels labels for the metric. * Tags can be used to create different graphs based for each value of a specific tag name, using a terms aggregation. - * Note that there will be a {@link MetricSet} created for each distinct set of tags. + * Note that there will be a {@link MetricSet} created for each distinct set of labels. * @param metric this supplier will be called for every reporting cycle * ({@link co.elastic.apm.agent.report.ReporterConfiguration#metricsInterval metrics_interval)}) */ - public void add(String name, Map tags, DoubleSupplier metric) { + public void add(String name, Labels labels, DoubleSupplier metric) { if (isDisabled(name)) { return; } - MetricSet metricSet = metricSets.get(tags); - if (metricSet == null) { - metricSets.putIfAbsent(tags, new MetricSet(tags)); - metricSet = metricSets.get(tags); + + long criticalValueAtEnter = phaser.writerCriticalSectionEnter(); + try { + final MetricSet metricSet = getOrCreateMetricSet(labels); + if (metricSet != null) { + metricSet.addGauge(name, metric); + } + } finally { + phaser.writerCriticalSectionExit(criticalValueAtEnter); } - metricSet.add(name, metric); } private boolean isDisabled(String name) { return WildcardMatcher.anyMatch(config.getDisableMetrics(), name) != null; } - public double get(String name, Map tags) { - final MetricSet metricSet = metricSets.get(tags); + public double getGauge(String name, Labels labels) { + final MetricSet metricSet = activeMetricSets.get(labels); if (metricSet != null) { - return metricSet.get(name).get(); + return metricSet.getGauge(name).get(); } return Double.NaN; } - public Map, MetricSet> getMetricSets() { - return metricSets; + public void report(MetricsReporter metricsReporter) { + try { + phaser.readerLock(); + ConcurrentMap temp = inactiveMetricSets; + inactiveMetricSets = activeMetricSets; + activeMetricSets = temp; + phaser.flipPhase(); + metricsReporter.report(inactiveMetricSets); + } finally { + phaser.readerUnlock(); + } + } + + public void updateTimer(String timerName, Labels labels, long durationUs) { + updateTimer(timerName, labels, durationUs, 1); + } + + public void updateTimer(String timerName, Labels labels, long durationUs, long count) { + long criticalValueAtEnter = phaser.writerCriticalSectionEnter(); + try { + final MetricSet metricSet = getOrCreateMetricSet(labels); + if (metricSet != null) { + metricSet.timer(timerName).update(durationUs, count); + } + } finally { + phaser.writerCriticalSectionExit(criticalValueAtEnter); + } } + + /* + * Must always be executed in context of a critical section so that the + * activeMetricSets and inactiveMetricSets reference can't swap while this method runs + */ + @Nullable + private MetricSet getOrCreateMetricSet(Labels labels) { + MetricSet metricSet = activeMetricSets.get(labels); + if (metricSet != null) { + return metricSet; + } + if (activeMetricSets.size() < METRIC_SET_LIMIT) { + return createMetricSet(labels.immutableCopy()); + } + return null; + } + + @Nonnull + private MetricSet createMetricSet(Labels.Immutable labelsCopy) { + // Gauges are the only metric types which are not reset after each report (as opposed to counters and timers) + // that's why both metric sets have to contain the exact same gauges. + // we can't access inactiveMetricSets as it might be swapped as this method is executed + // inactiveMetricSets is only stable after flipping the phase (phaser.flipPhase) + MetricSet metricSet = new MetricSet(labelsCopy); + final MetricSet racyMetricSet = metricSets1.putIfAbsent(labelsCopy, metricSet); + if (racyMetricSet != null) { + metricSet = racyMetricSet; + } + // even if the map already contains this metric set, the gauges reference will be the same + metricSets2.putIfAbsent(labelsCopy, new MetricSet(labelsCopy, metricSet.getGauges())); + if (metricSets1.size() >= METRIC_SET_LIMIT) { + logger.warn("The limit of 1000 timers has been reached, no new timers will be created. " + + "Try to name your transactions so that there are less distinct transaction names."); + } + return activeMetricSets.get(labelsCopy); + } + + public void incrementCounter(String name, Labels labels) { + long criticalValueAtEnter = phaser.writerCriticalSectionEnter(); + try { + final MetricSet metricSet = getOrCreateMetricSet(labels); + if (metricSet != null) { + metricSet.incrementCounter(name); + } + } finally { + phaser.writerCriticalSectionExit(criticalValueAtEnter); + } + } + + /** + * @see WriterReaderPhaser#writerCriticalSectionEnter() + */ + public long writerCriticalSectionEnter() { + return phaser.writerCriticalSectionEnter(); + } + + /** + * @see WriterReaderPhaser#writerCriticalSectionExit(long) + */ + public void writerCriticalSectionExit(long criticalValueAtEnter) { + phaser.writerCriticalSectionExit(criticalValueAtEnter); + } + + public interface MetricsReporter { + /** + * Don't hold a reference to metricSets after this method ends as it will be reused. + * + * @param metricSets the metrics to report + */ + void report(Map metricSets); + } + } diff --git a/apm-agent-core/src/main/java/co/elastic/apm/agent/metrics/MetricSet.java b/apm-agent-core/src/main/java/co/elastic/apm/agent/metrics/MetricSet.java index 7eac1a30b8..c59271654a 100644 --- a/apm-agent-core/src/main/java/co/elastic/apm/agent/metrics/MetricSet.java +++ b/apm-agent-core/src/main/java/co/elastic/apm/agent/metrics/MetricSet.java @@ -27,6 +27,7 @@ import java.util.Map; import java.util.concurrent.ConcurrentHashMap; import java.util.concurrent.ConcurrentMap; +import java.util.concurrent.atomic.AtomicLong; /** * A metric set is a collection of metrics which have the same labels. @@ -43,26 +44,73 @@ * */ public class MetricSet { - private final Map labels; - private final ConcurrentMap samples = new ConcurrentHashMap<>(); + private final Labels.Immutable labels; + private final ConcurrentMap gauges; + // low load factor as hash collisions are quite costly when tracking breakdown metrics + private final ConcurrentMap timers = new ConcurrentHashMap<>(32, 0.5f, Runtime.getRuntime().availableProcessors()); + private final ConcurrentMap counters = new ConcurrentHashMap<>(32, 0.5f, Runtime.getRuntime().availableProcessors()); + private volatile boolean hasNonEmptyTimer; + private volatile boolean hasNonEmptyCounter; - public MetricSet(Map labels) { + MetricSet(Labels.Immutable labels) { + this(labels, new ConcurrentHashMap()); + } + + MetricSet(Labels.Immutable labels, ConcurrentMap gauges) { this.labels = labels; + this.gauges = gauges; } - public void add(String name, DoubleSupplier metric) { - samples.putIfAbsent(name, metric); + void addGauge(String name, DoubleSupplier metric) { + gauges.putIfAbsent(name, metric); } - DoubleSupplier get(String name) { - return samples.get(name); + DoubleSupplier getGauge(String name) { + return gauges.get(name); } - public Map getLabels() { + public Labels getLabels() { return labels; } - public Map getSamples() { - return samples; + public ConcurrentMap getGauges() { + return gauges; + } + + public Timer timer(String timerName) { + hasNonEmptyTimer = true; + Timer timer = timers.get(timerName); + if (timer == null) { + timers.putIfAbsent(timerName, new Timer()); + timer = timers.get(timerName); + } + return timer; + } + + public void incrementCounter(String name) { + hasNonEmptyCounter = true; + AtomicLong counter = counters.get(name); + if (counter == null) { + counters.putIfAbsent(name, new AtomicLong()); + counter = counters.get(name); + } + counter.incrementAndGet(); + } + + public Map getTimers() { + return timers; + } + + public boolean hasContent() { + return !gauges.isEmpty() || hasNonEmptyTimer || hasNonEmptyCounter; + } + + public void onAfterReport() { + hasNonEmptyTimer = false; + hasNonEmptyCounter = false; + } + + public Map getCounters() { + return counters; } } diff --git a/apm-agent-core/src/main/java/co/elastic/apm/agent/metrics/Timer.java b/apm-agent-core/src/main/java/co/elastic/apm/agent/metrics/Timer.java new file mode 100644 index 0000000000..bbac5a3553 --- /dev/null +++ b/apm-agent-core/src/main/java/co/elastic/apm/agent/metrics/Timer.java @@ -0,0 +1,71 @@ +/*- + * #%L + * Elastic APM Java agent + * %% + * Copyright (C) 2018 - 2019 Elastic and contributors + * %% + * Licensed to Elasticsearch B.V. under one or more contributor + * license agreements. See the NOTICE file distributed with + * this work for additional information regarding copyright + * ownership. Elasticsearch B.V. licenses this file to you 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. + * #L% + */ +package co.elastic.apm.agent.metrics; + +import co.elastic.apm.agent.objectpool.Recyclable; + +import java.util.concurrent.TimeUnit; +import java.util.concurrent.atomic.AtomicLong; + +/** + * This timer track the total time and the count of invocations so that it allows for calculating weighted averages. + */ +public class Timer implements Recyclable { + private static final double MS_IN_MICROS = TimeUnit.MILLISECONDS.toMicros(1); + + private AtomicLong totalTime = new AtomicLong(); + private AtomicLong count = new AtomicLong(); + + public void update(long durationUs) { + update(durationUs, 1); + } + + public void update(long durationUs, long count) { + this.totalTime.addAndGet(durationUs); + this.count.addAndGet(count); + } + + public long getTotalTimeUs() { + return totalTime.get(); + } + + public double getTotalTimeMs() { + return totalTime.get() / MS_IN_MICROS; + } + + public long getCount() { + return count.get(); + } + + public boolean hasContent() { + return count.get() > 0; + } + + @Override + public void resetState() { + totalTime.set(0); + count.set(0); + } +} diff --git a/apm-agent-core/src/main/java/co/elastic/apm/agent/metrics/builtin/JvmGcMetrics.java b/apm-agent-core/src/main/java/co/elastic/apm/agent/metrics/builtin/JvmGcMetrics.java index c6cb5aa20b..b4432d609d 100644 --- a/apm-agent-core/src/main/java/co/elastic/apm/agent/metrics/builtin/JvmGcMetrics.java +++ b/apm-agent-core/src/main/java/co/elastic/apm/agent/metrics/builtin/JvmGcMetrics.java @@ -27,15 +27,14 @@ import co.elastic.apm.agent.context.LifecycleListener; import co.elastic.apm.agent.impl.ElasticApmTracer; import co.elastic.apm.agent.metrics.DoubleSupplier; +import co.elastic.apm.agent.metrics.Labels; import co.elastic.apm.agent.metrics.MetricRegistry; import com.sun.management.ThreadMXBean; import org.codehaus.mojo.animal_sniffer.IgnoreJRERequirement; import java.lang.management.GarbageCollectorMXBean; import java.lang.management.ManagementFactory; -import java.util.Collections; import java.util.List; -import java.util.Map; public class JvmGcMetrics implements LifecycleListener { @@ -48,7 +47,7 @@ public void start(ElasticApmTracer tracer) { void bindTo(final MetricRegistry registry) { for (final GarbageCollectorMXBean garbageCollectorMXBean : garbageCollectorMXBeans) { - final Map tags = Collections.singletonMap("name", garbageCollectorMXBean.getName()); + final Labels tags = Labels.Mutable.of("name", garbageCollectorMXBean.getName()); registry.addUnlessNegative("jvm.gc.count", tags, new DoubleSupplier() { @Override public double get() { @@ -70,7 +69,7 @@ public double get() { // but the actual MBean it uses (com.ibm.lang.management.internal.ExtendedThreadMXBeanImpl) does not implement it if (sunBeanClass.isInstance(ManagementFactory.getThreadMXBean())) { // in reference to JMH's GC profiler (gc.alloc.rate) - registry.add("jvm.gc.alloc", Collections.emptyMap(), + registry.add("jvm.gc.alloc", Labels.EMPTY, (DoubleSupplier) Class.forName(getClass().getName() + "$HotspotAllocationSupplier").getEnumConstants()[0]); } } catch (ClassNotFoundException ignore) { diff --git a/apm-agent-core/src/main/java/co/elastic/apm/agent/metrics/builtin/JvmMemoryMetrics.java b/apm-agent-core/src/main/java/co/elastic/apm/agent/metrics/builtin/JvmMemoryMetrics.java index def143145a..2556fe82b3 100644 --- a/apm-agent-core/src/main/java/co/elastic/apm/agent/metrics/builtin/JvmMemoryMetrics.java +++ b/apm-agent-core/src/main/java/co/elastic/apm/agent/metrics/builtin/JvmMemoryMetrics.java @@ -27,11 +27,11 @@ import co.elastic.apm.agent.context.LifecycleListener; import co.elastic.apm.agent.impl.ElasticApmTracer; import co.elastic.apm.agent.metrics.DoubleSupplier; +import co.elastic.apm.agent.metrics.Labels; import co.elastic.apm.agent.metrics.MetricRegistry; import java.lang.management.ManagementFactory; import java.lang.management.MemoryMXBean; -import java.util.Collections; public class JvmMemoryMetrics implements LifecycleListener { @@ -42,37 +42,37 @@ public void start(ElasticApmTracer tracer) { void bindTo(final MetricRegistry registry) { final MemoryMXBean platformMXBean = ManagementFactory.getPlatformMXBean(MemoryMXBean.class); - registry.add("jvm.memory.heap.used", Collections.emptyMap(), new DoubleSupplier() { + registry.add("jvm.memory.heap.used", Labels.EMPTY, new DoubleSupplier() { @Override public double get() { return platformMXBean.getHeapMemoryUsage().getUsed(); } }); - registry.add("jvm.memory.heap.committed", Collections.emptyMap(), new DoubleSupplier() { + registry.add("jvm.memory.heap.committed", Labels.EMPTY, new DoubleSupplier() { @Override public double get() { return platformMXBean.getHeapMemoryUsage().getCommitted(); } }); - registry.add("jvm.memory.heap.max", Collections.emptyMap(), new DoubleSupplier() { + registry.add("jvm.memory.heap.max", Labels.EMPTY, new DoubleSupplier() { @Override public double get() { return platformMXBean.getHeapMemoryUsage().getMax(); } }); - registry.add("jvm.memory.non_heap.used", Collections.emptyMap(), new DoubleSupplier() { + registry.add("jvm.memory.non_heap.used", Labels.EMPTY, new DoubleSupplier() { @Override public double get() { return platformMXBean.getNonHeapMemoryUsage().getUsed(); } }); - registry.add("jvm.memory.non_heap.committed", Collections.emptyMap(), new DoubleSupplier() { + registry.add("jvm.memory.non_heap.committed", Labels.EMPTY, new DoubleSupplier() { @Override public double get() { return platformMXBean.getNonHeapMemoryUsage().getCommitted(); } }); - registry.add("jvm.memory.non_heap.max", Collections.emptyMap(), new DoubleSupplier() { + registry.add("jvm.memory.non_heap.max", Labels.EMPTY, new DoubleSupplier() { @Override public double get() { return platformMXBean.getNonHeapMemoryUsage().getMax(); diff --git a/apm-agent-core/src/main/java/co/elastic/apm/agent/metrics/builtin/SystemMetrics.java b/apm-agent-core/src/main/java/co/elastic/apm/agent/metrics/builtin/SystemMetrics.java index 3076297ab0..ab595078a3 100644 --- a/apm-agent-core/src/main/java/co/elastic/apm/agent/metrics/builtin/SystemMetrics.java +++ b/apm-agent-core/src/main/java/co/elastic/apm/agent/metrics/builtin/SystemMetrics.java @@ -28,6 +28,7 @@ import co.elastic.apm.agent.impl.ElasticApmTracer; import co.elastic.apm.agent.matcher.WildcardMatcher; import co.elastic.apm.agent.metrics.DoubleSupplier; +import co.elastic.apm.agent.metrics.Labels; import co.elastic.apm.agent.metrics.MetricRegistry; import org.stagemonitor.util.StringUtils; @@ -39,7 +40,6 @@ import java.lang.management.OperatingSystemMXBean; import java.lang.reflect.Method; import java.util.Arrays; -import java.util.Collections; import java.util.HashMap; import java.util.List; import java.util.Map; @@ -110,21 +110,21 @@ public void start(ElasticApmTracer tracer) { } void bindTo(MetricRegistry metricRegistry) { - metricRegistry.addUnlessNegative("system.cpu.total.norm.pct", Collections.emptyMap(), new DoubleSupplier() { + metricRegistry.addUnlessNegative("system.cpu.total.norm.pct", Labels.EMPTY, new DoubleSupplier() { @Override public double get() { return invoke(systemCpuUsage); } }); - metricRegistry.addUnlessNegative("system.process.cpu.total.norm.pct", Collections.emptyMap(), new DoubleSupplier() { + metricRegistry.addUnlessNegative("system.process.cpu.total.norm.pct", Labels.EMPTY, new DoubleSupplier() { @Override public double get() { return invoke(processCpuUsage); } }); - metricRegistry.addUnlessNan("system.memory.total", Collections.emptyMap(), new DoubleSupplier() { + metricRegistry.addUnlessNan("system.memory.total", Labels.EMPTY, new DoubleSupplier() { @Override public double get() { return invoke(totalMemory); @@ -132,7 +132,7 @@ public double get() { }); if (memInfoFile.canRead()) { - metricRegistry.addUnlessNan("system.memory.actual.free", Collections.emptyMap(), new DoubleSupplier() { + metricRegistry.addUnlessNan("system.memory.actual.free", Labels.EMPTY, new DoubleSupplier() { final List relevantLines = Arrays.asList( caseSensitiveMatcher("MemAvailable:*kB"), caseSensitiveMatcher("MemFree:*kB"), @@ -162,7 +162,7 @@ public double get() { } }); } else { - metricRegistry.addUnlessNan("system.memory.actual.free", Collections.emptyMap(), new DoubleSupplier() { + metricRegistry.addUnlessNan("system.memory.actual.free", Labels.EMPTY, new DoubleSupplier() { @Override public double get() { return invoke(freeMemory); @@ -170,7 +170,7 @@ public double get() { }); } - metricRegistry.addUnlessNegative("system.process.memory.size", Collections.emptyMap(), new DoubleSupplier() { + metricRegistry.addUnlessNegative("system.process.memory.size", Labels.EMPTY, new DoubleSupplier() { @Override public double get() { return invoke(virtualProcessMemory); diff --git a/apm-agent-core/src/main/java/co/elastic/apm/agent/metrics/builtin/ThreadMetrics.java b/apm-agent-core/src/main/java/co/elastic/apm/agent/metrics/builtin/ThreadMetrics.java index 744f2285f1..c1bb17c02a 100644 --- a/apm-agent-core/src/main/java/co/elastic/apm/agent/metrics/builtin/ThreadMetrics.java +++ b/apm-agent-core/src/main/java/co/elastic/apm/agent/metrics/builtin/ThreadMetrics.java @@ -27,11 +27,11 @@ import co.elastic.apm.agent.context.LifecycleListener; import co.elastic.apm.agent.impl.ElasticApmTracer; import co.elastic.apm.agent.metrics.DoubleSupplier; +import co.elastic.apm.agent.metrics.Labels; import co.elastic.apm.agent.metrics.MetricRegistry; import java.lang.management.ManagementFactory; import java.lang.management.ThreadMXBean; -import java.util.Collections; public class ThreadMetrics implements LifecycleListener { @@ -42,7 +42,7 @@ public void start(ElasticApmTracer tracer) { void bindTo(final MetricRegistry registry) { final ThreadMXBean threadMXBean = ManagementFactory.getThreadMXBean(); - registry.add("jvm.thread.count", Collections.emptyMap(), new DoubleSupplier() { + registry.add("jvm.thread.count", Labels.EMPTY, new DoubleSupplier() { @Override public double get() { return threadMXBean.getThreadCount(); diff --git a/apm-agent-core/src/main/java/co/elastic/apm/agent/report/ReporterConfiguration.java b/apm-agent-core/src/main/java/co/elastic/apm/agent/report/ReporterConfiguration.java index 67108f167b..9f43542b8e 100644 --- a/apm-agent-core/src/main/java/co/elastic/apm/agent/report/ReporterConfiguration.java +++ b/apm-agent-core/src/main/java/co/elastic/apm/agent/report/ReporterConfiguration.java @@ -162,6 +162,8 @@ public class ReporterConfiguration extends ConfigurationOptionProvider { "If the name of a metric matches any of the wildcard expressions, it will not be collected.\n" + "Example: `foo.*,bar.*`\n" + "\n" + + "To disable all breakdown metric collection code paths, add `span.self_time` to the list.\n" + + "\n" + WildcardMatcher.DOCUMENTATION) .dynamic(false) .buildWithDefault(Collections.emptyList()); diff --git a/apm-agent-core/src/main/java/co/elastic/apm/agent/report/serialize/DslJsonSerializer.java b/apm-agent-core/src/main/java/co/elastic/apm/agent/report/serialize/DslJsonSerializer.java index 2164519ffa..f715c52fb1 100644 --- a/apm-agent-core/src/main/java/co/elastic/apm/agent/report/serialize/DslJsonSerializer.java +++ b/apm-agent-core/src/main/java/co/elastic/apm/agent/report/serialize/DslJsonSerializer.java @@ -52,7 +52,9 @@ import co.elastic.apm.agent.impl.transaction.SpanCount; import co.elastic.apm.agent.impl.transaction.TraceContext; import co.elastic.apm.agent.impl.transaction.Transaction; +import co.elastic.apm.agent.metrics.Labels; import co.elastic.apm.agent.metrics.MetricRegistry; +import co.elastic.apm.agent.metrics.MetricSet; import co.elastic.apm.agent.util.PotentiallyMultiValuedMap; import com.dslplatform.json.BoolConverter; import com.dslplatform.json.DslJson; @@ -81,7 +83,7 @@ import static com.dslplatform.json.JsonWriter.OBJECT_END; import static com.dslplatform.json.JsonWriter.OBJECT_START; -public class DslJsonSerializer implements PayloadSerializer { +public class DslJsonSerializer implements PayloadSerializer, MetricRegistry.MetricsReporter { /** * Matches default ZLIB buffer size. @@ -228,9 +230,14 @@ public int getBufferSize() { return jw.size(); } + @Override + public void report(Map metricSets) { + MetricRegistrySerializer.serialize(metricSets, replaceBuilder, jw); + } + @Override public void serializeMetrics(MetricRegistry metricRegistry) { - MetricRegistrySerializer.serialize(metricRegistry, replaceBuilder, jw); + metricRegistry.report(this); } private void serializeErrorPayload(ErrorPayload payload) { @@ -519,7 +526,7 @@ private void serializeTransaction(final Transaction transaction) { writeField("name", transaction.getName()); serializeTraceContext(transaction.getTraceContext(), false); writeField("type", transaction.getType()); - writeField("duration", transaction.getDuration()); + writeField("duration", transaction.getDurationMs()); writeField("result", transaction.getResult()); serializeContext(transaction.getContext(), transaction.getTraceContext()); serializeSpanCount(transaction.getSpanCount()); @@ -560,7 +567,7 @@ private void serializeSpan(final Span span) { writeField("name", span.getName()); writeTimestamp(span.getTimestamp()); serializeTraceContext(span.getTraceContext(), true); - writeField("duration", span.getDuration()); + writeField("duration", span.getDurationMs()); if (span.getStacktrace() != null) { serializeStacktrace(span.getStacktrace().getStackTrace()); } @@ -808,6 +815,45 @@ private static void serializeStringKeyScalarValueMap(Iterator 0) { + jw.writeByte(COMMA); + } + writeStringValue(sanitizeLabelKey(labels.getKey(i), replaceBuilder), replaceBuilder, jw); + jw.writeByte(JsonWriter.SEMI); + serializeScalarValue(replaceBuilder, jw, labels.getValue(i), false); + } + } + private static void serializeScalarValue(StringBuilder replaceBuilder, JsonWriter jw, Object value, boolean extendedStringLimit) { if (value instanceof String) { if (extendedStringLimit) { @@ -982,9 +1028,13 @@ void writeLongStringField(final String fieldName, @Nullable final String value) } void writeField(final String fieldName, @Nullable final String value) { + writeField(fieldName, value, replaceBuilder, jw); + } + + static void writeField(final String fieldName, @Nullable final CharSequence value, StringBuilder replaceBuilder, JsonWriter jw) { if (value != null) { - writeFieldName(fieldName); - writeStringValue(value); + writeFieldName(fieldName, jw); + writeStringValue(value, replaceBuilder, jw); jw.writeByte(COMMA); } } @@ -1072,9 +1122,13 @@ private void writeField(final String fieldName, final double value) { } void writeLastField(final String fieldName, @Nullable final String value) { - writeFieldName(fieldName); + writeLastField(fieldName, value, replaceBuilder, jw); + } + + static void writeLastField(final String fieldName, @Nullable final String value, StringBuilder replaceBuilder, final JsonWriter jw) { + writeFieldName(fieldName, jw); if (value != null) { - writeStringValue(value); + writeStringValue(value, replaceBuilder, jw); } else { jw.writeNull(); } diff --git a/apm-agent-core/src/main/java/co/elastic/apm/agent/report/serialize/MetricRegistrySerializer.java b/apm-agent-core/src/main/java/co/elastic/apm/agent/report/serialize/MetricRegistrySerializer.java index 7adc138718..9b4064e266 100644 --- a/apm-agent-core/src/main/java/co/elastic/apm/agent/report/serialize/MetricRegistrySerializer.java +++ b/apm-agent-core/src/main/java/co/elastic/apm/agent/report/serialize/MetricRegistrySerializer.java @@ -25,23 +25,28 @@ package co.elastic.apm.agent.report.serialize; import co.elastic.apm.agent.metrics.DoubleSupplier; -import co.elastic.apm.agent.metrics.MetricRegistry; +import co.elastic.apm.agent.metrics.Labels; import co.elastic.apm.agent.metrics.MetricSet; +import co.elastic.apm.agent.metrics.Timer; import com.dslplatform.json.JsonWriter; import com.dslplatform.json.NumberConverter; import java.util.Iterator; import java.util.Map; +import java.util.concurrent.atomic.AtomicLong; public class MetricRegistrySerializer { private static final byte NEW_LINE = '\n'; - public static void serialize(MetricRegistry metricRegistry, StringBuilder replaceBuilder, JsonWriter jw) { + public static void serialize(Map metricSets, StringBuilder replaceBuilder, JsonWriter jw) { final long timestamp = System.currentTimeMillis() * 1000; - for (MetricSet metricSet : metricRegistry.getMetricSets().values()) { - serializeMetricSet(metricSet, timestamp, replaceBuilder, jw); - jw.writeByte(NEW_LINE); + for (MetricSet metricSet : metricSets.values()) { + if (metricSet.hasContent()) { + serializeMetricSet(metricSet, timestamp, replaceBuilder, jw); + metricSet.onAfterReport(); + jw.writeByte(NEW_LINE); + } } } @@ -54,26 +59,23 @@ static void serializeMetricSet(MetricSet metricSet, long epochMicros, StringBuil DslJsonSerializer.writeFieldName("timestamp", jw); NumberConverter.serialize(epochMicros, jw); jw.writeByte(JsonWriter.COMMA); - - if (!metricSet.getLabels().isEmpty()) { - DslJsonSerializer.writeFieldName("tags", jw); - DslJsonSerializer.serializeStringLabels(metricSet.getLabels().entrySet().iterator(), replaceBuilder, jw); - jw.writeByte(JsonWriter.COMMA); - } - + DslJsonSerializer.serializeLabels(metricSet.getLabels(), replaceBuilder, jw); DslJsonSerializer.writeFieldName("samples", jw); - serializeSamples(metricSet.getSamples(), jw); + jw.writeByte(JsonWriter.OBJECT_START); + boolean hasSamples = serializeGauges(metricSet.getGauges(), jw); + hasSamples |= serializeTimers(metricSet.getTimers(), hasSamples, jw); + serializeCounters(metricSet.getCounters(), hasSamples, jw); + jw.writeByte(JsonWriter.OBJECT_END); } jw.writeByte(JsonWriter.OBJECT_END); } jw.writeByte(JsonWriter.OBJECT_END); } - private static void serializeSamples(Map samples, JsonWriter jw) { - jw.writeByte(JsonWriter.OBJECT_START); - final int size = samples.size(); + private static boolean serializeGauges(Map gauges, JsonWriter jw) { + final int size = gauges.size(); if (size > 0) { - final Iterator> iterator = samples.entrySet().iterator(); + final Iterator> iterator = gauges.entrySet().iterator(); // serialize first valid value double value = Double.NaN; @@ -81,7 +83,7 @@ private static void serializeSamples(Map samples, JsonWr Map.Entry kv = iterator.next(); value = kv.getValue().get(); if (isValid(value)) { - serializeSample(kv.getKey(), value, jw); + serializeValue(kv.getKey(), value, jw); } } @@ -91,23 +93,120 @@ private static void serializeSamples(Map samples, JsonWr value = kv.getValue().get(); if (isValid(value)) { jw.writeByte(JsonWriter.COMMA); - serializeSample(kv.getKey(), value, jw); + serializeValue(kv.getKey(), value, jw); + } + } + return true; + } + return false; + } + + private static boolean serializeTimers(Map timers, boolean hasSamples, JsonWriter jw) { + final int size = timers.size(); + if (size > 0) { + final Iterator> iterator = timers.entrySet().iterator(); + + // serialize first valid value + Timer value = null; + while (iterator.hasNext() && value == null) { + Map.Entry kv = iterator.next(); + if (kv.getValue().hasContent()) { + value = kv.getValue(); + if (hasSamples) { + jw.writeByte(JsonWriter.COMMA); + } + hasSamples = true; + serializeTimer(kv.getKey(), value, jw); + } + } + + // serialize rest + while (iterator.hasNext()) { + Map.Entry kv = iterator.next(); + value = kv.getValue(); + if (value.hasContent()) { + jw.writeByte(JsonWriter.COMMA); + serializeTimer(kv.getKey(), value, jw); } } } + return hasSamples; + } + + private static void serializeCounters(Map counters, boolean hasSamples, JsonWriter jw) { + final int size = counters.size(); + if (size > 0) { + final Iterator> iterator = counters.entrySet().iterator(); + + // serialize first valid value + AtomicLong value = null; + while (iterator.hasNext() && value == null) { + Map.Entry kv = iterator.next(); + if (kv.getValue().get() > 0) { + value = kv.getValue(); + if (hasSamples) { + jw.writeByte(JsonWriter.COMMA); + } + serializeCounter(kv.getKey(), value, jw); + } + } + + // serialize rest + while (iterator.hasNext()) { + Map.Entry kv = iterator.next(); + value = kv.getValue(); + if (kv.getValue().get() > 0) { + jw.writeByte(JsonWriter.COMMA); + serializeCounter(kv.getKey(), value, jw); + } + } + } + } + + private static void serializeCounter(String key, AtomicLong value, JsonWriter jw) { + serializeValueStart(key, "", jw); + NumberConverter.serialize(value.get(), jw); jw.writeByte(JsonWriter.OBJECT_END); + value.set(0); } private static boolean isValid(double value) { return !Double.isInfinite(value) && !Double.isNaN(value); } - private static void serializeSample(String key, double value, JsonWriter jw) { - jw.writeString(key); - jw.writeByte(JsonWriter.SEMI); - jw.writeByte(JsonWriter.OBJECT_START); - DslJsonSerializer.writeFieldName("value", jw); + private static void serializeTimer(String key, Timer timer, JsonWriter jw) { + serializeValue(key, ".count", timer.getCount(), jw); + jw.writeByte(JsonWriter.COMMA); + serializeValue(key, ".sum.us", timer.getTotalTimeUs(), jw); + timer.resetState(); + } + + private static void serializeValue(String key, double value, JsonWriter jw) { + serializeValue(key, "", value, jw); + } + + private static void serializeValue(String key, String suffix, double value, JsonWriter jw) { + serializeValueStart(key, suffix, jw); + NumberConverter.serialize(value, jw); + jw.writeByte(JsonWriter.OBJECT_END); + } + + private static void serializeValue(String key, String suffix, long value, JsonWriter jw) { + serializeValueStart(key, suffix, jw); NumberConverter.serialize(value, jw); jw.writeByte(JsonWriter.OBJECT_END); } + + private static void serializeValueStart(String key, String suffix, JsonWriter jw) { + jw.writeByte(JsonWriter.QUOTE); + jw.writeAscii(key); + jw.writeAscii(suffix); + jw.writeByte(JsonWriter.QUOTE); + jw.writeByte(JsonWriter.SEMI); + jw.writeByte(JsonWriter.OBJECT_START); + jw.writeByte(JsonWriter.QUOTE); + jw.writeAscii("value"); + jw.writeByte(JsonWriter.QUOTE); + jw.writeByte(JsonWriter.SEMI); + } } diff --git a/apm-agent-core/src/main/java/co/elastic/apm/agent/util/KeyListConcurrentHashMap.java b/apm-agent-core/src/main/java/co/elastic/apm/agent/util/KeyListConcurrentHashMap.java new file mode 100644 index 0000000000..31adb8d1ad --- /dev/null +++ b/apm-agent-core/src/main/java/co/elastic/apm/agent/util/KeyListConcurrentHashMap.java @@ -0,0 +1,113 @@ +/*- + * #%L + * Elastic APM Java agent + * %% + * Copyright (C) 2018 - 2019 Elastic and contributors + * %% + * Licensed to Elasticsearch B.V. under one or more contributor + * license agreements. See the NOTICE file distributed with + * this work for additional information regarding copyright + * ownership. Elasticsearch B.V. licenses this file to you 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. + * #L% + */ +package co.elastic.apm.agent.util; + +import java.util.ArrayList; +import java.util.Collections; +import java.util.List; +import java.util.Map; +import java.util.concurrent.ConcurrentHashMap; + +/** + * A subclass of {@link ConcurrentHashMap} which maintains a {@link List} of all the keys in the map. + * It can be used to iterate over the map's keys without allocating an {@link java.util.Iterator} + */ +public class KeyListConcurrentHashMap extends ConcurrentHashMap { + private final List keyList = Collections.synchronizedList(new ArrayList()); + + @Override + public V put(K key, V value) { + synchronized (this) { + final V previousValue = super.put(key, value); + if (previousValue == null) { + keyList.add(key); + } + return previousValue; + } + } + + @Override + public void putAll(Map m) { + synchronized (this) { + for (Entry entry : m.entrySet()) { + put(entry.getKey(), entry.getValue()); + } + } + } + + @Override + public V remove(Object key) { + synchronized (this) { + keyList.remove(key); + return super.remove(key); + } + } + + @Override + public void clear() { + synchronized (this) { + keyList.clear(); + super.clear(); + } + } + + @Override + public V putIfAbsent(K key, V value) { + synchronized (this) { + final V previousValue = super.putIfAbsent(key, value); + if (previousValue == null) { + keyList.add(key); + } + return previousValue; + } + } + + @Override + public boolean remove(Object key, Object value) { + synchronized (this) { + final boolean remove = super.remove(key, value); + if (remove) { + keyList.remove(key); + } + return remove; + } + } + + /** + * Returns a mutable {@link List}, roughly equal to the {@link #keySet()}. + *

+ * Note that in concurrent scenarios, the key list may be a subset of the values of the respective {@link #keySet()}. + * Entries added via the {@code compute*} family of methods are not reflected in the list. + *

+ *

+ * Do not modify this list. + *

+ * + * @return a {@link List}, roughly equal to the {@link #keySet()} + */ + public List keyList() { + return keyList; + } +} diff --git a/apm-agent-core/src/test/java/co/elastic/apm/agent/MockTracer.java b/apm-agent-core/src/test/java/co/elastic/apm/agent/MockTracer.java index e7ea615119..4783535c5c 100644 --- a/apm-agent-core/src/test/java/co/elastic/apm/agent/MockTracer.java +++ b/apm-agent-core/src/test/java/co/elastic/apm/agent/MockTracer.java @@ -49,8 +49,16 @@ public static ElasticApmTracer createRealTracer() { * the configuration. */ public static ElasticApmTracer createRealTracer(Reporter reporter) { + return createRealTracer(reporter, SpyConfiguration.createSpyConfig()); + } + + /** + * Creates a real tracer with a given reporter and a mock configuration which returns default values which can be customized by mocking + * the configuration. + */ + public static ElasticApmTracer createRealTracer(Reporter reporter, ConfigurationRegistry config) { return new ElasticApmTracerBuilder() - .configurationRegistry(SpyConfiguration.createSpyConfig()) + .configurationRegistry(config) .reporter(reporter) .build(); } diff --git a/apm-agent-core/src/test/java/co/elastic/apm/agent/TransactionUtils.java b/apm-agent-core/src/test/java/co/elastic/apm/agent/TransactionUtils.java index c83e3fd9df..a6523af54a 100644 --- a/apm-agent-core/src/test/java/co/elastic/apm/agent/TransactionUtils.java +++ b/apm-agent-core/src/test/java/co/elastic/apm/agent/TransactionUtils.java @@ -24,7 +24,6 @@ */ package co.elastic.apm.agent; -import co.elastic.apm.agent.impl.ElasticApmTracer; import co.elastic.apm.agent.impl.context.Request; import co.elastic.apm.agent.impl.context.TransactionContext; import co.elastic.apm.agent.impl.sampling.ConstantSampler; @@ -35,8 +34,6 @@ import java.util.ArrayList; import java.util.List; -import static org.mockito.Mockito.mock; - public class TransactionUtils { public static void fillTransaction(Transaction t) { @@ -86,7 +83,7 @@ public static void fillTransaction(Transaction t) { public static List getSpans(Transaction t) { List spans = new ArrayList<>(); - Span span = new Span(mock(ElasticApmTracer.class)) + Span span = new Span(MockTracer.create()) .start(TraceContext.fromParent(), t, -1, false) .withName("SELECT FROM product_types") .withType("db") @@ -101,20 +98,20 @@ public static List getSpans(Transaction t) { span.addLabel("framework", "some-framework"); spans.add(span); - spans.add(new Span(mock(ElasticApmTracer.class)) + spans.add(new Span(MockTracer.create()) .start(TraceContext.fromParent(), t, -1, false) .withName("GET /api/types") .withType("request")); - spans.add(new Span(mock(ElasticApmTracer.class)) + spans.add(new Span(MockTracer.create()) .start(TraceContext.fromParent(), t, -1, false) .withName("GET /api/types") .withType("request")); - spans.add(new Span(mock(ElasticApmTracer.class)) + spans.add(new Span(MockTracer.create()) .start(TraceContext.fromParent(), t, -1, false) .withName("GET /api/types") .withType("request")); - span = new Span(mock(ElasticApmTracer.class)) + span = new Span(MockTracer.create()) .start(TraceContext.fromParent(), t, -1, false) .appendToName("GET ") .appendToName("test.elastic.co") diff --git a/apm-agent-core/src/test/java/co/elastic/apm/agent/configuration/SpyConfiguration.java b/apm-agent-core/src/test/java/co/elastic/apm/agent/configuration/SpyConfiguration.java index 44a205e010..53c2ddc916 100644 --- a/apm-agent-core/src/test/java/co/elastic/apm/agent/configuration/SpyConfiguration.java +++ b/apm-agent-core/src/test/java/co/elastic/apm/agent/configuration/SpyConfiguration.java @@ -28,6 +28,7 @@ import org.mockito.Mockito; import org.stagemonitor.configuration.ConfigurationOptionProvider; import org.stagemonitor.configuration.ConfigurationRegistry; +import org.stagemonitor.configuration.source.ConfigurationSource; import org.stagemonitor.configuration.source.SimpleSource; import java.util.ServiceLoader; @@ -38,6 +39,18 @@ public class SpyConfiguration { public static final String CONFIG_SOURCE_NAME = "test config source"; + /** + * Creates a configuration registry where all {@link ConfigurationOptionProvider}s are wrapped with + * {@link Mockito#spy(Object)} + *

+ * That way, the default configuration values are returned but can be overridden by {@link Mockito#when(Object)} + * + * @return a syp configuration registry + */ + public static ConfigurationRegistry createSpyConfig() { + return createSpyConfig(new SimpleSource(CONFIG_SOURCE_NAME)); + } + /** * Creates a configuration registry where all {@link ConfigurationOptionProvider}s are wrapped with * {@link org.mockito.Mockito#spy(Object)} @@ -45,14 +58,15 @@ public class SpyConfiguration { * That way, the default configuration values are returned but can be overridden by {@link org.mockito.Mockito#when(Object)} * * @return a syp configuration registry + * @param configurationSource */ - public static ConfigurationRegistry createSpyConfig() { + public static ConfigurationRegistry createSpyConfig(ConfigurationSource configurationSource) { ConfigurationRegistry.Builder builder = ConfigurationRegistry.builder(); for (ConfigurationOptionProvider options : ServiceLoader.load(ConfigurationOptionProvider.class)) { builder.addOptionProvider(spy(options)); } return builder - .addConfigSource(new SimpleSource(CONFIG_SOURCE_NAME)) + .addConfigSource(configurationSource) .addConfigSource(new PropertyFileConfigurationSource("elasticapm.properties")) .build(); } diff --git a/apm-agent-core/src/test/java/co/elastic/apm/agent/impl/ElasticApmTracerTest.java b/apm-agent-core/src/test/java/co/elastic/apm/agent/impl/ElasticApmTracerTest.java index 2ce95b9a8a..a4295b46e6 100644 --- a/apm-agent-core/src/test/java/co/elastic/apm/agent/impl/ElasticApmTracerTest.java +++ b/apm-agent-core/src/test/java/co/elastic/apm/agent/impl/ElasticApmTracerTest.java @@ -352,9 +352,9 @@ void testTimestamps() { transaction.end(30); assertThat(transaction.getTimestamp()).isEqualTo(0); - assertThat(transaction.getDuration()).isEqualTo(0.03); + assertThat(transaction.getDuration()).isEqualTo(30); assertThat(span.getTimestamp()).isEqualTo(10); - assertThat(span.getDuration()).isEqualTo(0.01); + assertThat(span.getDuration()).isEqualTo(10); } @Test diff --git a/apm-agent-core/src/test/java/co/elastic/apm/agent/impl/ScopeManagementTest.java b/apm-agent-core/src/test/java/co/elastic/apm/agent/impl/ScopeManagementTest.java index 18259c17a4..ce226c59b4 100644 --- a/apm-agent-core/src/test/java/co/elastic/apm/agent/impl/ScopeManagementTest.java +++ b/apm-agent-core/src/test/java/co/elastic/apm/agent/impl/ScopeManagementTest.java @@ -98,7 +98,7 @@ void testActivateTwice() { } @Test - void testMissingDeactivation() { + void testRedundantActivation() { runTestWithAssertionsDisabled(() -> { final Transaction transaction = tracer.startTransaction(TraceContext.asRoot(), null, null).activate(); transaction.createSpan().activate(); diff --git a/apm-agent-core/src/test/java/co/elastic/apm/agent/impl/SpanTypeBreakdownTest.java b/apm-agent-core/src/test/java/co/elastic/apm/agent/impl/SpanTypeBreakdownTest.java new file mode 100644 index 0000000000..3593ca9cb8 --- /dev/null +++ b/apm-agent-core/src/test/java/co/elastic/apm/agent/impl/SpanTypeBreakdownTest.java @@ -0,0 +1,387 @@ +/*- + * #%L + * Elastic APM Java agent + * %% + * Copyright (C) 2018 - 2019 Elastic and contributors + * %% + * Licensed to Elasticsearch B.V. under one or more contributor + * license agreements. See the NOTICE file distributed with + * this work for additional information regarding copyright + * ownership. Elasticsearch B.V. licenses this file to you 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. + * #L% + */ +package co.elastic.apm.agent.impl; + +import co.elastic.apm.agent.MockReporter; +import co.elastic.apm.agent.MockTracer; +import co.elastic.apm.agent.configuration.SpyConfiguration; +import co.elastic.apm.agent.impl.sampling.ConstantSampler; +import co.elastic.apm.agent.impl.transaction.Span; +import co.elastic.apm.agent.impl.transaction.TraceContext; +import co.elastic.apm.agent.impl.transaction.TraceContextHolder; +import co.elastic.apm.agent.impl.transaction.Transaction; +import co.elastic.apm.agent.metrics.Labels; +import co.elastic.apm.agent.metrics.MetricSet; +import co.elastic.apm.agent.metrics.Timer; +import org.junit.jupiter.api.BeforeEach; +import org.junit.jupiter.api.Test; +import org.stagemonitor.configuration.source.SimpleSource; + +import javax.annotation.Nullable; +import java.util.Map; + +import static org.assertj.core.api.Assertions.assertThat; + +class SpanTypeBreakdownTest { + + private MockReporter reporter; + private ElasticApmTracer tracer; + + @BeforeEach + void setUp() { + reporter = new MockReporter(); + tracer = MockTracer.createRealTracer(reporter); + } + + /* + * ██████████████████████████████ + * 10 20 30 + */ + @Test + void testBreakdown_noSpans() { + tracer.startTransaction(TraceContext.asRoot(), null, ConstantSampler.of(true), 0, getClass().getClassLoader()) + .withName("test") + .withType("request") + .end(30); + tracer.getMetricRegistry().report(metricSets -> { + assertThat(getTimer(metricSets, "span.self_time", "app", null).getCount()).isEqualTo(1); + assertThat(getTimer(metricSets, "span.self_time", "app", null).getTotalTimeUs()).isEqualTo(30); + assertThat(getTimer(metricSets, "transaction.duration", null, null).getTotalTimeUs()).isEqualTo(30); + assertThatTransactionBreakdownCounterCreated(metricSets); + }); + } + + /* + * ██████████░░░░░░░░░░██████████ + * └─────────██████████ + * 10 20 30g + */ + @Test + void testBreakdown_singleDbSpan() { + final Transaction transaction = tracer.startTransaction(TraceContext.asRoot(), null, ConstantSampler.of(true), 0, getClass().getClassLoader()) + .withName("test") + .withType("request"); + transaction.createSpan(10).withType("db").withSubtype("mysql").end(20); + transaction.end(30); + + tracer.getMetricRegistry().report(metricSets -> { + assertThat(getTimer(metricSets, "span.self_time", "app", null).getCount()).isEqualTo(1); + assertThat(getTimer(metricSets, "span.self_time", "app", null).getTotalTimeUs()).isEqualTo(20); + assertThat(getTimer(metricSets, "transaction.duration", null, null).getTotalTimeUs()).isEqualTo(30); + assertThatTransactionBreakdownCounterCreated(metricSets); + assertThat(getTimer(metricSets, "span.self_time", "db", "mysql").getCount()).isEqualTo(1); + assertThat(getTimer(metricSets, "span.self_time", "db", "mysql").getTotalTimeUs()).isEqualTo(10); + }); + } + + /* + * ██████████░░░░░░░░░░██████████ + * └─────────██████████ + * 10 20 30 + */ + @Test + void testBreakdown_singleDbSpan_breakdownMetricsDisabled() { + tracer = MockTracer.createRealTracer(reporter, SpyConfiguration.createSpyConfig(SimpleSource.forTest("disable_metrics", "span.self_time"))); + final Transaction transaction = tracer.startTransaction(TraceContext.asRoot(), null, ConstantSampler.of(true), 0, getClass().getClassLoader()) + .withName("test") + .withType("request"); + transaction.createSpan(10).withType("db").withSubtype("mysql").end(20); + transaction.end(30); + + assertThat(transaction.getTimerBySpanTypeAndSubtype()).isEmpty(); + tracer.getMetricRegistry().report(metricSets -> { + assertThat(getTimer(metricSets, "span.self_time", "app", null)).isNull(); + assertThat(getTimer(metricSets, "span.self_time", "db", "mysql")).isNull(); + assertThat(getTimer(metricSets, "transaction.duration", null, null).getTotalTimeUs()).isEqualTo(30); + }); + } + + /* + * ██████████░░░░░░░░░░██████████ + * └─────────██████████ + * 10 20 30 + */ + @Test + void testBreakdown_singleAppSpan() { + final Transaction transaction = tracer.startTransaction(TraceContext.asRoot(), null, ConstantSampler.of(true), 0, getClass().getClassLoader()) + .withName("test") + .withType("request"); + transaction.createSpan(10).withType("app").end(20); + transaction.end(30); + + tracer.getMetricRegistry().report(metricSets -> { + assertThat(getTimer(metricSets, "span.self_time", "app", null).getCount()).isEqualTo(2); + assertThat(getTimer(metricSets, "span.self_time", "app", null).getTotalTimeUs()).isEqualTo(30); + assertThat(getTimer(metricSets, "transaction.duration", null, null).getTotalTimeUs()).isEqualTo(30); + assertThatTransactionBreakdownCounterCreated(metricSets); + }); + } + + /* + * ██████████░░░░░░░░░░██████████ + * ├─────────██████████ + * └─────────██████████ + * 10 20 30 + */ + @Test + void testBreakdown_concurrentDbSpans_fullyOverlapping() { + final Transaction transaction = tracer.startTransaction(TraceContext.asRoot(), null, ConstantSampler.of(true), 0, getClass().getClassLoader()) + .withName("test") + .withType("request"); + final Span span1 = transaction.createSpan(10).withType("db").withSubtype("mysql"); + final Span span2 = transaction.createSpan(10).withType("db").withSubtype("mysql"); + span1.end(20); + span2.end(20); + transaction.end(30); + + tracer.getMetricRegistry().report(metricSets -> { + assertThat(getTimer(metricSets, "span.self_time", "app", null).getCount()).isEqualTo(1); + assertThat(getTimer(metricSets, "span.self_time", "app", null).getTotalTimeUs()).isEqualTo(20); + assertThat(getTimer(metricSets, "transaction.duration", null, null).getTotalTimeUs()).isEqualTo(30); + assertThatTransactionBreakdownCounterCreated(metricSets); + assertThat(getTimer(metricSets, "span.self_time", "db", "mysql").getCount()).isEqualTo(2); + assertThat(getTimer(metricSets, "span.self_time", "db", "mysql").getTotalTimeUs()).isEqualTo(20); + }); + } + + /* + * ██████████░░░░░░░░░░░░░░░█████ + * ├─────────██████████ + * └──────────────██████████ + * 10 20 30 + */ + @Test + void testBreakdown_concurrentDbSpans_partiallyOverlapping() { + final Transaction transaction = tracer.startTransaction(TraceContext.asRoot(), null, ConstantSampler.of(true), 0, getClass().getClassLoader()) + .withName("test") + .withType("request"); + final Span span1 = transaction.createSpan(10).withType("db").withSubtype("mysql"); + final Span span2 = transaction.createSpan(15).withType("db").withSubtype("mysql"); + span1.end(20); + span2.end(25); + transaction.end(30); + + tracer.getMetricRegistry().report(metricSets -> { + assertThat(getTimer(metricSets, "span.self_time", "app", null).getCount()).isEqualTo(1); + assertThat(getTimer(metricSets, "span.self_time", "app", null).getTotalTimeUs()).isEqualTo(15); + assertThat(getTimer(metricSets, "transaction.duration", null, null).getTotalTimeUs()).isEqualTo(30); + assertThatTransactionBreakdownCounterCreated(metricSets); + assertThat(getTimer(metricSets, "span.self_time", "db", "mysql").getCount()).isEqualTo(2); + assertThat(getTimer(metricSets, "span.self_time", "db", "mysql").getTotalTimeUs()).isEqualTo(20); + }); + } + + /* + * █████░░░░░░░░░░░░░░░░░░░░█████ + * ├────██████████ + * └──────────────██████████ + * 10 20 30 + */ + @Test + void testBreakdown_serialDbSpans_notOverlapping_withoutGap() { + final Transaction transaction = tracer.startTransaction(TraceContext.asRoot(), null, ConstantSampler.of(true), 0, getClass().getClassLoader()) + .withName("test") + .withType("request"); + transaction.createSpan(5).withType("db").withSubtype("mysql").end(15); + transaction.createSpan(15).withType("db").withSubtype("mysql").end(25); + transaction.end(30); + + tracer.getMetricRegistry().report(metricSets -> { + assertThat(getTimer(metricSets, "span.self_time", "app", null).getCount()).isEqualTo(1); + assertThat(getTimer(metricSets, "span.self_time", "app", null).getTotalTimeUs()).isEqualTo(10); + assertThat(getTimer(metricSets, "transaction.duration", null, null).getTotalTimeUs()).isEqualTo(30); + assertThatTransactionBreakdownCounterCreated(metricSets); + assertThat(getTimer(metricSets, "span.self_time", "db", "mysql").getCount()).isEqualTo(2); + assertThat(getTimer(metricSets, "span.self_time", "db", "mysql").getTotalTimeUs()).isEqualTo(20); + }); + } + + /* + * ██████████░░░░░█████░░░░░█████ + * ├─────────█████ + * └───────────────────█████ + * 10 20 30 + */ + @Test + void testBreakdown_serialDbSpans_notOverlapping_withGap() { + final Transaction transaction = tracer.startTransaction(TraceContext.asRoot(), null, ConstantSampler.of(true), 0, getClass().getClassLoader()) + .withName("test") + .withType("request"); + transaction.createSpan(10).withType("db").withSubtype("mysql").end(15); + transaction.createSpan(20).withType("db").withSubtype("mysql").end(25); + transaction.end(30); + + tracer.getMetricRegistry().report(metricSets -> { + assertThat(getTimer(metricSets, "span.self_time", "app", null).getCount()).isEqualTo(1); + assertThat(getTimer(metricSets, "span.self_time", "app", null).getTotalTimeUs()).isEqualTo(20); + assertThat(getTimer(metricSets, "transaction.duration", null, null).getTotalTimeUs()).isEqualTo(30); + assertThatTransactionBreakdownCounterCreated(metricSets); + assertThat(getTimer(metricSets, "span.self_time", "db", "mysql").getCount()).isEqualTo(2); + assertThat(getTimer(metricSets, "span.self_time", "db", "mysql").getTotalTimeUs()).isEqualTo(10); + }); + } + + /* + * ██████████░░░░░░░░░░██████████ + * └─────────█████░░░░░ <- all child timers are force-stopped when a span finishes + * └────██████████ <- does not influence the transaction's self-time as it's not a direct child + * 10 20 30 + */ + @Test + void testBreakdown_asyncGrandchildExceedsChild() { + final Transaction transaction = tracer.startTransaction(TraceContext.asRoot(), null, ConstantSampler.of(true), 0, getClass().getClassLoader()) + .withName("test") + .withType("request"); + final Span app = transaction.createSpan(10).withType("app"); + final Span db = app.createSpan(15).withType("db").withSubtype("mysql"); + app.end(20); + db.end(25); + transaction.end(30); + + tracer.getMetricRegistry().report(metricSets -> { + assertThat(getTimer(metricSets, "span.self_time", "app", null).getCount()).isEqualTo(2); + assertThat(getTimer(metricSets, "span.self_time", "app", null).getTotalTimeUs()).isEqualTo(25); + assertThat(getTimer(metricSets, "transaction.duration", null, null).getTotalTimeUs()).isEqualTo(30); + assertThatTransactionBreakdownCounterCreated(metricSets); + assertThat(getTimer(metricSets, "span.self_time", "db", "mysql").getCount()).isEqualTo(1); + assertThat(getTimer(metricSets, "span.self_time", "db", "mysql").getTotalTimeUs()).isEqualTo(10); + }); + } + + /* + * breakdowns are reported when the transaction ends + * any spans which outlive the transaction are not included in the breakdown + * v + * ██████████░░░░░░░░░░ + * └─────────██████████░░░░░░░░░░ + * └─────────██████████ + * 10 20 30 + */ + @Test + void testBreakdown_asyncGrandchildExceedsChildAndTransaction() { + final Transaction transaction = tracer.startTransaction(TraceContext.asRoot(), null, ConstantSampler.of(true), 0, getClass().getClassLoader()) + .withName("test") + .withType("request"); + final Span app = transaction.createSpan(10).withType("app"); + transaction.end(20); + reporter.decrementReferences(); + final Span db = app.createSpan(20).withType("db").withSubtype("mysql"); + app.end(30); + db.end(30); + + assertThat(transaction.getSelfDuration()).isEqualTo(10); + assertThat(app.getSelfDuration()).isEqualTo(10); + assertThat(db.getSelfDuration()).isEqualTo(10); + + reporter.decrementReferences(); + assertThat(transaction.isReferenced()).isFalse(); + assertThat(app.isReferenced()).isFalse(); + assertThat(db.isReferenced()).isFalse(); + + tracer.getMetricRegistry().report(metricSets -> { + assertThat(getTimer(metricSets, "span.self_time", "app", null).getCount()).isEqualTo(1); + assertThat(getTimer(metricSets, "span.self_time", "app", null).getTotalTimeUs()).isEqualTo(10); + assertThat(getTimer(metricSets, "transaction.duration", null, null).getTotalTimeUs()).isEqualTo(20); + assertThatTransactionBreakdownCounterCreated(metricSets); + assertThat(getTimer(metricSets, "span.self_time", "db", "mysql")).isNull(); + }); + } + + /* + * breakdowns are reported when the transaction ends + * any spans which outlive the transaction are not included in the breakdown + * v + * ██████████░░░░░░░░░░ + * └─────────████████████████████ + * 10 20 30 + */ + @Test + void testBreakdown_singleDbSpan_exceedingParent() { + final Transaction transaction = tracer.startTransaction(TraceContext.asRoot(), null, ConstantSampler.of(true), 0, getClass().getClassLoader()) + .withName("test") + .withType("request"); + final Span span = transaction.createSpan(10).withType("db").withSubtype("mysql"); + transaction.end(20); + span.end(30); + + // recycled transactions should not leak child timings + reporter.assertRecycledAfterDecrementingReferences(); + assertThat(reporter.getFirstTransaction().getTimerBySpanTypeAndSubtype().get("db")).isNull(); + + tracer.getMetricRegistry().report(metricSets -> { + assertThat(getTimer(metricSets, "span.self_time", "app", null).getCount()).isEqualTo(1); + assertThat(getTimer(metricSets, "span.self_time", "app", null).getTotalTimeUs()).isEqualTo(10); + assertThat(getTimer(metricSets, "transaction.duration", null, null).getTotalTimeUs()).isEqualTo(20); + assertThatTransactionBreakdownCounterCreated(metricSets); + assertThat(getTimer(metricSets, "span.self_time", "db", "mysql")).isNull(); + }); + } + + /* + * breakdowns are reported when the transaction ends + * any spans which outlive the transaction are not included in the breakdown + * v + * ██████████ + * └───────────────────██████████ + * 10 20 30 + */ + @Test + void testBreakdown_spanStartedAfterParentEnded() { + final Transaction transaction = tracer.startTransaction(TraceContext.asRoot(), null, ConstantSampler.of(true), 0, getClass().getClassLoader()) + .withName("test") + .withType("request"); + final Runnable runnable = transaction.withActive(() -> { + final TraceContextHolder active = tracer.getActive(); + assertThat(active).isSameAs(transaction); + assertThat(transaction.getTraceContext().getId().isEmpty()).isFalse(); + active.createSpan(20).withType("db").withSubtype("mysql").end(30); + }); + transaction.end(10); + runnable.run(); + + reporter.assertRecycledAfterDecrementingReferences(); + + tracer.getMetricRegistry().report(metricSets -> { + assertThat(getTimer(metricSets, "span.self_time", "app", null).getCount()).isEqualTo(1); + assertThat(getTimer(metricSets, "span.self_time", "app", null).getTotalTimeUs()).isEqualTo(10); + assertThat(getTimer(metricSets, "transaction.duration", null, null).getTotalTimeUs()).isEqualTo(10); + assertThatTransactionBreakdownCounterCreated(metricSets); + assertThat(getTimer(metricSets, "span.self_time", "db", "mysql")).isNull(); + }); + } + + private void assertThatTransactionBreakdownCounterCreated(Map metricSets) { + assertThat(metricSets.get(Labels.Mutable.of().transactionName("test").transactionType("request")).getCounters().get("transaction.breakdown.count").get()).isEqualTo(1); + } + + @Nullable + private Timer getTimer(Map metricSets, String timerName, @Nullable String spanType, @Nullable String spanSubType) { + final MetricSet metricSet = metricSets.get(Labels.Mutable.of().transactionName("test").transactionType("request").spanType(spanType).spanSubType(spanSubType)); + if (metricSet == null) { + return null; + } + return metricSet.timer(timerName); + } +} diff --git a/apm-agent-core/src/test/java/co/elastic/apm/agent/impl/payload/PayloadUtils.java b/apm-agent-core/src/test/java/co/elastic/apm/agent/impl/payload/PayloadUtils.java index e04aa3af82..c6d5f16b5b 100644 --- a/apm-agent-core/src/test/java/co/elastic/apm/agent/impl/payload/PayloadUtils.java +++ b/apm-agent-core/src/test/java/co/elastic/apm/agent/impl/payload/PayloadUtils.java @@ -24,6 +24,7 @@ */ package co.elastic.apm.agent.impl.payload; +import co.elastic.apm.agent.MockTracer; import co.elastic.apm.agent.TransactionUtils; import co.elastic.apm.agent.impl.ElasticApmTracer; import co.elastic.apm.agent.impl.error.ErrorPayload; @@ -45,7 +46,7 @@ public class PayloadUtils { } public static TransactionPayload createTransactionPayloadWithAllValues() { - final Transaction transaction = new Transaction(mock(ElasticApmTracer.class)); + final Transaction transaction = new Transaction(MockTracer.create()); TransactionUtils.fillTransaction(transaction); final TransactionPayload payload = createTransactionPayload(); payload.getTransactions().add(transaction); diff --git a/apm-agent-core/src/test/java/co/elastic/apm/agent/impl/payload/TransactionPayloadJsonSchemaTest.java b/apm-agent-core/src/test/java/co/elastic/apm/agent/impl/payload/TransactionPayloadJsonSchemaTest.java index e11555307b..7f9c4fd534 100644 --- a/apm-agent-core/src/test/java/co/elastic/apm/agent/impl/payload/TransactionPayloadJsonSchemaTest.java +++ b/apm-agent-core/src/test/java/co/elastic/apm/agent/impl/payload/TransactionPayloadJsonSchemaTest.java @@ -24,6 +24,7 @@ */ package co.elastic.apm.agent.impl.payload; +import co.elastic.apm.agent.MockTracer; import co.elastic.apm.agent.TransactionUtils; import co.elastic.apm.agent.impl.ElasticApmTracer; import co.elastic.apm.agent.impl.sampling.ConstantSampler; @@ -67,7 +68,7 @@ private TransactionPayload createPayloadWithRequiredValues() { final TransactionPayload payload = createPayload(); final Transaction transaction = createTransactionWithRequiredValues(); payload.getTransactions().add(transaction); - Span span = new Span(mock(ElasticApmTracer.class)); + Span span = new Span(MockTracer.create()); span.start(TraceContext.fromParent(), transaction, -1, false) .withType("type") .withSubtype("subtype") @@ -78,7 +79,7 @@ private TransactionPayload createPayloadWithRequiredValues() { } private Transaction createTransactionWithRequiredValues() { - Transaction t = new Transaction(mock(ElasticApmTracer.class)); + Transaction t = new Transaction(MockTracer.create()); t.start(TraceContext.asRoot(), null, (long) 0, ConstantSampler.of(true)); t.withType("type"); t.getContext().getRequest().withMethod("GET"); @@ -87,7 +88,7 @@ private Transaction createTransactionWithRequiredValues() { } private TransactionPayload createPayloadWithAllValues() { - final Transaction transaction = new Transaction(mock(ElasticApmTracer.class)); + final Transaction transaction = new Transaction(MockTracer.create()); TransactionUtils.fillTransaction(transaction); final TransactionPayload payload = createPayload(); payload.getTransactions().add(transaction); @@ -109,7 +110,7 @@ private TransactionPayload createPayload(SystemInfo system) { @Test void testJsonSchemaDslJsonEmptyValues() throws IOException { final TransactionPayload payload = createPayload(); - payload.getTransactions().add(new Transaction(mock(ElasticApmTracer.class))); + payload.getTransactions().add(new Transaction(MockTracer.create())); final String content = new DslJsonSerializer(mock(StacktraceConfiguration.class)).toJsonString(payload); System.out.println(content); objectMapper.readTree(content); diff --git a/apm-agent-core/src/test/java/co/elastic/apm/agent/impl/transaction/SpanTest.java b/apm-agent-core/src/test/java/co/elastic/apm/agent/impl/transaction/SpanTest.java index 4c43355a93..319614f35f 100644 --- a/apm-agent-core/src/test/java/co/elastic/apm/agent/impl/transaction/SpanTest.java +++ b/apm-agent-core/src/test/java/co/elastic/apm/agent/impl/transaction/SpanTest.java @@ -24,6 +24,7 @@ */ package co.elastic.apm.agent.impl.transaction; +import co.elastic.apm.agent.MockTracer; import co.elastic.apm.agent.impl.ElasticApmTracer; import org.junit.jupiter.api.Test; @@ -34,7 +35,7 @@ class SpanTest { @Test void resetState() { - Span span = new Span(mock(ElasticApmTracer.class)) + Span span = new Span(MockTracer.create()) .withName("SELECT FROM product_types") .withType("db") .withSubtype("postgresql") diff --git a/apm-agent-core/src/test/java/co/elastic/apm/agent/impl/transaction/TransactionTest.java b/apm-agent-core/src/test/java/co/elastic/apm/agent/impl/transaction/TransactionTest.java index fab85955a5..c13af0a542 100644 --- a/apm-agent-core/src/test/java/co/elastic/apm/agent/impl/transaction/TransactionTest.java +++ b/apm-agent-core/src/test/java/co/elastic/apm/agent/impl/transaction/TransactionTest.java @@ -24,6 +24,7 @@ */ package co.elastic.apm.agent.impl.transaction; +import co.elastic.apm.agent.MockTracer; import co.elastic.apm.agent.TransactionUtils; import co.elastic.apm.agent.impl.ElasticApmTracer; import co.elastic.apm.agent.impl.stacktrace.StacktraceConfiguration; @@ -45,9 +46,9 @@ void setUp() { @Test void resetState() { - final Transaction transaction = new Transaction(mock(ElasticApmTracer.class)); + final Transaction transaction = new Transaction(MockTracer.create()); TransactionUtils.fillTransaction(transaction); transaction.resetState(); - assertThat(jsonSerializer.toJsonString(transaction)).isEqualTo(jsonSerializer.toJsonString(new Transaction(mock(ElasticApmTracer.class)))); + assertThat(jsonSerializer.toJsonString(transaction)).isEqualTo(jsonSerializer.toJsonString(new Transaction(MockTracer.create()))); } } diff --git a/apm-agent-core/src/test/java/co/elastic/apm/agent/metrics/LabelsTest.java b/apm-agent-core/src/test/java/co/elastic/apm/agent/metrics/LabelsTest.java new file mode 100644 index 0000000000..9005402f5d --- /dev/null +++ b/apm-agent-core/src/test/java/co/elastic/apm/agent/metrics/LabelsTest.java @@ -0,0 +1,95 @@ +/*- + * #%L + * Elastic APM Java agent + * %% + * Copyright (C) 2018 - 2019 Elastic and contributors + * %% + * Licensed to Elasticsearch B.V. under one or more contributor + * license agreements. See the NOTICE file distributed with + * this work for additional information regarding copyright + * ownership. Elasticsearch B.V. licenses this file to you 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. + * #L% + */ +package co.elastic.apm.agent.metrics; + +import org.junit.jupiter.api.Test; + +import static org.assertj.core.api.Assertions.assertThat; +import static org.assertj.core.api.Assertions.assertThatThrownBy; + +class LabelsTest { + + @Test + void testCharSequenceHash() { + assertThat(Labels.Mutable.hash("foo")).isEqualTo(Labels.Mutable.hash(new StringBuilder("foo"))); + } + + @Test + void testEqualsHashCode() { + assertEqualsHashCode( + Labels.Mutable.of("foo", "bar"), + Labels.Mutable.of("foo", "bar")); + assertEqualsHashCode( + Labels.Mutable.of().transactionName("foo"), + Labels.Mutable.of().transactionName("foo")); + assertEqualsHashCode( + Labels.Mutable.of().transactionName("foo"), + Labels.Mutable.of().transactionName(new StringBuilder("foo"))); + assertEqualsHashCode( + Labels.Mutable.of("foo", "bar"), + Labels.Mutable.of("foo", new StringBuilder("bar"))); + assertEqualsHashCode( + Labels.Mutable.of("foo", new StringBuilder("bar")).add("baz", "qux"), + Labels.Mutable.of("foo", "bar").add("baz", new StringBuilder("qux"))); + assertEqualsHashCode( + Labels.Mutable.of("foo", "bar"), + Labels.Mutable.of("foo", new StringBuilder("bar")).immutableCopy()); + } + + @Test + void testNotEquals() { + assertNotEqual( + Labels.Mutable.of("foo", "bar"), + Labels.Mutable.of("bar", "foo")); + assertNotEqual( + Labels.Mutable.of("foo", "bar").add("baz", "qux"), + Labels.Mutable.of("baz", "qux").add("foo", "bar")); + assertNotEqual( + Labels.Mutable.of("foo", "bar").add("baz", "qux"), + Labels.Mutable.of("baz", "qux").add("foo", "bar")); + } + + @Test + void testRecycle() { + final Labels.Mutable resetLabels = Labels.Mutable.of("foo", "bar").transactionName(new StringBuilder("baz")); + final Labels immutableLabels = resetLabels.immutableCopy(); + resetLabels.resetState(); + assertEqualsHashCode( + immutableLabels, + Labels.Mutable.of("foo", "bar").transactionName("baz")); + assertNotEqual(resetLabels, immutableLabels); + assertEqualsHashCode(resetLabels, Labels.EMPTY); + } + + private void assertNotEqual(Labels l1, Labels l2) { + assertThat(l1.hashCode()).isNotEqualTo(l2.hashCode()); + assertThat(l1).isNotEqualTo(l2); + } + + private void assertEqualsHashCode(Labels l1, Labels l2) { + assertThat(l1).hasSameHashCodeAs(l2); + assertThat(l1).isEqualTo(l2); + } +} diff --git a/apm-agent-core/src/test/java/co/elastic/apm/agent/metrics/MetricRegistryTest.java b/apm-agent-core/src/test/java/co/elastic/apm/agent/metrics/MetricRegistryTest.java index 60afdb26ed..951af52b50 100644 --- a/apm-agent-core/src/test/java/co/elastic/apm/agent/metrics/MetricRegistryTest.java +++ b/apm-agent-core/src/test/java/co/elastic/apm/agent/metrics/MetricRegistryTest.java @@ -11,9 +11,9 @@ * 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 @@ -30,8 +30,8 @@ import org.junit.jupiter.api.Test; import java.util.List; +import java.util.stream.IntStream; -import static java.util.Collections.emptyMap; import static org.assertj.core.api.Assertions.assertThat; import static org.mockito.Mockito.mock; import static org.mockito.Mockito.when; @@ -53,9 +53,27 @@ void testDisabledMetrics() { final DoubleSupplier problematicMetric = () -> { throw new RuntimeException("Huston, we have a problem"); }; - metricRegistry.addUnlessNegative("jvm.gc.count", emptyMap(), problematicMetric); - metricRegistry.addUnlessNan("jvm.gc.count", emptyMap(), problematicMetric); - metricRegistry.add("jvm.gc.count", emptyMap(), problematicMetric); - assertThat(metricRegistry.getMetricSets()).isEmpty(); + metricRegistry.addUnlessNegative("jvm.gc.count", Labels.EMPTY, problematicMetric); + metricRegistry.addUnlessNan("jvm.gc.count", Labels.EMPTY, problematicMetric); + metricRegistry.add("jvm.gc.count", Labels.EMPTY, problematicMetric); + metricRegistry.report(metricSets -> assertThat(metricSets).isEmpty()); + } + + @Test + void testReportGaugeTwice() { + metricRegistry.add("foo", Labels.EMPTY, () -> 42); + metricRegistry.report(metricSets -> assertThat(metricSets.get(Labels.EMPTY).getGauge("foo").get()).isEqualTo(42)); + // the active and inactive metricSets are now switched, verify that the previous inactive metricSets also contain the same gauges + metricRegistry.report(metricSets -> assertThat(metricSets.get(Labels.EMPTY).getGauge("foo").get()).isEqualTo(42)); + } + + @Test + void testLimitTimers() { + IntStream.range(1, 505).forEach(i -> metricRegistry.updateTimer("timer" + i, Labels.Mutable.of("foo", Integer.toString(i)), 1)); + IntStream.range(1, 505).forEach(i -> metricRegistry.updateTimer("timer" + i, Labels.Mutable.of("bar", Integer.toString(i)), 1)); + + metricRegistry.report(metricSets -> assertThat(metricSets).hasSize(1000)); + // the active and inactive metricSets are now switched, also check the size of the previously inactive metricSets + metricRegistry.report(metricSets -> assertThat(metricSets).hasSize(1000)); } } diff --git a/apm-agent-core/src/test/java/co/elastic/apm/agent/metrics/builtin/JvmMemoryMetricsTest.java b/apm-agent-core/src/test/java/co/elastic/apm/agent/metrics/builtin/JvmMemoryMetricsTest.java index c9ae080829..af2c4f551e 100644 --- a/apm-agent-core/src/test/java/co/elastic/apm/agent/metrics/builtin/JvmMemoryMetricsTest.java +++ b/apm-agent-core/src/test/java/co/elastic/apm/agent/metrics/builtin/JvmMemoryMetricsTest.java @@ -24,12 +24,11 @@ */ package co.elastic.apm.agent.metrics.builtin; +import co.elastic.apm.agent.metrics.Labels; import co.elastic.apm.agent.metrics.MetricRegistry; import co.elastic.apm.agent.report.ReporterConfiguration; import org.junit.jupiter.api.Test; -import java.util.Collections; - import static org.assertj.core.api.Assertions.assertThat; import static org.mockito.Mockito.mock; @@ -42,12 +41,12 @@ void testMetrics() { final MetricRegistry registry = new MetricRegistry(mock(ReporterConfiguration.class)); jvmMemoryMetrics.bindTo(registry); System.out.println(registry.toString()); - assertThat(registry.get("jvm.memory.heap.used", Collections.emptyMap())).isNotZero(); - assertThat(registry.get("jvm.memory.heap.committed", Collections.emptyMap())).isNotZero(); - assertThat(registry.get("jvm.memory.heap.max", Collections.emptyMap())).isNotZero(); - assertThat(registry.get("jvm.memory.non_heap.used", Collections.emptyMap())).isNotZero(); - assertThat(registry.get("jvm.memory.non_heap.committed", Collections.emptyMap())).isNotZero(); - assertThat(registry.get("jvm.memory.non_heap.max", Collections.emptyMap())).isNotZero(); + assertThat(registry.getGauge("jvm.memory.heap.used", Labels.EMPTY)).isNotZero(); + assertThat(registry.getGauge("jvm.memory.heap.committed", Labels.EMPTY)).isNotZero(); + assertThat(registry.getGauge("jvm.memory.heap.max", Labels.EMPTY)).isNotZero(); + assertThat(registry.getGauge("jvm.memory.non_heap.used", Labels.EMPTY)).isNotZero(); + assertThat(registry.getGauge("jvm.memory.non_heap.committed", Labels.EMPTY)).isNotZero(); + assertThat(registry.getGauge("jvm.memory.non_heap.max", Labels.EMPTY)).isNotZero(); final long[] longs = new long[1000000]; System.out.println(registry.toString()); } diff --git a/apm-agent-core/src/test/java/co/elastic/apm/agent/metrics/builtin/SystemMetricsTest.java b/apm-agent-core/src/test/java/co/elastic/apm/agent/metrics/builtin/SystemMetricsTest.java index 94cded7c36..59d305a7cb 100644 --- a/apm-agent-core/src/test/java/co/elastic/apm/agent/metrics/builtin/SystemMetricsTest.java +++ b/apm-agent-core/src/test/java/co/elastic/apm/agent/metrics/builtin/SystemMetricsTest.java @@ -24,6 +24,7 @@ */ package co.elastic.apm.agent.metrics.builtin; +import co.elastic.apm.agent.metrics.Labels; import co.elastic.apm.agent.metrics.MetricRegistry; import co.elastic.apm.agent.report.ReporterConfiguration; import org.junit.jupiter.api.Test; @@ -31,7 +32,6 @@ import org.junit.jupiter.params.provider.CsvSource; import java.io.File; -import java.util.Collections; import static org.assertj.core.api.Assertions.assertThat; import static org.mockito.Mockito.mock; @@ -47,10 +47,11 @@ void testSystemMetrics() throws InterruptedException { // makes sure system.cpu.total.norm.pct does not return NaN consumeCpu(); Thread.sleep(1000); - assertThat(metricRegistry.get("system.process.cpu.total.norm.pct", Collections.emptyMap())).isBetween(0.0, 1.0); - assertThat(metricRegistry.get("system.memory.total", Collections.emptyMap())).isGreaterThan(0.0); - assertThat(metricRegistry.get("system.memory.actual.free", Collections.emptyMap())).isGreaterThan(0.0); - assertThat(metricRegistry.get("system.process.memory.size", Collections.emptyMap())).isGreaterThan(0.0); + assertThat(metricRegistry.getGauge("system.cpu.total.norm.pct", Labels.EMPTY)).isBetween(0.0, 1.0); + assertThat(metricRegistry.getGauge("system.process.cpu.total.norm.pct", Labels.EMPTY)).isBetween(0.0, 1.0); + assertThat(metricRegistry.getGauge("system.memory.total", Labels.EMPTY)).isGreaterThan(0.0); + assertThat(metricRegistry.getGauge("system.memory.actual.free", Labels.EMPTY)).isGreaterThan(0.0); + assertThat(metricRegistry.getGauge("system.process.memory.size", Labels.EMPTY)).isGreaterThan(0.0); } @ParameterizedTest @@ -61,7 +62,7 @@ void testSystemMetrics() throws InterruptedException { void testFreeMemoryMeminfo(String file, long value) throws Exception { SystemMetrics systemMetrics = new SystemMetrics(new File(getClass().getResource(file).toURI())); systemMetrics.bindTo(metricRegistry); - assertThat(metricRegistry.get("system.memory.actual.free", Collections.emptyMap())).isEqualTo(value); + assertThat(metricRegistry.getGauge("system.memory.actual.free", Labels.EMPTY)).isEqualTo(value); } private void consumeCpu() { diff --git a/apm-agent-core/src/test/java/co/elastic/apm/agent/metrics/builtin/ThreadMetricsTest.java b/apm-agent-core/src/test/java/co/elastic/apm/agent/metrics/builtin/ThreadMetricsTest.java index 5e49834103..7a6fe52f18 100644 --- a/apm-agent-core/src/test/java/co/elastic/apm/agent/metrics/builtin/ThreadMetricsTest.java +++ b/apm-agent-core/src/test/java/co/elastic/apm/agent/metrics/builtin/ThreadMetricsTest.java @@ -24,12 +24,11 @@ */ package co.elastic.apm.agent.metrics.builtin; +import co.elastic.apm.agent.metrics.Labels; import co.elastic.apm.agent.metrics.MetricRegistry; import co.elastic.apm.agent.report.ReporterConfiguration; import org.junit.jupiter.api.Test; -import java.util.Collections; - import static org.assertj.core.api.Assertions.assertThat; import static org.mockito.Mockito.mock; @@ -42,7 +41,7 @@ class ThreadMetricsTest { @Test void testThreadCount() { threadMetrics.bindTo(registry); - double numThreads = registry.get("jvm.thread.count", Collections.emptyMap()); + double numThreads = registry.getGauge("jvm.thread.count", Labels.EMPTY); assertThat(numThreads).isNotZero(); for (int i = 0; i < NUM_ADDED_THREADS; i++) { Thread thread = new Thread(() -> { @@ -56,6 +55,6 @@ void testThreadCount() { thread.setDaemon(true); thread.start(); } - assertThat(registry.get("jvm.thread.count", Collections.emptyMap())).isEqualTo(numThreads + NUM_ADDED_THREADS); + assertThat(registry.getGauge("jvm.thread.count", Labels.EMPTY)).isEqualTo(numThreads + NUM_ADDED_THREADS); } } diff --git a/apm-agent-core/src/test/java/co/elastic/apm/agent/report/ApmServerReporterTest.java b/apm-agent-core/src/test/java/co/elastic/apm/agent/report/ApmServerReporterTest.java index e41c321572..d9ceec5224 100644 --- a/apm-agent-core/src/test/java/co/elastic/apm/agent/report/ApmServerReporterTest.java +++ b/apm-agent-core/src/test/java/co/elastic/apm/agent/report/ApmServerReporterTest.java @@ -61,7 +61,7 @@ void setUp() { @Test void testTransactionProcessor() throws Exception { - reporter.report(new Transaction(mock(ElasticApmTracer.class))); + reporter.report(new Transaction(MockTracer.create())); reporter.flush().get(); assertThat(reporter.getDropped()).isEqualTo(0); diff --git a/apm-agent-core/src/test/java/co/elastic/apm/agent/report/IntakeV2ReportingEventHandlerTest.java b/apm-agent-core/src/test/java/co/elastic/apm/agent/report/IntakeV2ReportingEventHandlerTest.java index 3bb2bd6cea..50ca65c1d2 100644 --- a/apm-agent-core/src/test/java/co/elastic/apm/agent/report/IntakeV2ReportingEventHandlerTest.java +++ b/apm-agent-core/src/test/java/co/elastic/apm/agent/report/IntakeV2ReportingEventHandlerTest.java @@ -213,14 +213,14 @@ void testRandomJitter() { private void reportTransaction(IntakeV2ReportingEventHandler reportingEventHandler) { final ReportingEvent reportingEvent = new ReportingEvent(); - reportingEvent.setTransaction(new Transaction(mock(ElasticApmTracer.class))); + reportingEvent.setTransaction(new Transaction(MockTracer.create())); reportingEventHandler.onEvent(reportingEvent, -1, true); } private void reportSpan() { final ReportingEvent reportingEvent = new ReportingEvent(); - reportingEvent.setSpan(new Span(mock(ElasticApmTracer.class))); + reportingEvent.setSpan(new Span(MockTracer.create())); reportingEventHandler.onEvent(reportingEvent, -1, true); } diff --git a/apm-agent-core/src/test/java/co/elastic/apm/agent/report/ReporterFactoryTest.java b/apm-agent-core/src/test/java/co/elastic/apm/agent/report/ReporterFactoryTest.java index 0e694d910d..2eb50f4559 100644 --- a/apm-agent-core/src/test/java/co/elastic/apm/agent/report/ReporterFactoryTest.java +++ b/apm-agent-core/src/test/java/co/elastic/apm/agent/report/ReporterFactoryTest.java @@ -24,6 +24,7 @@ */ package co.elastic.apm.agent.report; +import co.elastic.apm.agent.MockTracer; import co.elastic.apm.agent.configuration.SpyConfiguration; import co.elastic.apm.agent.impl.ElasticApmTracer; import co.elastic.apm.agent.impl.MetaData; @@ -112,7 +113,7 @@ void testNotValidatingSslCertificate() throws Exception { when(reporterConfiguration.isVerifyServerCert()).thenReturn(false); final Reporter reporter = reporterFactory.createReporter(configuration, new ApmServerClient(reporterConfiguration), MetaData.create(configuration, null, null)); - reporter.report(new Transaction(mock(ElasticApmTracer.class))); + reporter.report(new Transaction(MockTracer.create())); reporter.flush().get(); assertThat(requestHandled).isTrue(); @@ -124,7 +125,7 @@ void testValidatingSslCertificate() throws Exception { when(reporterConfiguration.isVerifyServerCert()).thenReturn(true); final Reporter reporter = reporterFactory.createReporter(configuration, new ApmServerClient(reporterConfiguration), MetaData.create(configuration, null, null)); - reporter.report(new Transaction(mock(ElasticApmTracer.class))); + reporter.report(new Transaction(MockTracer.create())); reporter.flush().get(); assertThat(requestHandled).isFalse(); diff --git a/apm-agent-core/src/test/java/co/elastic/apm/agent/report/serialize/DslJsonSerializerTest.java b/apm-agent-core/src/test/java/co/elastic/apm/agent/report/serialize/DslJsonSerializerTest.java index ded5eadd33..5d440e4cfd 100644 --- a/apm-agent-core/src/test/java/co/elastic/apm/agent/report/serialize/DslJsonSerializerTest.java +++ b/apm-agent-core/src/test/java/co/elastic/apm/agent/report/serialize/DslJsonSerializerTest.java @@ -158,7 +158,7 @@ void testLimitStringValueLength() throws IOException { @Test void testNullHeaders() throws IOException { - Transaction transaction = new Transaction(mock(ElasticApmTracer.class)); + Transaction transaction = new Transaction(MockTracer.create()); transaction.getContext().getRequest().addHeader("foo", (String) null); transaction.getContext().getRequest().addHeader("baz", (Enumeration) null); transaction.getContext().getRequest().getHeaders().add("bar", null); @@ -173,7 +173,7 @@ void testNullHeaders() throws IOException { @Test void testSpanTypeSerialization() throws IOException { - Span span = new Span(mock(ElasticApmTracer.class)); + Span span = new Span(MockTracer.create()); span.getTraceContext().asRootSpan(ConstantSampler.of(true)); span.withType("template.jsf.render.view"); JsonNode spanJson = objectMapper.readTree(serializer.toJsonString(span)); @@ -183,19 +183,19 @@ void testSpanTypeSerialization() throws IOException { spanJson = objectMapper.readTree(serializer.toJsonString(span)); assertThat(spanJson.get("type").textValue()).isEqualTo("template.jsf_lifecycle.render_view"); - span = new Span(mock(ElasticApmTracer.class)); + span = new Span(MockTracer.create()); span.getTraceContext().asRootSpan(ConstantSampler.of(true)); span.withType("template").withAction("jsf.render"); spanJson = objectMapper.readTree(serializer.toJsonString(span)); assertThat(spanJson.get("type").textValue()).isEqualTo("template..jsf_render"); - span = new Span(mock(ElasticApmTracer.class)); + span = new Span(MockTracer.create()); span.getTraceContext().asRootSpan(ConstantSampler.of(true)); span.withType("template").withSubtype("jsf.render"); spanJson = objectMapper.readTree(serializer.toJsonString(span)); assertThat(spanJson.get("type").textValue()).isEqualTo("template.jsf_render"); - span = new Span(mock(ElasticApmTracer.class)); + span = new Span(MockTracer.create()); span.getTraceContext().asRootSpan(ConstantSampler.of(true)); span.withSubtype("jsf").withAction("render"); spanJson = objectMapper.readTree(serializer.toJsonString(span)); diff --git a/apm-agent-core/src/test/java/co/elastic/apm/agent/report/serialize/MetricSetSerializationTest.java b/apm-agent-core/src/test/java/co/elastic/apm/agent/report/serialize/MetricSetSerializationTest.java index 38c843d021..8b52d94897 100644 --- a/apm-agent-core/src/test/java/co/elastic/apm/agent/report/serialize/MetricSetSerializationTest.java +++ b/apm-agent-core/src/test/java/co/elastic/apm/agent/report/serialize/MetricSetSerializationTest.java @@ -11,9 +11,9 @@ * 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 @@ -24,48 +24,109 @@ */ package co.elastic.apm.agent.report.serialize; -import co.elastic.apm.agent.metrics.MetricSet; +import co.elastic.apm.agent.metrics.Labels; +import co.elastic.apm.agent.metrics.MetricRegistry; +import co.elastic.apm.agent.report.ReporterConfiguration; import com.dslplatform.json.DslJson; import com.dslplatform.json.JsonWriter; import com.fasterxml.jackson.databind.JsonNode; import com.fasterxml.jackson.databind.ObjectMapper; import org.junit.jupiter.api.Test; +import javax.annotation.Nonnull; import java.io.IOException; -import java.util.Collections; import static org.assertj.core.api.Assertions.assertThat; +import static org.mockito.Mockito.mock; class MetricSetSerializationTest { private JsonWriter jw = new DslJson<>().newWriter(); private ObjectMapper objectMapper = new ObjectMapper(); + private MetricRegistry registry = new MetricRegistry(mock(ReporterConfiguration.class)); @Test - void testSerialization() throws IOException { - final MetricSet metricSet = new MetricSet(Collections.singletonMap("foo.bar", "baz")); - metricSet.add("foo.bar", () -> 42); - metricSet.add("bar.baz", () -> 42); - MetricRegistrySerializer.serializeMetricSet(metricSet, System.currentTimeMillis() * 1000, new StringBuilder(), jw); - final String metricSetAsString = jw.toString(); - System.out.println(metricSetAsString); - final JsonNode jsonNode = objectMapper.readTree(metricSetAsString); + void testSerializeGauges() throws IOException { + final Labels.Mutable labels = Labels.Mutable.of("foo.bar", "baz"); + registry.add("foo.bar", labels, () -> 42); + registry.add("bar.baz", labels, () -> 42); + + final JsonNode jsonNode = reportAsJson(labels); + assertThat(jsonNode.get("metricset").get("samples").get("foo.bar").get("value").doubleValue()).isEqualTo(42); } + @Test + void testSerializeTimers() throws IOException { + final Labels.Mutable labels = Labels.Mutable.of("foo.bar", "baz"); + + registry.updateTimer("foo.bar", labels, 42); + registry.updateTimer("bar.baz", labels, 42, 2); + final JsonNode jsonNode = reportAsJson(labels); + final JsonNode samples = jsonNode.get("metricset").get("samples"); + assertThat(samples.get("foo.bar.sum.us").get("value").doubleValue()).isEqualTo(42); + assertThat(samples.get("foo.bar.count").get("value").doubleValue()).isEqualTo(1); + assertThat(samples.get("bar.baz.sum.us").get("value").doubleValue()).isEqualTo(42); + assertThat(samples.get("bar.baz.count").get("value").doubleValue()).isEqualTo(2); + } + + @Test + void testSerializeTimersWithTopLevelLabels() throws IOException { + final Labels.Mutable labels = Labels.Mutable.of("foo", "bar") + .transactionName("foo") + .transactionType("bar") + .spanType("baz") + .spanSubType("qux"); + registry.updateTimer("foo.bar", labels, 42); + + final JsonNode jsonNode = reportAsJson(labels); + + final JsonNode metricset = jsonNode.get("metricset"); + assertThat(metricset.get("tags").get("foo").textValue()).isEqualTo("bar"); + assertThat(metricset.get("tags").get("transaction_name")).isNull(); + assertThat(metricset.get("tags").get("transaction.name")).isNull(); + assertThat(metricset.get("transaction").get("name").textValue()).isEqualTo("foo"); + assertThat(metricset.get("transaction").get("type").textValue()).isEqualTo("bar"); + assertThat(metricset.get("span").get("type").textValue()).isEqualTo("baz"); + assertThat(metricset.get("span").get("subtype").textValue()).isEqualTo("qux"); + assertThat(metricset.get("samples").get("foo.bar.sum.us").get("value").doubleValue()).isEqualTo(42); + } + + @Test + void testSerializeTimersReset() throws IOException { + final Labels.Mutable labels = Labels.Mutable.of("foo.bar", "baz"); + registry.updateTimer("foo.bar", labels, 42); + registry.updateTimer("bar.baz", labels, 42, 2); + + reportAsJson(labels); + + registry.updateTimer("foo.bar", labels, 42); + final JsonNode samples = reportAsJson(labels).get("metricset").get("samples"); + + assertThat(samples.get("foo.bar.sum.us").get("value").doubleValue()).isEqualTo(42); + assertThat(samples.get("foo.bar.count").get("value").doubleValue()).isEqualTo(1); + } + + @Test + void testSerializeEmptyMetricSet() throws IOException { + final Labels.Mutable labels = Labels.Mutable.of("foo.bar", "baz"); + registry.updateTimer("foo.bar", labels, 42); + + assertThat(reportAsJson(labels).get("metricset").get("samples")).isNotEmpty(); + + assertThat(reportAsJson(labels).get("metricset").get("samples")).isEmpty(); + } + @Test void testNonFiniteSerialization() throws IOException { - final MetricSet metricSet = new MetricSet(Collections.emptyMap()); - metricSet.add("valid", () -> 4.0); - metricSet.add("infinite", () -> Double.POSITIVE_INFINITY); - metricSet.add("NaN", () -> Double.NaN); - metricSet.add("negative.infinite", () -> Double.NEGATIVE_INFINITY); - metricSet.add("also.valid", () -> 5.0); - MetricRegistrySerializer.serializeMetricSet(metricSet, System.currentTimeMillis() * 1000, new StringBuilder(), jw); - final String metricSetAsString = jw.toString(); - System.out.println(metricSetAsString); - final JsonNode jsonNode = objectMapper.readTree(metricSetAsString); - JsonNode samples = jsonNode.get("metricset").get("samples"); + registry.add("valid", Labels.EMPTY, () -> 4.0); + registry.add("infinite", Labels.EMPTY, () -> Double.POSITIVE_INFINITY); + registry.add("NaN", Labels.EMPTY, () -> Double.NaN); + registry.add("negative.infinite", Labels.EMPTY, () -> Double.NEGATIVE_INFINITY); + registry.add("also.valid", Labels.EMPTY, () -> 5.0); + + JsonNode samples = reportAsJson(Labels.EMPTY).get("metricset").get("samples"); + assertThat(samples.size()).isEqualTo(2); assertThat(samples.get("valid").get("value").doubleValue()).isEqualTo(4.0); assertThat(samples.get("also.valid").get("value").doubleValue()).isEqualTo(5.0); @@ -73,21 +134,54 @@ void testNonFiniteSerialization() throws IOException { @Test void testNonFiniteCornerCasesSerialization() throws IOException { - final MetricSet metricSet = new MetricSet(Collections.emptyMap()); - MetricRegistrySerializer.serializeMetricSet(metricSet, System.currentTimeMillis() * 1000, new StringBuilder(), jw); - String metricSetAsString = jw.toString(); - System.out.println(metricSetAsString); - JsonNode jsonNode = objectMapper.readTree(metricSetAsString); - JsonNode samples = jsonNode.get("metricset").get("samples"); - assertThat(samples.size()).isEqualTo(0); - - metricSet.add("infinite", () -> Double.POSITIVE_INFINITY); - metricSet.add("NaN", () -> Double.NaN); - metricSet.add("negative.infinite", () -> Double.NEGATIVE_INFINITY); - MetricRegistrySerializer.serializeMetricSet(metricSet, System.currentTimeMillis() * 1000, new StringBuilder(), jw); - metricSetAsString = jw.toString(); - jsonNode = objectMapper.readTree(metricSetAsString); - samples = jsonNode.get("metricset").get("samples"); - assertThat(samples.size()).isEqualTo(0); + registry.add("infinite", Labels.EMPTY, () -> Double.POSITIVE_INFINITY); + registry.add("NaN", Labels.EMPTY, () -> Double.NaN); + registry.add("negative.infinite", Labels.EMPTY, () -> Double.NEGATIVE_INFINITY); + + final JsonNode jsonNode = reportAsJson(Labels.EMPTY); + + assertThat(jsonNode.get("metricset").get("samples")).isEmpty(); + } + + @Test + void serializeEmptyMetricSet() throws IOException { + registry.updateTimer("foo", Labels.EMPTY, 0, 0); + + final JsonNode jsonNode = reportAsJson(Labels.EMPTY); + + assertThat(jsonNode.get("metricset").get("samples")).isEmpty(); + } + + @Test + void testCounterReset() throws IOException { + registry.incrementCounter("foo", Labels.EMPTY); + + JsonNode samples = reportAsJson(Labels.EMPTY).get("metricset").get("samples"); + assertThat(samples.size()).isEqualTo(1); + assertThat(samples.get("foo").get("value").intValue()).isOne(); + + assertThat(reportAsJson(Labels.EMPTY).get("metricset").get("samples")).hasSize(0); + } + + @Test + void testTimerReset() throws IOException { + registry.updateTimer("foo", Labels.EMPTY, 1); + + JsonNode samples = reportAsJson(Labels.EMPTY).get("metricset").get("samples"); + assertThat(samples.size()).isEqualTo(2); + assertThat(samples.get("foo.sum.us").get("value").intValue()).isOne(); + assertThat(samples.get("foo.count").get("value").intValue()).isOne(); + + assertThat(reportAsJson(Labels.EMPTY).get("metricset").get("samples")).hasSize(0); + } + + @Nonnull + private JsonNode reportAsJson(Labels labels) throws IOException { + registry.report(metricSets -> MetricRegistrySerializer.serializeMetricSet(metricSets.get(labels), System.currentTimeMillis() * 1000, new StringBuilder(), jw)); + final String jsonString = jw.toString(); + System.out.println(jsonString); + final JsonNode json = objectMapper.readTree(jsonString); + jw.reset(); + return json; } } diff --git a/apm-agent-plugins/apm-api-plugin/src/test/java/co/elastic/apm/api/ElasticApmApiInstrumentationTest.java b/apm-agent-plugins/apm-api-plugin/src/test/java/co/elastic/apm/api/ElasticApmApiInstrumentationTest.java index d1fbc824f6..6da3c822c0 100644 --- a/apm-agent-plugins/apm-api-plugin/src/test/java/co/elastic/apm/api/ElasticApmApiInstrumentationTest.java +++ b/apm-agent-plugins/apm-api-plugin/src/test/java/co/elastic/apm/api/ElasticApmApiInstrumentationTest.java @@ -301,8 +301,8 @@ void testManualTimestamps() { transaction.startSpan().setStartTimestamp(1000).end(2000); transaction.end(3000); - assertThat(reporter.getFirstTransaction().getDuration()).isEqualTo(3); - assertThat(reporter.getFirstSpan().getDuration()).isEqualTo(1); + assertThat(reporter.getFirstTransaction().getDuration()).isEqualTo(3000); + assertThat(reporter.getFirstSpan().getDuration()).isEqualTo(1000); } @Test diff --git a/apm-agent-plugins/apm-java-concurrent-plugin/src/main/java/co/elastic/apm/agent/concurrent/ExecutorInstrumentation.java b/apm-agent-plugins/apm-java-concurrent-plugin/src/main/java/co/elastic/apm/agent/concurrent/ExecutorInstrumentation.java index bf738bfd20..c92f834147 100644 --- a/apm-agent-plugins/apm-java-concurrent-plugin/src/main/java/co/elastic/apm/agent/concurrent/ExecutorInstrumentation.java +++ b/apm-agent-plugins/apm-java-concurrent-plugin/src/main/java/co/elastic/apm/agent/concurrent/ExecutorInstrumentation.java @@ -11,9 +11,9 @@ * 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 diff --git a/apm-agent-plugins/apm-web-plugin/src/test/java/co/elastic/apm/agent/web/SanitizingWebProcessorTest.java b/apm-agent-plugins/apm-web-plugin/src/test/java/co/elastic/apm/agent/web/SanitizingWebProcessorTest.java index 47e2babbe5..20a4ea57ed 100644 --- a/apm-agent-plugins/apm-web-plugin/src/test/java/co/elastic/apm/agent/web/SanitizingWebProcessorTest.java +++ b/apm-agent-plugins/apm-web-plugin/src/test/java/co/elastic/apm/agent/web/SanitizingWebProcessorTest.java @@ -24,6 +24,7 @@ */ package co.elastic.apm.agent.web; +import co.elastic.apm.agent.MockTracer; import co.elastic.apm.agent.configuration.SpyConfiguration; import co.elastic.apm.agent.impl.ElasticApmTracer; import co.elastic.apm.agent.impl.context.TransactionContext; @@ -46,7 +47,7 @@ void setUp() { @Test void processTransactions() { - Transaction transaction = new Transaction(mock(ElasticApmTracer.class)); + Transaction transaction = new Transaction(MockTracer.create()); fillContext(transaction.getContext()); processor.processBeforeReport(transaction); diff --git a/apm-opentracing/src/test/java/co/elastic/apm/opentracing/OpenTracingBridgeTest.java b/apm-opentracing/src/test/java/co/elastic/apm/opentracing/OpenTracingBridgeTest.java index 28fc82b439..32ae30f8ef 100644 --- a/apm-opentracing/src/test/java/co/elastic/apm/opentracing/OpenTracingBridgeTest.java +++ b/apm-opentracing/src/test/java/co/elastic/apm/opentracing/OpenTracingBridgeTest.java @@ -68,7 +68,7 @@ void testCreateNonActiveTransaction() { span.finish(TimeUnit.MILLISECONDS.toMicros(1)); assertThat(reporter.getTransactions()).hasSize(1); - assertThat(reporter.getFirstTransaction().getDuration()).isEqualTo(1); + assertThat(reporter.getFirstTransaction().getDuration()).isEqualTo(1000); assertThat(reporter.getFirstTransaction().getName().toString()).isEqualTo("test"); } @@ -80,11 +80,11 @@ void sanityCheckRealTimestamps() { final long epochMicros = System.currentTimeMillis() * 1000; assertThat(reporter.getTransactions()).hasSize(1); - assertThat(reporter.getFirstTransaction().getDuration()).isLessThan(MINUTES.toMillis(1)); + assertThat(reporter.getFirstTransaction().getDuration()).isLessThan(MINUTES.toMicros(1)); assertThat(reporter.getFirstTransaction().getTimestamp()).isCloseTo(epochMicros, offset(MINUTES.toMicros(1))); assertThat(reporter.getSpans()).hasSize(1); - assertThat(reporter.getFirstSpan().getDuration()).isLessThan(MINUTES.toMillis(1)); + assertThat(reporter.getFirstSpan().getDuration()).isLessThan(MINUTES.toMicros(1)); assertThat(reporter.getFirstSpan().getTimestamp()).isCloseTo(epochMicros, offset(MINUTES.toMicros(1))); } @@ -189,7 +189,7 @@ void testCreateActiveTransaction() { assertThat(reporter.getTransactions()).hasSize(0); // manually finish span - scope.span().finish(TimeUnit.MILLISECONDS.toMicros(1)); + scope.span().finish(1); assertThat(reporter.getTransactions()).hasSize(1); assertThat(reporter.getFirstTransaction().getDuration()).isEqualTo(1); assertThat(reporter.getFirstTransaction().getName().toString()).isEqualTo("test"); diff --git a/docs/configuration.asciidoc b/docs/configuration.asciidoc index 1754042c6a..ef5a31ffe1 100644 --- a/docs/configuration.asciidoc +++ b/docs/configuration.asciidoc @@ -1071,6 +1071,8 @@ Disables the collection of certain metrics. If the name of a metric matches any of the wildcard expressions, it will not be collected. Example: `foo.*,bar.*` +To disable all breakdown metric collection code paths, add `span.self_time` to the list. + This option supports the wildcard `*`, which matches zero or more characters. Examples: `/foo/*/bar/*/baz*`, `*foo*`. Matching is case insensitive by default. @@ -1727,6 +1729,8 @@ The default unit for this option is `ms` # If the name of a metric matches any of the wildcard expressions, it will not be collected. # Example: `foo.*,bar.*` # +# To disable all breakdown metric collection code paths, add `span.self_time` to the list. +# # This option supports the wildcard `*`, which matches zero or more characters. # Examples: `/foo/*/bar/*/baz*`, `*foo*`. # Matching is case insensitive by default. diff --git a/docs/metrics.asciidoc b/docs/metrics.asciidoc index a3122c8c19..666d50a687 100644 --- a/docs/metrics.asciidoc +++ b/docs/metrics.asciidoc @@ -205,3 +205,65 @@ An approximation of the total amount of memory, in bytes, allocated in heap memory. -- +[float] +[[metrics-application]] +=== Application Metrics + +*`transaction.duration`*:: ++ +-- +type: simple timer + +This timer tracks the duration of transactions and allows for the creation of graphs displaying a weighted average. + +Fields: + +* `sum`: The sum of all transaction durations in ms since the last report (the delta) +* `count`: The count of all transactions since the last report (the delta) + +You can filter and group by these dimensions: + +* `transaction.name`: The name of the transaction +* `transaction.type`: The type of the transaction, for example `request` + +-- + + +*`transaction.breakdown.count`*:: ++ +-- +type: long + +format: count (delta) + +The number of transactions for which breakdown metrics (`span.self_time`) have been created. +As the Java agent tracks the breakdown for both sampled and non-sampled transactions, +this metric is equivalent to `transaction.duration.count` + +You can filter and group by these dimensions: + +* `transaction.name`: The name of the transaction +* `transaction.type`: The type of the transaction, for example `request` + +-- + +*`span.self_time`*:: ++ +-- +type: simple timer + +This timer tracks the span self-times and is the basis of the transaction breakdown visualization. + +Fields: + +* `sum`: The sum of all span self-times in ms since the last report (the delta) +* `count`: The count of all span self-times since the last report (the delta) + +You can filter and group by these dimensions: + +* `transaction.name`: The name of the transaction +* `transaction.type`: The type of the transaction, for example `request` +* `span.type`: The type of the span, for example `app`, `template` or `db` +* `span.subtype`: The sub-type of the span, for example `mysql` (optional) + +-- diff --git a/elastic-apm-agent/pom.xml b/elastic-apm-agent/pom.xml index da4ebc01dd..5f757fdbef 100644 --- a/elastic-apm-agent/pom.xml +++ b/elastic-apm-agent/pom.xml @@ -55,6 +55,17 @@ **/NOTICE + + org.hdrhistogram:HdrHistogram + + + org/HdrHistogram/WriterReaderPhaser.class + + @@ -98,6 +109,10 @@ com.blogspot.mydailyjava.weaklockfree co.elastic.apm.agent.shaded.weaklockfree + + org.HdrHistogram + co.elastic.apm.agent.shaded.HdrHistogram +