From 58e2224df9b8f55cf2ecbd298e8fdfed03590426 Mon Sep 17 00:00:00 2001 From: Larry Safran <107004254+larry-safran@users.noreply.github.com> Date: Fri, 24 Mar 2023 16:40:35 -0700 Subject: [PATCH] Fix order dependent tests regarding message duration b/271122310 (#9930) * Fix order dependent test by changing the initializations and comparison so that elapsed time isn't as significant in identifying whether it was the context or call option's duration that was used. fixes b/271122310 --- ...InternalLoggingChannelInterceptorTest.java | 19 +++++++++--------- .../InternalLoggingServerInterceptorTest.java | 2 +- .../protobuf/services/BinlogHelperTest.java | 20 ++++++++++--------- 3 files changed, 22 insertions(+), 19 deletions(-) diff --git a/gcp-observability/src/test/java/io/grpc/gcp/observability/interceptors/InternalLoggingChannelInterceptorTest.java b/gcp-observability/src/test/java/io/grpc/gcp/observability/interceptors/InternalLoggingChannelInterceptorTest.java index 7458a5329c..19e5724bcb 100644 --- a/gcp-observability/src/test/java/io/grpc/gcp/observability/interceptors/InternalLoggingChannelInterceptorTest.java +++ b/gcp-observability/src/test/java/io/grpc/gcp/observability/interceptors/InternalLoggingChannelInterceptorTest.java @@ -352,11 +352,12 @@ public class InternalLoggingChannelInterceptorTest { @SuppressWarnings("unchecked") ClientCall.Listener mockListener = mock(ClientCall.Listener.class); + int durationSecs = 5; ClientCall interceptedLoggingCall = factory.create() .interceptCall( method, - CallOptions.DEFAULT.withDeadlineAfter(1, TimeUnit.SECONDS), + CallOptions.DEFAULT.withDeadlineAfter(durationSecs, TimeUnit.SECONDS), new Channel() { @Override public ClientCall newCall( @@ -387,8 +388,8 @@ public class InternalLoggingChannelInterceptorTest { ArgumentMatchers.any()), any(SpanContext.class)); Duration timeout = callOptTimeoutCaptor.getValue(); - assertThat(TimeUnit.SECONDS.toNanos(1) - Durations.toNanos(timeout)) - .isAtMost(TimeUnit.MILLISECONDS.toNanos(250)); + assertThat(Math.abs(TimeUnit.SECONDS.toNanos(durationSecs) - Durations.toNanos(timeout))) + .isAtMost(TimeUnit.MILLISECONDS.toNanos(750)); } @Test @@ -396,7 +397,7 @@ public class InternalLoggingChannelInterceptorTest { final SettableFuture> callFuture = SettableFuture.create(); Context.current() .withDeadline( - Deadline.after(1, TimeUnit.SECONDS), + Deadline.after(2, TimeUnit.SECONDS), Executors.newSingleThreadScheduledExecutor()) .run(() -> { MethodDescriptor method = @@ -413,7 +414,7 @@ public class InternalLoggingChannelInterceptorTest { factory.create() .interceptCall( method, - CallOptions.DEFAULT.withDeadlineAfter(1, TimeUnit.SECONDS), + CallOptions.DEFAULT.withDeadlineAfter(5, TimeUnit.SECONDS), new Channel() { @Override public ClientCall newCall( @@ -447,8 +448,8 @@ public class InternalLoggingChannelInterceptorTest { ArgumentMatchers.any()), any(SpanContext.class)); Duration timeout = contextTimeoutCaptor.getValue(); - assertThat(TimeUnit.SECONDS.toNanos(1) - Durations.toNanos(timeout)) - .isAtMost(TimeUnit.MILLISECONDS.toNanos(250)); + assertThat(Math.abs(TimeUnit.SECONDS.toNanos(2) - Durations.toNanos(timeout))) + .isAtMost(TimeUnit.MILLISECONDS.toNanos(750)); } @Test @@ -512,8 +513,8 @@ public class InternalLoggingChannelInterceptorTest { Duration timeout = timeoutCaptor.getValue(); assertThat(LogHelper.min(contextDeadline, callOptionsDeadline)) .isSameInstanceAs(contextDeadline); - assertThat(TimeUnit.SECONDS.toNanos(10) - Durations.toNanos(timeout)) - .isAtMost(TimeUnit.MILLISECONDS.toNanos(250)); + assertThat(Math.abs(TimeUnit.SECONDS.toNanos(10) - Durations.toNanos(timeout))) + .isAtMost(TimeUnit.MILLISECONDS.toNanos(750)); } @Test diff --git a/gcp-observability/src/test/java/io/grpc/gcp/observability/interceptors/InternalLoggingServerInterceptorTest.java b/gcp-observability/src/test/java/io/grpc/gcp/observability/interceptors/InternalLoggingServerInterceptorTest.java index fc4eec7f44..23cd59178c 100644 --- a/gcp-observability/src/test/java/io/grpc/gcp/observability/interceptors/InternalLoggingServerInterceptorTest.java +++ b/gcp-observability/src/test/java/io/grpc/gcp/observability/interceptors/InternalLoggingServerInterceptorTest.java @@ -354,7 +354,7 @@ public class InternalLoggingServerInterceptorTest { eq(SpanContext.INVALID)); verifyNoMoreInteractions(mockLogHelper); Duration timeout = timeoutCaptor.getValue(); - assertThat(TimeUnit.SECONDS.toNanos(1) - Durations.toNanos(timeout)) + assertThat(Math.abs(TimeUnit.SECONDS.toNanos(1) - Durations.toNanos(timeout))) .isAtMost(TimeUnit.MILLISECONDS.toNanos(250)); } diff --git a/services/src/test/java/io/grpc/protobuf/services/BinlogHelperTest.java b/services/src/test/java/io/grpc/protobuf/services/BinlogHelperTest.java index 37e503ccd4..d9b335d117 100644 --- a/services/src/test/java/io/grpc/protobuf/services/BinlogHelperTest.java +++ b/services/src/test/java/io/grpc/protobuf/services/BinlogHelperTest.java @@ -979,7 +979,7 @@ public final class BinlogHelperTest { ArgumentMatchers.isNull()); verifyNoMoreInteractions(mockSinkWriter); Duration timeout = timeoutCaptor.getValue(); - assertThat(TimeUnit.SECONDS.toNanos(1) - Durations.toNanos(timeout)) + assertThat(Math.abs(TimeUnit.SECONDS.toNanos(1) - Durations.toNanos(timeout))) .isAtMost(TimeUnit.MILLISECONDS.toNanos(250)); } @@ -1000,7 +1000,7 @@ public final class BinlogHelperTest { .getClientInterceptor(CALL_ID) .interceptCall( method, - CallOptions.DEFAULT.withDeadlineAfter(1, TimeUnit.SECONDS), + CallOptions.DEFAULT.withDeadlineAfter(2, TimeUnit.SECONDS), new Channel() { @Override public ClientCall newCall( @@ -1028,17 +1028,18 @@ public final class BinlogHelperTest { AdditionalMatchers.or(ArgumentMatchers.isNull(), ArgumentMatchers.any())); Duration timeout = callOptTimeoutCaptor.getValue(); - assertThat(TimeUnit.SECONDS.toNanos(1) - Durations.toNanos(timeout)) - .isAtMost(TimeUnit.MILLISECONDS.toNanos(250)); + assertThat(Math.abs(TimeUnit.SECONDS.toNanos(2) - Durations.toNanos(timeout))) + .isAtMost(TimeUnit.MILLISECONDS.toNanos(750)); } @Test public void clientDeadlineLogged_deadlineSetViaContext() throws Exception { // important: deadline is read from the ctx where call was created final SettableFuture> callFuture = SettableFuture.create(); + Deadline expectedDeadline = Deadline.after(2, TimeUnit.SECONDS); Context.current() .withDeadline( - Deadline.after(1, TimeUnit.SECONDS), Executors.newSingleThreadScheduledExecutor()) + expectedDeadline, Executors.newSingleThreadScheduledExecutor()) .run(new Runnable() { @Override public void run() { @@ -1054,7 +1055,7 @@ public final class BinlogHelperTest { .getClientInterceptor(CALL_ID) .interceptCall( method, - CallOptions.DEFAULT.withDeadlineAfter(1, TimeUnit.SECONDS), + CallOptions.DEFAULT.withDeadlineAfter(10, TimeUnit.SECONDS), new Channel() { @Override public ClientCall newCall( @@ -1085,9 +1086,10 @@ public final class BinlogHelperTest { anyLong(), AdditionalMatchers.or(ArgumentMatchers.isNull(), ArgumentMatchers.any())); - Duration timeout = callOptTimeoutCaptor.getValue(); - assertThat(TimeUnit.SECONDS.toNanos(1) - Durations.toNanos(timeout)) - .isAtMost(TimeUnit.MILLISECONDS.toNanos(250)); + long expectedTimeRemaining = expectedDeadline.timeRemaining(TimeUnit.NANOSECONDS); + long timeout = Durations.toNanos(callOptTimeoutCaptor.getValue()); + assertThat(Math.abs(expectedTimeRemaining - timeout)) + .isAtMost(TimeUnit.MILLISECONDS.toNanos(750)); } @Test