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.

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

Akka Scheduler doesn't propage Kamon context #1093

Closed
antoine-morisseau opened this issue Dec 8, 2021 · 2 comments
Closed

Akka Scheduler doesn't propage Kamon context #1093

antoine-morisseau opened this issue Dec 8, 2021 · 2 comments

Comments

@antoine-morisseau
Copy link

It come from the discussion on Discord that i raised : https://discord.com/channels/866301994074243132/866301994074243135/918121791577264148

I am using :

  • Play framework 2.8.7
  • kamon-bundle 2.4.2
  • akka-actor 2.6.14

Here is a code snippet that reproduce the issue :

  def status = Action.async { implicit request =>
    logger.debug(s"before run with context tag. contexthashcode: ${Kamon.currentContext().hashCode()}")
    Kamon.runWithContextTag("tag", "value") {
      logger.debug(s"before future for yield. contexthashcode: ${Kamon.currentContext().hashCode()}, tags: ${Kamon.currentContext().tags}")
      for {
        _ <- retryFailFuture().recover { case ex => "success" }
      } yield {
        logger.debug(s"in future yield. contexthashcode: ${Kamon.currentContext().hashCode()}, ${Kamon.currentContext().tags}")
        Ok
      }
    }
  }

  private def retryFailFuture() = {
    logger.debug(s"before akka.pattern.retry. contexthashcode: ${Kamon.currentContext().hashCode()}, tags: ${Kamon.currentContext().tags}")
    val res = akka.pattern.retry(failFuture, 3, 0.1.second, 1.seconds, 0.1)
    logger.debug(s"after akka.pattern.retry. contexthashcode: ${Kamon.currentContext().hashCode()}, tags: ${Kamon.currentContext().tags}")
    res
  }

  private def failFuture(): Future[String] = {
    logger.debug(s"In future failed. contexthashcode: ${Kamon.currentContext().hashCode()}, tags: ${Kamon.currentContext().tags}")
    FastFuture.failed(new Exception("Boom"))
  }

and here is the log output :

"message":"before run with context tag. contexthashcode: 1365688801"
"message":"before future for yield. contexthashcode: 1927114542, tags: {tag=value}"
"message":"before akka.pattern.retry. contexthashcode: 1927114542, tags: {tag=value}"
"message":"In future failed. contexthashcode: 1927114542, tags: {tag=value}"
"message":"after akka.pattern.retry. contexthashcode: 1927114542, tags: {tag=value}"
"message":"In future failed. contexthashcode: 354660169, tags: {}"
"message":"In future failed. contexthashcode: 354660169, tags: {}"
"message":"In future failed. contexthashcode: 354660169, tags: {}"
"message":"in future yield. contexthashcode: 1927114542, {tag=value}"

The issue come from the implicit Scheduler used from akka.pattern.retry method.

It lose the context and Kamon create another one with no inheritance from the previous.

a workaround was found by doing this :

val ctx = Kamon.currentContext()
akka.pattern.retry(Kamon.runWithContext(ctx)(failFuture), 3, 0.1.second, 1.seconds, 0.1)
@nathanmbrown
Copy link

nathanmbrown commented Feb 2, 2022

Unsurprisingly I see the same for startTimerWithFixedDelay
This is particularly icky as the only workaround I can see is to send the context (or the relevant parts of it) in the message being scheduled. Horrible.

@ivantopo
Copy link
Contributor

ivantopo commented Mar 3, 2022

Hey @antoine-morisseau, @nathanmbrown,

We knew it was necessary to instrument Scheduler.scheduleOnce since long time ago because that is what powers akka.pattern.retry and akka.pattern.after under the hood. In fact, it is used by TimerScheduler.startSingleTimer too! I just wrote instrumentation for that and will push it in a little bit.

On the other hand, calls to Scheduler.scheduleWithFixedDelay and Scheduler.scheduleAtFixedRate (which happen to be used by TimerScheduler.startTimerWithFixedDelay) should not be instrumented, at least not out of the box. In most cases a call to scheduleOnce is definitely connected to the context of the "current request", but when something needs to be done repeatedly it is really hard to take a blanket decision and propagate all the time. Those cases will require manual propagation.

There is a possible workaround for your use case @nathanmbrown: since the scheduler instrumentation creates a few anonymous Runnables within the akka.actor.SchedulerClass and we have a way to target specific implementations, adding this to your configuration file might be enough to support startTimerWithFixedDelay as well:

kanela.modules.executor-service.within += "^akka.actor.Scheduler.*"

I didn't try it out, but it should probably work. Let me know if it does!

ivantopo added a commit to ivantopo/Kamon that referenced this issue Mar 3, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

3 participants