Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

GRPC serialization errors when apply all executors instrumentation #5293

Closed
Asafb26 opened this issue Feb 2, 2022 · 7 comments
Closed

GRPC serialization errors when apply all executors instrumentation #5293

Asafb26 opened this issue Feb 2, 2022 · 7 comments
Labels
bug Something isn't working

Comments

@Asafb26
Copy link
Contributor

Asafb26 commented Feb 2, 2022 •
edited
Loading

Describe the bug
We use spring-boot with grpc-java version 1.42.0, our first grpc request test result with a broken context.
We think that it related to executors instrumentation which wasn't applied at this point (can it be related? can we propagate grpc requests without the executor instrumentation?), so we added the sysprop System.setProperty("otel.instrumentation.executors.include-all", "true")
Now we see an error on debug mode:

[otel.javaagent 2022-02-02 18:34:31:843 +0200] [http-nio-2728-exec-7] DEBUG io.opentelemetry.javaagent.tooling.AgentInstaller$TransformLoggingListener - Failed to handle io.grpc.internal.SerializingExecutor for transformation on classloader jdk.internal.loader.ClassLoaders$AppClassLoader@73d16e93
java.lang.IllegalStateException: Cannot assign void to interface java.util.concurrent.Future
	at net.bytebuddy.asm.Advice$OffsetMapping$ForReturnValue.resolve(Advice.java:3554)
	at net.bytebuddy.asm.Advice$Dispatcher$Inlining$Resolved$ForMethodExit.doApply(Advice.java:8960)
	at net.bytebuddy.asm.Advice$Dispatcher$Inlining$Resolved$ForMethodExit.apply(Advice.java:8918)
	at net.bytebuddy.asm.Advice$Dispatcher$Inlining$Resolved$AdviceMethodInliner.visitMethod(Advice.java:8332)
	at org.objectweb.asm.ClassReader.readMethod(ClassReader.java:1353)
	at org.objectweb.asm.ClassReader.accept(ClassReader.java:744)
	at org.objectweb.asm.ClassReader.accept(ClassReader.java:424)
	at net.bytebuddy.asm.Advice$Dispatcher$Inlining$Resolved$AdviceMethodInliner.apply(Advice.java:8325)
	at net.bytebuddy.asm.Advice$AdviceVisitor$WithExitAdvice.onUserEnd(Advice.java:10835)
	at net.bytebuddy.asm.Advice$AdviceVisitor.visitMaxs(Advice.java:10614)
	at org.objectweb.asm.MethodVisitor.visitMaxs(MethodVisitor.java:773)
	at org.objectweb.asm.ClassReader.readCode(ClassReader.java:2665)
	at org.objectweb.asm.ClassReader.readMethod(ClassReader.java:1514)
	at org.objectweb.asm.ClassReader.accept(ClassReader.java:744)
	at org.objectweb.asm.ClassReader.accept(ClassReader.java:424)
	at net.bytebuddy.dynamic.scaffold.TypeWriter$Default$ForInlining.create(TypeWriter.java:3951)
	at net.bytebuddy.dynamic.scaffold.TypeWriter$Default.make(TypeWriter.java:2213)
	at net.bytebuddy.dynamic.scaffold.inline.RedefinitionDynamicTypeBuilder.make(RedefinitionDynamicTypeBuilder.java:224)
	at net.bytebuddy.agent.builder.AgentBuilder$Default$ExecutingTransformer.doTransform(AgentBuilder.java:11757)
	at net.bytebuddy.agent.builder.AgentBuilder$Default$ExecutingTransformer.transform(AgentBuilder.java:11692)
	at net.bytebuddy.agent.builder.AgentBuilder$Default$ExecutingTransformer.access$1700(AgentBuilder.java:11405)
	at net.bytebuddy.agent.builder.AgentBuilder$Default$ExecutingTransformer$Java9CapableVmDispatcher.run(AgentBuilder.java:12172)
	at net.bytebuddy.agent.builder.AgentBuilder$Default$ExecutingTransformer$Java9CapableVmDispatcher.run(AgentBuilder.java:12104)
	at java.base/java.security.AccessController.doPrivileged(AccessController.java:391)
	at net.bytebuddy.agent.builder.AgentBuilder$Default$ExecutingTransformer.doPrivileged(AgentBuilder.java)
	at net.bytebuddy.agent.builder.AgentBuilder$Default$ExecutingTransformer.transform(AgentBuilder.java:11633)
	at net.bytebuddy.agent.builder.AgentBuilder$Default$ExecutingTransformer$ByteBuddy$ModuleSupport.transform(Unknown Source)
	at java.instrument/sun.instrument.TransformerManager.transform(TransformerManager.java:188)
	at java.instrument/sun.instrument.InstrumentationImpl.transform(InstrumentationImpl.java:563)
	at java.base/java.lang.ClassLoader.defineClass1(Native Method)
	at java.base/java.lang.ClassLoader.defineClass(ClassLoader.java:1016)
	at java.base/java.security.SecureClassLoader.defineClass(SecureClassLoader.java:151)
	at java.base/jdk.internal.loader.BuiltinClassLoader.defineClass(BuiltinClassLoader.java:825)
	at java.base/jdk.internal.loader.BuiltinClassLoader.findClassOnClassPathOrNull(BuiltinClassLoader.java:723)
	at java.base/jdk.internal.loader.BuiltinClassLoader.loadClassOrNull(BuiltinClassLoader.java:646)
	at java.base/jdk.internal.loader.BuiltinClassLoader.loadClass(BuiltinClassLoader.java:604)
	at java.base/jdk.internal.loader.ClassLoaders$AppClassLoader.loadClass(ClassLoaders.java:168)
	at java.base/java.lang.ClassLoader.loadClass(ClassLoader.java:522)
	at io.grpc.internal.ClientCallImpl.<init>(ClientCallImpl.java:114)
	at io.grpc.internal.ManagedChannelImpl$RealChannel$1.newCall(ManagedChannelImpl.java:955)
	at io.grpc.internal.ManagedChannelImpl$RealChannel.newClientCall(ManagedChannelImpl.java:1144)
	at io.grpc.internal.ManagedChannelImpl$RealChannel.access$4500(ManagedChannelImpl.java:936)
	at io.grpc.internal.ManagedChannelImpl$RealChannel$PendingCall$1.run(ManagedChannelImpl.java:1106)
	at io.grpc.stub.ClientCalls$ThreadlessExecutor.waitAndDrain(ClientCalls.java:741)
	at io.grpc.stub.ClientCalls.blockingUnaryCall(ClientCalls.java:149)
	at bianka.service.v1.BiankaServiceGrpc$BiankaServiceBlockingStub.reportBusiness(BiankaServiceGrpc.java:282)
	at com.fiverr.kore.utils.bianka.BiankaService.reportBusiness(BiankaService.kt:39)
	at com.fiverr.kore.utils.bianka.BiankaService.reportBusiness$default(BiankaService.kt:24)
	at com.fiverr.apps.cms_kimera.api.handler.ContentfulApiProxy.ping(ContentfulApiProxy.kt:48)
	at com.fiverr.apps.cms_kimera.configuration.RouteConfiguration$routes$1$1$1$1.invoke(RouteConfiguration.kt:18)
	at com.fiverr.apps.cms_kimera.configuration.RouteConfiguration$routes$1$1$1$1.invoke(RouteConfiguration.kt:18)
	at org.springframework.web.servlet.function.RouterFunctionDslKt$sam$org_springframework_web_servlet_function_HandlerFunction$0.handle(RouterFunctionDsl.kt)
	at org.springframework.web.servlet.function.support.HandlerFunctionAdapter.handle(HandlerFunctionAdapter.java:106)
	at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1067)
	at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:963)
	at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1006)
	at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:898)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:655)
	at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:883)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:764)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:227)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162)
	at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162)
	at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:100)
	at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:117)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162)
	at org.springframework.web.filter.FormContentFilter.doFilterInternal(FormContentFilter.java:93)
	at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:117)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162)
	at org.springframework.boot.actuate.metrics.web.servlet.WebMvcMetricsFilter.doFilterInternal(WebMvcMetricsFilter.java:96)
	at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:117)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162)
	at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:201)
	at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:117)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162)
	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:197)
	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:97)
	at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:540)
	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:135)
	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92)
	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:78)
	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:357)
	at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:382)
	at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65)
	at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:895)
	at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1732)
	at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
	at org.apache.tomcat.util.threads.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1191)
	at org.apache.tomcat.util.threads.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:659)
	at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
	at java.base/java.lang.Thread.run(Thread.java:832)

What did you expect to see?
The same traceId propagated successfully on the consumer.

What did you see instead?
Missing traceID on the consumer.

What version are you using?
v1.10.0
@Asafb26 Asafb26 added the bug Something isn't working label Feb 2, 2022
@mateuszrzeszutek mateuszrzeszutek mentioned this issue Feb 2, 2022
Merged
@Asafb26
Copy link
Contributor Author

Asafb26 commented Feb 3, 2022

@mateuszrzeszutek we found more errors:

java.lang.IllegalStateException: Cannot assign class io.grpc.SynchronizationContext$ScheduledHandle to interface java.util.concurrent.Future
	at net.bytebuddy.asm.Advice$OffsetMapping$ForReturnValue.resolve(Advice.java:3554)
	at net.bytebuddy.asm.Advice$Dispatcher$Inlining$Resolved$ForMethodExit.doApply(Advice.java:8960)
	at net.bytebuddy.asm.Advice$Dispatcher$Inlining$Resolved$ForMethodExit.apply(Advice.java:8918)
	at net.bytebuddy.asm.Advice$Dispatcher$Inlining$Resolved$AdviceMethodInliner.visitMethod(Advice.java:8332)
	at org.objectweb.asm.ClassReader.readMethod(ClassReader.java:1353)
	at org.objectweb.asm.ClassReader.accept(ClassReader.java:744)
	at org.objectweb.asm.ClassReader.accept(ClassReader.java:424)
	at net.bytebuddy.asm.Advice$Dispatcher$Inlining$Resolved$AdviceMethodInliner.apply(Advice.java:8325)
	at net.bytebuddy.asm.Advice$AdviceVisitor$WithExitAdvice.onUserEnd(Advice.java:10835)
	at net.bytebuddy.asm.Advice$AdviceVisitor.visitMaxs(Advice.java:10614)
	at org.objectweb.asm.ClassReader.readCode(ClassReader.java:2665)
	at org.objectweb.asm.ClassReader.readMethod(ClassReader.java:1514)
	at org.objectweb.asm.ClassReader.accept(ClassReader.java:744)
	at org.objectweb.asm.ClassReader.accept(ClassReader.java:424)
	at net.bytebuddy.dynamic.scaffold.TypeWriter$Default$ForInlining.create(TypeWriter.java:3951)
	at net.bytebuddy.dynamic.scaffold.TypeWriter$Default.make(TypeWriter.java:2213)
	at net.bytebuddy.dynamic.scaffold.inline.RedefinitionDynamicTypeBuilder.make(RedefinitionDynamicTypeBuilder.java:224)
	at net.bytebuddy.agent.builder.AgentBuilder$Default$ExecutingTransformer.doTransform(AgentBuilder.java:11757)
	at net.bytebuddy.agent.builder.AgentBuilder$Default$ExecutingTransformer.transform(AgentBuilder.java:11692)
	at net.bytebuddy.agent.builder.AgentBuilder$Default$ExecutingTransformer.access$1700(AgentBuilder.java:11405)
	at net.bytebuddy.agent.builder.AgentBuilder$Default$ExecutingTransformer$Java9CapableVmDispatcher.run(AgentBuilder.java:12172)
	at net.bytebuddy.agent.builder.AgentBuilder$Default$ExecutingTransformer$Java9CapableVmDispatcher.run(AgentBuilder.java:12104)
	at java.base/java.security.AccessController.doPrivileged(AccessController.java:391)
	at net.bytebuddy.agent.builder.AgentBuilder$Default$ExecutingTransformer.doPrivileged(AgentBuilder.java)
	at net.bytebuddy.agent.builder.AgentBuilder$Default$ExecutingTransformer.transform(AgentBuilder.java:11633)
	at net.bytebuddy.agent.builder.AgentBuilder$Default$ExecutingTransformer$ByteBuddy$ModuleSupport.transform(Unknown Source)
	at java.instrument/sun.instrument.TransformerManager.transform(TransformerManager.java:188)
	at java.instrument/sun.instrument.InstrumentationImpl.transform(InstrumentationImpl.java:563)
	at java.instrument/sun.instrument.InstrumentationImpl.retransformClasses0(Native Method)
	at java.instrument/sun.instrument.InstrumentationImpl.retransformClasses(InstrumentationImpl.java:167)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:64)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:564)
	at net.bytebuddy.utility.Invoker$Dispatcher.invoke(Unknown Source)
	at net.bytebuddy.utility.dispatcher.JavaDispatcher$Dispatcher$ForNonStaticMethod.invoke(JavaDispatcher.java:1019)
	at net.bytebuddy.utility.dispatcher.JavaDispatcher$ProxiedInvocationHandler.invoke(JavaDispatcher.java:1149)
	at net.bytebuddy.agent.builder.$Proxy140.retransformClasses(Unknown Source)
	at net.bytebuddy.agent.builder.AgentBuilder$RedefinitionStrategy$Collector$ForRetransformation.doApply(AgentBuilder.java:7998)
	at net.bytebuddy.agent.builder.AgentBuilder$RedefinitionStrategy$Collector.apply(AgentBuilder.java:7813)
	at net.bytebuddy.agent.builder.AgentBuilder$RedefinitionStrategy.apply(AgentBuilder.java:5631)
	at net.bytebuddy.agent.builder.AgentBuilder$Default.doInstall(AgentBuilder.java:10785)
	at net.bytebuddy.agent.builder.AgentBuilder$Default.installOn(AgentBuilder.java:10711)
	at net.bytebuddy.agent.builder.AgentBuilder$Default$Delegator.installOn(AgentBuilder.java:12447)
	at io.opentelemetry.javaagent.tooling.AgentInstaller.installBytebuddyAgent(AgentInstaller.java:175)
	at io.opentelemetry.javaagent.tooling.AgentInstaller.installBytebuddyAgent(AgentInstaller.java:96)
	at io.opentelemetry.javaagent.tooling.AgentStarterImpl.start(AgentStarterImpl.java:65)
	at io.opentelemetry.javaagent.bootstrap.AgentInitializer.initialize(AgentInitializer.java:37)
	at io.opentelemetry.javaagent.OpenTelemetryAgent.startAgent(OpenTelemetryAgent.java:55)
	at io.opentelemetry.javaagent.OpenTelemetryAgent.agentmain(OpenTelemetryAgent.java:48)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:64)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:564)
	at java.instrument/sun.instrument.InstrumentationImpl.loadClassAndStartAgent(InstrumentationImpl.java:513)
	at java.instrument/sun.instrument.InstrumentationImpl.loadClassAndCallAgentmain(InstrumentationImpl.java:535)

@mateuszrzeszutek
Copy link
Member

Hey @Asafb26 ,
Did that error occur with the latest javaagent SNAPSHOT version? (one that contains my fix from yesterday)

@Asafb26
Copy link
Contributor Author

Asafb26 commented Feb 3, 2022

Hey @Asafb26 , Did that error occur with the latest javaagent SNAPSHOT version? (one that contains my fix from yesterday)

Apparently, the 1.11.0 snapshot fixed that issue.
but we still have a broken context on GRPC, we have no idea why

@trask
Copy link
Member

trask commented Feb 3, 2022

@Asafb26 can you create a repro of the broken context issue that we can use to troubleshoot it?

@Asafb26
Copy link
Contributor Author

Asafb26 commented Feb 7, 2022

@Asafb26 can you create a repro of the broken context issue that we can use to troubleshoot it?

Sure, What exactly do you need?

@mateuszrzeszutek
Copy link
Member

mateuszrzeszutek commented Feb 7, 2022 •
edited
Loading

Sure, What exactly do you need?

A small repository containing simple app(s) that reproduce your issue would be very appreciated 👍

@laurit
Copy link
Contributor

laurit commented Feb 24, 2022

Feel free to reopen when you are ready to provide additional details.

@laurit laurit closed this as completed Feb 24, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
bug Something isn't working
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
4 participants
@trask @laurit @Asafb26 @mateuszrzeszutek