ScalaConsultants / mesmer

OpenTelemetry agent for Scala applications
https://mesmer.io
Apache License 2.0
71 stars 12 forks source link

Launch issues: Jackson dependencies + NoClassDefFoundError #486

Open vasigorc opened 2 years ago

vasigorc commented 2 years ago

Hello all!

We have an Akka app that declares the following related dependencies:

// from project/Dependencies.scala
...
lazy val akkaVersion = "2.6.19"
...
lazy val logbackVersion = "1.2.11"
...
lazy val otelVersion = "1.14.0"
...

  val compileDependencies: Seq[ModuleID] = Seq(
    "ch.qos.logback" % "logback-classic" % logbackVersion,
    "ch.qos.logback" % "logback-core" % logbackVersion,
...
    "com.fasterxml.jackson.core" % "jackson-databind" % "2.13.3",
...
    "com.typesafe.akka" %% "akka-actor" % akkaVersion,
    "com.typesafe.akka" %% "akka-persistence" % akkaVersion,
    "com.typesafe.akka" %% "akka-slf4j" % akkaVersion,
...
    "com.typesafe.scala-logging" %% "scala-logging" % "3.9.5",
...
    "io.opentelemetry" % "opentelemetry-api" % otelVersion,
    "io.opentelemetry" % "opentelemetry-extension-annotations" % otelVersion,
...
    "io.scalac" %% "mesmer-akka-extension" % "0.7.0",
...

I try to run the app through sbt, so I have a dedicated runner in my build.sbt file:

lazy val runWithObservability = taskKey[Unit]("Run application with observability.")
runWithObservability / fork := true
runWithObservability / javaOptions ++= {
  parseOtelJavaagentInfo.value match {
    case Actual(sourceLocation, _, version) =>
      Seq(
        s"-javaagent:$sourceLocation/opentelemetry-javaagent-all-$version.jar",
        s"-Dotel.javaagent.extensions=$sourceLocation/mesmer-otel-extension.jar",
        s"-Dotel.javaagent.configuration-file=$sourceLocation/otel.properties"
      )
    case Empty => Seq.empty[String]
  }
}
...
fullRunTask(runWithObservability, Compile, mainClass)

When running the application with sbt clean runWithObservability I get the following errors. First there seems to be a conflict with Jackson libraries:

...
[info] 13:31:58,864 |-ERROR in ch.qos.logback.classic.joran.JoranConfigurator@63262071 - Could not open URL [file:/Users/vasilegorcinschi/path/to/the/app/target/scala-2.13/classes/logback.xml]. com.fasterxml.jackson.databind.JsonMappingException: Scala module 2.11.4 requires Jackson Databind version >= 2.11.0 and < 2.12.0
[info]  at com.fasterxml.jackson.databind.JsonMappingException: Scala module 2.11.4 requires Jackson Databind version >= 2.11.0 and < 2.12.0
[info]  at  at com.fasterxml.jackson.module.scala.JacksonModule.setupModule(JacksonModule.scala:61)
[info]  at  at com.fasterxml.jackson.module.scala.JacksonModule.setupModule$(JacksonModule.scala:46)
[info]  at  at com.fasterxml.jackson.module.scala.DefaultScalaModule.setupModule(DefaultScalaModule.scala:17)
[info]  at  at com.fasterxml.jackson.databind.ObjectMapper.registerModule(ObjectMapper.java:853)
[info]  at  at com.fasterxml.jackson.databind.ObjectMapper.registerModules(ObjectMapper.java:1055)
[info]  at  at com.fasterxml.jackson.databind.ObjectMapper.findAndRegisterModules(ObjectMapper.java:1139)
[info]  at  at net.logstash.logback.composite.AbstractCompositeJsonFormatter.createJsonFactory(AbstractCompositeJsonFormatter.java:247)
...

Analyzing the dependency tree I observe that the 2.11.4 dependencies are being brought in by Mesmer's transitive akka-serialization-jackson dependency (not all dependencies shown):

Screen Shot 2022-08-22 at 2 12 25 PM

Besides that I'm having this thrown at the startup:

[error] Exception in thread "main" java.lang.NoClassDefFoundError: io/scalac/mesmer/core/model/Reporting$
[error]     at io.scalac.mesmer.core.actor.ConfiguredAttributeFactory.$anonfun$matchers$4(ActorRefConfiguration.scala:54)
[error]     at scala.collection.immutable.List.flatMap(List.scala:293)
[error]     at io.scalac.mesmer.core.actor.ConfiguredAttributeFactory.$anonfun$matchers$3(ActorRefConfiguration.scala:50)
[error]     at scala.Option.map(Option.scala:242)
...

despite having carried out the prerequisites from the Getting Started guide:

After removing both the dependency and the reference to the agent the application starts-up normally. Here are other pieces of information which could be relevant:

Any hint or advice will be helpful πŸ™‚

vasigorc commented 2 years ago

Following-up, I think that I've managed to address the first issue by excluding one transient dependency:

    "io.scalac" %% "mesmer-akka-extension" % "0.7.0"
      exclude (org = "com.fasterxml.jackson.module", name = "jackson-module-scala_2.13"),
vasigorc commented 2 years ago

For the second problem, could it be because io.scalac.mesmer.core.model.Reporting is expected to be packaged in mesmer-akka_core_2.13 but that it is not included in 0.7.0?

Screen Shot 2022-08-23 at 11 50 21 AM

vasigorc commented 2 years ago

In our case unfortunately it is, with the following dependency configuration the app starts up:

    "io.scalac" %% "mesmer-akka-extension" % "0.8.0.RC1"
      exclude (org = "com.fasterxml.jackson.module", name = "jackson-module-scala_2.13"),

"Unfortunately" is because I'd be reluctant to add a dependency with RC1 suffix to our app πŸ™‚

vasigorc commented 2 years ago

I've figured it out for the version part. It was code 18 πŸ™‚ . The thing is that I had another otel.javaagent.extensions line inside otel.properties file and that overrode what was passed with the -D flag. So I can run the code with

 "io.scalac" %% "mesmer-akka-extension" % "0.7.0"
      exclude (org = "com.fasterxml.jackson.module", name = "jackson-module-scala_2.13"),

...but now the system exits with another NoClassDefFoundError:

[error] Uncaught error from thread [my-app-akka.actor.default-dispatcher-7]: io/opentelemetry/instrumentation/api/field/VirtualField, shutting down JVM since 'akka.jvm-exit-on-fatal-error' is enabled for ActorSystem[my-app]
[error] java.lang.NoClassDefFoundError: io/opentelemetry/instrumentation/api/field/VirtualField
[error]     at io.scalac.mesmer.core.actor.ActorCellDecorator$.getMetrics(ActorCellDecorator.scala:10)
[error]     at io.scalac.mesmer.core.actor.ActorCellDecorator$.getMetrics(ActorCellDecorator.scala:14)
[error]     at io.scalac.mesmer.extension.ActorEventsMonitorActor$ReflectiveActorMetricsReader$.$anonfun$read$1(ActorEventsMonitorActor.scala:97)
[error]     at scala.Option.flatMap(Option.scala:283)
[error]     at io.scalac.mesmer.extension.ActorEventsMonitorActor$ReflectiveActorMetricsReader$.read(ActorEventsMonitorActor.scala:96)
[error]     at io.scalac.mesmer.extension.ActorEventsMonitorActor.$anonfun$update$1(ActorEventsMonitorActor.scala:238)
[error]     at io.scalac.mesmer.extension.util.Tree$TreeFOps$.innerFoldRight$extension(Tree.scala:24)
[error]     at io.scalac.mesmer.extension.util.Tree$TreeFOps$.$anonfun$foldRight$1(Tree.scala:26)
[error]     at io.scalac.mesmer.extension.util.Tree$TreeFOps$.$anonfun$foldRight$1$adapted(Tree.scala:26)
[error]     at scala.collection.immutable.Vector1.map(Vector.scala:1872)
[error]     at scala.collection.immutable.Vector1.map(Vector.scala:375)
[error]     at io.scalac.mesmer.extension.util.TreeF.map(Tree.scala:9)
[error]     at io.scalac.mesmer.extension.util.Tree$TreeFOps$.foldRight$extension(Tree.scala:26)
[error]     at io.scalac.mesmer.extension.ActorEventsMonitorActor.io$scalac$mesmer$extension$ActorEventsMonitorActor$$update(ActorEventsMonitorActor.scala:230)
[error]     at io.scalac.mesmer.extension.ActorEventsMonitorActor$$anonfun$io$scalac$mesmer$extension$ActorEventsMonitorActor$$receive$1.applyOrElse(ActorEventsMonitorActor.scala:208)
[error]     at io.scalac.mesmer.extension.ActorEventsMonitorActor$$anonfun$io$scalac$mesmer$extension$ActorEventsMonitorActor$$receive$1.applyOrElse(ActorEventsMonitorActor.scala:198)
[error]     at akka.actor.typed.scaladsl.Behaviors$.$anonfun$receiveMessagePartial$1(Behaviors.scala:139)

I initially was attaching the opentelemetry java agent version 1.13.1 but this can be also reproduced with 1.13.0. Again this error doesn't occur when using version 0.8.0.RC1.

vasigorc commented 2 years ago

@lgajowy Could you please confirm that using the 0.8.0.RC1 version is currently expected? Or else did I messed-up with the setup?

lgajowy commented 2 years ago

The reason for the NoClassDefFound errors might be that the opentelemetry agent has not loaded the classes. We typically add them in *InstrumentationModule.getAdditionalHelperClassNames (eg. in your case MesmerAkkaActorInstrumentationModule). That's an opentelemetry extension's mechanism to load all code that is necessary for instrumenting the akka actor metrics.

BTW: As you can see we are doing it manually so probably we missed some classes. Opentelemetry-java-instrumentation project does that automatically with a "Muzzle Gradle Plugin". This is one of the reasons we want to migrate the project to gradle, hopefully avoiding such errors.

I honestly don't know from the top of my head why you get the error for VirtualFields. Those are part of opentelemetry so they should be there in the agent for you. I'd need to investigate that further.

In version 0.8.0.RC1 the metrics were redone - our goal was to remove the Akka extension. So that might be why you don't see the errors - the internals were simplified/refactored.

When it comes to using 0.8.0.RC1 version: let me know if you need actors_terminated, mailbox_size and akka Streaming metrics. If no, then you're probably good to use it. If yes, then you'd need to wait for RC2/ next version where I will reinstate the above-mentioned metrics (there are some problems with displaying them now).

We might alternatively create a 0.7.1 patched version for you if the issue is urgent (lmk pls).

Sorry for the inconvenience.

vasigorc commented 2 years ago

Hey @lgajowy, thanks for following-up! mailbox_size would be of particular interest to us, yes.

If you could cut a patch release (0.7.1) that would certainly be preferable then using a *RC version.