search

newrelic / newrelic-java-agent

The New Relic Java agent
Apache License 2.0
202 stars 143 forks source link

successfully delay creation of transactions #479

Closed smiklos closed 2 years ago

smiklos commented 3 years ago

Overview

This pr moves creation of the transaction to happen when the request is actually run and not during the construction of the effect itself. This seems to cause invalid tracer states and nullpointer exceptions in one of our application that uses cats effect and Doobie.

This fix is only an assumption as debugging/reproducing this is relatively time consuming. According to how cats effect support is implemented the transaction creation should be delayed which is done by wrapping that into Sync.delay(AgentBridge.instrumentation.createScalaTxnTracer()). This works because delay take a call by name parameter. However, the construct helper method takes a call by value parameter and therefor circumvents the lazy evaluation of creating the transaction.

In our application I believe that this leads to the tracer being null by the time completeTxn is run and therefor causes our backend to return 500 error.

Related 'stack trace' (as seen in cloudwatch logs)

2021-10-11 17:06:55java.lang.NullPointerException: null
2021-10-11 17:06:55at com.nr.instrumentation.http4s.TransactionMiddleware$.completeTxn(TransactionMiddleware.scala:36)
2021-10-11 17:06:55at com.nr.instrumentation.http4s.TransactionMiddleware$.$anonfun$nrRequestResponse$5(TransactionMiddleware.scala:21)
2021-10-11 17:06:55at evalOn @ doobie.util.transactor$Transactor$fromDataSource$FromDataSourceUnapplied.$anonfun$apply$13(transactor.scala:294)
2021-10-11 17:06:55at $anonfun$tailRecM$1 @ doobie.free.KleisliInterpreter$ConnectionInterpreter.$anonfun$bracketCase$28(kleisliinterpreter.scala:750)
2021-10-11 17:06:55at evalOn @ doobie.util.transactor$Transactor$fromDataSource$FromDataSourceUnapplied.$anonfun$apply$13(transactor.scala:294)

Other error logs during execution 

2021-10-11T15:06:55,882+0000 [1 35] com.newrelic ERROR: Inconsistent state! tracer != last tracer for com.newrelic.agent.TransactionActivity@0 (com.newrelic.agent.tracers.OtherRootTracer@5b415617 != com.newrelic.agent.tracers.OtherRootTracer@3d974848)

Checks

[ ] Are your contributions backwards compatible with relevant frameworks and APIs? [ ] Does your code contain any breaking changes? Nope.
[ ] Does your code introduce any new dependencies? Nope.

CLAassistant commented 3 years ago

CLA assistant check
All committers have signed the CLA.

smiklos commented 3 years ago

Just added a test that fails on master but no longer fails on this branch. Getting exactly the same errors as in our setup

twcrone commented 3 years ago

Thanks! One of our Scala engineers is working on applying your fix to other versions as well. He will include your commits in his PR soon.

jasonjkeller commented 3 years ago

@twcrone Can you confirm what the status of this PR is? From your last comment it sounds like these changes might be pulled into a larger PR and that this one should be closed. Is that correct? Or is the goal to merge this PR?

twcrone commented 3 years ago

@twcrone Can you confirm what the status of this PR is? From your last comment it sounds like these changes might be pulled into a larger PR and that this one should be closed. Is that correct? Or is the goal to merge this PR?

Yes, I'm reaching out to @richard-gibson as he is reviewing and integrating this fix.

kford-newrelic commented 3 years ago

Needed to move this out of the 7.4.0 release target. Slated for the next (7.5.0) release.

richard-gibson commented 2 years ago

Hi @smiklos, thanks for the contribution! The code you submitted is fine. I just had to add a test for the 2.12 blaze server instrumentation. For convenience I've created a new PR #530 with your commits and the extra test and will close this