From 1ffe7714b1a8860941f90a15e960808b8e066160 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Do=C4=9Fa=C3=A7=20Eldenk?= Date: Wed, 21 Jun 2023 15:05:19 +0300 Subject: [PATCH 1/6] add slow request sampler --- .../armeria/common/util/AndSampler.java | 63 +++++++++++ .../armeria/common/util/OrSampler.java | 65 +++++++++++ .../linecorp/armeria/common/util/Sampler.java | 33 ++++++ .../util/SlidingWindowPercentileSampler.java | 70 ++++++++++++ .../decorator/LoggingDecorator.java | 8 ++ .../LoggingDecoratorFactoryFunction.java | 30 +++-- .../server/logging/LoggingService.java | 8 +- .../server/logging/LoggingServiceBuilder.java | 24 +++- .../armeria/common/util/SamplerTest.java | 67 ++++++++++++ .../SlidingWindowPercentileSamplerTest.java | 103 ++++++++++++++++++ 10 files changed, 459 insertions(+), 12 deletions(-) create mode 100644 core/src/main/java/com/linecorp/armeria/common/util/AndSampler.java create mode 100644 core/src/main/java/com/linecorp/armeria/common/util/OrSampler.java create mode 100644 core/src/main/java/com/linecorp/armeria/common/util/SlidingWindowPercentileSampler.java create mode 100644 core/src/test/java/com/linecorp/armeria/common/util/SlidingWindowPercentileSamplerTest.java diff --git a/core/src/main/java/com/linecorp/armeria/common/util/AndSampler.java b/core/src/main/java/com/linecorp/armeria/common/util/AndSampler.java new file mode 100644 index 00000000000..9f5b08b5fa8 --- /dev/null +++ b/core/src/main/java/com/linecorp/armeria/common/util/AndSampler.java @@ -0,0 +1,63 @@ +/* + * Copyright 2017 LINE Corporation + * + * LINE Corporation 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: + * + * https://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. + * + * Copyright 2013 + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * https://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ +package com.linecorp.armeria.common.util; + +/** + * This sampler is appropriate for low-traffic instrumentation (ex servers that each receive <100K + * requests), or those who do not provision random trace ids. It is not appropriate for collectors + * as the sampling decision isn't idempotent (consistent based on trace id). + * + *

Implementation

+ * + *

This initializes a random bitset of size 100 (corresponding to 1% granularity). This means + * that it is accurate in units of 100 traces. At runtime, this loops through the bitset, returning + * the value according to a counter. + * + *

Forked from brave-core 5.6.3 at d4cbd86e1df75687339da6ec2964d42ab3a8cf14 + */ +final class AndSampler implements Sampler { + + private final Sampler left, right; + + AndSampler(Sampler left, Sampler right) { + this.left = left; + this.right = right; + } + + @Override + public boolean isSampled(T t) { + return left.isSampled(t) && right.isSampled(t); + } + + @Override + public String toString() { + return left.toString() + " and " + right.toString(); + } +} diff --git a/core/src/main/java/com/linecorp/armeria/common/util/OrSampler.java b/core/src/main/java/com/linecorp/armeria/common/util/OrSampler.java new file mode 100644 index 00000000000..a16b79b3c11 --- /dev/null +++ b/core/src/main/java/com/linecorp/armeria/common/util/OrSampler.java @@ -0,0 +1,65 @@ +/* + * Copyright 2017 LINE Corporation + * + * LINE Corporation 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: + * + * https://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. + * + * Copyright 2013 + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * https://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ +package com.linecorp.armeria.common.util; + +import java.util.Random; + +/** + * This sampler is appropriate for low-traffic instrumentation (ex servers that each receive <100K + * requests), or those who do not provision random trace ids. It is not appropriate for collectors + * as the sampling decision isn't idempotent (consistent based on trace id). + * + *

Implementation

+ * + *

This initializes a random bitset of size 100 (corresponding to 1% granularity). This means + * that it is accurate in units of 100 traces. At runtime, this loops through the bitset, returning + * the value according to a counter. + * + *

Forked from brave-core 5.6.3 at d4cbd86e1df75687339da6ec2964d42ab3a8cf14 + */ +final class OrSampler implements Sampler { + + private final Sampler left, right; + + OrSampler(Sampler left, Sampler right) { + this.left = left; + this.right = right; + } + + @Override + public boolean isSampled(T t) { + return left.isSampled(t) || right.isSampled(t); + } + + @Override + public String toString() { + return left.toString() + " or " + right.toString(); + } +} diff --git a/core/src/main/java/com/linecorp/armeria/common/util/Sampler.java b/core/src/main/java/com/linecorp/armeria/common/util/Sampler.java index 2969df2a61c..63a0087b04c 100644 --- a/core/src/main/java/com/linecorp/armeria/common/util/Sampler.java +++ b/core/src/main/java/com/linecorp/armeria/common/util/Sampler.java @@ -42,6 +42,39 @@ */ @FunctionalInterface public interface Sampler { + + default Sampler or(Sampler other) { + return new OrSampler<>(this, other); + } + + default Sampler and(Sampler other) { + return new AndSampler<>(this, other); + } + + static > Sampler greaterThan(T val) { + return object -> object.compareTo(val) > 0; + } + + static > Sampler greaterThanOrEqual(T val) { + return object -> object.compareTo(val) >= 0; + } + + static > Sampler lessThan(T val) { + return object -> object.compareTo(val) < 0; + } + + static > Sampler lessThanOrEqual(T val) { + return object -> object.compareTo(val) <= 0; + } + + static > Sampler equal(T val) { + return object -> object.compareTo(val) == 0; + } + + static Sampler percentile(float percentile, long windowMilliseconds) { + return new SlidingWindowPercentileSampler(percentile, windowMilliseconds); + } + /** * Returns a probabilistic sampler which samples at the specified {@code probability} * between {@code 0.0} and {@code 1.0}. diff --git a/core/src/main/java/com/linecorp/armeria/common/util/SlidingWindowPercentileSampler.java b/core/src/main/java/com/linecorp/armeria/common/util/SlidingWindowPercentileSampler.java new file mode 100644 index 00000000000..eec324455b8 --- /dev/null +++ b/core/src/main/java/com/linecorp/armeria/common/util/SlidingWindowPercentileSampler.java @@ -0,0 +1,70 @@ +/* + * Copyright 2017 LINE Corporation + * + * LINE Corporation 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: + * + * https://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. + * + * Copyright 2013 + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * https://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ +package com.linecorp.armeria.common.util; + +import java.util.concurrent.TimeUnit; + +import com.codahale.metrics.Histogram; +import com.codahale.metrics.SlidingTimeWindowReservoir; + +final class SlidingWindowPercentileSampler implements Sampler { + + private final float percentile; + private final long windowLengthMillis; + + private final Histogram histogram; + + SlidingWindowPercentileSampler(float percentile, long windowLengthMillis) { + this.percentile = percentile; + this.windowLengthMillis = windowLengthMillis; + + // TODO: Check memory footprint, try limiting resources. + SlidingTimeWindowReservoir reservoir = new SlidingTimeWindowReservoir(windowLengthMillis, + TimeUnit.MILLISECONDS); + this.histogram = new Histogram(reservoir); + } + + static SlidingWindowPercentileSampler create(float percentile, long windowLengthMillis) { + return new SlidingWindowPercentileSampler(percentile, windowLengthMillis); + } + + @Override + public boolean isSampled(Long t) { + histogram.update(t); + // TODO: get snapshot calls might be expensive, consider caching snapshot + return histogram.getSnapshot().getValue(this.percentile) <= t; + } + + @Override + public String toString() { + return "SlidingWindowPercentileSampler with " + windowLengthMillis + " ms window and " + percentile + + " percentile"; + } +} diff --git a/core/src/main/java/com/linecorp/armeria/server/annotation/decorator/LoggingDecorator.java b/core/src/main/java/com/linecorp/armeria/server/annotation/decorator/LoggingDecorator.java index 3f56a31ff6d..6564b6fbce6 100644 --- a/core/src/main/java/com/linecorp/armeria/server/annotation/decorator/LoggingDecorator.java +++ b/core/src/main/java/com/linecorp/armeria/server/annotation/decorator/LoggingDecorator.java @@ -83,6 +83,14 @@ */ float failureSamplingRate() default -1.0f; + float slowRequestSamplingPercentile() default -1.0f; + + long slowRequestSamplingWindowMilliseconds() default 60 * 1000; + + long slowRequestSamplingLowerBoundMilliseconds() default 0L; + + long slowRequestSamplingUpperBoundMilliseconds() default Long.MAX_VALUE; + /** * The order of decoration, where a {@link Decorator} of lower value will be applied first. */ diff --git a/core/src/main/java/com/linecorp/armeria/server/annotation/decorator/LoggingDecoratorFactoryFunction.java b/core/src/main/java/com/linecorp/armeria/server/annotation/decorator/LoggingDecoratorFactoryFunction.java index 5d1e19fe7d1..8399b33d6a4 100644 --- a/core/src/main/java/com/linecorp/armeria/server/annotation/decorator/LoggingDecoratorFactoryFunction.java +++ b/core/src/main/java/com/linecorp/armeria/server/annotation/decorator/LoggingDecoratorFactoryFunction.java @@ -21,6 +21,7 @@ import com.linecorp.armeria.server.HttpService; import com.linecorp.armeria.server.annotation.DecoratorFactoryFunction; import com.linecorp.armeria.server.logging.LoggingService; +import com.linecorp.armeria.server.logging.LoggingServiceBuilder; /** * A factory which creates a {@link LoggingService} decorator. @@ -38,15 +39,24 @@ public final class LoggingDecoratorFactoryFunction implements DecoratorFactoryFu final float failureSamplingRate = parameter.failureSamplingRate() >= 0.0f ? parameter.failureSamplingRate() : parameter.samplingRate(); - return LoggingService.builder() - .logWriter(LogWriter.builder() - .requestLogLevel(parameter.requestLogLevel()) - .successfulResponseLogLevel( - parameter.successfulResponseLogLevel()) - .failureResponseLogLevel(parameter.failureResponseLogLevel()) - .build()) - .successSamplingRate(successSamplingRate) - .failureSamplingRate(failureSamplingRate) - .newDecorator(); + LoggingServiceBuilder builder = LoggingService.builder() + .logWriter(LogWriter.builder() + .requestLogLevel( + parameter.requestLogLevel()) + .successfulResponseLogLevel( + parameter.successfulResponseLogLevel()) + .failureResponseLogLevel( + parameter.failureResponseLogLevel()) + .build()) + .successSamplingRate(successSamplingRate) + .failureSamplingRate(failureSamplingRate); + + if (parameter.slowRequestSamplingPercentile() >= 0.0f) { + builder.slowRequestSamplingPercentile(parameter.slowRequestSamplingPercentile(), + parameter.slowRequestSamplingWindowMilliseconds(), + parameter.slowRequestSamplingLowerBoundMilliseconds(), + parameter.slowRequestSamplingUpperBoundMilliseconds()); + } + return builder.newDecorator(); } } diff --git a/core/src/main/java/com/linecorp/armeria/server/logging/LoggingService.java b/core/src/main/java/com/linecorp/armeria/server/logging/LoggingService.java index 73f4e615776..751c6941ea0 100644 --- a/core/src/main/java/com/linecorp/armeria/server/logging/LoggingService.java +++ b/core/src/main/java/com/linecorp/armeria/server/logging/LoggingService.java @@ -56,17 +56,23 @@ public static LoggingServiceBuilder builder() { LoggingService(HttpService delegate, LogWriter logWriter, Sampler successSampler, - Sampler failureSampler) { + Sampler failureSampler, + Sampler slowRequestSampler) { super(requireNonNull(delegate, "delegate")); this.logWriter = requireNonNull(logWriter, "logWriter"); requireNonNull(successSampler, "successSampler"); requireNonNull(failureSampler, "failureSampler"); sampler = requestLog -> { final ServiceRequestContext ctx = (ServiceRequestContext) requestLog.context(); + if (slowRequestSampler.isSampled(requestLog.totalDurationNanos())) { + return true; + } + if (ctx.config().successFunction().isSuccess(ctx, requestLog)) { return successSampler.isSampled(ctx); } return failureSampler.isSampled(ctx); + }; } diff --git a/core/src/main/java/com/linecorp/armeria/server/logging/LoggingServiceBuilder.java b/core/src/main/java/com/linecorp/armeria/server/logging/LoggingServiceBuilder.java index ab293209767..9a94dc4010b 100644 --- a/core/src/main/java/com/linecorp/armeria/server/logging/LoggingServiceBuilder.java +++ b/core/src/main/java/com/linecorp/armeria/server/logging/LoggingServiceBuilder.java @@ -50,6 +50,8 @@ public final class LoggingServiceBuilder extends LoggingDecoratorBuilder { private Sampler failureSampler = Sampler.always(); + private Sampler slowRequestSampler = Sampler.never(); + LoggingServiceBuilder() {} /** @@ -107,6 +109,11 @@ public LoggingServiceBuilder failureSampler( return this; } + public LoggingServiceBuilder slowRequestSampler(Sampler slowRequestSampler) { + this.slowRequestSampler = requireNonNull(slowRequestSampler, "slowRequestSampler"); + return this; + } + /** * Sets the rate at which to sample requests to log. Any number between {@code 0.0} and {@code 1.0} will * cause a random sample of the failure requests to be logged. @@ -118,12 +125,27 @@ public LoggingServiceBuilder failureSamplingRate(float failureSamplingRate) { return failureSampler(Sampler.random(failureSamplingRate)); } + public LoggingServiceBuilder slowRequestSamplingPercentile(float slowRequestPercentile, + long windowMilliseconds, + long slowRequestSamplingLowerBoundMilliseconds, + long slowRequestSamplingUpperBoundMilliseconds) { + checkArgument(0.0 <= slowRequestPercentile && slowRequestPercentile <= 1.0, + "slowRequestPercentile: %s (expected: 0.0 <= slowRequestPercentile <= 1.0)", + slowRequestPercentile); + return slowRequestSampler( + Sampler.greaterThanOrEqual(slowRequestSamplingLowerBoundMilliseconds * 1000) + .or(Sampler.percentile(slowRequestPercentile, windowMilliseconds) + .and(Sampler.greaterThan( + slowRequestSamplingUpperBoundMilliseconds * 1000))) + ); + } + /** * Returns a newly-created {@link LoggingService} decorating {@link HttpService} based on the properties * of this builder. */ public LoggingService build(HttpService delegate) { - return new LoggingService(delegate, logWriter(), successSampler, failureSampler); + return new LoggingService(delegate, logWriter(), successSampler, failureSampler, slowRequestSampler); } /** diff --git a/core/src/test/java/com/linecorp/armeria/common/util/SamplerTest.java b/core/src/test/java/com/linecorp/armeria/common/util/SamplerTest.java index 3e3c5302508..45e5b74060b 100644 --- a/core/src/test/java/com/linecorp/armeria/common/util/SamplerTest.java +++ b/core/src/test/java/com/linecorp/armeria/common/util/SamplerTest.java @@ -88,4 +88,71 @@ void badOf() { assertThatThrownBy(() -> Sampler.of("rate-limiting=")).isInstanceOf(IllegalArgumentException.class); assertThatThrownBy(() -> Sampler.of("rate-limiting=x")).isInstanceOf(IllegalArgumentException.class); } + + @Test + void andOr() { + Sampler alwaysAndAlwaysSampler = Sampler.always().and(Sampler.always()); + for (int i = 0; i < 10; i++) { + assertThat(alwaysAndAlwaysSampler.isSampled(i)).isTrue(); + } + + Sampler alwaysOrAlwaysSampler = Sampler.always().or(Sampler.always()); + for (int i = 0; i < 10; i++) { + assertThat(alwaysOrAlwaysSampler.isSampled(i)).isTrue(); + } + + Sampler neverOrAlwaysSampler = Sampler.never().or(Sampler.always()); + for (int i = 0; i < 10; i++) { + assertThat(neverOrAlwaysSampler.isSampled(i)).isTrue(); + } + + Sampler neverAndAlwaysSampler = Sampler.never().and(Sampler.always()); + for (int i = 0; i < 10; i++) { + assertThat(neverAndAlwaysSampler.isSampled(i)).isFalse(); + } + + Sampler halfAndHalfSampler = Sampler.random(0.5f).and(Sampler.random(0.5f)); + int halfAndHalfSamplerCount = 0; + for (int i = 0; i < 10000; i++) { + if (halfAndHalfSampler.isSampled(i)) {halfAndHalfSamplerCount += 1;} + } + // 0.5*0.5 = 0.25 + assertThat(halfAndHalfSamplerCount).isBetween(2000, 3000); // Should be roughly 2500 // + + Sampler halfOrHalfSampler = Sampler.random(0.5f).or(Sampler.random(0.5f)); + int halfOrHalfSamplerCount = 0; + for (int i = 0; i < 10000; i++) { + if (halfOrHalfSampler.isSampled(i)) {halfOrHalfSamplerCount += 1;} + } + // 1 - (0.5*0.5) = 0.75 + assertThat(halfOrHalfSamplerCount).isBetween(7000, 8000); // Should be roughly 7500 + } + + @Test + void compare() { + Sampler greaterThanOne = Sampler.greaterThan(1); + assertThat(greaterThanOne.isSampled(0)).isFalse(); + assertThat(greaterThanOne.isSampled(1)).isFalse(); + assertThat(greaterThanOne.isSampled(2)).isTrue(); + + Sampler greaterThanOrEqualOne = Sampler.greaterThanOrEqual(1); + assertThat(greaterThanOrEqualOne.isSampled(0)).isFalse(); + assertThat(greaterThanOrEqualOne.isSampled(1)).isTrue(); + assertThat(greaterThanOrEqualOne.isSampled(2)).isTrue(); + + Sampler lessThanOne = Sampler.lessThan(1); + assertThat(lessThanOne.isSampled(0)).isTrue(); + assertThat(lessThanOne.isSampled(1)).isFalse(); + assertThat(lessThanOne.isSampled(2)).isFalse(); + + Sampler lessThanOrEqualOne = Sampler.lessThanOrEqual(1); + assertThat(lessThanOrEqualOne.isSampled(0)).isTrue(); + assertThat(lessThanOrEqualOne.isSampled(1)).isTrue(); + assertThat(lessThanOrEqualOne.isSampled(2)).isFalse(); + + Sampler equalOne = Sampler.equal(1); + assertThat(equalOne.isSampled(0)).isFalse(); + assertThat(equalOne.isSampled(1)).isTrue(); + assertThat(equalOne.isSampled(2)).isFalse(); + } } diff --git a/core/src/test/java/com/linecorp/armeria/common/util/SlidingWindowPercentileSamplerTest.java b/core/src/test/java/com/linecorp/armeria/common/util/SlidingWindowPercentileSamplerTest.java new file mode 100644 index 00000000000..5c3f63f57d8 --- /dev/null +++ b/core/src/test/java/com/linecorp/armeria/common/util/SlidingWindowPercentileSamplerTest.java @@ -0,0 +1,103 @@ +/* + * Copyright 2019 LINE Corporation + * + * LINE Corporation 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: + * + * https://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. + */ +/* + * Copyright 2013-2019 The OpenZipkin Authors + * + * Licensed under the Apache License, Version 2.0 (the "License"); you may not use this file except + * in compliance with the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software distributed under the License + * is distributed on an "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express + * or implied. See the License for the specific language governing permissions and limitations under + * the License. + */ + +package com.linecorp.armeria.common.util; + +import static org.assertj.core.api.Assertions.assertThat; + +import org.junit.jupiter.api.Test; + +public class SlidingWindowPercentileSamplerTest { + @Test + public void testSamplingMinimumPercentile() { + final Sampler sampler = SlidingWindowPercentileSampler.create(0.0f, 10000L); + + // Should sample everything + assertThat(sampler.isSampled(10L)).isTrue(); + assertThat(sampler.isSampled(20L)).isTrue(); + assertThat(sampler.isSampled(0L)).isTrue(); + } + + @Test + public void testSamplingMaximumPercentile() { + final Sampler sampler = SlidingWindowPercentileSampler.create(1.0f, 10000L); + + // Should only sample the maximum value + assertThat(sampler.isSampled(10L)).isTrue(); + assertThat(sampler.isSampled(20L)).isTrue(); + assertThat(sampler.isSampled(0L)).isFalse(); + assertThat(sampler.isSampled(19L)).isFalse(); + assertThat(sampler.isSampled(20L)).isTrue(); + assertThat(sampler.isSampled(21L)).isTrue(); + assertThat(sampler.isSampled(20L)).isFalse(); + } + + @Test + public void testSamplingWindowExpires() throws InterruptedException { + final long windowLength = 1000L; + final Sampler sampler = SlidingWindowPercentileSampler.create(1.0f, windowLength); + + // Should only sample the maximum value + assertThat(sampler.isSampled(20L)).isTrue(); + assertThat(sampler.isSampled(19L)).isFalse(); + + // Sliding window expires, new maximum should be 19 + Thread.sleep(windowLength + 1L); + assertThat(sampler.isSampled(19L)).isTrue(); + } + + @Test + public void testSampling0_5Percentile() { + final Sampler sampler = SlidingWindowPercentileSampler.create(.5f, 10000L); + + // Create a uniform distribution of 1000 values from 1 to 1000 + for (long i = 1; i <= 1000; i++) { + sampler.isSampled(i); + } + + // 0.5 percentile should be 500 + assertThat(sampler.isSampled(500L)).isTrue(); + assertThat(sampler.isSampled(499L)).isFalse(); + } + + @Test + public void testSampling0_95Percentile() { + final Sampler sampler = SlidingWindowPercentileSampler.create(.95f, 10000L); + + // Create a uniform distribution of 1000 values from 1 to 1000 + for (long i = 1; i <= 1000; i++) { + sampler.isSampled(i); + } + + // 0.95 percentile is roughly 950, but not exactly + assertThat(sampler.isSampled(951L)).isTrue(); + assertThat(sampler.isSampled(952L)).isTrue(); + assertThat(sampler.isSampled(0L)).isFalse(); + } +} From 229901fa7d6ced91ff8b622c3a4e64e0598c0294 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Do=C4=9Fa=C3=A7=20Eldenk?= Date: Wed, 21 Jun 2023 16:54:41 +0300 Subject: [PATCH 2/6] document and lint properly --- .../armeria/common/util/AndSampler.java | 42 +++--------- .../armeria/common/util/OrSampler.java | 44 +++---------- .../linecorp/armeria/common/util/Sampler.java | 25 +++++++ .../util/SlidingWindowPercentileSampler.java | 33 +++------- .../decorator/LoggingDecorator.java | 14 ++++ .../LoggingDecoratorFactoryFunction.java | 21 +++--- .../server/logging/LoggingService.java | 12 ++-- .../server/logging/LoggingServiceBuilder.java | 47 ++++++++++++-- .../armeria/common/util/SamplerTest.java | 65 +++++++++++++++---- .../SlidingWindowPercentileSamplerTest.java | 15 +---- 10 files changed, 172 insertions(+), 146 deletions(-) diff --git a/core/src/main/java/com/linecorp/armeria/common/util/AndSampler.java b/core/src/main/java/com/linecorp/armeria/common/util/AndSampler.java index 9f5b08b5fa8..522a6141c6e 100644 --- a/core/src/main/java/com/linecorp/armeria/common/util/AndSampler.java +++ b/core/src/main/java/com/linecorp/armeria/common/util/AndSampler.java @@ -1,50 +1,21 @@ /* - * Copyright 2017 LINE Corporation + * Copyright 2023 LINE Corporation * * LINE Corporation 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: * * https://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. - * - * Copyright 2013 - * - * Licensed under the Apache License, Version 2.0 (the "License"); - * you may not use this file except in compliance with the License. - * You may obtain a copy of the License at - * - * https://www.apache.org/licenses/LICENSE-2.0 - * - * Unless required by applicable law or agreed to in writing, software - * distributed under the License is distributed on an "AS IS" BASIS, - * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. - * See the License for the specific language governing permissions and - * limitations under the License. */ package com.linecorp.armeria.common.util; /** - * This sampler is appropriate for low-traffic instrumentation (ex servers that each receive <100K - * requests), or those who do not provision random trace ids. It is not appropriate for collectors - * as the sampling decision isn't idempotent (consistent based on trace id). - * - *

Implementation

- * - *

This initializes a random bitset of size 100 (corresponding to 1% granularity). This means - * that it is accurate in units of 100 traces. At runtime, this loops through the bitset, returning - * the value according to a counter. - * - *

Forked from brave-core 5.6.3 at d4cbd86e1df75687339da6ec2964d42ab3a8cf14 + * Sample if both of the samplers sample. */ final class AndSampler implements Sampler { - private final Sampler left, right; + private final Sampler left; + private final Sampler right; AndSampler(Sampler left, Sampler right) { this.left = left; @@ -53,7 +24,10 @@ final class AndSampler implements Sampler { @Override public boolean isSampled(T t) { - return left.isSampled(t) && right.isSampled(t); + // Assign the variables otherwise the short-circuiting will cause sampler to not be used. + final boolean leftSampled = left.isSampled(t); + final boolean rightSampled = right.isSampled(t); + return leftSampled && rightSampled; } @Override diff --git a/core/src/main/java/com/linecorp/armeria/common/util/OrSampler.java b/core/src/main/java/com/linecorp/armeria/common/util/OrSampler.java index a16b79b3c11..e42ea20bfc1 100644 --- a/core/src/main/java/com/linecorp/armeria/common/util/OrSampler.java +++ b/core/src/main/java/com/linecorp/armeria/common/util/OrSampler.java @@ -1,52 +1,21 @@ /* - * Copyright 2017 LINE Corporation + * Copyright 2023 LINE Corporation * * LINE Corporation 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: * * https://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. - * - * Copyright 2013 - * - * Licensed under the Apache License, Version 2.0 (the "License"); - * you may not use this file except in compliance with the License. - * You may obtain a copy of the License at - * - * https://www.apache.org/licenses/LICENSE-2.0 - * - * Unless required by applicable law or agreed to in writing, software - * distributed under the License is distributed on an "AS IS" BASIS, - * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. - * See the License for the specific language governing permissions and - * limitations under the License. */ package com.linecorp.armeria.common.util; -import java.util.Random; - /** - * This sampler is appropriate for low-traffic instrumentation (ex servers that each receive <100K - * requests), or those who do not provision random trace ids. It is not appropriate for collectors - * as the sampling decision isn't idempotent (consistent based on trace id). - * - *

Implementation

- * - *

This initializes a random bitset of size 100 (corresponding to 1% granularity). This means - * that it is accurate in units of 100 traces. At runtime, this loops through the bitset, returning - * the value according to a counter. - * - *

Forked from brave-core 5.6.3 at d4cbd86e1df75687339da6ec2964d42ab3a8cf14 + * Sample if one of the samplers samples. */ final class OrSampler implements Sampler { - private final Sampler left, right; + private final Sampler left; + private final Sampler right; OrSampler(Sampler left, Sampler right) { this.left = left; @@ -55,7 +24,10 @@ final class OrSampler implements Sampler { @Override public boolean isSampled(T t) { - return left.isSampled(t) || right.isSampled(t); + // Assign the variables otherwise the short-circuiting will cause sampler to not be used. + final boolean leftSampled = left.isSampled(t); + final boolean rightSampled = right.isSampled(t); + return leftSampled || rightSampled; } @Override diff --git a/core/src/main/java/com/linecorp/armeria/common/util/Sampler.java b/core/src/main/java/com/linecorp/armeria/common/util/Sampler.java index 63a0087b04c..ced7374783b 100644 --- a/core/src/main/java/com/linecorp/armeria/common/util/Sampler.java +++ b/core/src/main/java/com/linecorp/armeria/common/util/Sampler.java @@ -43,34 +43,59 @@ @FunctionalInterface public interface Sampler { + /** + * Returns a sampler that applies logical or operator to both samplers decisions. + */ default Sampler or(Sampler other) { return new OrSampler<>(this, other); } + /** + * Returns a sampler that applies logical and operator to both samplers decisions. + */ default Sampler and(Sampler other) { return new AndSampler<>(this, other); } + /** + * Returns a sampler that returns {@code true} if the value is greater than the given value. + */ static > Sampler greaterThan(T val) { return object -> object.compareTo(val) > 0; } + /** + * Returns a sampler that returns {@code true} if the value is less than or equal to the given value. + */ static > Sampler greaterThanOrEqual(T val) { return object -> object.compareTo(val) >= 0; } + /** + * Returns a sampler that returns {@code true} if the value is less than the given value. + */ static > Sampler lessThan(T val) { return object -> object.compareTo(val) < 0; } + /** + * Returns a sampler that returns {@code true} if the value is less than or equal to the given value. + */ static > Sampler lessThanOrEqual(T val) { return object -> object.compareTo(val) <= 0; } + /** + * Returns a sampler that returns {@code true} if the value is equal to the given value. + */ static > Sampler equal(T val) { return object -> object.compareTo(val) == 0; } + /** + * Returns a sampler that returns {@code true} if the value is inside the percentile distribution + * in the given time window. + */ static Sampler percentile(float percentile, long windowMilliseconds) { return new SlidingWindowPercentileSampler(percentile, windowMilliseconds); } diff --git a/core/src/main/java/com/linecorp/armeria/common/util/SlidingWindowPercentileSampler.java b/core/src/main/java/com/linecorp/armeria/common/util/SlidingWindowPercentileSampler.java index eec324455b8..775f46dbf38 100644 --- a/core/src/main/java/com/linecorp/armeria/common/util/SlidingWindowPercentileSampler.java +++ b/core/src/main/java/com/linecorp/armeria/common/util/SlidingWindowPercentileSampler.java @@ -1,31 +1,11 @@ /* - * Copyright 2017 LINE Corporation + * Copyright 2023 LINE Corporation * * LINE Corporation 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: * * https://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. - * - * Copyright 2013 - * - * Licensed under the Apache License, Version 2.0 (the "License"); - * you may not use this file except in compliance with the License. - * You may obtain a copy of the License at - * - * https://www.apache.org/licenses/LICENSE-2.0 - * - * Unless required by applicable law or agreed to in writing, software - * distributed under the License is distributed on an "AS IS" BASIS, - * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. - * See the License for the specific language governing permissions and - * limitations under the License. */ package com.linecorp.armeria.common.util; @@ -34,6 +14,9 @@ import com.codahale.metrics.Histogram; import com.codahale.metrics.SlidingTimeWindowReservoir; +/** + * Sample if the value is less than the percentile of the values in the last window. + */ final class SlidingWindowPercentileSampler implements Sampler { private final float percentile; @@ -46,8 +29,8 @@ final class SlidingWindowPercentileSampler implements Sampler { this.windowLengthMillis = windowLengthMillis; // TODO: Check memory footprint, try limiting resources. - SlidingTimeWindowReservoir reservoir = new SlidingTimeWindowReservoir(windowLengthMillis, - TimeUnit.MILLISECONDS); + final SlidingTimeWindowReservoir reservoir = new SlidingTimeWindowReservoir(windowLengthMillis, + TimeUnit.MILLISECONDS); this.histogram = new Histogram(reservoir); } @@ -64,7 +47,7 @@ public boolean isSampled(Long t) { @Override public String toString() { - return "SlidingWindowPercentileSampler with " + windowLengthMillis + " ms window and " + percentile - + " percentile"; + return "SlidingWindowPercentileSampler with " + windowLengthMillis + " ms window and " + percentile + + " percentile"; } } diff --git a/core/src/main/java/com/linecorp/armeria/server/annotation/decorator/LoggingDecorator.java b/core/src/main/java/com/linecorp/armeria/server/annotation/decorator/LoggingDecorator.java index 6564b6fbce6..e4f9f512462 100644 --- a/core/src/main/java/com/linecorp/armeria/server/annotation/decorator/LoggingDecorator.java +++ b/core/src/main/java/com/linecorp/armeria/server/annotation/decorator/LoggingDecorator.java @@ -83,12 +83,26 @@ */ float failureSamplingRate() default -1.0f; + /** + * Sample the requests if they are slower than the {@code slowRequestSamplingPercentile} percent + * of the requests. + */ float slowRequestSamplingPercentile() default -1.0f; + /** + * Slow request percentiles are calculated over the last {@code slowRequestSamplingWindowMilliseconds}. + */ long slowRequestSamplingWindowMilliseconds() default 60 * 1000; + /** + * Don't sample the requests if they are faster than the {@code slowRequestSamplingLowerBoundMilliseconds}. + * Should be used with {@link #slowRequestSamplingUpperBoundMilliseconds()}. + */ long slowRequestSamplingLowerBoundMilliseconds() default 0L; + /** + * Always sample the requests if they are slower than the {@code slowRequestSamplingUpperBoundMilliseconds}. + */ long slowRequestSamplingUpperBoundMilliseconds() default Long.MAX_VALUE; /** diff --git a/core/src/main/java/com/linecorp/armeria/server/annotation/decorator/LoggingDecoratorFactoryFunction.java b/core/src/main/java/com/linecorp/armeria/server/annotation/decorator/LoggingDecoratorFactoryFunction.java index 8399b33d6a4..304d18a1376 100644 --- a/core/src/main/java/com/linecorp/armeria/server/annotation/decorator/LoggingDecoratorFactoryFunction.java +++ b/core/src/main/java/com/linecorp/armeria/server/annotation/decorator/LoggingDecoratorFactoryFunction.java @@ -39,17 +39,16 @@ public final class LoggingDecoratorFactoryFunction implements DecoratorFactoryFu final float failureSamplingRate = parameter.failureSamplingRate() >= 0.0f ? parameter.failureSamplingRate() : parameter.samplingRate(); - LoggingServiceBuilder builder = LoggingService.builder() - .logWriter(LogWriter.builder() - .requestLogLevel( - parameter.requestLogLevel()) - .successfulResponseLogLevel( - parameter.successfulResponseLogLevel()) - .failureResponseLogLevel( - parameter.failureResponseLogLevel()) - .build()) - .successSamplingRate(successSamplingRate) - .failureSamplingRate(failureSamplingRate); + final LogWriter logWriter = LogWriter.builder() + .requestLogLevel(parameter.requestLogLevel()) + .successfulResponseLogLevel(parameter.successfulResponseLogLevel()) + .failureResponseLogLevel(parameter.failureResponseLogLevel()) + .build(); + final LoggingServiceBuilder builder + = LoggingService.builder() + .logWriter(logWriter) + .successSamplingRate(successSamplingRate) + .failureSamplingRate(failureSamplingRate); if (parameter.slowRequestSamplingPercentile() >= 0.0f) { builder.slowRequestSamplingPercentile(parameter.slowRequestSamplingPercentile(), diff --git a/core/src/main/java/com/linecorp/armeria/server/logging/LoggingService.java b/core/src/main/java/com/linecorp/armeria/server/logging/LoggingService.java index 751c6941ea0..ef4c9ccdbd9 100644 --- a/core/src/main/java/com/linecorp/armeria/server/logging/LoggingService.java +++ b/core/src/main/java/com/linecorp/armeria/server/logging/LoggingService.java @@ -64,15 +64,15 @@ public static LoggingServiceBuilder builder() { requireNonNull(failureSampler, "failureSampler"); sampler = requestLog -> { final ServiceRequestContext ctx = (ServiceRequestContext) requestLog.context(); - if (slowRequestSampler.isSampled(requestLog.totalDurationNanos())) { - return true; - } - + final boolean isSlow = slowRequestSampler.isSampled(requestLog.totalDurationNanos()); + final boolean successOrFailure; if (ctx.config().successFunction().isSuccess(ctx, requestLog)) { - return successSampler.isSampled(ctx); + successOrFailure = successSampler.isSampled(ctx); + } else { + successOrFailure = failureSampler.isSampled(ctx); } - return failureSampler.isSampled(ctx); + return successOrFailure || isSlow; }; } diff --git a/core/src/main/java/com/linecorp/armeria/server/logging/LoggingServiceBuilder.java b/core/src/main/java/com/linecorp/armeria/server/logging/LoggingServiceBuilder.java index 9a94dc4010b..0bc801dc89f 100644 --- a/core/src/main/java/com/linecorp/armeria/server/logging/LoggingServiceBuilder.java +++ b/core/src/main/java/com/linecorp/armeria/server/logging/LoggingServiceBuilder.java @@ -109,6 +109,9 @@ public LoggingServiceBuilder failureSampler( return this; } + /** + * Sets the {@link Sampler} that determines whether a request is slow enough to be logged. + */ public LoggingServiceBuilder slowRequestSampler(Sampler slowRequestSampler) { this.slowRequestSampler = requireNonNull(slowRequestSampler, "slowRequestSampler"); return this; @@ -125,18 +128,48 @@ public LoggingServiceBuilder failureSamplingRate(float failureSamplingRate) { return failureSampler(Sampler.random(failureSamplingRate)); } + /** + * Sets conditions to sample slow requests. + * + *

If {slowRequestPercentile} is 0.99, {windowMilliseconds} is 60000, we will sample requests that are + * slower than 99% of the requests within 1-minute time window. This will make sure our sampling adapts the + * traffic pattern. For example, traffic can be very low during the night thus our average response time + * will be pretty low. Therefore, our p99s should be lower than the midday traffic. + * Otherwise, we won't log any p99s during night.

+ * + *

If we set {slowRequestSamplingLowerBoundMilliseconds} to 100, we won't sample any request that took + * less than 1000ms. This is useful to filter out requests that are too fast to be considered + * as slow requests. If your endpoint performs pretty healthy, you shouldn't see any slow request logs.

+ * + *

If we set {slowRequestSamplingUpperBoundMilliseconds} to 1000, we will sample any request that + * took more than 1000 milliseconds. This is useful to make sure we log slow requests even if + * they are not in the p99 percentile. If your service is unhealthy, this will make sure any slow request + * is logged into your system.

+ * + * @param slowRequestPercentile percentile of slow requests. + * @param windowMilliseconds window size to calculate percentile. + * @param slowRequestSamplingLowerBoundMilliseconds lower bound of slow requests. + * Any request that took less than this amount of time won't be sampled. + * @param slowRequestSamplingUpperBoundMilliseconds upper bound of slow requests. + * Any request that took more than this amount of time will be sampled regardless + * of their percentile. + */ public LoggingServiceBuilder slowRequestSamplingPercentile(float slowRequestPercentile, long windowMilliseconds, long slowRequestSamplingLowerBoundMilliseconds, long slowRequestSamplingUpperBoundMilliseconds) { - checkArgument(0.0 <= slowRequestPercentile && slowRequestPercentile <= 1.0, - "slowRequestPercentile: %s (expected: 0.0 <= slowRequestPercentile <= 1.0)", - slowRequestPercentile); + final Sampler percentileMatches; + if (0.0 <= slowRequestPercentile && slowRequestPercentile <= 1.0) { + percentileMatches = Sampler.never(); + } else { + percentileMatches = Sampler.percentile(slowRequestPercentile, windowMilliseconds); + } + + final Sampler isSlow = Sampler.greaterThanOrEqual( + slowRequestSamplingLowerBoundMilliseconds * 1000); + final Sampler isVerySlow = Sampler.greaterThan(slowRequestSamplingUpperBoundMilliseconds * 1000); return slowRequestSampler( - Sampler.greaterThanOrEqual(slowRequestSamplingLowerBoundMilliseconds * 1000) - .or(Sampler.percentile(slowRequestPercentile, windowMilliseconds) - .and(Sampler.greaterThan( - slowRequestSamplingUpperBoundMilliseconds * 1000))) + isVerySlow.or(percentileMatches.and(isSlow)) ); } diff --git a/core/src/test/java/com/linecorp/armeria/common/util/SamplerTest.java b/core/src/test/java/com/linecorp/armeria/common/util/SamplerTest.java index 45e5b74060b..e86fbbcfee1 100644 --- a/core/src/test/java/com/linecorp/armeria/common/util/SamplerTest.java +++ b/core/src/test/java/com/linecorp/armeria/common/util/SamplerTest.java @@ -91,66 +91,105 @@ void badOf() { @Test void andOr() { - Sampler alwaysAndAlwaysSampler = Sampler.always().and(Sampler.always()); + final Sampler alwaysAndAlwaysSampler = Sampler.always().and(Sampler.always()); for (int i = 0; i < 10; i++) { assertThat(alwaysAndAlwaysSampler.isSampled(i)).isTrue(); } - Sampler alwaysOrAlwaysSampler = Sampler.always().or(Sampler.always()); + final Sampler alwaysOrAlwaysSampler = Sampler.always().or(Sampler.always()); for (int i = 0; i < 10; i++) { assertThat(alwaysOrAlwaysSampler.isSampled(i)).isTrue(); } - Sampler neverOrAlwaysSampler = Sampler.never().or(Sampler.always()); + final Sampler neverOrAlwaysSampler = Sampler.never().or(Sampler.always()); for (int i = 0; i < 10; i++) { assertThat(neverOrAlwaysSampler.isSampled(i)).isTrue(); } - Sampler neverAndAlwaysSampler = Sampler.never().and(Sampler.always()); + final Sampler neverAndAlwaysSampler = Sampler.never().and(Sampler.always()); for (int i = 0; i < 10; i++) { assertThat(neverAndAlwaysSampler.isSampled(i)).isFalse(); } - Sampler halfAndHalfSampler = Sampler.random(0.5f).and(Sampler.random(0.5f)); + final Sampler halfAndHalfSampler = Sampler.random(0.5f).and(Sampler.random(0.5f)); int halfAndHalfSamplerCount = 0; for (int i = 0; i < 10000; i++) { - if (halfAndHalfSampler.isSampled(i)) {halfAndHalfSamplerCount += 1;} + if (halfAndHalfSampler.isSampled(i)) { + halfAndHalfSamplerCount += 1; + } } // 0.5*0.5 = 0.25 assertThat(halfAndHalfSamplerCount).isBetween(2000, 3000); // Should be roughly 2500 // - Sampler halfOrHalfSampler = Sampler.random(0.5f).or(Sampler.random(0.5f)); + final Sampler halfOrHalfSampler = Sampler.random(0.5f).or(Sampler.random(0.5f)); int halfOrHalfSamplerCount = 0; for (int i = 0; i < 10000; i++) { - if (halfOrHalfSampler.isSampled(i)) {halfOrHalfSamplerCount += 1;} + if (halfOrHalfSampler.isSampled(i)) { + halfOrHalfSamplerCount += 1; + } } // 1 - (0.5*0.5) = 0.75 assertThat(halfOrHalfSamplerCount).isBetween(7000, 8000); // Should be roughly 7500 } + private static class SampleOnce implements Sampler { + int count; + + @Override + public boolean isSampled(Object object) { + return count++ == 0; + } + + public void reset() { + count = 0; + } + } + + @Test + void andOrNotShortCircuited() { + final SampleOnce first = new SampleOnce(); + final SampleOnce second = new SampleOnce(); + + assertThat(first.and(second).isSampled(0)).isTrue(); + assertThat(first.isSampled(0)).isFalse(); + assertThat(second.isSampled(0)).isFalse(); + + first.reset(); + second.reset(); + + assertThat(first.or(second).isSampled(0)).isTrue(); + assertThat(first.isSampled(0)).isFalse(); + assertThat(second.isSampled(0)).isFalse(); + + first.reset(); + second.reset(); + + assertThat(second.and(second).isSampled(0)).isFalse(); + } + @Test void compare() { - Sampler greaterThanOne = Sampler.greaterThan(1); + final Sampler greaterThanOne = Sampler.greaterThan(1); assertThat(greaterThanOne.isSampled(0)).isFalse(); assertThat(greaterThanOne.isSampled(1)).isFalse(); assertThat(greaterThanOne.isSampled(2)).isTrue(); - Sampler greaterThanOrEqualOne = Sampler.greaterThanOrEqual(1); + final Sampler greaterThanOrEqualOne = Sampler.greaterThanOrEqual(1); assertThat(greaterThanOrEqualOne.isSampled(0)).isFalse(); assertThat(greaterThanOrEqualOne.isSampled(1)).isTrue(); assertThat(greaterThanOrEqualOne.isSampled(2)).isTrue(); - Sampler lessThanOne = Sampler.lessThan(1); + final Sampler lessThanOne = Sampler.lessThan(1); assertThat(lessThanOne.isSampled(0)).isTrue(); assertThat(lessThanOne.isSampled(1)).isFalse(); assertThat(lessThanOne.isSampled(2)).isFalse(); - Sampler lessThanOrEqualOne = Sampler.lessThanOrEqual(1); + final Sampler lessThanOrEqualOne = Sampler.lessThanOrEqual(1); assertThat(lessThanOrEqualOne.isSampled(0)).isTrue(); assertThat(lessThanOrEqualOne.isSampled(1)).isTrue(); assertThat(lessThanOrEqualOne.isSampled(2)).isFalse(); - Sampler equalOne = Sampler.equal(1); + final Sampler equalOne = Sampler.equal(1); assertThat(equalOne.isSampled(0)).isFalse(); assertThat(equalOne.isSampled(1)).isTrue(); assertThat(equalOne.isSampled(2)).isFalse(); diff --git a/core/src/test/java/com/linecorp/armeria/common/util/SlidingWindowPercentileSamplerTest.java b/core/src/test/java/com/linecorp/armeria/common/util/SlidingWindowPercentileSamplerTest.java index 5c3f63f57d8..496cf56dbba 100644 --- a/core/src/test/java/com/linecorp/armeria/common/util/SlidingWindowPercentileSamplerTest.java +++ b/core/src/test/java/com/linecorp/armeria/common/util/SlidingWindowPercentileSamplerTest.java @@ -1,5 +1,5 @@ /* - * Copyright 2019 LINE Corporation + * Copyright 2023 LINE Corporation * * LINE Corporation licenses this file to you under the Apache License, * version 2.0 (the "License"); you may not use this file except in compliance @@ -13,19 +13,6 @@ * License for the specific language governing permissions and limitations * under the License. */ -/* - * Copyright 2013-2019 The OpenZipkin Authors - * - * Licensed under the Apache License, Version 2.0 (the "License"); you may not use this file except - * in compliance with the License. You may obtain a copy of the License at - * - * http://www.apache.org/licenses/LICENSE-2.0 - * - * Unless required by applicable law or agreed to in writing, software distributed under the License - * is distributed on an "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express - * or implied. See the License for the specific language governing permissions and limitations under - * the License. - */ package com.linecorp.armeria.common.util; From 0a0bc0548748cbdda0fa9529e53c0b97dbb734d4 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Do=C4=9Fa=C3=A7=20Eldenk?= Date: Mon, 26 Jun 2023 22:58:16 +0300 Subject: [PATCH 3/6] try 2 --- .../linecorp/armeria/common/util/Sampler.java | 2 +- .../util/SlidingWindowPercentileSampler.java | 53 -------------- .../util/TimeWindowPercentileSampler.java | 72 +++++++++++++++++++ .../decorator/LoggingDecorator.java | 2 +- ...a => TimeWindowPercentileSamplerTest.java} | 16 ++--- 5 files changed, 82 insertions(+), 63 deletions(-) delete mode 100644 core/src/main/java/com/linecorp/armeria/common/util/SlidingWindowPercentileSampler.java create mode 100644 core/src/main/java/com/linecorp/armeria/common/util/TimeWindowPercentileSampler.java rename core/src/test/java/com/linecorp/armeria/common/util/{SlidingWindowPercentileSamplerTest.java => TimeWindowPercentileSamplerTest.java} (81%) diff --git a/core/src/main/java/com/linecorp/armeria/common/util/Sampler.java b/core/src/main/java/com/linecorp/armeria/common/util/Sampler.java index ced7374783b..58c9c37f191 100644 --- a/core/src/main/java/com/linecorp/armeria/common/util/Sampler.java +++ b/core/src/main/java/com/linecorp/armeria/common/util/Sampler.java @@ -97,7 +97,7 @@ static > Sampler equal(T val) { * in the given time window. */ static Sampler percentile(float percentile, long windowMilliseconds) { - return new SlidingWindowPercentileSampler(percentile, windowMilliseconds); + return new TimeWindowPercentileSampler(percentile, windowMilliseconds); } /** diff --git a/core/src/main/java/com/linecorp/armeria/common/util/SlidingWindowPercentileSampler.java b/core/src/main/java/com/linecorp/armeria/common/util/SlidingWindowPercentileSampler.java deleted file mode 100644 index 775f46dbf38..00000000000 --- a/core/src/main/java/com/linecorp/armeria/common/util/SlidingWindowPercentileSampler.java +++ /dev/null @@ -1,53 +0,0 @@ -/* - * Copyright 2023 LINE Corporation - * - * LINE Corporation 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: - * - * https://www.apache.org/licenses/LICENSE-2.0 - */ -package com.linecorp.armeria.common.util; - -import java.util.concurrent.TimeUnit; - -import com.codahale.metrics.Histogram; -import com.codahale.metrics.SlidingTimeWindowReservoir; - -/** - * Sample if the value is less than the percentile of the values in the last window. - */ -final class SlidingWindowPercentileSampler implements Sampler { - - private final float percentile; - private final long windowLengthMillis; - - private final Histogram histogram; - - SlidingWindowPercentileSampler(float percentile, long windowLengthMillis) { - this.percentile = percentile; - this.windowLengthMillis = windowLengthMillis; - - // TODO: Check memory footprint, try limiting resources. - final SlidingTimeWindowReservoir reservoir = new SlidingTimeWindowReservoir(windowLengthMillis, - TimeUnit.MILLISECONDS); - this.histogram = new Histogram(reservoir); - } - - static SlidingWindowPercentileSampler create(float percentile, long windowLengthMillis) { - return new SlidingWindowPercentileSampler(percentile, windowLengthMillis); - } - - @Override - public boolean isSampled(Long t) { - histogram.update(t); - // TODO: get snapshot calls might be expensive, consider caching snapshot - return histogram.getSnapshot().getValue(this.percentile) <= t; - } - - @Override - public String toString() { - return "SlidingWindowPercentileSampler with " + windowLengthMillis + " ms window and " + percentile + - " percentile"; - } -} diff --git a/core/src/main/java/com/linecorp/armeria/common/util/TimeWindowPercentileSampler.java b/core/src/main/java/com/linecorp/armeria/common/util/TimeWindowPercentileSampler.java new file mode 100644 index 00000000000..78b5694e017 --- /dev/null +++ b/core/src/main/java/com/linecorp/armeria/common/util/TimeWindowPercentileSampler.java @@ -0,0 +1,72 @@ +/* + * Copyright 2023 LINE Corporation + * + * LINE Corporation 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: + * + * https://www.apache.org/licenses/LICENSE-2.0 + */ +package com.linecorp.armeria.common.util; + +import java.time.Duration; + +import io.micrometer.core.instrument.Clock; +import io.micrometer.core.instrument.distribution.DistributionStatisticConfig; +import io.micrometer.core.instrument.distribution.HistogramSnapshot; +import io.micrometer.core.instrument.distribution.TimeWindowPercentileHistogram; + +/** + * Sample if the value is less than the percentile of the values in the last window. + */ +final class TimeWindowPercentileSampler implements Sampler { + + private final float percentile; + private final long windowLengthMillis; + + private final TimeWindowPercentileHistogram histogram; + private static final long SNAPSHOT_UPDATE_MILLIS = 1000L; + private long lastSnapshotMillis = 0L; + private HistogramSnapshot histogramSnapshot; + + TimeWindowPercentileSampler(float percentile, long windowLengthMillis) { + this.percentile = percentile; + this.windowLengthMillis = windowLengthMillis; + + final DistributionStatisticConfig distributionStatisticConfig = + DistributionStatisticConfig.builder() + .percentiles(percentile) + .percentilePrecision(2) + .minimumExpectedValue(1.0) + .maximumExpectedValue(Double.POSITIVE_INFINITY) + .expiry(Duration.ofMillis(windowLengthMillis)) + .bufferLength(3) + .build(); + this.histogram = new TimeWindowPercentileHistogram(Clock.SYSTEM, distributionStatisticConfig, true); + this.histogramSnapshot = histogram.takeSnapshot(0, 0, 0); + this.lastSnapshotMillis = System.currentTimeMillis(); + } + + static TimeWindowPercentileSampler create(float percentile, long windowLengthMillis) { + return new TimeWindowPercentileSampler(percentile, windowLengthMillis); + } + + @Override + public boolean isSampled(Long t) { + histogram.recordLong(t); + + if (lastSnapshotMillis + SNAPSHOT_UPDATE_MILLIS < System.currentTimeMillis()) { + histogramSnapshot = histogram.takeSnapshot(0, 0, 0); + lastSnapshotMillis = System.currentTimeMillis(); + } + + final Double percentileValue = histogramSnapshot.percentileValues()[0].value(); + return percentileValue.longValue() <= t; + } + + @Override + public String toString() { + return "SlidingWindowPercentileSampler with " + windowLengthMillis + " ms window and " + percentile + + " percentile"; + } +} diff --git a/core/src/main/java/com/linecorp/armeria/server/annotation/decorator/LoggingDecorator.java b/core/src/main/java/com/linecorp/armeria/server/annotation/decorator/LoggingDecorator.java index e4f9f512462..299c47a0ff4 100644 --- a/core/src/main/java/com/linecorp/armeria/server/annotation/decorator/LoggingDecorator.java +++ b/core/src/main/java/com/linecorp/armeria/server/annotation/decorator/LoggingDecorator.java @@ -92,7 +92,7 @@ /** * Slow request percentiles are calculated over the last {@code slowRequestSamplingWindowMilliseconds}. */ - long slowRequestSamplingWindowMilliseconds() default 60 * 1000; + long slowRequestSamplingWindowMilliseconds() default 10 * 60 * 1000; /** * Don't sample the requests if they are faster than the {@code slowRequestSamplingLowerBoundMilliseconds}. diff --git a/core/src/test/java/com/linecorp/armeria/common/util/SlidingWindowPercentileSamplerTest.java b/core/src/test/java/com/linecorp/armeria/common/util/TimeWindowPercentileSamplerTest.java similarity index 81% rename from core/src/test/java/com/linecorp/armeria/common/util/SlidingWindowPercentileSamplerTest.java rename to core/src/test/java/com/linecorp/armeria/common/util/TimeWindowPercentileSamplerTest.java index 496cf56dbba..e90f8f1114a 100644 --- a/core/src/test/java/com/linecorp/armeria/common/util/SlidingWindowPercentileSamplerTest.java +++ b/core/src/test/java/com/linecorp/armeria/common/util/TimeWindowPercentileSamplerTest.java @@ -20,10 +20,10 @@ import org.junit.jupiter.api.Test; -public class SlidingWindowPercentileSamplerTest { +public class TimeWindowPercentileSamplerTest { @Test public void testSamplingMinimumPercentile() { - final Sampler sampler = SlidingWindowPercentileSampler.create(0.0f, 10000L); + final Sampler sampler = TimeWindowPercentileSampler.create(0.0f, 10000L); // Should sample everything assertThat(sampler.isSampled(10L)).isTrue(); @@ -33,7 +33,7 @@ public void testSamplingMinimumPercentile() { @Test public void testSamplingMaximumPercentile() { - final Sampler sampler = SlidingWindowPercentileSampler.create(1.0f, 10000L); + final Sampler sampler = TimeWindowPercentileSampler.create(1.0f, 10000L); // Should only sample the maximum value assertThat(sampler.isSampled(10L)).isTrue(); @@ -48,7 +48,7 @@ public void testSamplingMaximumPercentile() { @Test public void testSamplingWindowExpires() throws InterruptedException { final long windowLength = 1000L; - final Sampler sampler = SlidingWindowPercentileSampler.create(1.0f, windowLength); + final Sampler sampler = TimeWindowPercentileSampler.create(1.0f, windowLength); // Should only sample the maximum value assertThat(sampler.isSampled(20L)).isTrue(); @@ -61,21 +61,21 @@ public void testSamplingWindowExpires() throws InterruptedException { @Test public void testSampling0_5Percentile() { - final Sampler sampler = SlidingWindowPercentileSampler.create(.5f, 10000L); + final Sampler sampler = TimeWindowPercentileSampler.create(.5f, 10000L); // Create a uniform distribution of 1000 values from 1 to 1000 for (long i = 1; i <= 1000; i++) { sampler.isSampled(i); } - // 0.5 percentile should be 500 - assertThat(sampler.isSampled(500L)).isTrue(); + // 0.5 percentile should be approximately 500 + assertThat(sampler.isSampled(501L)).isTrue(); assertThat(sampler.isSampled(499L)).isFalse(); } @Test public void testSampling0_95Percentile() { - final Sampler sampler = SlidingWindowPercentileSampler.create(.95f, 10000L); + final Sampler sampler = TimeWindowPercentileSampler.create(.95f, 10000L); // Create a uniform distribution of 1000 values from 1 to 1000 for (long i = 1; i <= 1000; i++) { From 01847b87f703a876930f0daba6b4683c8d05c511 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Do=C4=9Fa=C3=A7=20Eldenk?= Date: Fri, 14 Jul 2023 15:02:40 +0300 Subject: [PATCH 4/6] comment resolution --- .../armeria/common/util/AndSampler.java | 2 +- .../armeria/common/util/OrSampler.java | 2 +- .../linecorp/armeria/common/util/Sampler.java | 18 +++++++++++-- .../util/TimeWindowPercentileSampler.java | 26 ++++++++++++++----- .../armeria/common/util/SamplerTest.java | 24 +++++------------ 5 files changed, 44 insertions(+), 28 deletions(-) diff --git a/core/src/main/java/com/linecorp/armeria/common/util/AndSampler.java b/core/src/main/java/com/linecorp/armeria/common/util/AndSampler.java index 522a6141c6e..1a6e3e71516 100644 --- a/core/src/main/java/com/linecorp/armeria/common/util/AndSampler.java +++ b/core/src/main/java/com/linecorp/armeria/common/util/AndSampler.java @@ -32,6 +32,6 @@ public boolean isSampled(T t) { @Override public String toString() { - return left.toString() + " and " + right.toString(); + return left + " and " + right; } } diff --git a/core/src/main/java/com/linecorp/armeria/common/util/OrSampler.java b/core/src/main/java/com/linecorp/armeria/common/util/OrSampler.java index e42ea20bfc1..98759bb5b3f 100644 --- a/core/src/main/java/com/linecorp/armeria/common/util/OrSampler.java +++ b/core/src/main/java/com/linecorp/armeria/common/util/OrSampler.java @@ -32,6 +32,6 @@ public boolean isSampled(T t) { @Override public String toString() { - return left.toString() + " or " + right.toString(); + return left + " or " + right; } } diff --git a/core/src/main/java/com/linecorp/armeria/common/util/Sampler.java b/core/src/main/java/com/linecorp/armeria/common/util/Sampler.java index 58c9c37f191..f0cede79e08 100644 --- a/core/src/main/java/com/linecorp/armeria/common/util/Sampler.java +++ b/core/src/main/java/com/linecorp/armeria/common/util/Sampler.java @@ -29,6 +29,8 @@ */ package com.linecorp.armeria.common.util; +import static java.util.Objects.requireNonNull; + /** * Sampler is responsible for deciding if a particular trace should be "sampled", i.e. whether the * overhead of tracing will occur and/or if a trace will be reported to the collection tier. @@ -47,20 +49,28 @@ public interface Sampler { * Returns a sampler that applies logical or operator to both samplers decisions. */ default Sampler or(Sampler other) { - return new OrSampler<>(this, other); + return new OrSampler<>(this, requireNonNull(other, "other")); } /** * Returns a sampler that applies logical and operator to both samplers decisions. */ default Sampler and(Sampler other) { - return new AndSampler<>(this, other); + return new AndSampler<>(this, requireNonNull(other, "other")); + } + + /** + * Returns a sampler that applies logical not operator to the sampler decision. + */ + default Sampler not() { + return object -> !isSampled(object); } /** * Returns a sampler that returns {@code true} if the value is greater than the given value. */ static > Sampler greaterThan(T val) { + requireNonNull(val, "val"); return object -> object.compareTo(val) > 0; } @@ -68,6 +78,7 @@ static > Sampler greaterThan(T val) { * Returns a sampler that returns {@code true} if the value is less than or equal to the given value. */ static > Sampler greaterThanOrEqual(T val) { + requireNonNull(val, "val"); return object -> object.compareTo(val) >= 0; } @@ -75,6 +86,7 @@ static > Sampler greaterThanOrEqual(T val) { * Returns a sampler that returns {@code true} if the value is less than the given value. */ static > Sampler lessThan(T val) { + requireNonNull(val, "val"); return object -> object.compareTo(val) < 0; } @@ -82,6 +94,7 @@ static > Sampler lessThan(T val) { * Returns a sampler that returns {@code true} if the value is less than or equal to the given value. */ static > Sampler lessThanOrEqual(T val) { + requireNonNull(val, "val"); return object -> object.compareTo(val) <= 0; } @@ -89,6 +102,7 @@ static > Sampler lessThanOrEqual(T val) { * Returns a sampler that returns {@code true} if the value is equal to the given value. */ static > Sampler equal(T val) { + requireNonNull(val, "val"); return object -> object.compareTo(val) == 0; } diff --git a/core/src/main/java/com/linecorp/armeria/common/util/TimeWindowPercentileSampler.java b/core/src/main/java/com/linecorp/armeria/common/util/TimeWindowPercentileSampler.java index 78b5694e017..76acba7bdd9 100644 --- a/core/src/main/java/com/linecorp/armeria/common/util/TimeWindowPercentileSampler.java +++ b/core/src/main/java/com/linecorp/armeria/common/util/TimeWindowPercentileSampler.java @@ -10,6 +10,9 @@ package com.linecorp.armeria.common.util; import java.time.Duration; +import java.util.concurrent.atomic.AtomicReference; + +import com.google.common.annotations.VisibleForTesting; import io.micrometer.core.instrument.Clock; import io.micrometer.core.instrument.distribution.DistributionStatisticConfig; @@ -23,13 +26,19 @@ final class TimeWindowPercentileSampler implements Sampler { private final float percentile; private final long windowLengthMillis; - private final TimeWindowPercentileHistogram histogram; private static final long SNAPSHOT_UPDATE_MILLIS = 1000L; - private long lastSnapshotMillis = 0L; + private long lastSnapshotMillis; private HistogramSnapshot histogramSnapshot; + private final AtomicReference isTakingSnapshot = new AtomicReference<>(false); + TimeWindowPercentileSampler(float percentile, long windowLengthMillis) { + this(percentile, windowLengthMillis, Clock.SYSTEM); + } + + @VisibleForTesting + TimeWindowPercentileSampler(float percentile, long windowLengthMillis, Clock clock) { this.percentile = percentile; this.windowLengthMillis = windowLengthMillis; @@ -42,7 +51,7 @@ final class TimeWindowPercentileSampler implements Sampler { .expiry(Duration.ofMillis(windowLengthMillis)) .bufferLength(3) .build(); - this.histogram = new TimeWindowPercentileHistogram(Clock.SYSTEM, distributionStatisticConfig, true); + this.histogram = new TimeWindowPercentileHistogram(clock, distributionStatisticConfig, true); this.histogramSnapshot = histogram.takeSnapshot(0, 0, 0); this.lastSnapshotMillis = System.currentTimeMillis(); } @@ -56,17 +65,20 @@ public boolean isSampled(Long t) { histogram.recordLong(t); if (lastSnapshotMillis + SNAPSHOT_UPDATE_MILLIS < System.currentTimeMillis()) { - histogramSnapshot = histogram.takeSnapshot(0, 0, 0); - lastSnapshotMillis = System.currentTimeMillis(); + if (isTakingSnapshot.compareAndSet(false, true)) { + histogramSnapshot = histogram.takeSnapshot(0, 0, 0); + lastSnapshotMillis = System.currentTimeMillis(); + isTakingSnapshot.set(false); + } } final Double percentileValue = histogramSnapshot.percentileValues()[0].value(); - return percentileValue.longValue() <= t; + return t >= percentileValue.longValue(); } @Override public String toString() { - return "SlidingWindowPercentileSampler with " + windowLengthMillis + " ms window and " + percentile + + return "TimeWindowPercentileSampler with " + windowLengthMillis + " ms window and " + percentile + " percentile"; } } diff --git a/core/src/test/java/com/linecorp/armeria/common/util/SamplerTest.java b/core/src/test/java/com/linecorp/armeria/common/util/SamplerTest.java index e86fbbcfee1..33deb9d21e2 100644 --- a/core/src/test/java/com/linecorp/armeria/common/util/SamplerTest.java +++ b/core/src/test/java/com/linecorp/armeria/common/util/SamplerTest.java @@ -111,25 +111,15 @@ void andOr() { assertThat(neverAndAlwaysSampler.isSampled(i)).isFalse(); } - final Sampler halfAndHalfSampler = Sampler.random(0.5f).and(Sampler.random(0.5f)); - int halfAndHalfSamplerCount = 0; - for (int i = 0; i < 10000; i++) { - if (halfAndHalfSampler.isSampled(i)) { - halfAndHalfSamplerCount += 1; - } + final Sampler notNeverSampler = Sampler.never().not(); + for (int i = 0; i < 10; i++) { + assertThat(notNeverSampler.isSampled(i)).isTrue(); } - // 0.5*0.5 = 0.25 - assertThat(halfAndHalfSamplerCount).isBetween(2000, 3000); // Should be roughly 2500 // - - final Sampler halfOrHalfSampler = Sampler.random(0.5f).or(Sampler.random(0.5f)); - int halfOrHalfSamplerCount = 0; - for (int i = 0; i < 10000; i++) { - if (halfOrHalfSampler.isSampled(i)) { - halfOrHalfSamplerCount += 1; - } + + final Sampler notAlwaysSampler = Sampler.always().not(); + for (int i = 0; i < 10; i++) { + assertThat(notAlwaysSampler.isSampled(i)).isFalse(); } - // 1 - (0.5*0.5) = 0.75 - assertThat(halfOrHalfSamplerCount).isBetween(7000, 8000); // Should be roughly 7500 } private static class SampleOnce implements Sampler { From 7222a1c93757b1e676c1f7d0e22c90f6c16b36eb Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Do=C4=9Fa=C3=A7=20Eldenk?= Date: Sat, 22 Jul 2023 14:35:48 +0300 Subject: [PATCH 5/6] use distribution config --- .../util/TimeWindowPercentileSampler.java | 21 +++++++++++-------- .../util/TimeWindowPercentileSamplerTest.java | 9 ++++++-- 2 files changed, 19 insertions(+), 11 deletions(-) diff --git a/core/src/main/java/com/linecorp/armeria/common/util/TimeWindowPercentileSampler.java b/core/src/main/java/com/linecorp/armeria/common/util/TimeWindowPercentileSampler.java index 76acba7bdd9..cebcab053b1 100644 --- a/core/src/main/java/com/linecorp/armeria/common/util/TimeWindowPercentileSampler.java +++ b/core/src/main/java/com/linecorp/armeria/common/util/TimeWindowPercentileSampler.java @@ -14,6 +14,8 @@ import com.google.common.annotations.VisibleForTesting; +import com.linecorp.armeria.common.metric.MoreMeters; + import io.micrometer.core.instrument.Clock; import io.micrometer.core.instrument.distribution.DistributionStatisticConfig; import io.micrometer.core.instrument.distribution.HistogramSnapshot; @@ -27,10 +29,12 @@ final class TimeWindowPercentileSampler implements Sampler { private final float percentile; private final long windowLengthMillis; private final TimeWindowPercentileHistogram histogram; - private static final long SNAPSHOT_UPDATE_MILLIS = 1000L; + @VisibleForTesting + static long SNAPSHOT_UPDATE_MILLIS = 1000L; private long lastSnapshotMillis; private HistogramSnapshot histogramSnapshot; + private final Clock clock; private final AtomicReference isTakingSnapshot = new AtomicReference<>(false); TimeWindowPercentileSampler(float percentile, long windowLengthMillis) { @@ -44,16 +48,15 @@ final class TimeWindowPercentileSampler implements Sampler { final DistributionStatisticConfig distributionStatisticConfig = DistributionStatisticConfig.builder() + .percentilesHistogram(false) .percentiles(percentile) - .percentilePrecision(2) - .minimumExpectedValue(1.0) - .maximumExpectedValue(Double.POSITIVE_INFINITY) .expiry(Duration.ofMillis(windowLengthMillis)) - .bufferLength(3) - .build(); + .build() + .merge(MoreMeters.distributionStatisticConfig()); this.histogram = new TimeWindowPercentileHistogram(clock, distributionStatisticConfig, true); this.histogramSnapshot = histogram.takeSnapshot(0, 0, 0); - this.lastSnapshotMillis = System.currentTimeMillis(); + this.clock = clock; + this.lastSnapshotMillis = clock.wallTime(); } static TimeWindowPercentileSampler create(float percentile, long windowLengthMillis) { @@ -64,10 +67,10 @@ static TimeWindowPercentileSampler create(float percentile, long windowLengthMil public boolean isSampled(Long t) { histogram.recordLong(t); - if (lastSnapshotMillis + SNAPSHOT_UPDATE_MILLIS < System.currentTimeMillis()) { + if (lastSnapshotMillis + SNAPSHOT_UPDATE_MILLIS <= clock.wallTime()) { if (isTakingSnapshot.compareAndSet(false, true)) { histogramSnapshot = histogram.takeSnapshot(0, 0, 0); - lastSnapshotMillis = System.currentTimeMillis(); + lastSnapshotMillis = clock.wallTime(); isTakingSnapshot.set(false); } } diff --git a/core/src/test/java/com/linecorp/armeria/common/util/TimeWindowPercentileSamplerTest.java b/core/src/test/java/com/linecorp/armeria/common/util/TimeWindowPercentileSamplerTest.java index e90f8f1114a..b970df55703 100644 --- a/core/src/test/java/com/linecorp/armeria/common/util/TimeWindowPercentileSamplerTest.java +++ b/core/src/test/java/com/linecorp/armeria/common/util/TimeWindowPercentileSamplerTest.java @@ -23,7 +23,8 @@ public class TimeWindowPercentileSamplerTest { @Test public void testSamplingMinimumPercentile() { - final Sampler sampler = TimeWindowPercentileSampler.create(0.0f, 10000L); + TimeWindowPercentileSampler.SNAPSHOT_UPDATE_MILLIS = 0; + final Sampler sampler = TimeWindowPercentileSampler.create(0.0f, 10000000L); // Should sample everything assertThat(sampler.isSampled(10L)).isTrue(); @@ -33,7 +34,8 @@ public void testSamplingMinimumPercentile() { @Test public void testSamplingMaximumPercentile() { - final Sampler sampler = TimeWindowPercentileSampler.create(1.0f, 10000L); + TimeWindowPercentileSampler.SNAPSHOT_UPDATE_MILLIS = 0; + final Sampler sampler = TimeWindowPercentileSampler.create(1.0f, 10000000L); // Should only sample the maximum value assertThat(sampler.isSampled(10L)).isTrue(); @@ -48,6 +50,7 @@ public void testSamplingMaximumPercentile() { @Test public void testSamplingWindowExpires() throws InterruptedException { final long windowLength = 1000L; + TimeWindowPercentileSampler.SNAPSHOT_UPDATE_MILLIS = 0; final Sampler sampler = TimeWindowPercentileSampler.create(1.0f, windowLength); // Should only sample the maximum value @@ -61,6 +64,7 @@ public void testSamplingWindowExpires() throws InterruptedException { @Test public void testSampling0_5Percentile() { + TimeWindowPercentileSampler.SNAPSHOT_UPDATE_MILLIS = 0; final Sampler sampler = TimeWindowPercentileSampler.create(.5f, 10000L); // Create a uniform distribution of 1000 values from 1 to 1000 @@ -75,6 +79,7 @@ public void testSampling0_5Percentile() { @Test public void testSampling0_95Percentile() { + TimeWindowPercentileSampler.SNAPSHOT_UPDATE_MILLIS = 0; final Sampler sampler = TimeWindowPercentileSampler.create(.95f, 10000L); // Create a uniform distribution of 1000 values from 1 to 1000 From a26c7be8f51feb02b5e68a062f2f94ce6f336dc8 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Do=C4=9Fa=C3=A7=20Eldenk?= Date: Fri, 20 Oct 2023 16:16:21 +0300 Subject: [PATCH 6/6] comment resolution and much more tests --- .../util/TimeWindowPercentileSampler.java | 48 ++++++--- .../decorator/LoggingDecorator.java | 14 +-- .../LoggingDecoratorFactoryFunction.java | 11 ++- .../server/logging/LoggingServiceBuilder.java | 27 +++-- .../util/TimeWindowPercentileSamplerTest.java | 23 ++--- .../DecoratorAnnotationUtilTest.java | 25 +++++ .../server/logging/LoggingServiceTest.java | 99 +++++++++++++++++++ 7 files changed, 205 insertions(+), 42 deletions(-) diff --git a/core/src/main/java/com/linecorp/armeria/common/util/TimeWindowPercentileSampler.java b/core/src/main/java/com/linecorp/armeria/common/util/TimeWindowPercentileSampler.java index cebcab053b1..bd0ca9ff42b 100644 --- a/core/src/main/java/com/linecorp/armeria/common/util/TimeWindowPercentileSampler.java +++ b/core/src/main/java/com/linecorp/armeria/common/util/TimeWindowPercentileSampler.java @@ -10,9 +10,11 @@ package com.linecorp.armeria.common.util; import java.time.Duration; +import java.util.concurrent.TimeUnit; import java.util.concurrent.atomic.AtomicReference; import com.google.common.annotations.VisibleForTesting; +import com.google.common.base.MoreObjects; import com.linecorp.armeria.common.metric.MoreMeters; @@ -29,20 +31,21 @@ final class TimeWindowPercentileSampler implements Sampler { private final float percentile; private final long windowLengthMillis; private final TimeWindowPercentileHistogram histogram; - @VisibleForTesting - static long SNAPSHOT_UPDATE_MILLIS = 1000L; - private long lastSnapshotMillis; + private final long snapshotUpdateNanos; + private static final long DEFAULT_SNAPSHOT_UPDATE_NANOS = TimeUnit.SECONDS.toNanos(1); + private long lastSnapshotNanos; private HistogramSnapshot histogramSnapshot; private final Clock clock; private final AtomicReference isTakingSnapshot = new AtomicReference<>(false); TimeWindowPercentileSampler(float percentile, long windowLengthMillis) { - this(percentile, windowLengthMillis, Clock.SYSTEM); + this(percentile, windowLengthMillis, Clock.SYSTEM, DEFAULT_SNAPSHOT_UPDATE_NANOS); } @VisibleForTesting - TimeWindowPercentileSampler(float percentile, long windowLengthMillis, Clock clock) { + TimeWindowPercentileSampler(float percentile, long windowLengthMillis, Clock clock, + long snapshotUpdateNanos) { this.percentile = percentile; this.windowLengthMillis = windowLengthMillis; @@ -54,24 +57,37 @@ final class TimeWindowPercentileSampler implements Sampler { .build() .merge(MoreMeters.distributionStatisticConfig()); this.histogram = new TimeWindowPercentileHistogram(clock, distributionStatisticConfig, true); + this.snapshotUpdateNanos = snapshotUpdateNanos; this.histogramSnapshot = histogram.takeSnapshot(0, 0, 0); this.clock = clock; - this.lastSnapshotMillis = clock.wallTime(); + this.lastSnapshotNanos = clock.monotonicTime(); } - static TimeWindowPercentileSampler create(float percentile, long windowLengthMillis) { - return new TimeWindowPercentileSampler(percentile, windowLengthMillis); + @VisibleForTesting + static TimeWindowPercentileSampler create(float percentile, long windowLengthMillis, + long snapshotUpdateNanos) { + return new TimeWindowPercentileSampler(percentile, windowLengthMillis, Clock.SYSTEM, + snapshotUpdateNanos); } @Override public boolean isSampled(Long t) { histogram.recordLong(t); - if (lastSnapshotMillis + SNAPSHOT_UPDATE_MILLIS <= clock.wallTime()) { + System.out.println("lastSnapshotNanos: " + lastSnapshotNanos); + System.out.println("snapshotUpdateNanos: " + snapshotUpdateNanos); + System.out.println("clock.monotonicTime(): " + clock.monotonicTime()); + + if (lastSnapshotNanos + snapshotUpdateNanos <= clock.monotonicTime()) { if (isTakingSnapshot.compareAndSet(false, true)) { - histogramSnapshot = histogram.takeSnapshot(0, 0, 0); - lastSnapshotMillis = clock.wallTime(); - isTakingSnapshot.set(false); + // Two threads reach here back to back. Make sure snapshot is not taken very recently before + // we acquired the lock. + if (lastSnapshotNanos + snapshotUpdateNanos <= clock.monotonicTime()) { + System.out.println("Taking snapshot"); + histogramSnapshot = histogram.takeSnapshot(0, 0, 0); + lastSnapshotNanos = clock.monotonicTime(); + isTakingSnapshot.set(false); + } } } @@ -81,7 +97,11 @@ public boolean isSampled(Long t) { @Override public String toString() { - return "TimeWindowPercentileSampler with " + windowLengthMillis + " ms window and " + percentile + - " percentile"; + return MoreObjects.toStringHelper(this) + .omitNullValues() + .add("percentile", percentile) + .add("windowLengthMillis", windowLengthMillis) + .add("snapshotUpdateNanos", snapshotUpdateNanos) + .toString(); } } diff --git a/core/src/main/java/com/linecorp/armeria/server/annotation/decorator/LoggingDecorator.java b/core/src/main/java/com/linecorp/armeria/server/annotation/decorator/LoggingDecorator.java index 299c47a0ff4..08f921756fa 100644 --- a/core/src/main/java/com/linecorp/armeria/server/annotation/decorator/LoggingDecorator.java +++ b/core/src/main/java/com/linecorp/armeria/server/annotation/decorator/LoggingDecorator.java @@ -90,20 +90,20 @@ float slowRequestSamplingPercentile() default -1.0f; /** - * Slow request percentiles are calculated over the last {@code slowRequestSamplingWindowMilliseconds}. + * Slow request percentiles are calculated over the last {@code slowRequestSamplingWindowMillis}. */ - long slowRequestSamplingWindowMilliseconds() default 10 * 60 * 1000; + long slowRequestSamplingWindowMillis() default 10 * 60 * 1000; /** - * Don't sample the requests if they are faster than the {@code slowRequestSamplingLowerBoundMilliseconds}. - * Should be used with {@link #slowRequestSamplingUpperBoundMilliseconds()}. + * Don't sample the requests if they are faster than the {@code slowRequestSamplingLowerBoundMillis()}. + * Should be used with {@link #slowRequestSamplingUpperBoundMillis()}. */ - long slowRequestSamplingLowerBoundMilliseconds() default 0L; + long slowRequestSamplingLowerBoundMillis() default 0L; /** - * Always sample the requests if they are slower than the {@code slowRequestSamplingUpperBoundMilliseconds}. + * Always sample the requests if they are slower than the {@code slowRequestSamplingUpperBoundMillis()}. */ - long slowRequestSamplingUpperBoundMilliseconds() default Long.MAX_VALUE; + long slowRequestSamplingUpperBoundMillis() default Long.MAX_VALUE; /** * The order of decoration, where a {@link Decorator} of lower value will be applied first. diff --git a/core/src/main/java/com/linecorp/armeria/server/annotation/decorator/LoggingDecoratorFactoryFunction.java b/core/src/main/java/com/linecorp/armeria/server/annotation/decorator/LoggingDecoratorFactoryFunction.java index 304d18a1376..7ca1d20dd85 100644 --- a/core/src/main/java/com/linecorp/armeria/server/annotation/decorator/LoggingDecoratorFactoryFunction.java +++ b/core/src/main/java/com/linecorp/armeria/server/annotation/decorator/LoggingDecoratorFactoryFunction.java @@ -50,11 +50,14 @@ public final class LoggingDecoratorFactoryFunction implements DecoratorFactoryFu .successSamplingRate(successSamplingRate) .failureSamplingRate(failureSamplingRate); - if (parameter.slowRequestSamplingPercentile() >= 0.0f) { + if ( + parameter.slowRequestSamplingPercentile() >= 0.0f || + parameter.slowRequestSamplingUpperBoundMillis() >= 0 + ) { builder.slowRequestSamplingPercentile(parameter.slowRequestSamplingPercentile(), - parameter.slowRequestSamplingWindowMilliseconds(), - parameter.slowRequestSamplingLowerBoundMilliseconds(), - parameter.slowRequestSamplingUpperBoundMilliseconds()); + parameter.slowRequestSamplingWindowMillis(), + parameter.slowRequestSamplingLowerBoundMillis(), + parameter.slowRequestSamplingUpperBoundMillis()); } return builder.newDecorator(); } diff --git a/core/src/main/java/com/linecorp/armeria/server/logging/LoggingServiceBuilder.java b/core/src/main/java/com/linecorp/armeria/server/logging/LoggingServiceBuilder.java index 74c74396c16..147e7981963 100644 --- a/core/src/main/java/com/linecorp/armeria/server/logging/LoggingServiceBuilder.java +++ b/core/src/main/java/com/linecorp/armeria/server/logging/LoggingServiceBuilder.java @@ -19,6 +19,7 @@ import static com.google.common.base.Preconditions.checkArgument; import static java.util.Objects.requireNonNull; +import java.util.concurrent.TimeUnit; import java.util.function.BiFunction; import java.util.function.Function; import java.util.function.Predicate; @@ -153,23 +154,37 @@ public LoggingServiceBuilder failureSamplingRate(float failureSamplingRate) { * @param slowRequestSamplingUpperBoundMilliseconds upper bound of slow requests. * Any request that took more than this amount of time will be sampled regardless * of their percentile. + * */ public LoggingServiceBuilder slowRequestSamplingPercentile(float slowRequestPercentile, long windowMilliseconds, long slowRequestSamplingLowerBoundMilliseconds, long slowRequestSamplingUpperBoundMilliseconds) { + // Check if configuration is valid. A valid configuration requires at least one parameter to be set + // correctly. Either `slowRequestPercentile` or `slowRequestSamplingUpperBoundMilliseconds` should be + // set to a value that would trigger sampling. + if ((slowRequestPercentile <= 0.0 || windowMilliseconds <= 0) && + slowRequestSamplingUpperBoundMilliseconds == Long.MAX_VALUE) { + // Ignore the invalid configuration. + return this; + } + + // Samplers should use Nanoseconds as the unit. final Sampler percentileMatches; if (0.0 <= slowRequestPercentile && slowRequestPercentile <= 1.0) { - percentileMatches = Sampler.never(); - } else { percentileMatches = Sampler.percentile(slowRequestPercentile, windowMilliseconds); + } else { + percentileMatches = Sampler.never(); } - final Sampler isSlow = Sampler.greaterThanOrEqual( - slowRequestSamplingLowerBoundMilliseconds * 1000); - final Sampler isVerySlow = Sampler.greaterThan(slowRequestSamplingUpperBoundMilliseconds * 1000); + final long slowEnoughNanos = TimeUnit.MILLISECONDS.toNanos(slowRequestSamplingLowerBoundMilliseconds); + final Sampler isSlowEnough = Sampler.greaterThanOrEqual(slowEnoughNanos); + + final long verySlowNanos = TimeUnit.MILLISECONDS.toNanos(slowRequestSamplingUpperBoundMilliseconds); + final Sampler isVerySlow = Sampler.greaterThan(verySlowNanos); + return slowRequestSampler( - isVerySlow.or(percentileMatches.and(isSlow)) + isVerySlow.or(isSlowEnough.and(percentileMatches)) ); } diff --git a/core/src/test/java/com/linecorp/armeria/common/util/TimeWindowPercentileSamplerTest.java b/core/src/test/java/com/linecorp/armeria/common/util/TimeWindowPercentileSamplerTest.java index b970df55703..50d21c2f9ce 100644 --- a/core/src/test/java/com/linecorp/armeria/common/util/TimeWindowPercentileSamplerTest.java +++ b/core/src/test/java/com/linecorp/armeria/common/util/TimeWindowPercentileSamplerTest.java @@ -18,13 +18,15 @@ import static org.assertj.core.api.Assertions.assertThat; +import java.util.concurrent.TimeUnit; + import org.junit.jupiter.api.Test; public class TimeWindowPercentileSamplerTest { @Test public void testSamplingMinimumPercentile() { - TimeWindowPercentileSampler.SNAPSHOT_UPDATE_MILLIS = 0; - final Sampler sampler = TimeWindowPercentileSampler.create(0.0f, 10000000L); + final Sampler sampler = TimeWindowPercentileSampler.create(0.0f, + TimeUnit.SECONDS.toMillis(60), 0L); // Should sample everything assertThat(sampler.isSampled(10L)).isTrue(); @@ -34,8 +36,8 @@ public void testSamplingMinimumPercentile() { @Test public void testSamplingMaximumPercentile() { - TimeWindowPercentileSampler.SNAPSHOT_UPDATE_MILLIS = 0; - final Sampler sampler = TimeWindowPercentileSampler.create(1.0f, 10000000L); + final Sampler sampler = TimeWindowPercentileSampler.create(1.0f, + TimeUnit.SECONDS.toMillis(60), 0L); // Should only sample the maximum value assertThat(sampler.isSampled(10L)).isTrue(); @@ -49,9 +51,8 @@ public void testSamplingMaximumPercentile() { @Test public void testSamplingWindowExpires() throws InterruptedException { - final long windowLength = 1000L; - TimeWindowPercentileSampler.SNAPSHOT_UPDATE_MILLIS = 0; - final Sampler sampler = TimeWindowPercentileSampler.create(1.0f, windowLength); + final long windowLength = TimeUnit.SECONDS.toMillis(1); + final Sampler sampler = TimeWindowPercentileSampler.create(1.0f, windowLength, 0L); // Should only sample the maximum value assertThat(sampler.isSampled(20L)).isTrue(); @@ -64,8 +65,8 @@ public void testSamplingWindowExpires() throws InterruptedException { @Test public void testSampling0_5Percentile() { - TimeWindowPercentileSampler.SNAPSHOT_UPDATE_MILLIS = 0; - final Sampler sampler = TimeWindowPercentileSampler.create(.5f, 10000L); + final Sampler sampler = TimeWindowPercentileSampler.create(.5f, + TimeUnit.SECONDS.toMillis(60), 0L); // Create a uniform distribution of 1000 values from 1 to 1000 for (long i = 1; i <= 1000; i++) { @@ -79,8 +80,8 @@ public void testSampling0_5Percentile() { @Test public void testSampling0_95Percentile() { - TimeWindowPercentileSampler.SNAPSHOT_UPDATE_MILLIS = 0; - final Sampler sampler = TimeWindowPercentileSampler.create(.95f, 10000L); + final Sampler sampler = TimeWindowPercentileSampler.create(.95f, + TimeUnit.SECONDS.toMillis(60), 0); // Create a uniform distribution of 1000 values from 1 to 1000 for (long i = 1; i <= 1000; i++) { diff --git a/core/src/test/java/com/linecorp/armeria/internal/server/annotation/DecoratorAnnotationUtilTest.java b/core/src/test/java/com/linecorp/armeria/internal/server/annotation/DecoratorAnnotationUtilTest.java index d15fc0a8ecf..3570f8367b1 100644 --- a/core/src/test/java/com/linecorp/armeria/internal/server/annotation/DecoratorAnnotationUtilTest.java +++ b/core/src/test/java/com/linecorp/armeria/internal/server/annotation/DecoratorAnnotationUtilTest.java @@ -122,6 +122,24 @@ void ofUserDefinedRepeatableDecorator() throws NoSuchMethodException { assertThat(udd2.value()).isEqualTo(2); } + @Test + void ofSlowSamplingRequest() throws Exception { + final List list = + DecoratorAnnotationUtil.collectDecorators(TestClass.class, + TestClass.class.getMethod("slowRequestSampling")); + + assertThat(values(list)).containsExactly(Decorator1.class, + LoggingDecoratorFactoryFunction.class, + LoggingDecoratorFactoryFunction.class); + + final LoggingDecorator loggingDecorator = (LoggingDecorator) list.get(2).annotation(); + + assertThat(loggingDecorator.slowRequestSamplingPercentile()).isEqualTo(0.5f); + assertThat(loggingDecorator.slowRequestSamplingLowerBoundMillis()).isEqualTo(1L); + assertThat(loggingDecorator.slowRequestSamplingUpperBoundMillis()).isEqualTo(10L); + assertThat(loggingDecorator.slowRequestSamplingWindowMillis()).isEqualTo(100L); + } + private static List> values(List list) { return list.stream() .map(DecoratorAndOrder::annotation) @@ -189,6 +207,13 @@ public String globalScopeOrdering() { public String userDefinedRepeatableDecorator() { return ""; } + + @LoggingDecorator( + slowRequestSamplingPercentile = 0.5f, slowRequestSamplingLowerBoundMillis = 1L, + slowRequestSamplingUpperBoundMillis = 10L, slowRequestSamplingWindowMillis = 100L) + public String slowRequestSampling() { + return ""; + } } @Retention(RetentionPolicy.RUNTIME) diff --git a/core/src/test/java/com/linecorp/armeria/server/logging/LoggingServiceTest.java b/core/src/test/java/com/linecorp/armeria/server/logging/LoggingServiceTest.java index 2925f4b0311..7900002b710 100644 --- a/core/src/test/java/com/linecorp/armeria/server/logging/LoggingServiceTest.java +++ b/core/src/test/java/com/linecorp/armeria/server/logging/LoggingServiceTest.java @@ -52,6 +52,7 @@ import com.linecorp.armeria.common.logging.LogLevel; import com.linecorp.armeria.common.logging.LogWriter; import com.linecorp.armeria.common.logging.RegexBasedSanitizer; +import com.linecorp.armeria.common.util.Sampler; import com.linecorp.armeria.internal.common.logging.LoggingTestUtil; import com.linecorp.armeria.internal.testing.ImmediateEventLoop; import com.linecorp.armeria.server.HttpResponseException; @@ -659,4 +660,102 @@ void sanitizerAndLogWriterCanNotSetTogether() { .hasMessageContaining( "The logWriter and the log properties cannot be set together."); } + + @Test + void slowRequestSampler() throws Exception { + final ServiceRequestContext ctx = serviceRequestContext(); + final Logger logger = LoggingTestUtil.newMockLogger(ctx, capturedCause); + when(logger.isDebugEnabled()).thenReturn(true); + final LoggingService service = + LoggingService.builder() + .slowRequestSampler(Sampler.always()) + .logWriter(LogWriter.builder() + .logger(logger) + .build()) + .samplingRate(0.0f) + .newDecorator() + .apply(delegate); + + service.serve(ctx, ctx.request()); + + verify(logger).debug(matches(".*Response:.*totalDuration=.*")); + } + + @Test + void slowRequestSamplerNever() throws Exception { + final ServiceRequestContext ctx = serviceRequestContext(); + final Logger logger = LoggingTestUtil.newMockLogger(ctx, capturedCause); + final LoggingService service = + LoggingService.builder() + .slowRequestSampler(Sampler.never()) + .logWriter(LogWriter.builder() + .logger(logger) + .build()) + .samplingRate(0.0f) + .newDecorator() + .apply(delegate); + + service.serve(ctx, ctx.request()); + + verifyNoInteractions(logger); + } + + @Test + void slowRequestSamplerPercentage() throws Exception { + final ServiceRequestContext ctx = serviceRequestContext(); + final Logger logger = LoggingTestUtil.newMockLogger(ctx, capturedCause); + when(logger.isDebugEnabled()).thenReturn(true); + final LoggingService service = + LoggingService.builder() + .slowRequestSamplingPercentile(1.0f, 60_000L, 0L, Long.MAX_VALUE) + .logWriter(LogWriter.builder() + .logger(logger) + .build()) + .samplingRate(0.0f) + .newDecorator() + .apply(delegate); + + service.serve(ctx, ctx.request()); + + verify(logger).debug(matches(".*Response:.*totalDuration=.*")); + } + + @Test + void slowRequestSamplerUpperBound() throws Exception { + final ServiceRequestContext ctx = serviceRequestContext(); + final Logger logger = LoggingTestUtil.newMockLogger(ctx, capturedCause); + when(logger.isDebugEnabled()).thenReturn(true); + final LoggingService service = + LoggingService.builder() + .slowRequestSamplingPercentile(0.0f, 60_000L, 0L, 1L) + .logWriter(LogWriter.builder() + .logger(logger) + .build()) + .samplingRate(0.0f) + .newDecorator() + .apply(delegate); + + service.serve(ctx, ctx.request()); + + verify(logger).debug(matches(".*Response:.*totalDuration=.*")); + } + + @Test + void slowRequestSamplerLowerBound() throws Exception { + final ServiceRequestContext ctx = serviceRequestContext(); + final Logger logger = LoggingTestUtil.newMockLogger(ctx, capturedCause); + final LoggingService service = + LoggingService.builder() + .slowRequestSamplingPercentile(1.0f, 60_000L, 10000L, Long.MAX_VALUE) + .logWriter(LogWriter.builder() + .logger(logger) + .build()) + .samplingRate(0.0f) + .newDecorator() + .apply(delegate); + + service.serve(ctx, ctx.request()); + + verifyNoInteractions(logger); + } }