Skip to content

gRPC flaky test: "INTERNAL" where "OK" is expected #1280

Closed
#1613
Closed
gRPC flaky test: "INTERNAL" where "OK" is expected#1280
#1613
Labels
agent-javaflaky-testUnstable or unreliable test cases.
Milestone
7.11
@SylvainJuge

Description

@SylvainJuge
SylvainJuge
opened on Jul 8, 2020

Test method

co.elastic.apm.agent.grpc.AbstractGrpcServerInstrumentationTest.serverListenerException

Expecting:
 <"INTERNAL">
to be equal to:
 <"OK">
but was not.

Test logs

Click to expand 
org.opentest4j.AssertionFailedError: 
Expecting:
 <"INTERNAL">
to be equal to:
 <"OK">
but was not.
	at java.base/jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
	at java.base/jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
	at java.base/jdk.internal.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
	at co.elastic.apm.agent.grpc.AbstractGrpcServerInstrumentationTest.checkUnaryTransaction(AbstractGrpcServerInstrumentationTest.java:201)
	at co.elastic.apm.agent.grpc.AbstractGrpcServerInstrumentationTest.serverListenerException(AbstractGrpcServerInstrumentationTest.java:181)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
	at org.junit.platform.commons.util.ReflectionUtils.invokeMethod(ReflectionUtils.java:686)
	at org.junit.jupiter.engine.execution.MethodInvocation.proceed(MethodInvocation.java:60)
	at org.junit.jupiter.engine.execution.InvocationInterceptorChain$ValidatingInvocation.proceed(InvocationInterceptorChain.java:131)
	at org.junit.jupiter.engine.extension.TimeoutExtension.intercept(TimeoutExtension.java:149)
	at org.junit.jupiter.engine.extension.TimeoutExtension.interceptTestableMethod(TimeoutExtension.java:140)
	at org.junit.jupiter.engine.extension.TimeoutExtension.interceptTestTemplateMethod(TimeoutExtension.java:92)
	at org.junit.jupiter.engine.execution.ExecutableInvoker$ReflectiveInterceptorCall.lambda$ofVoidMethod$0(ExecutableInvoker.java:115)
	at org.junit.jupiter.engine.execution.ExecutableInvoker.lambda$invoke$0(ExecutableInvoker.java:105)
	at org.junit.jupiter.engine.execution.InvocationInterceptorChain$InterceptedInvocation.proceed(InvocationInterceptorChain.java:106)
	at org.junit.jupiter.engine.execution.InvocationInterceptorChain.proceed(InvocationInterceptorChain.java:64)
	at org.junit.jupiter.engine.execution.InvocationInterceptorChain.chainAndInvoke(InvocationInterceptorChain.java:45)
	at org.junit.jupiter.engine.execution.InvocationInterceptorChain.invoke(InvocationInterceptorChain.java:37)
	at org.junit.jupiter.engine.execution.ExecutableInvoker.invoke(ExecutableInvoker.java:104)
	at org.junit.jupiter.engine.execution.ExecutableInvoker.invoke(ExecutableInvoker.java:98)
	at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.lambda$invokeTestMethod$6(TestMethodTestDescriptor.java:212)
	at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
	at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.invokeTestMethod(TestMethodTestDescriptor.java:208)
	at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.execute(TestMethodTestDescriptor.java:137)
	at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.execute(TestMethodTestDescriptor.java:71)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$5(NodeTestTask.java:135)
	at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$7(NodeTestTask.java:125)
	at org.junit.platform.engine.support.hierarchical.Node.around(Node.java:135)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$8(NodeTestTask.java:123)
	at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.executeRecursively(NodeTestTask.java:122)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.execute(NodeTestTask.java:80)
	at org.junit.platform.engine.support.hierarchical.SameThreadHierarchicalTestExecutorService.submit(SameThreadHierarchicalTestExecutorService.java:32)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask$DefaultDynamicTestExecutor.execute(NodeTestTask.java:198)
	at org.junit.jupiter.engine.descriptor.TestTemplateTestDescriptor.execute(TestTemplateTestDescriptor.java:138)
	at org.junit.jupiter.engine.descriptor.TestTemplateTestDescriptor.lambda$execute$2(TestTemplateTestDescriptor.java:106)
	at java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.accept(ForEachOps.java:183)
	at java.base/java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:195)
	at java.base/java.util.stream.ReferencePipeline$2$1.accept(ReferencePipeline.java:177)
	at java.base/java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:195)
	at java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.accept(ForEachOps.java:183)
	at java.base/java.util.stream.ReferencePipeline$11$1.accept(ReferencePipeline.java:442)
	at java.base/java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:195)
	at java.base/java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:195)
	at java.base/java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:195)
	at java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.accept(ForEachOps.java:183)
	at java.base/java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:195)
	at java.base/java.util.Spliterators$ArraySpliterator.forEachRemaining(Spliterators.java:948)
	at java.base/java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:484)
	at java.base/java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:474)
	at java.base/java.util.stream.ForEachOps$ForEachOp.evaluateSequential(ForEachOps.java:150)
	at java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.evaluateSequential(ForEachOps.java:173)
	at java.base/java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234)
	at java.base/java.util.stream.ReferencePipeline.forEach(ReferencePipeline.java:497)
	at java.base/java.util.stream.ReferencePipeline$7$1.accept(ReferencePipeline.java:274)
	at java.base/java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:195)
	at java.base/java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:195)
	at java.base/java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:195)
	at java.base/java.util.ArrayList$ArrayListSpliterator.forEachRemaining(ArrayList.java:1654)
	at java.base/java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:484)
	at java.base/java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:474)
	at java.base/java.util.stream.ForEachOps$ForEachOp.evaluateSequential(ForEachOps.java:150)
	at java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.evaluateSequential(ForEachOps.java:173)
	at java.base/java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234)
	at java.base/java.util.stream.ReferencePipeline.forEach(ReferencePipeline.java:497)
	at java.base/java.util.stream.ReferencePipeline$7$1.accept(ReferencePipeline.java:274)
	at java.base/java.util.ArrayList$ArrayListSpliterator.forEachRemaining(ArrayList.java:1654)
	at java.base/java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:484)
	at java.base/java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:474)
	at java.base/java.util.stream.ForEachOps$ForEachOp.evaluateSequential(ForEachOps.java:150)
	at java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.evaluateSequential(ForEachOps.java:173)
	at java.base/java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234)
	at java.base/java.util.stream.ReferencePipeline.forEach(ReferencePipeline.java:497)
	at org.junit.jupiter.engine.descriptor.TestTemplateTestDescriptor.execute(TestTemplateTestDescriptor.java:106)
	at org.junit.jupiter.engine.descriptor.TestTemplateTestDescriptor.execute(TestTemplateTestDescriptor.java:41)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$5(NodeTestTask.java:135)
	at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$7(NodeTestTask.java:125)
	at org.junit.platform.engine.support.hierarchical.Node.around(Node.java:135)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$8(NodeTestTask.java:123)
	at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.executeRecursively(NodeTestTask.java:122)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.execute(NodeTestTask.java:80)
	at java.base/java.util.ArrayList.forEach(ArrayList.java:1540)
	at org.junit.platform.engine.support.hierarchical.SameThreadHierarchicalTestExecutorService.invokeAll(SameThreadHierarchicalTestExecutorService.java:38)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$5(NodeTestTask.java:139)
	at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$7(NodeTestTask.java:125)
	at org.junit.platform.engine.support.hierarchical.Node.around(Node.java:135)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$8(NodeTestTask.java:123)
	at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.executeRecursively(NodeTestTask.java:122)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.execute(NodeTestTask.java:80)
	at java.base/java.util.ArrayList.forEach(ArrayList.java:1540)
	at org.junit.platform.engine.support.hierarchical.SameThreadHierarchicalTestExecutorService.invokeAll(SameThreadHierarchicalTestExecutorService.java:38)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$5(NodeTestTask.java:139)
	at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$7(NodeTestTask.java:125)
	at org.junit.platform.engine.support.hierarchical.Node.around(Node.java:135)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$8(NodeTestTask.java:123)
	at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.executeRecursively(NodeTestTask.java:122)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.execute(NodeTestTask.java:80)
	at org.junit.platform.engine.support.hierarchical.SameThreadHierarchicalTestExecutorService.submit(SameThreadHierarchicalTestExecutorService.java:32)
	at org.junit.platform.engine.support.hierarchical.HierarchicalTestExecutor.execute(HierarchicalTestExecutor.java:57)
	at org.junit.platform.engine.support.hierarchical.HierarchicalTestEngine.execute(HierarchicalTestEngine.java:51)
	at org.junit.platform.launcher.core.DefaultLauncher.execute(DefaultLauncher.java:220)
	at org.junit.platform.launcher.core.DefaultLauncher.lambda$execute$6(DefaultLauncher.java:188)
	at org.junit.platform.launcher.core.DefaultLauncher.withInterceptedStreams(DefaultLauncher.java:202)
	at org.junit.platform.launcher.core.DefaultLauncher.execute(DefaultLauncher.java:181)
	at org.junit.platform.launcher.core.DefaultLauncher.execute(DefaultLauncher.java:128)
	at org.apache.maven.surefire.junitplatform.JUnitPlatformProvider.invokeAllTests(JUnitPlatformProvider.java:150)
	at org.apache.maven.surefire.junitplatform.JUnitPlatformProvider.invoke(JUnitPlatformProvider.java:124)
	at org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:384)
	at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:345)
	at org.apache.maven.surefire.booter.ForkedBooter.execute(ForkedBooter.java:126)
	at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:418)
Standard Output
2020-07-08 16:38:34,707 [main] INFO  co.elastic.apm.agent.grpc.testapp.HelloServer - starting grpc server on port 24299
2020-07-08 16:38:34,710 [main] INFO  co.elastic.apm.agent.grpc.testapp.HelloServer - grpc server start complete
2020-07-08 16:38:34,717 [grpc-server-0] DEBUG co.elastic.apm.agent.objectpool.impl.BookkeeperObjectPool - creating pooled object: '' 00-00000000000000000000000000000000-0000000000000000-00 (12750efd)
2020-07-08 16:38:34,718 [grpc-server-0] DEBUG co.elastic.apm.agent.impl.transaction.AbstractSpan - increment references to '' 00-f0f68920474975eb7d2fb801a18a4903-f4068d35460326ee-01 (12750efd) (1)
2020-07-08 16:38:34,718 [grpc-server-0] DEBUG co.elastic.apm.agent.impl.ElasticApmTracer - startTransaction '' 00-f0f68920474975eb7d2fb801a18a4903-f4068d35460326ee-01 (12750efd) {
2020-07-08 16:38:34,718 [grpc-server-0] DEBUG co.elastic.apm.agent.impl.ElasticApmTracer - Activating 'helloworld.Hello/SayHello' 00-f0f68920474975eb7d2fb801a18a4903-f4068d35460326ee-01 (12750efd) on thread 135
2020-07-08 16:38:34,718 [grpc-server-0] DEBUG co.elastic.apm.agent.impl.transaction.AbstractSpan - increment references to 'helloworld.Hello/SayHello' 00-f0f68920474975eb7d2fb801a18a4903-f4068d35460326ee-01 (12750efd) (2)
2020-07-08 16:38:34,719 [grpc-server-0] DEBUG co.elastic.apm.agent.impl.ElasticApmTracer - Deactivating 'helloworld.Hello/SayHello' 00-f0f68920474975eb7d2fb801a18a4903-f4068d35460326ee-01 (12750efd) on thread 135
2020-07-08 16:38:34,719 [grpc-server-0] DEBUG co.elastic.apm.agent.impl.transaction.AbstractSpan - decrement references to 'helloworld.Hello/SayHello' 00-f0f68920474975eb7d2fb801a18a4903-f4068d35460326ee-01 (12750efd) (1)
2020-07-08 16:38:34,719 [grpc-server-0] DEBUG co.elastic.apm.agent.impl.ElasticApmTracer - Activating 'helloworld.Hello/SayHello' 00-f0f68920474975eb7d2fb801a18a4903-f4068d35460326ee-01 (12750efd) on thread 135
2020-07-08 16:38:34,719 [grpc-server-0] DEBUG co.elastic.apm.agent.impl.transaction.AbstractSpan - increment references to 'helloworld.Hello/SayHello' 00-f0f68920474975eb7d2fb801a18a4903-f4068d35460326ee-01 (12750efd) (2)
2020-07-08 16:38:34,719 [grpc-server-0] DEBUG co.elastic.apm.agent.impl.ElasticApmTracer - Deactivating 'helloworld.Hello/SayHello' 00-f0f68920474975eb7d2fb801a18a4903-f4068d35460326ee-01 (12750efd) on thread 135
2020-07-08 16:38:34,719 [grpc-server-0] DEBUG co.elastic.apm.agent.impl.transaction.AbstractSpan - decrement references to 'helloworld.Hello/SayHello' 00-f0f68920474975eb7d2fb801a18a4903-f4068d35460326ee-01 (12750efd) (1)
2020-07-08 16:38:34,720 [grpc-server-0] DEBUG co.elastic.apm.agent.impl.ElasticApmTracer - Activating 'helloworld.Hello/SayHello' 00-f0f68920474975eb7d2fb801a18a4903-f4068d35460326ee-01 (12750efd) on thread 135
2020-07-08 16:38:34,720 [grpc-server-0] DEBUG co.elastic.apm.agent.impl.transaction.AbstractSpan - increment references to 'helloworld.Hello/SayHello' 00-f0f68920474975eb7d2fb801a18a4903-f4068d35460326ee-01 (12750efd) (2)
2020-07-08 16:38:34,720 [grpc-server-0] DEBUG co.elastic.apm.agent.impl.ElasticApmTracer - Deactivating 'helloworld.Hello/SayHello' 00-f0f68920474975eb7d2fb801a18a4903-f4068d35460326ee-01 (12750efd) on thread 135
2020-07-08 16:38:34,720 [grpc-server-0] DEBUG co.elastic.apm.agent.impl.transaction.AbstractSpan - decrement references to 'helloworld.Hello/SayHello' 00-f0f68920474975eb7d2fb801a18a4903-f4068d35460326ee-01 (12750efd) (1)
2020-07-08 16:38:34,720 [grpc-server-0] DEBUG co.elastic.apm.agent.impl.ElasticApmTracer - Activating 'helloworld.Hello/SayHello' 00-f0f68920474975eb7d2fb801a18a4903-f4068d35460326ee-01 (12750efd) on thread 135
2020-07-08 16:38:34,721 [grpc-server-0] DEBUG co.elastic.apm.agent.impl.transaction.AbstractSpan - increment references to 'helloworld.Hello/SayHello' 00-f0f68920474975eb7d2fb801a18a4903-f4068d35460326ee-01 (12750efd) (2)
2020-07-08 16:38:34,721 [grpc-server-0] INFO  co.elastic.apm.agent.grpc.testapp.HelloServer - start processing
2020-07-08 16:38:34,721 [grpc-server-0] INFO  co.elastic.apm.agent.grpc.testapp.HelloServer - end of processing, response not sent yet
2020-07-08 16:38:34,721 [grpc-server-0] INFO  co.elastic.apm.agent.grpc.testapp.HelloServer - start sending response
2020-07-08 16:38:34,722 [grpc-server-0] INFO  co.elastic.apm.agent.grpc.testapp.HelloServer - end of sending response
2020-07-08 16:38:34,722 [grpc-server-0] DEBUG co.elastic.apm.agent.impl.ElasticApmTracer - Deactivating 'helloworld.Hello/SayHello' 00-f0f68920474975eb7d2fb801a18a4903-f4068d35460326ee-01 (12750efd) on thread 135
2020-07-08 16:38:34,722 [grpc-server-0] DEBUG co.elastic.apm.agent.impl.transaction.AbstractSpan - decrement references to 'helloworld.Hello/SayHello' 00-f0f68920474975eb7d2fb801a18a4903-f4068d35460326ee-01 (12750efd) (1)
2020-07-08 16:38:34,723 [grpc-server-1] DEBUG co.elastic.apm.agent.impl.ElasticApmTracer - Activating 'helloworld.Hello/SayHello' 00-f0f68920474975eb7d2fb801a18a4903-f4068d35460326ee-01 (12750efd) on thread 136
2020-07-08 16:38:34,724 [grpc-server-1] DEBUG co.elastic.apm.agent.impl.transaction.AbstractSpan - increment references to 'helloworld.Hello/SayHello' 00-f0f68920474975eb7d2fb801a18a4903-f4068d35460326ee-01 (12750efd) (2)
2020-07-08 16:38:34,724 [grpc-server-1] DEBUG co.elastic.apm.agent.impl.ElasticApmTracer - Deactivating 'helloworld.Hello/SayHello' 00-f0f68920474975eb7d2fb801a18a4903-f4068d35460326ee-01 (12750efd) on thread 136
2020-07-08 16:38:34,724 [grpc-server-1] DEBUG co.elastic.apm.agent.impl.transaction.AbstractSpan - decrement references to 'helloworld.Hello/SayHello' 00-f0f68920474975eb7d2fb801a18a4903-f4068d35460326ee-01 (12750efd) (1)
2020-07-08 16:38:34,725 [grpc-server-1] DEBUG co.elastic.apm.agent.impl.ElasticApmTracer - endTransaction 'helloworld.Hello/SayHello' 00-f0f68920474975eb7d2fb801a18a4903-f4068d35460326ee-01 (12750efd)
2020-07-08 16:38:34,756 [main] DEBUG co.elastic.apm.agent.impl.transaction.AbstractSpan - decrement references to 'helloworld.Hello/SayHello' 00-f0f68920474975eb7d2fb801a18a4903-f4068d35460326ee-01 (12750efd) (0)
2020-07-08 16:38:34,756 [main] DEBUG co.elastic.apm.agent.objectpool.impl.BookkeeperObjectPool - recycling pooled object: 'helloworld.Hello/SayHello' 00-f0f68920474975eb7d2fb801a18a4903-f4068d35460326ee-01 (12750efd)
2020-07-08 16:38:34,961 [main] INFO  co.elastic.apm.agent.grpc.testapp.HelloClient - client channel has been properly shut down
2020-07-08 16:38:34,961 [main] INFO  co.elastic.apm.agent.grpc.testapp.HelloServer - stopping grpc server
2020-07-08 16:38:34,963 [main] INFO  co.elastic.apm.agent.grpc.testapp.HelloServer - grpc server shutdown complete

Additional context

Metadata

Metadata

Assignees

No one assigned

    Labels

    agent-javaflaky-testUnstable or unreliable test cases.

    Type

    No type

    Fields

    No fields configured for issues without a type.

    Projects

    No projects

    Milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions