# Bugreport: APM Plugin GRPC in combination with grpc-spring-boot-starter
**URL:** https://discuss.elastic.co/t/bugreport-apm-plugin-grpc-in-combination-with-grpc-spring-boot-starter/337669
**Category:** APM
**Tags:** java
**Created:** [July 5, 2023, 12:04pm UTC](https://discuss.elastic.co/t/bugreport-apm-plugin-grpc-in-combination-with-grpc-spring-boot-starter/337669 "2023-07-05T12:04:33Z")
**Posts on this page:** 6
**Page:** 1
### Author:  [@hackermann](https://discuss.elastic.co/u/hackermann)
#### Post date: [July 5, 2023, 12:04pm UTC](https://discuss.elastic.co/t/bugreport-apm-plugin-grpc-in-combination-with-grpc-spring-boot-starter/337669/1 "2023-07-05T12:04:33Z")
Hey Elastic APM Team,
I would like to report a bug for: [GitHub - elastic/apm-agent-java: Elastic APM Java Agent](https://github.com/elastic/apm-agent-java) (apm-agent-plugins/apm-grpc/apm-grpc-plugin)
**APM Agent language and version** : Java, 1.39.0
**tl;dr**
A warning will be shown for every grpc-request, if those 2 dependencies are both used in a project:
1. [GitHub - elastic/apm-agent-java: Elastic APM Java Agent](https://github.com/elastic/apm-agent-java) (apm-agent-plugins/apm-grpc/apm-grpc-plugin, newest version 1.39.0)
2. [GitHub - yidongnan/grpc-spring-boot-starter: Spring Boot starter module for gRPC framework.](https://github.com/yidongnan/grpc-spring-boot-starter) (newest version 2.14.0.RELEASE) -- The most commonly used spring-boot / grpc integration
I do not think it is really the fault of the second dependency, I debugged into the problem a bit and I think this dependency uses a feature of the official grpc library, that is not commonly used otherwise.
**Bug description**
The first GRPC request of a freshly started micro-service throws the following exception:
```auto
WARN co.elastic.apm.agent.impl.transaction.AbstractSpan - End has already been called: 'de.testservice.TestService/> testRequest' 00-00000000000000000000000000000000-0000000000000000-00 (000000)
java.lang.Throwable: null
at co.elastic.apm.agent.impl.transaction.AbstractSpan.end(AbstractSpan.java:584) ~[elastic-apm-agent-00000000000000000000000000000000-00000000000000000000000000000000.jar:1.39.0]
at co.elastic.apm.agent.impl.transaction.AbstractSpan.end(AbstractSpan.java:559) ~[elastic-apm-agent-00000000000000000000000000000000-00000000000000000000000000000000.jar:1.39.0]
at co.elastic.apm.agent.grpc.GrpcHelper.exitServerListenerMethod(GrpcHelper.java:272) ~[elastic-apm-agent-00000000000000000000000000000000-00000000000000000000000000000000.jar:1.39.0]
at co.elastic.apm.agent.grpc.ServerCallListenerInstrumentation$OnComplete$OnCompleteAdvice.onExit(ServerCallListenerInstrumentation.java:166) > ~[elastic-apm-agent-00000000000000000000000000000000-00000000000000000000000000000000.jar:1.39.0]
at io.grpc.Contexts$ContextualizedServerCallListener.onComplete(Contexts.java:110) ~[grpc-api-1.51.0.jar!/:1.51.0]
at io.grpc.internal.ServerCallImpl$ServerStreamListenerImpl.closedInternal(ServerCallImpl.java:375) ~[grpc-core-1.51.0.jar!/:1.51.0]
at io.grpc.internal.ServerCallImpl$ServerStreamListenerImpl.closed(ServerCallImpl.java:365) ~[grpc-core-1.51.0.jar!/:1.51.0]
at io.grpc.internal.ServerImpl$JumpToApplicationThreadServerStreamListener$1Closed.runInContext(ServerImpl.java:923) ~[grpc-core-1.51.0.jar!/:1.51.0]
at io.grpc.internal.ContextRunnable.run(ContextRunnable.java:37) ~[grpc-core-1.51.0.jar!/:1.51.0]
at io.grpc.internal.SerializingExecutor.run(SerializingExecutor.java:133) ~[grpc-core-1.51.0.jar!/:1.51.0]
at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source) ~[?:?]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source) ~[?:?]
at java.lang.Thread.run(Unknown Source) [?:?]
```
Every other request just logs a warning:
```auto
WARN co.elastic.apm.agent.impl.transaction.AbstractSpan - End has already been called: 'de.testservice.TestService/> testRequest' 00-00000000000000000000000000000000-0000000000000000-00 (000000)
```
**Minimal reproducible example**
I tried to create a service of minimal size, that can be used to reproduce the bug. To start the code, set the environment variable ELASTIC\_APM\_SECRET\_TOKEN and then:
```auto
mvn clean install spring-boot:run
```
The sourcecode can be found here: 5.189.140.198/test-service.zip
**My thoughts on what goes wrong**
I tried to debug a bit into it myself, because I thought at first the bug might be in the other dependency. I think the problem is as follows:
grpc-spring-boot-starter uses the officially supported method:
io.grpc.Contexts.interceptCall
to integrate grpc into spring-boot. This constructs a ContextualizedServerCallListener, which overrides the method onComplete, but also calls super.onComplete in this overwritten method.
But now
co.elastic.apm.agent.grpc.OnComplete.OnCompleteAdvice
gets called twice with the same listener, once for the onComplete and once for the super.onComplete (instead of just once as usually, if another listener is used)
In the debugger we now see the following invocations:
```auto
GrpcHelper.getInstance().enterServerListenerMethod(A);
GrpcHelper.getInstance().enterServerListenerMethod(A);
GrpcHelper.getInstance().exitServerListenerMethod(thrown, A, transaction, Status.CANCELLED);
GrpcHelper.getInstance().exitServerListenerMethod(thrown, A, transaction, Status.CANCELLED);
```
The last exitServerListenerMethod invocation now writes the warning, because A was already exited before.
I am not 100% sure that this is the problem, but it looks like if I debug into it with and without the grpc-spring-boot-starter dependency in use.
**Conclusion**
For now, I would be happy if you could confirm or deny that bug, because we see **a lot** of those warnings in all our micro-services. If you need anything else from me, I am happy to help.
Kind regards,
Hilmar
---
### Author:  [@Sylvain\_Juge](https://discuss.elastic.co/u/Sylvain_Juge)
#### Post date: [July 5, 2023, 2:12pm UTC](https://discuss.elastic.co/t/bugreport-apm-plugin-grpc-in-combination-with-grpc-spring-boot-starter/337669/2 "2023-07-05T14:12:42Z")
Hi @hackermann, welcome to the forum and thanks for reporting this.
As you've managed to create a minimal project to reproduce this, do you mind pushing it directly on a github repo so we could easily reproduce it on our side ?
This extra warning definitely looks like a bug in what you described, so we'd better investigate that while you have a reproducible way to trigger it at hand.
---
### Author:  [@hackermann](https://discuss.elastic.co/u/hackermann)
#### Post date: [July 5, 2023, 2:31pm UTC](https://discuss.elastic.co/t/bugreport-apm-plugin-grpc-in-combination-with-grpc-spring-boot-starter/337669/3 "2023-07-05T14:31:11Z")
Hey @Sylvain_Juge
yes sure, I created the following repo with the code:
[Github Repo](https://github.com/hackermann/reproducible_example_bug_elastic_apm_grpc)
Kind regards,
Hilmar
---
### Author:  [@Sylvain\_Juge](https://discuss.elastic.co/u/Sylvain_Juge)
#### Post date: [July 6, 2023, 2:22pm UTC](https://discuss.elastic.co/t/bugreport-apm-plugin-grpc-in-combination-with-grpc-spring-boot-starter/337669/4 "2023-07-06T14:22:45Z")
Hi @hackermann ,
Thanks for providing a sample project, that made reproducing the issue trivial !!
In this case there is effectively a call to `onCancel` which is a bit odd to me as the request processing completes, and I thought that this kind of call only happened when there was a timeout or when the client stopped waiting for the response.
However, it definitely looks like a corner case and due to an implementation detail, as the transaction seems to be perfectly captured otherwise I think it's fine to surgically avoid double-ending the transaction when this happens.
Could you test with [this agent snapshot](https://github.com/elastic/apm-agent-java/suites/14107814972/artifacts/789368828) (to be used with `-javaagent` unlike the provided project that used the programmatic attach), hopefully the issue is gone and we can include this fix for the next release.
---
### Author:  [@hackermann](https://discuss.elastic.co/u/hackermann)
#### Post date: [July 7, 2023, 8:24am UTC](https://discuss.elastic.co/t/bugreport-apm-plugin-grpc-in-combination-with-grpc-spring-boot-starter/337669/5 "2023-07-07T08:24:14Z")
Hey @Sylvain_Juge ,
Thanks for the fast reply.
I just tried the snapshot on our original code, and it worked! I did not see any warnings anymore.
Kind regards,
Hilmar
---
### Author:  [@system](https://discuss.elastic.co/u/system)
#### Post date: [August 4, 2023, 8:24am UTC](https://discuss.elastic.co/t/bugreport-apm-plugin-grpc-in-combination-with-grpc-spring-boot-starter/337669/6 "2023-08-04T08:24:55Z")
This topic was automatically closed 28 days after the last reply. New replies are no longer allowed.