The Kamon Instrumentation Agent
License: Apache License 2.0
When attaching instrumentation at runtime via Kamon.init() it could happen that some of the classes that are targeted by instrumentation are already loaded which can lead to half instrumented apps. It would be awesome if when attaching at runtime we could at least capture whether a targeted class has been loaded or not and it it is, either log some warnings or make the information available so that it can be used from the status page.
When there is a configured SecurityManager it might happen that some thread pools will use InnocuousThreads as worker threads and any mixin triggered from code executing in those threads will throw a ClassNotFoundException while trying to find Kamon-related classes.
This is happening because an InnocuousThread does not allow for their context class loader to be changed and they always default to the system class loader on calls to .getContextClassLoader(). When the MixinClassVisitor hits this point it gets the system classloader which might not have the right classes there. In the particular case that I was testing, I was trying to use the Mongo Driver from a Play application running on DEV mode and as it turns out, SBT uses a TrapExit Security Manager to handle the execution, which causes thread pools to behave differently and trigger this problem.
We introduced the InstrumentationClassPath utility for figuring out from where to load instrumentation and classes. What about making sure that the MixinClassVisitor always tries to load classes from the same class loader that was returned by the InstrumentationClassPath?
Since URL is used empty spaces are converted to %20 which breaks loading the jar from paths with empty spaces in it.
[main] ERROR 2020-08-04 15:48:52 Logger : Error when trying to Load build-in instrumentation modules.: java.nio.file.NoSuchFileException: /Volumes/Home%20HD/altoo/Library/Caches/Coursier/v1/https/nexus/repository/maven-public/io/kamon/kanela-agent/1.0.6/kanela-agent-1.0.6.jar
at java.base/sun.nio.fs.UnixException.translateToIOException(UnixException.java:92)
at java.base/sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:111)
at java.base/sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:116)
at java.base/sun.nio.fs.UnixFileAttributeViews$Basic.readAttributes(UnixFileAttributeViews.java:55)
| => cat java.base/sun.nio.fs.UnixFileSystemProvider.readAttributes(UnixFileSystemProvider.java:149)
at java.base/java.nio.file.Files.readAttributes(Files.java:1842)
at java.base/java.util.zip.ZipFile$Source.get(ZipFile.java:1160)
at java.base/java.util.zip.ZipFile$CleanableResource.<init>(ZipFile.java:719)
at java.base/java.util.zip.ZipFile.<init>(ZipFile.java:239)
at java.base/java.util.zip.ZipFile.<init>(ZipFile.java:169)
at java.base/java.util.jar.JarFile.<init>(JarFile.java:346)
at java.base/java.util.jar.JarFile.<init>(JarFile.java:317)
at java.base/java.util.jar.JarFile.<init>(JarFile.java:256)
at kanela.agent.util.Jar.lambda$searchWith$ebfbc2f4$1(Jar.java:63)
at kanela.agent.libs.io.vavr.control.Try.mapTry(Try.java:634)
at kanela.agent.util.Jar.searchWith(Jar.java:61)
at kanela.agent.util.BuiltInModuleLoader.findModules(BuiltInModuleLoader.java:34)
at kanela.agent.util.classloader.InstrumentationClassPath.<init>(InstrumentationClassPath.java:54)
at kanela.agent.util.classloader.InstrumentationClassPath.build(InstrumentationClassPath.java:68)
at kanela.agent.Kanela.lambda$start$1(Kanela.java:68)
at kanela.agent.util.Execution.timed(Execution.java:32)
at kanela.agent.util.Execution.runWithTimeSpent(Execution.java:41)
at kanela.agent.Kanela.start(Kanela.java:67)
at kanela.agent.Kanela.premain(Kanela.java:47)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:567)
at java.instrument/sun.instrument.InstrumentationImpl.loadClassAndStartAgent(InstrumentationImpl.java:513)
at java.instrument/sun.instrument.InstrumentationImpl.loadClassAndCallPremain(InstrumentationImpl.java:525)
Is there a way to hide the initial logs from Kanela? E.g. the big logo that's printed on startup:
$ sbt run
[info] Loading settings for project myapp-build from plugins.sbt ...
[info] Loading project definition from /home/amdelamar/workspace/myapp/project
[info] Loading settings for project root from build.sbt ...
[info] Set current project to myapp (in build file:/home/amdelamar/workspace/myapp/)
[info] Packaging /home/amdelamar/workspace/myapp/target/scala-2.12/myapp.12-1.0.jar ...
[info] Done packaging.
[info] Running com.amdelamar.App
OpenJDK 64-Bit Server VM warning: Sharing is only supported for boot loader classes because bootstrap classpath has been appended
_ __ _ ______
| |/ / | | \ \ \ \
| ' / __ _ _ __ ___| | __ _ \ \ \ \
| < / _` | '_ \ / _ \ |/ _` | ) ) ) )
| . \ (_| | | | | __/ | (_| | / / / /
|_|\_\__,_|_| |_|\___|_|\__,_| /_/_/_/
==============================
Running with Kanela, the Kamon Instrumentation Agent :: (v1.0.3)
WARNING: An illegal reflective access operation has occurred
WARNING: Illegal reflective access by kamon.instrumentation.executor.ExecutorInstrumentation$ (file:/tmp/sbt_260136f9/target/ab60b3b8/kamon-bundle_2.12-2.0.4.jar) to field java.util.concurrent.Executors$DelegatedExecutorService.e
WARNING: Please consider reporting this to the maintainers of kamon.instrumentation.executor.ExecutorInstrumentation$
WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations
WARNING: All illegal access operations will be denied in a future release
19:06:48.543 [INFO ] - App running at http://localhost:8080/
I've tried adding this to my logback.xml but to no success.
<logger name="kamon" level="WARN"/>
<logger name="io.kamon" level="WARN"/>
Sometimes we noticed this error happening when we launch our application with the Kanela agent:
[main] ERROR 2019-09-06 09:31:18 Logger : File too large: java.io.IOException: File too large
at sun.nio.ch.FileDispatcherImpl.write0(Native Method)
at sun.nio.ch.FileDispatcherImpl.write(FileDispatcherImpl.java:60)
at sun.nio.ch.IOUtil.writeFromNativeBuffer(IOUtil.java:93)
at sun.nio.ch.IOUtil.write(IOUtil.java:65)
at sun.nio.ch.FileChannelImpl.write(FileChannelImpl.java:211)
at java.nio.channels.Channels.writeFullyImpl(Channels.java:78)
at java.nio.channels.Channels.writeFully(Channels.java:101)
at java.nio.channels.Channels.access$000(Channels.java:61)
at java.nio.channels.Channels$1.write(Channels.java:174)
at java.nio.file.Files.copy(Files.java:2909)
at java.nio.file.Files.copy(Files.java:3027)
at kanela.agent.util.Jar.lambda$getEmbeddedFile$e1c0ab03$1(Jar.java:47)
at kanela.agent.libs.io.vavr.control.Try.of(Try.java:75)
at kanela.agent.util.Jar.getEmbeddedFile(Jar.java:43)
at kanela.agent.util.Jar.getEmbeddedJar(Jar.java:39)
at kanela.agent.util.BootstrapInjector.injectJar(BootstrapInjector.java:36)
at kanela.agent.Kanela.lambda$null$0(Kanela.java:70)
at kanela.agent.util.classloader.InstrumentationClassPath.use(InstrumentationClassPath.java:74)
at kanela.agent.Kanela.lambda$start$1(Kanela.java:68)
at kanela.agent.util.Execution.timed(Execution.java:32)
at kanela.agent.util.Execution.runWithTimeSpent(Execution.java:41)
at kanela.agent.Kanela.start(Kanela.java:67)
at kanela.agent.Kanela.premain(Kanela.java:47)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at sun.instrument.InstrumentationImpl.loadClassAndStartAgent(InstrumentationImpl.java:386)
at sun.instrument.InstrumentationImpl.loadClassAndCallPremain(InstrumentationImpl.java:401)
[main] ERROR 2019-09-06 09:31:18 Logger : Unable to start Kanela Agent. Please remove -javaagent from your startup arguments and contact Kanela support.: java.io.IOException: File too large
at sun.nio.ch.FileDispatcherImpl.write0(Native Method)
at sun.nio.ch.FileDispatcherImpl.write(FileDispatcherImpl.java:60)
at sun.nio.ch.IOUtil.writeFromNativeBuffer(IOUtil.java:93)
at sun.nio.ch.IOUtil.write(IOUtil.java:65)
at sun.nio.ch.FileChannelImpl.write(FileChannelImpl.java:211)
at java.nio.channels.Channels.writeFullyImpl(Channels.java:78)
at java.nio.channels.Channels.writeFully(Channels.java:101)
at java.nio.channels.Channels.access$000(Channels.java:61)
at java.nio.channels.Channels$1.write(Channels.java:174)
at java.nio.file.Files.copy(Files.java:2909)
at java.nio.file.Files.copy(Files.java:3027)
at kanela.agent.util.Jar.lambda$getEmbeddedFile$e1c0ab03$1(Jar.java:47)
at kanela.agent.libs.io.vavr.control.Try.of(Try.java:75)
at kanela.agent.util.Jar.getEmbeddedFile(Jar.java:43)
at kanela.agent.util.Jar.getEmbeddedJar(Jar.java:39)
at kanela.agent.util.BootstrapInjector.injectJar(BootstrapInjector.java:36)
at kanela.agent.Kanela.lambda$null$0(Kanela.java:70)
at kanela.agent.util.classloader.InstrumentationClassPath.use(InstrumentationClassPath.java:74)
at kanela.agent.Kanela.lambda$start$1(Kanela.java:68)
at kanela.agent.util.Execution.timed(Execution.java:32)
at kanela.agent.util.Execution.runWithTimeSpent(Execution.java:41)
at kanela.agent.Kanela.start(Kanela.java:67)
at kanela.agent.Kanela.premain(Kanela.java:47)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at sun.instrument.InstrumentationImpl.loadClassAndStartAgent(InstrumentationImpl.java:386)
at sun.instrument.InstrumentationImpl.loadClassAndCallPremain(InstrumentationImpl.java:401)
bruno.ferreira@Brunos-MacBook-Pro ~> kubectl logs -f worker-pod -n worker-c6eb709b-namespace
[main] ERROR 2019-09-06 09:36:17 Logger : File too large: java.io.IOException: File too large
at sun.nio.ch.FileDispatcherImpl.write0(Native Method)
at sun.nio.ch.FileDispatcherImpl.write(FileDispatcherImpl.java:60)
at sun.nio.ch.IOUtil.writeFromNativeBuffer(IOUtil.java:93)
at sun.nio.ch.IOUtil.write(IOUtil.java:65)
at sun.nio.ch.FileChannelImpl.write(FileChannelImpl.java:211)
at java.nio.channels.Channels.writeFullyImpl(Channels.java:78)
at java.nio.channels.Channels.writeFully(Channels.java:101)
at java.nio.channels.Channels.access$000(Channels.java:61)
at java.nio.channels.Channels$1.write(Channels.java:174)
at java.nio.file.Files.copy(Files.java:2909)
at java.nio.file.Files.copy(Files.java:3027)
at kanela.agent.util.Jar.lambda$getEmbeddedFile$e1c0ab03$1(Jar.java:47)
at kanela.agent.libs.io.vavr.control.Try.of(Try.java:75)
at kanela.agent.util.Jar.getEmbeddedFile(Jar.java:43)
at kanela.agent.util.Jar.getEmbeddedJar(Jar.java:39)
at kanela.agent.util.BootstrapInjector.injectJar(BootstrapInjector.java:36)
at kanela.agent.Kanela.lambda$null$0(Kanela.java:70)
at kanela.agent.util.classloader.InstrumentationClassPath.use(InstrumentationClassPath.java:74)
at kanela.agent.Kanela.lambda$start$1(Kanela.java:68)
at kanela.agent.util.Execution.timed(Execution.java:32)
at kanela.agent.util.Execution.runWithTimeSpent(Execution.java:41)
at kanela.agent.Kanela.start(Kanela.java:67)
at kanela.agent.Kanela.premain(Kanela.java:47)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at sun.instrument.InstrumentationImpl.loadClassAndStartAgent(InstrumentationImpl.java:386)
at sun.instrument.InstrumentationImpl.loadClassAndCallPremain(InstrumentationImpl.java:401)
[main] ERROR 2019-09-06 09:36:17 Logger : Unable to start Kanela Agent. Please remove -javaagent from your startup arguments and contact Kanela support.: java.io.IOException: File too large
at sun.nio.ch.FileDispatcherImpl.write0(Native Method)
at sun.nio.ch.FileDispatcherImpl.write(FileDispatcherImpl.java:60)
at sun.nio.ch.IOUtil.writeFromNativeBuffer(IOUtil.java:93)
at sun.nio.ch.IOUtil.write(IOUtil.java:65)
at sun.nio.ch.FileChannelImpl.write(FileChannelImpl.java:211)
at java.nio.channels.Channels.writeFullyImpl(Channels.java:78)
at java.nio.channels.Channels.writeFully(Channels.java:101)
at java.nio.channels.Channels.access$000(Channels.java:61)
at java.nio.channels.Channels$1.write(Channels.java:174)
at java.nio.file.Files.copy(Files.java:2909)
at java.nio.file.Files.copy(Files.java:3027)
at kanela.agent.util.Jar.lambda$getEmbeddedFile$e1c0ab03$1(Jar.java:47)
at kanela.agent.libs.io.vavr.control.Try.of(Try.java:75)
at kanela.agent.util.Jar.getEmbeddedFile(Jar.java:43)
at kanela.agent.util.Jar.getEmbeddedJar(Jar.java:39)
at kanela.agent.util.BootstrapInjector.injectJar(BootstrapInjector.java:36)
at kanela.agent.Kanela.lambda$null$0(Kanela.java:70)
at kanela.agent.util.classloader.InstrumentationClassPath.use(InstrumentationClassPath.java:74)
at kanela.agent.Kanela.lambda$start$1(Kanela.java:68)
at kanela.agent.util.Execution.timed(Execution.java:32)
at kanela.agent.util.Execution.runWithTimeSpent(Execution.java:41)
at kanela.agent.Kanela.start(Kanela.java:67)
at kanela.agent.Kanela.premain(Kanela.java:47)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at sun.instrument.InstrumentationImpl.loadClassAndStartAgent(InstrumentationImpl.java:386)
at sun.instrument.InstrumentationImpl.loadClassAndCallPremain(InstrumentationImpl.java:401)
I investigated a little and it doesn't make much sense.
Jar.getEmbeddedFile
can easily handle files up to Gig (i.e. couldn't reproduce the exception locally)
and bootstrap.jar is just a few Kb.
I'm sorry I don't have much more information, I will report any progress in narrowing this down.
One thing that keeps coming up again and again is the need to enable/disable instrumentation via configuration alone, without fiddling with SBT plugins or selectively calling Kamon.init(). Something as simple as having a kanela.enabled setting should be enough.
I got a report of this exception during startup:
[ExpiringMap-Expirer] ERROR 2020-05-06 14:46:10 Logger : Error => java.util.concurrent.locks.AbstractQueuedSynchronizer$Node with message java/util/concurrent/locks/AbstractQueuedSynchronizer$Node. Class loader: Bootstrap ClassLoader: java.lang.ClassCircularityError: java/util/concurrent/locks/AbstractQueuedSynchronizer$Node
at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:692)
at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireShared(AbstractQueuedSynchronizer.java:1026)
at java.base/java.util.concurrent.locks.ReentrantReadWriteLock$ReadLock.lock(ReentrantReadWriteLock.java:738)
at kanela.agent.libs.net.jodah.expiringmap.ExpiringMap.getEntry(ExpiringMap.java:1243)
at kanela.agent.libs.net.jodah.expiringmap.ExpiringMap.get(ExpiringMap.java:742)
at kanela.agent.cache.PoolStrategyCache.locate(PoolStrategyCache.java:56)
at kanela.agent.libs.net.bytebuddy.agent.builder.AgentBuilder$PoolStrategy$WithTypePoolCache.typePool(AgentBuilder.java:2813)
at kanela.agent.libs.net.bytebuddy.agent.builder.AgentBuilder$Default$ExecutingTransformer.transform(AgentBuilder.java:10455)
at kanela.agent.libs.net.bytebuddy.agent.builder.AgentBuilder$Default$ExecutingTransformer.access$1500(AgentBuilder.java:10223)
at kanela.agent.libs.net.bytebuddy.agent.builder.AgentBuilder$Default$ExecutingTransformer$Java9CapableVmDispatcher.run(AgentBuilder.java:10907)
at kanela.agent.libs.net.bytebuddy.agent.builder.AgentBuilder$Default$ExecutingTransformer$Java9CapableVmDispatcher.run(AgentBuilder.java:10845)
at java.base/java.security.AccessController.doPrivileged(AccessController.java:391)
at kanela.agent.libs.net.bytebuddy.agent.builder.AgentBuilder$Default$ExecutingTransformer.transform(AgentBuilder.java:10413)
at kanela.agent.libs.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.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:1650)
at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1182)
at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:899)
at java.base/java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1056)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1116)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:630)
at java.base/java.lang.Thread.run(Thread.java:832)
It seems to be the same issue that was reported in #90 and fixed by #91. It just looks like we might be missing a few more types to pre-initialize, maybe ThreadLocalRandom as in the original implementation from glowroot.
During application startup sometimes the following exception occurred java.lang.ClassCircularityError. Is it some kanela issue?
_ __ _ ______
| |/ / | | \ \ \ \
| ' / __ _ _ __ ___| | __ _ \ \ \ \
| < / _` | '_ \ / _ \ |/ _` | ) ) ) )
| . \ (_| | | | | __/ | (_| | / / / /
|_|\_\__,_|_| |_|\___|_|\__,_| /_/_/_/
==============================
๏ฟฝ[32;1mRunning with Kanela, the Kamon Instrumentation Agent :: (v1.0.1)๏ฟฝ[0m
๏ฟฝ[31m[kamon-agent-strategy-cache-listener-1] ERROR ๏ฟฝ[90m2019-09-04 08:16:06 ๏ฟฝ[38;5;24mLogger ๏ฟฝ[97m: ๏ฟฝ[10mError => java.util.concurrent.locks.LockSupport with message java/util/concurrent/locks/LockSupport. Class loader: Bootstrap ClassLoader: java.lang.ClassCircularityError: java/util/concurrent/locks/LockSupport
at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:836)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireShared(AbstractQueuedSynchronizer.java:967)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireShared(AbstractQueuedSynchronizer.java:1283)
at java.util.concurrent.locks.ReentrantReadWriteLock$ReadLock.lock(ReentrantReadWriteLock.java:727)
at kanela.agent.libs.net.jodah.expiringmap.ExpiringMap.getEntry(ExpiringMap.java:1243)
at kanela.agent.libs.net.jodah.expiringmap.ExpiringMap.get(ExpiringMap.java:742)
at kanela.agent.cache.PoolStrategyCache.locate(PoolStrategyCache.java:56)
at kanela.agent.libs.net.bytebuddy.agent.builder.AgentBuilder$PoolStrategy$WithTypePoolCache.typePool(AgentBuilder.java:2815)
at kanela.agent.libs.net.bytebuddy.agent.builder.AgentBuilder$Default$ExecutingTransformer.transform(AgentBuilder.java:10512)
at kanela.agent.libs.net.bytebuddy.agent.builder.AgentBuilder$Default$ExecutingTransformer.access$1500(AgentBuilder.java:10280)
at kanela.agent.libs.net.bytebuddy.agent.builder.AgentBuilder$Default$ExecutingTransformer$LegacyVmDispatcher.run(AgentBuilder.java:10890)
at kanela.agent.libs.net.bytebuddy.agent.builder.AgentBuilder$Default$ExecutingTransformer$LegacyVmDispatcher.run(AgentBuilder.java:10837)
at java.security.AccessController.doPrivileged(Native Method)
at kanela.agent.libs.net.bytebuddy.agent.builder.AgentBuilder$Default$ExecutingTransformer.transform(AgentBuilder.java:10437)
at sun.instrument.TransformerManager.transform(TransformerManager.java:188)
at sun.instrument.InstrumentationImpl.transform(InstrumentationImpl.java:428)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1093)
at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)๏ฟฝ[0m
08:16:08,425 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback-test.xml]
08:16:08,427 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback.groovy]
08:16:08,427 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Found resource [logback.xml] at [file:/opt/cif-gen/conf/logback.xml]
08:16:08,429 |-WARN in ch.qos.logback.classic.LoggerContext[default] - Resource [logback.xml] occurs multiple times on the classpath.
08:16:08,429 |-WARN in ch.qos.logback.classic.LoggerContext[default] - Resource [logback.xml] occurs at [file:/opt/cif-gen/conf/logback.xml]
08:16:08,429 |-WARN in ch.qos.logback.classic.LoggerContext[default] - Resource [logback.xml] occurs at [jar:file:/opt/cif-gen/lib/com.finfactory.cif.cif-gen-1.0-r29.jar!/logback.xml]
08:16:08,655 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - debug attribute not set
08:16:08,689 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - Will scan for changes in [file:/opt/cif-gen/conf/logback.xml]
08:16:08,689 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - Setting ReconfigureOnChangeTask scanning period to 1 minutes
08:16:08,692 |-INFO in ch.qos.logback.core.joran.action.ConversionRuleAction - registering conversion word contextEntry with class [kamon.instrumentation.logback.tools.ContextEntryConverter]
08:16:08,693 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.rolling.RollingFileAppender]
08:16:08,713 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [FILE]
08:16:08,757 |-INFO in c.q.l.core.rolling.SizeAndTimeBasedRollingPolicy@1443675930 - setting totalSizeCap to 500 MB
08:16:08,766 |-INFO in c.q.l.core.rolling.SizeAndTimeBasedRollingPolicy@1443675930 - Archive files will be limited to [50 MB] each.
08:16:08,805 |-INFO in c.q.l.core.rolling.SizeAndTimeBasedRollingPolicy@1443675930 - Will use gz compression
08:16:08,840 |-INFO in c.q.l.core.rolling.SizeAndTimeBasedRollingPolicy@1443675930 - Will use the pattern /var/log/cif-gen/cif-gen.log.%d{yyyy-MM-dd}.%i for the active file
08:16:08,844 |-INFO in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@5fe8b721 - The date pattern is 'yyyy-MM-dd' from file name pattern '/var/log/cif-gen/cif-gen.log.%d{yyyy-MM-dd}.%i.gz'.
08:16:08,844 |-INFO in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@5fe8b721 - Roll-over at midnight.
08:16:08,860 |-INFO in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@5fe8b721 - Setting initial period to Wed Sep 04 08:16:06 UTC 2019
08:16:08,870 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property
08:16:08,959 |-INFO in ch.qos.logback.core.rolling.RollingFileAppender[FILE] - Active log file name: /var/log/cif-gen/cif-gen.log
08:16:08,959 |-INFO in ch.qos.logback.core.rolling.RollingFileAppender[FILE] - File property is set to [/var/log/cif-gen/cif-gen.log]
08:16:08,965 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.classic.AsyncAppender]
08:16:09,314 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [ASYNC_FILE]
08:16:09,314 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [FILE] to ch.qos.logback.classic.AsyncAppender[ASYNC_FILE]
08:16:09,314 |-INFO in ch.qos.logback.classic.AsyncAppender[ASYNC_FILE] - Attaching appender named [FILE] to AsyncAppender.
08:16:09,315 |-INFO in ch.qos.logback.classic.AsyncAppender[ASYNC_FILE] - Setting discardingThreshold to 51
08:16:09,319 |-INFO in ch.qos.logback.classic.joran.action.RootLoggerAction - Setting level of ROOT logger to INFO
08:16:09,319 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [ASYNC_FILE] to Logger[ROOT]
08:16:09,321 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [com.finfactory] to INFO
08:16:09,321 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [eu.akkamo.AkkaHttpModule] to INFO
08:16:09,321 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - End of configuration.
08:16:09,322 |-INFO in ch.qos.logback.classic.joran.JoranConfigurator@551a20d6 - Registering current configuration as safe fallback point
๏ฟฝ[31m[main] ERROR ๏ฟฝ[90m2019-09-04 08:16:10 ๏ฟฝ[38;5;24mLogger ๏ฟฝ[97m: ๏ฟฝ[10mError => com.google.common.collect.Maps with message java/util/concurrent/locks/LockSupport. Class loader: sun.misc.Launcher$AppClassLoader@14dad5dc: java.lang.ClassCircularityError: java/util/concurrent/locks/LockSupport
at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:836)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireShared(AbstractQueuedSynchronizer.java:967)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireShared(AbstractQueuedSynchronizer.java:1283)
at java.util.concurrent.locks.ReentrantReadWriteLock$ReadLock.lock(ReentrantReadWriteLock.java:727)
at kanela.agent.libs.net.jodah.expiringmap.ExpiringMap.getEntry(ExpiringMap.java:1243)
at kanela.agent.libs.net.jodah.expiringmap.ExpiringMap.get(ExpiringMap.java:742)
at kanela.agent.cache.PoolStrategyCache.locate(PoolStrategyCache.java:56)
at kanela.agent.libs.net.bytebuddy.agent.builder.AgentBuilder$PoolStrategy$WithTypePoolCache.typePool(AgentBuilder.java:2815)
at kanela.agent.libs.net.bytebuddy.agent.builder.AgentBuilder$Default$ExecutingTransformer.transform(AgentBuilder.java:10512)
at kanela.agent.libs.net.bytebuddy.agent.builder.AgentBuilder$Default$ExecutingTransformer.access$1500(AgentBuilder.java:10280)
at kanela.agent.libs.net.bytebuddy.agent.builder.AgentBuilder$Default$ExecutingTransformer$LegacyVmDispatcher.run(AgentBuilder.java:10890)
at kanela.agent.libs.net.bytebuddy.agent.builder.AgentBuilder$Default$ExecutingTransformer$LegacyVmDispatcher.run(AgentBuilder.java:10837)
at java.security.AccessController.doPrivileged(Native Method)
at kanela.agent.libs.net.bytebuddy.agent.builder.AgentBuilder$Default$ExecutingTransformer.transform(AgentBuilder.java:10437)
at sun.instrument.TransformerManager.transform(TransformerManager.java:188)
at sun.instrument.InstrumentationImpl.transform(InstrumentationImpl.java:428)
at java.lang.ClassLoader.defineClass1(Native Method)
at java.lang.ClassLoader.defineClass(ClassLoader.java:760)
at java.security.SecureClassLoader.defineClass(SecureClassLoader.java:142)
at java.net.URLClassLoader.defineClass(URLClassLoader.java:467)
at java.net.URLClassLoader.access$100(URLClassLoader.java:73)
at java.net.URLClassLoader$1.run(URLClassLoader.java:368)
at java.net.URLClassLoader$1.run(URLClassLoader.java:362)
at java.security.AccessController.doPrivileged(Native Method)
at java.net.URLClassLoader.findClass(URLClassLoader.java:361)
at java.lang.ClassLoader.loadClass(ClassLoader.java:424)
at sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:331)
at java.lang.ClassLoader.loadClass(ClassLoader.java:357)
at com.google.inject.internal.CycleDetectingLock$CycleDetectingLockFactory.<clinit>(CycleDetectingLock.java:85)
at com.google.inject.internal.Initializer.<init>(Initializer.java:51)
at com.google.inject.internal.InternalInjectorCreator.<init>(InternalInjectorCreator.java:63)
at com.google.inject.Guice.createInjector(Guice.java:87)
at com.google.inject.Guice.createInjector(Guice.java:69)
at com.google.inject.Guice.createInjector(Guice.java:59)
at com.finfactory.cif.generic.modules.GenericApp.<init>(GenericApp.scala:38)
at com.finfactory.cif.generic.modules.GenericApp$.main(GenericApp.scala:82)
at com.finfactory.cif.generic.modules.GenericApp.main(GenericApp.scala)๏ฟฝ[0m
Exception in thread "kamon-scheduler-1" java.lang.ClassCircularityError: java/util/concurrent/locks/LockSupport
at java.util.concurrent.locks.AbstractQueuedSynchronizer.unparkSuccessor(AbstractQueuedSynchronizer.java:662)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.release(AbstractQueuedSynchronizer.java:1264)
at java.util.concurrent.locks.ReentrantLock.unlock(ReentrantLock.java:457)
at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1104)
at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
Exception in thread "kamon-scheduler-3" java.lang.IllegalMonitorStateException
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.signal(AbstractQueuedSynchronizer.java:1939)
at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1103)
at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
Uncaught error from thread [application-akka.actor.default-dispatcher-2]: java/util/concurrent/locks/LockSupport, shutting down JVM since 'akka.jvm-exit-on-fatal-error' is enabled for ActorSystem[application]
java.lang.ClassCircularityError: java/util/concurrent/locks/LockSupport
at java.util.concurrent.locks.AbstractQueuedSynchronizer.unparkSuccessor(AbstractQueuedSynchronizer.java:662)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.release(AbstractQueuedSynchronizer.java:1264)
at java.util.concurrent.locks.ReentrantLock.unlock(ReentrantLock.java:457)
at java.util.concurrent.ArrayBlockingQueue.put(ArrayBlockingQueue.java:356)
at ch.qos.logback.core.AsyncAppenderBase.putUninterruptibly(AsyncAppenderBase.java:181)
at ch.qos.logback.core.AsyncAppenderBase.put(AsyncAppenderBase.java:172)
at ch.qos.logback.core.AsyncAppenderBase.append(AsyncAppenderBase.java:161)
at ch.qos.logback.core.UnsynchronizedAppenderBase.doAppend(UnsynchronizedAppenderBase.java:84)
at ch.qos.logback.core.spi.AppenderAttachableImpl.appendLoopOnAppenders$original$Bp07aQdf(AppenderAttachableImpl.java:51)
at ch.qos.logback.core.spi.AppenderAttachableImpl.appendLoopOnAppenders$original$Bp07aQdf$accessor$gGlSLLus(AppenderAttachableImpl.java)
at ch.qos.logback.core.spi.AppenderAttachableImpl$auxiliary$RUIZdJ7z.call(Unknown Source)
at kamon.instrumentation.logback.AppendLoopMethodInterceptor$.$anonfun$aroundAppendLoop$1(LogbackInstrumentation.scala:83)
at scala.runtime.java8.JFunction0$mcI$sp.apply(JFunction0$mcI$sp.java:12)
at kamon.ContextStorage.runWithContext(ContextStorage.scala:67)
at kamon.ContextStorage.runWithContext$(ContextStorage.scala:64)
at kamon.Kamon$.runWithContext(Kamon.scala:19)
at kamon.instrumentation.logback.AppendLoopMethodInterceptor$.aroundAppendLoop(LogbackInstrumentation.scala:83)
at ch.qos.logback.core.spi.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java)
at ch.qos.logback.classic.Logger.appendLoopOnAppenders(Logger.java:270)
at ch.qos.logback.classic.Logger.callAppenders(Logger.java:257)
at ch.qos.logback.classic.Logger.buildLoggingEventAndAppend(Logger.java:421)
at ch.qos.logback.classic.Logger.filterAndLog_0_Or3Plus(Logger.java:383)
at ch.qos.logback.classic.Logger.info(Logger.java:579)
at akka.event.slf4j.Slf4jLogger$$anonfun$receive$1.applyOrElse(Slf4jLogger.scala:101)
at akka.actor.Actor.aroundReceive(Actor.scala:539)
at akka.actor.Actor.aroundReceive$(Actor.scala:537)
at akka.event.slf4j.Slf4jLogger.aroundReceive(Slf4jLogger.scala:55)
at akka.actor.ActorCell.receiveMessage(ActorCell.scala:612)
at akka.actor.ActorCell.invoke(ActorCell.scala:581)
at akka.dispatch.Mailbox.processMailbox(Mailbox.scala:268)
at akka.dispatch.Mailbox.run(Mailbox.scala:229)
at kamon.instrumentation.executor.ExecutorInstrumentation$InstrumentedForkJoinPool$TimingRunnable.run(ExecutorInstrumentation.scala:653)
at akka.dispatch.ForkJoinExecutorConfigurator$AkkaForkJoinTask.exec(ForkJoinExecutorConfigurator.scala:49)
at akka.dispatch.forkjoin.ForkJoinTask.doExec(ForkJoinTask.java:260)
at akka.dispatch.forkjoin.ForkJoinPool$WorkQueue.runTask(ForkJoinPool.java:1339)
at akka.dispatch.forkjoin.ForkJoinPool.runWorker(ForkJoinPool.java:1979)
at akka.dispatch.forkjoin.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:107)
related to kamon-io/Kamon#121
The agent must be able to dump the bytecode of a class.
Features:
if we execute this command in the console java -javaagent:kamon-agent.jar we get:
Exception in thread "main" java.lang.reflect.InvocationTargetException
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:497)
at sun.instrument.InstrumentationImpl.loadClassAndStartAgent(InstrumentationImpl.java:386)
at sun.instrument.InstrumentationImpl.loadClassAndCallPremain(InstrumentationImpl.java:401)
Caused by: java.lang.NoClassDefFoundError: scala/Product
at java.lang.ClassLoader.defineClass1(Native Method)
at java.lang.ClassLoader.defineClass(ClassLoader.java:760)
at java.security.SecureClassLoader.defineClass(SecureClassLoader.java:142)
at java.net.URLClassLoader.defineClass(URLClassLoader.java:467)
at java.net.URLClassLoader.access$100(URLClassLoader.java:73)
at java.net.URLClassLoader$1.run(URLClassLoader.java:368)
at java.net.URLClassLoader$1.run(URLClassLoader.java:362)
at java.security.AccessController.doPrivileged(Native Method)
at java.net.URLClassLoader.findClass(URLClassLoader.java:361)
at java.lang.ClassLoader.loadClass(ClassLoader.java:424)
at sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:331)
at java.lang.ClassLoader.loadClass(ClassLoader.java:357)
at kamon.agent.BuildInfo.version(BuildInfo.scala)
at kamon.agent.util.banner.AgentBanner.show(AgentBanner.java:48)
at kamon.agent.AgentEntryPoint.lambda$start$0(AgentEntryPoint.java:44)
at kamon.agent.util.AgentUtil.timed(AgentUtil.java:33)
at kamon.agent.util.AgentUtil.withTimeSpent(AgentUtil.java:37)
at kamon.agent.AgentEntryPoint.start(AgentEntryPoint.java:42)
at kamon.agent.AgentEntryPoint.premain(AgentEntryPoint.java:53)
at kamon.agent.KamonAgent.premain(KamonAgent.java:34)
... 6 more
Caused by: java.lang.ClassNotFoundException: scala.Product
at java.net.URLClassLoader.findClass(URLClassLoader.java:381)
at java.lang.ClassLoader.loadClass(ClassLoader.java:424)
at sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:331)
at java.lang.ClassLoader.loadClass(ClassLoader.java:357)
... 26 more
FATAL ERROR in native method: processing of -javaagent failed
[1] 19246 abort (core dumped) java -javaagent:kamon-agent.jar
this error is because the sbt-buildinfo plugin introduce a scala dependency :(
here: sbt/sbt-buildinfo#98 a solution but not merged
Depending cleaning strategy of the os, /tmp can become full because of kanela jar files (/tmp/kanela-agent-1.0.9.*.jar)
Could this file be deleted after use ? (is it downloaded each time or extracted ?)
It would be nice !
(I have a lot of /tmp/tmpXXX empty directory too ..)
This feature maybe should by for kamon-core
This came up when trying to upgrade the Scalaz Future instrumentation. Here is the stacktrace we were getting:
[error] Uncaught exception when running kamon.scalaz.instrumentation.FutureInstrumentationSpec: java.lang.VerifyError: Bad type on operand stack
[error] Exception Details:
[error] Location:
[error] scalaz/concurrent/Future$$anonfun$apply$15$$anon$3.<init>(Lscalaz/concurrent/Future$$anonfun$apply$15;Lscala/Function1;)V @6: invokevirtual
[error] Reason:
[error] Type uninitializedThis (current frame, stack[1]) is not assignable to 'scalaz/concurrent/Future$$anonfun$apply$15$$anon$3'
[error] Current Frame:
[error] bci: @6
[error] flags: { flagThisUninit }
[error] locals: { uninitializedThis, 'scalaz/concurrent/Future$$anonfun$apply$15', 'scala/Function1' }
[error] stack: { null, uninitializedThis }
[error] Bytecode:
[error] 0x0000000: 2bc7 0009 012a b600 68bf 2a2b b500 142a
[error] 0x0000010: 2cb5 0012 2ab7 0041 2ab6 0068 b1
[error] Stackmap Table:
[error] same_frame(@10)
[error] sbt.ForkMain$ForkError: java.lang.VerifyError: Bad type on operand stack
[error] Exception Details:
[error] Location:
[error] scalaz/concurrent/Future$$anonfun$apply$15$$anon$3.<init>(Lscalaz/concurrent/Future$$anonfun$apply$15;Lscala/Function1;)V @6: invokevirtual
[error] Reason:
[error] Type uninitializedThis (current frame, stack[1]) is not assignable to 'scalaz/concurrent/Future$$anonfun$apply$15$$anon$3'
[error] Current Frame:
[error] bci: @6
[error] flags: { flagThisUninit }
[error] locals: { uninitializedThis, 'scalaz/concurrent/Future$$anonfun$apply$15', 'scala/Function1' }
[error] stack: { null, uninitializedThis }
[error] Bytecode:
[error] 0x0000000: 2bc7 0009 012a b600 68bf 2a2b b500 142a
[error] 0x0000010: 2cb5 0012 2ab7 0041 2ab6 0068 b1
[error] Stackmap Table:
[error] same_frame(@10)
[error]
[error] at scalaz.concurrent.Future$$anonfun$apply$15.apply(Future.scala:432)
[error] at scalaz.concurrent.Future$$anonfun$apply$15.apply(Future.scala:431)
[error] at scalaz.concurrent.Future.unsafePerformListen(Future.scala:77)
[error] at scalaz.concurrent.Future.unsafePerformAsync(Future.scala:159)
[error] at scalaz.concurrent.Future.unsafeStart(Future.scala:144)
[error] at kamon.scalaz.instrumentation.FutureInstrumentationSpec$$anonfun$1$$anonfun$apply$mcV$sp$1$$anonfun$apply$mcV$sp$2$$anonfun$2.apply(FutureInstrumentationSpec.scala:38)
[error] at kamon.scalaz.instrumentation.FutureInstrumentationSpec$$anonfun$1$$anonfun$apply$mcV$sp$1$$anonfun$apply$mcV$sp$2$$anonfun$2.apply(FutureInstrumentationSpec.scala:38)
[error] at kamon.ContextStorage$class.withContext(ContextStorage.scala:23)
[error] at kamon.Kamon$.withContext(Kamon.scala:18)
[error] at kamon.scalaz.instrumentation.FutureInstrumentationSpec$$anonfun$1$$anonfun$apply$mcV$sp$1$$anonfun$apply$mcV$sp$2.apply(FutureInstrumentationSpec.scala:37)
[error] at kamon.scalaz.instrumentation.FutureInstrumentationSpec$$anonfun$1$$anonfun$apply$mcV$sp$1$$anonfun$apply$mcV$sp$2.apply(FutureInstrumentationSpec.scala:34)
[error] at org.scalatest.OutcomeOf$class.outcomeOf(OutcomeOf.scala:85)
[error] at org.scalatest.OutcomeOf$.outcomeOf(OutcomeOf.scala:104)
[error] at org.scalatest.Transformer.apply(Transformer.scala:22)
[error] at org.scalatest.Transformer.apply(Transformer.scala:20)
[error] at org.scalatest.WordSpecLike$$anon$1.apply(WordSpecLike.scala:1078)
[error] at org.scalatest.TestSuite$class.withFixture(TestSuite.scala:196)
[error] at org.scalatest.WordSpec.withFixture(WordSpec.scala:1881)
[error] at org.scalatest.WordSpecLike$class.invokeWithFixture$1(WordSpecLike.scala:1075)
[error] at org.scalatest.WordSpecLike$$anonfun$runTest$1.apply(WordSpecLike.scala:1088)
[error] at org.scalatest.WordSpecLike$$anonfun$runTest$1.apply(WordSpecLike.scala:1088)
[error] at org.scalatest.SuperEngine.runTestImpl(Engine.scala:289)
[error] at org.scalatest.WordSpecLike$class.runTest(WordSpecLike.scala:1088)
[error] at org.scalatest.WordSpec.runTest(WordSpec.scala:1881)
[error] at org.scalatest.WordSpecLike$$anonfun$runTests$1.apply(WordSpecLike.scala:1147)
[error] at org.scalatest.WordSpecLike$$anonfun$runTests$1.apply(WordSpecLike.scala:1147)
[error] at org.scalatest.SuperEngine$$anonfun$traverseSubNodes$1$1.apply(Engine.scala:396)
[error] at org.scalatest.SuperEngine$$anonfun$traverseSubNodes$1$1.apply(Engine.scala:384)
[error] at scala.collection.immutable.List.foreach(List.scala:381)
[error] at org.scalatest.SuperEngine.traverseSubNodes$1(Engine.scala:384)
[error] at org.scalatest.SuperEngine.org$scalatest$SuperEngine$$runTestsInBranch(Engine.scala:373)
[error] at org.scalatest.SuperEngine$$anonfun$traverseSubNodes$1$1.apply(Engine.scala:410)
[error] at org.scalatest.SuperEngine$$anonfun$traverseSubNodes$1$1.apply(Engine.scala:384)
[error] at scala.collection.immutable.List.foreach(List.scala:381)
[error] at org.scalatest.SuperEngine.traverseSubNodes$1(Engine.scala:384)
[error] at org.scalatest.SuperEngine.org$scalatest$SuperEngine$$runTestsInBranch(Engine.scala:373)
[error] at org.scalatest.SuperEngine$$anonfun$traverseSubNodes$1$1.apply(Engine.scala:410)
[error] at org.scalatest.SuperEngine$$anonfun$traverseSubNodes$1$1.apply(Engine.scala:384)
[error] at scala.collection.immutable.List.foreach(List.scala:381)
[error] at org.scalatest.SuperEngine.traverseSubNodes$1(Engine.scala:384)
[error] at org.scalatest.SuperEngine.org$scalatest$SuperEngine$$runTestsInBranch(Engine.scala:379)
[error] at org.scalatest.SuperEngine.runTestsImpl(Engine.scala:461)
[error] at org.scalatest.WordSpecLike$class.runTests(WordSpecLike.scala:1147)
[error] at org.scalatest.WordSpec.runTests(WordSpec.scala:1881)
[error] at org.scalatest.Suite$class.run(Suite.scala:1147)
[error] at org.scalatest.WordSpec.org$scalatest$WordSpecLike$$super$run(WordSpec.scala:1881)
[error] at org.scalatest.WordSpecLike$$anonfun$run$1.apply(WordSpecLike.scala:1192)
[error] at org.scalatest.WordSpecLike$$anonfun$run$1.apply(WordSpecLike.scala:1192)
[error] at org.scalatest.SuperEngine.runImpl(Engine.scala:521)
[error] at org.scalatest.WordSpecLike$class.run(WordSpecLike.scala:1192)
[error] at org.scalatest.WordSpec.run(WordSpec.scala:1881)
[error] at org.scalatest.tools.Framework.org$scalatest$tools$Framework$$runSuite(Framework.scala:314)
[error] at org.scalatest.tools.Framework$ScalaTestTask.execute(Framework.scala:480)
[error] at sbt.ForkMain$Run.lambda$runTest$1(ForkMain.java:304)
[error] at java.util.concurrent.FutureTask.run(FutureTask.java:266)
[error] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[error] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[error] at java.lang.Thread.run(Thread.java:748)
And the instrumentation was looking like this:
class FutureInstrumentation extends KanelaInstrumentation {
forSubtypeOf("java.util.concurrent.Callable") { builder โ
builder
.withMixin(classOf[HasContextMixin])
.withAdvisorFor(method("call"), classOf[RunMethodAdvisor])
.build()
}
}
class HasContextMixin extends HasContext {
private var _context: Context = _
@Initializer
def initialize(): Unit =
_context = Kamon.currentContext()
override def context: Context =
_context
}
class RunMethodAdvisor
object RunMethodAdvisor {
@Advice.OnMethodEnter
def enter(@Advice.This hasContext: HasContext): Storage.Scope =
Kamon.storeContext(hasContext.context)
@Advice.OnMethodExit(onThrowable = classOf[Throwable])
def exit(@Advice.Enter scope: Storage.Scope): Unit =
scope.close()
}I'm using FluencyLogbackAppender to report events to FluentD and i'm getting a NPE when Kanela tries to instrument a pool used by Fluency.
01:39:19,511 |-ERROR in ch.qos.logback.core.joran.spi.Interpreter@110:13 - RuntimeException in Action for tag [appender] java.lang.RuntimeException: java.lang.NullPointerException
at java.lang.RuntimeException: java.lang.NullPointerException
at at ch.qos.logback.more.appenders.FluencyLogbackAppender.start(FluencyLogbackAppender.java:47)
at at ch.qos.logback.core.joran.action.AppenderAction.end(AppenderAction.java:90)
at at ch.qos.logback.core.joran.spi.Interpreter.callEndAction(Interpreter.java:309)
at at ch.qos.logback.core.joran.spi.Interpreter.endElement(Interpreter.java:193)
at at ch.qos.logback.core.joran.spi.Interpreter.endElement(Interpreter.java:179)
at at ch.qos.logback.core.joran.spi.EventPlayer.play(EventPlayer.java:62)
at at ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:165)
at at ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:152)
at at ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:110)
at at ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:53)
at at ch.qos.logback.classic.util.ContextInitializer.configureByResource(ContextInitializer.java:75)
at at ch.qos.logback.classic.util.ContextInitializer.autoConfig(ContextInitializer.java:150)
at at org.slf4j.impl.StaticLoggerBinder.init(StaticLoggerBinder.java:84)
at at org.slf4j.impl.StaticLoggerBinder.<clinit>(StaticLoggerBinder.java:55)
at at org.slf4j.LoggerFactory.bind(LoggerFactory.java:150)
at at org.slf4j.LoggerFactory.performInitialization(LoggerFactory.java:124)
at at org.slf4j.LoggerFactory.getILoggerFactory(LoggerFactory.java:412)
at at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:357)
at at kamon.Kamon$.<init>(Kamon.scala:33)
at at kamon.Kamon$.<clinit>(Kamon.scala)
at at kamon.Kamon.currentContext(Kamon.scala)
at at kamon.executors.instrumentation.ExecutorInstrumentation$ContextAwareCallable.<init>(ExecutorInstrumentation.java:100)
at at kamon.executors.instrumentation.ExecutorInstrumentation$KamonContextProvider.wrapInContextAware(ExecutorInstrumentation.java:125)
at at kanela.agent.bootstrap.context.ContextHandler.wrapInContextAware(ContextHandler.java:52)
at at java.util.concurrent.Executors$DelegatedExecutorService.submit(Executors.java:681)
at at com.newrelic.agent.utilization.UtilizationService.scheduleUtilizationTask(UtilizationService.java:96)
at at com.newrelic.agent.utilization.UtilizationService.doStart(UtilizationService.java:87)
at at com.newrelic.agent.service.AbstractService.start(AbstractService.java:56)
at at com.newrelic.agent.service.ServiceManagerImpl.doStart(ServiceManagerImpl.java:174)
at at com.newrelic.agent.service.AbstractService.start(AbstractService.java:56)
at at com.newrelic.agent.Agent.premain(Agent.java:319)
at at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at at java.lang.reflect.Method.invoke(Method.java:498)
at at com.newrelic.bootstrap.BootstrapAgent.startAgent(BootstrapAgent.java:160)
at at com.newrelic.bootstrap.BootstrapAgent.premain(BootstrapAgent.java:66)
at at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at at java.lang.reflect.Method.invoke(Method.java:498)
at at sun.instrument.InstrumentationImpl.loadClassAndStartAgent(InstrumentationImpl.java:386)
at at sun.instrument.InstrumentationImpl.loadClassAndCallPremain(InstrumentationImpl.java:401)
Caused by: java.lang.NullPointerException
at at kamon.Kamon$.currentContext(Kamon.scala:109)
at at kamon.Kamon.currentContext(Kamon.scala)
at at kamon.executors.instrumentation.ExecutorInstrumentation$ContextAwareRunnable.<init>(ExecutorInstrumentation.java:76)
at at kamon.executors.instrumentation.ExecutorInstrumentation$KamonContextProvider.wrapInContextAware(ExecutorInstrumentation.java:120)
at at kanela.agent.bootstrap.context.ContextHandler.wrapInContextAware(ContextHandler.java:51)
at at java.util.concurrent.Executors$DelegatedExecutorService.execute(Executors.java:668)
at at org.komamitsu.fluency.flusher.AsyncFlusher.<init>(AsyncFlusher.java:78)
at at org.komamitsu.fluency.flusher.AsyncFlusher.<init>(AsyncFlusher.java:32)
at at org.komamitsu.fluency.flusher.AsyncFlusher$Config.createInstance(AsyncFlusher.java:174)
at at org.komamitsu.fluency.flusher.AsyncFlusher$Config.createInstance(AsyncFlusher.java:120)
at at org.komamitsu.fluency.Fluency$Builder.build(Fluency.java:449)
at at org.komamitsu.fluency.Fluency.buildDefaultFluency(Fluency.java:163)
at at org.komamitsu.fluency.Fluency.defaultFluency(Fluency.java:182)
at at ch.qos.logback.more.appenders.FluencyLogbackAppender.start(FluencyLogbackAppender.java:45)
at ... 42 common frames omitted
Dependencies:
"com.sndyuk" % "logback-more-appenders" % "1.4.3",
"org.komamitsu" % "fluency" % "1.8.1",
"io.kamon" % "kanela-agent-bundle" % "0.0.14" % "agent",
"io.kamon" %% "kamon-core" % "1.1.3",
"io.kamon" %% "kanela-scala-extension" % "0.0.14",
"io.kamon" %% "kamon-servlet-3" % "1.0.0",
"io.kamon" %% "kamon-jaeger" % "1.0.2",
"io.kamon" %% "kamon-zipkin" % "1.0.0",
"io.kamon" %% "kamon-prometheus" % "1.1.1",
"io.kamon" % "kamon-annotation-api" % "1.0.3",
Config
kamon {
environment.service = "bkd-connect"
trace.sampler = "never"
trace.join-remote-parents-with-same-span-id = true
reporters = []
}
kanela {
show-banner = false
log-level = "ERROR"
modules {
annotation-module.within = [ "com.despegar.bookedia..*" ]
mariadb-module {
name = "MariaDB Instrumentation Module"
instrumentations = [
"com.despegar.bookedia.connect.monitoring.instrumentation.MariaDBInstrumentation"
]
within = [
"org.mariadb.jdbc..*"
]
}
}
}
Cheers!
When i tried to download the dependencies i cannot get the sbt-kanela-runner-play-2.8 V2.0.9.
I tried with 2.0.6 and the same thing happened. This is not working since today (12/04/2021)
This is the error log. When ivy tries to get the dependency the response is a 403 Forbidden from the server.
The resource is https://dl.bintray.com/sbt/sbt-plugin-releases/io.kamon/sbt-kanela-runner-play-2.8/scala_2.12/sbt_1.0/2.0.9/ivys/ivy.xml
[error] download error: Caught java.io.IOException: Server returned HTTP response code: 403 for URL: https://dl.bintray.com/kamon-io/sbt-plugins/io.kamon/sbt-kanela-runner-play-2.8/scala_2.12/sbt_1.0/2.0.9/ivys/ivy.xml (Server returned HTTP response code: 403 for URL: https://dl.bintray.com/kamon-io/sbt-plugins/io.kamon/sbt-kanela-runner-play-2.8/scala_2.12/sbt_1.0/2.0.9/ivys/ivy.xml) while downloading https://dl.bintray.com/kamon-io/sbt-plugins/io.kamon/sbt-kanela-runner-play-2.8/scala_2.12/sbt_1.0/2.0.9/ivys/ivy.xml
[error] download error: Caught java.io.IOException: Server returned HTTP response code: 403 for URL: https://dl.bintray.com/sbt/sbt-plugin-releases/io.kamon/sbt-kanela-runner-play-2.8/scala_2.12/sbt_1.0/2.0.9/ivys/ivy.xml (Server returned HTTP response code: 403 for URL: https://dl.bintray.com/sbt/sbt-plugin-releases/io.kamon/sbt-kanela-runner-play-2.8/scala_2.12/sbt_1.0/2.0.9/ivys/ivy.xml) while downloading https://repo.scala-sbt.org/scalasbt/sbt-plugin-releases/io.kamon/sbt-kanela-runner-play-2.8/scala_2.12/sbt_1.0/2.0.9/ivys/ivy.xml
[error] download error: Caught java.io.IOException: Server returned HTTP response code: 403 for URL: https://dl.bintray.com/typesafe/ivy-releases/io.kamon/sbt-kanela-runner-play-2.8/scala_2.12/sbt_1.0/2.0.9/ivys/ivy.xml (Server returned HTTP response code: 403 for URL: https://dl.bintray.com/typesafe/ivy-releases/io.kamon/sbt-kanela-runner-play-2.8/scala_2.12/sbt_1.0/2.0.9/ivys/ivy.xml) while downloading https://repo.typesafe.com/typesafe/ivy-releases/io.kamon/sbt-kanela-runner-play-2.8/scala_2.12/sbt_1.0/2.0.9/ivys/ivy.xml
You can help me with this ? Thanks you !
I am experiencing an error trying to run the Block Explorer App
when i execute the sbt run command i get this error
Unable to start Kanela Agent. Please remove -javaagent from your startup arguments and contact Kanela support.: java.lang.NoClassDefFoundError: Could not initialize class org.apache.logging.log4j.util.PropertiesUtil
at org.apache.logging.log4j.status.StatusLogger.<clinit>(StatusLogger.java:78)
at org.apache.logging.log4j.LogManager.<clinit>(LogManager.java:60)
at org.apache.logging.slf4j.Log4jLoggerFactory.getContext(Log4jLoggerFactory.java:43)
at org.apache.logging.log4j.spi.AbstractLoggerAdapter.getLogger(AbstractLoggerAdapter.java:46)
at org.apache.logging.slf4j.Log4jLoggerFactory.getLogger(Log4jLoggerFactory.java:29)
at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:358)
at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:383)
at io.methvin.watcher.DirectoryWatcher$Builder.staticLogger(DirectoryWatcher.java:137)
at io.methvin.watcher.DirectoryWatcher$Builder.build(DirectoryWatcher.java:115)
at play.dev.filewatch.DefaultFileWatchService.watch(DefaultFileWatchService.scala:41)
at play.dev.filewatch.FileWatchService$$anon$1.watch(FileWatchService.scala:90)
at kamon.instrumentation.sbt.play.KanelaReloader.<init>(KanelaReloader.scala:408)
at kamon.instrumentation.sbt.play.KanelaReloader$.reloader$lzycompute$1(KanelaReloader.scala:261)
at kamon.instrumentation.sbt.play.KanelaReloader$.kamon$instrumentation$sbt$play$KanelaReloader$$reloader$1(KanelaReloader.scala:252)
at kamon.instrumentation.sbt.play.KanelaReloader$$anon$3.get(KanelaReloader.scala:245)
at play.runsupport.classloader.DelegatingClassLoader.getResources(DelegatingClassLoader.java:51)
at java.lang.ClassLoader.getResources(ClassLoader.java:1131)
at kanela.agent.util.classloader.ChildFirstURLClassLoader.getResources(ChildFirstURLClassLoader.java:106)
at kanela.agent.libs.com.typesafe.config.impl.Parseable$ParseableResources.rawParseValue(Parseable.java:721)
at kanela.agent.libs.com.typesafe.config.impl.Parseable$ParseableResources.rawParseValue(Parseable.java:701)
at kanela.agent.libs.com.typesafe.config.impl.Parseable.parseValue(Parseable.java:180)
at kanela.agent.libs.com.typesafe.config.impl.Parseable.parseValue(Parseable.java:174)
at kanela.agent.libs.com.typesafe.config.impl.Parseable.parse(Parseable.java:152)
at kanela.agent.libs.com.typesafe.config.impl.SimpleIncluder.fromBasename(SimpleIncluder.java:185)
at kanela.agent.libs.com.typesafe.config.impl.ConfigImpl.parseResourcesAnySyntax(ConfigImpl.java:133)
at kanela.agent.libs.com.typesafe.config.ConfigFactory.parseResourcesAnySyntax(ConfigFactory.java:1029)
at kanela.agent.libs.com.typesafe.config.DefaultConfigLoadingStrategy.parseApplicationConfig(DefaultConfigLoadingStrategy.java:36)
at kanela.agent.libs.com.typesafe.config.ConfigFactory.defaultApplication(ConfigFactory.java:478)
at kanela.agent.libs.com.typesafe.config.ConfigFactory.load(ConfigFactory.java:308)
at kanela.agent.util.conf.KanelaConfiguration.loadDefaultConfig(KanelaConfiguration.java:304)
at kanela.agent.util.conf.KanelaConfiguration.lambda$loadConfig$84c4dc62$1(KanelaConfiguration.java:261)
at kanela.agent.libs.io.vavr.control.Try.of(Try.java:75)
at kanela.agent.util.conf.KanelaConfiguration.loadConfig(KanelaConfiguration.java:261)
at kanela.agent.util.conf.KanelaConfiguration.from(KanelaConfiguration.java:59)
at kanela.agent.Kanela.lambda$null$0(Kanela.java:73)
at kanela.agent.util.classloader.InstrumentationClassPath.use(InstrumentationClassPath.java:84)
at kanela.agent.Kanela.lambda$start$1(Kanela.java:68)
at kanela.agent.util.Execution.timed(Execution.java:32)
at kanela.agent.util.Execution.runWithTimeSpent(Execution.java:41)
at kanela.agent.Kanela.start(Kanela.java:67)
at kanela.agent.Kanela.agentmain(Kanela.java:54)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at sun.instrument.InstrumentationImpl.loadClassAndStartAgent(InstrumentationImpl.java:386)
at sun.instrument.InstrumentationImpl.loadClassAndCallAgentmain(InstrumentationImpl.java:411)
While I was investigating #98 I noticed that "causes" of exceptions are not being displayed in the logs. For example, see the message we got from this error in the logs: "java.lang.RuntimeException: The class file could not be written"
I was suspicious that there was something else behind that and only after running with a debugger to investigate further I could see that the actual issue was a problem with not finding a class file:
Ideally it would be nice to see the whole stack trace for the main exception and all the "caused by" as we see in some other places.
I am trying to run an application with Kamon monitoring and the Kanela agent running in a read-only container (e.g. docker run --read-only ...).
I am getting the following exception:
Unable to start Kanela Agent. Please remove -javaagent from your startup arguments and contact Kanela support.: java.io.IOException: Read-only file system
at java.io.UnixFileSystem.createFileExclusively(Native Method)
at java.io.File.createTempFile(File.java:2024)
at java.io.File.createTempFile(File.java:2070)
at kanela.agent.util.Jar.lambda$getEmbeddedFile$e1c0ab03$1(Jar.java:44)
at kanela.agent.libs.io.vavr.control.Try.of(Try.java:75)
at kanela.agent.util.Jar.getEmbeddedFile(Jar.java:43)
at kanela.agent.util.Jar.getEmbeddedJar(Jar.java:39)
at kanela.agent.util.BootstrapInjector.injectJar(BootstrapInjector.java:36)
at kanela.agent.Kanela.lambda$null$0(Kanela.java:71)
at kanela.agent.util.classloader.InstrumentationClassPath.use(InstrumentationClassPath.java:84)
at kanela.agent.Kanela.lambda$start$1(Kanela.java:68)
at kanela.agent.util.Execution.timed(Execution.java:32)
at kanela.agent.util.Execution.runWithTimeSpent(Execution.java:41)
at kanela.agent.Kanela.start(Kanela.java:67)
at kanela.agent.Kanela.premain(Kanela.java:47)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at sun.instrument.InstrumentationImpl.loadClassAndStartAgent(InstrumentationImpl.java:386)
at sun.instrument.InstrumentationImpl.loadClassAndCallPremain(InstrumentationImpl.java:401)
This seems to be related to bootstrapping a jar, maybe the Kanela jar.
Is it possible to put the necessary jar upfront, so no extra copying is required?
After fix it, refactor travis-test.sh in order to execute agent tests by the command sbt "project agent" +test
Logback Access: https://logback.qos.ch/access.html
Kanela version: 0.0.14
Kamon versions:
"io.kamon" % "kanela-agent-bundle" % KanelaVersion % "agent",
"io.kamon" %% "kamon-core" % "1.1.3",
"io.kamon" %% "kanela-scala-extension" % "0.0.14",
"io.kamon" %% "kamon-servlet-3" % "1.0.0",
"io.kamon" %% "kamon-jaeger" % "1.0.2",
"io.kamon" %% "kamon-zipkin" % "1.0.0",
"io.kamon" %% "kamon-prometheus" % "1.1.1",
"io.kamon" % "kamon-annotation-api" % "1.0.3",
Jetty config
private def configureHandlers(): Unit = {
jettyServer.setHandler {
val handlers = new HandlerCollection()
handlers.addHandler {
val contextHandler = new ServletContextHandler()
contextHandler setContextPath contextPath
contextHandler.setInitParameter(ScalatraListener.LifeCycleKey, "com.despegar.bookedia.connect.server.ScalatraBootstrap")
contextHandler.addEventListener(new ScalatraListener)
contextHandler.addServlet(classOf[DefaultServlet], "/")
contextHandler.addFilter(new FilterHolder(new TeeFilter()), "/*", util.EnumSet.of(DispatcherType.INCLUDE, DispatcherType.REQUEST, DispatcherType.FORWARD))
contextHandler.addFilter(new FilterHolder(new MaintenanceFilter()), "/*", util.EnumSet.of(DispatcherType.INCLUDE, DispatcherType.REQUEST, DispatcherType.FORWARD))
val requestLogHandler = new RequestLogHandler
val requestLog = new RequestLogImpl
requestLog.setResource("/logback-access.xml")
requestLogHandler.setRequestLog(requestLog)
requestLogHandler.setHandler(contextHandler)
requestLogHandler
}
handlers
}
}Exception when starting app:
java.lang.ClassCastException: ch.qos.logback.access.spi.AccessEvent cannot be cast to kamon.logback.instrumentation.ContextAwareLoggingEvent
at kamon.logback.instrumentation.kanela.AppendLoopMethodInterceptor$.aroundAppendLoop(AsyncAppenderInstrumentation.scala:100)
at ch.qos.logback.core.spi.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java)
at ch.qos.logback.access.jetty.RequestLogImpl.log(RequestLogImpl.java:137)
at org.eclipse.jetty.server.handler.RequestLogHandler.handle(RequestLogHandler.java:104)
at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:109)
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:98)
at org.eclipse.jetty.server.Server.handle(Server.java:461)
at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:284)
at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:244)
at org.eclipse.jetty.io.AbstractConnection$2.run(AbstractConnection.java:534)
at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:607)
at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:536)
at java.lang.Thread.run(Thread.java:748)```After migration to kanela-agent from 1.0.9 to 1.0.10 mdc context stopped propagate in logs.
With 1.0.9 everything works fine. Kamon version didn't change.
Exception in thread "main" java.lang.ExceptionInInitializerError
at kamon.instrumentation.akka.instrumentations.akka_26.InstrumentNewExecutorServiceOnAkka26$.around(DispatcherInstrumentation.scala:118)
at akka.dispatch.ForkJoinExecutorConfigurator$ForkJoinExecutorServiceFactory.createExecutorService(ForkJoinExecutorConfigurator.scala)
at akka.dispatch.Dispatcher$LazyExecutorServiceDelegate.executor$lzycompute(Dispatcher.scala:44)
at akka.dispatch.Dispatcher$LazyExecutorServiceDelegate.executor(Dispatcher.scala:44)
at akka.dispatch.ExecutorServiceDelegate.execute(ThreadPoolBuilder.scala:219)
at akka.dispatch.ExecutorServiceDelegate.execute$(ThreadPoolBuilder.scala:219)
at akka.dispatch.Dispatcher$LazyExecutorServiceDelegate.execute(Dispatcher.scala:43)
at akka.dispatch.Dispatcher.registerForExecution(Dispatcher.scala:127)
at akka.dispatch.MessageDispatcher.attach(AbstractDispatcher.scala:152)
at akka.actor.dungeon.Dispatch.start(Dispatch.scala:121)
at akka.actor.dungeon.Dispatch.start$(Dispatch.scala:119)
at akka.actor.ActorCell.start(ActorCell.scala:410)
at akka.actor.LocalActorRef.start(ActorRef.scala:384)
at akka.actor.LocalActorRefProvider.init(ActorRefProvider.scala:605)
at akka.actor.ActorSystemImpl.liftedTree2$1(ActorSystem.scala:1026)
at akka.actor.ActorSystemImpl._start$lzycompute(ActorSystem.scala:1022)
at akka.actor.ActorSystemImpl._start(ActorSystem.scala:1022)
at akka.actor.ActorSystemImpl.start(ActorSystem.scala:1045)
at akka.actor.ActorSystem$.apply(ActorSystem.scala:272)
at akka.actor.ActorSystem$.apply(ActorSystem.scala:316)
at akka.actor.ActorSystem$.apply(ActorSystem.scala:260)
at com.despegar.zoom.ensemble.Ensemble.<init>(Ensemble.scala:71)
at com.despegar.zoom.server.ServerApp$.delayedEndpoint$com$despegar$zoom$server$ServerApp$1(ServerApp.scala:30)
at com.despegar.zoom.server.ServerApp$delayedInit$body.apply(ServerApp.scala:29)
at scala.Function0.apply$mcV$sp(Function0.scala:39)
at scala.Function0.apply$mcV$sp$(Function0.scala:39)
at scala.runtime.AbstractFunction0.apply$mcV$sp(AbstractFunction0.scala:17)
at scala.App.$anonfun$main$1(App.scala:76)
at scala.App.$anonfun$main$1$adapted(App.scala:76)
at scala.collection.IterableOnceOps.foreach(IterableOnce.scala:563)
at scala.collection.IterableOnceOps.foreach$(IterableOnce.scala:561)
at scala.collection.AbstractIterable.foreach(Iterable.scala:919)
at scala.App.main(App.scala:76)
at scala.App.main$(App.scala:74)
at com.despegar.zoom.server.ServerApp$.main(ServerApp.scala:29)
at com.despegar.zoom.server.ServerApp.main(ServerApp.scala)
Caused by: java.lang.reflect.InaccessibleObjectException: Unable to make field private final java.util.concurrent.ExecutorService java.util.concurrent.Executors$DelegatedExecutorService.e accessible: module java.base does not "opens java.util.concurrent" to unnamed module @6e4784bc
at java.base/java.lang.reflect.AccessibleObject.checkCanSetAccessible(AccessibleObject.java:357)
at java.base/java.lang.reflect.AccessibleObject.checkCanSetAccessible(AccessibleObject.java:297)
at java.base/java.lang.reflect.Field.checkCanSetAccessible(Field.java:177)
at java.base/java.lang.reflect.Field.setAccessible(Field.java:171)
at kamon.instrumentation.executor.ExecutorInstrumentation$.<clinit>(ExecutorInstrumentation.scala:260)
... 36 more
See this example from the Play instrumentation:
onType("play.core.server.netty.PlayRequestHandler")
.when(isNettyAround)
.mixin(classOf[HasServerInstrumentation.Mixin])
.mixin(classOf[HasTimestamp.Mixin])
.advise(isConstructor, PlayRequestHandlerConstructorAdvice)
.advise(isConstructor, CaptureCurrentTimestampOnExit)
.advise(method("handle"), NettyPlayRequestHandlerHandleAdvice)
}
The last advice on that example uses Netty-specific classes that will only be present if Netty is present and since all of this is loaded when the instrumentation is loaded by Kanela then the whole instrumentation loading fails with this error:
Error trying to load Instrumentation: kamon.instrumentation.play.PlayServerInstrumentation with error: java.lang.NoClassDefFoundError: io/netty/util/concurrent/GenericFutureListener
My proposal here would be that when using the .when(refiner) we need to provide a function that gets lazily evaluated, only when the refiner predicate succeeds. The instrumentation above would look like this:
onType("play.core.server.netty.PlayRequestHandler")
.when(isNettyAround, target => {
target
.mixin(classOf[HasServerInstrumentation.Mixin])
.mixin(classOf[HasTimestamp.Mixin])
.advise(isConstructor, PlayRequestHandlerConstructorAdvice)
.advise(isConstructor, CaptureCurrentTimestampOnExit)
.advise(method("handle"), NettyPlayRequestHandlerHandleAdvice)
})
This is very similar to what we had in the very early versions of Kanela where everything was lazy loaded.. now I understand why it was like that ๐. What other proposals come to mind here?
This issue originated on the kamon.io side (kamon-io/Kamon#827)
Occasionally my instances fail to start. They hang right after the kanela banner. I am including a jstack output which identifies a deadlock.
kanela-agent: 1.0.6
kamon depedencies/bundles: 2.1.4
stdout
`OpenJDK 64-Bit Server VM warning: Sharing is only supported for boot loader classes because bootstrap classpath has been appended
| |/ / | | \ \
| ' / __ _ _ __ | | __ _ \ \
| < / | '_ \ / _ \ |/ _ | ) ) ) )
| . \ (| | | | | / | (| | / / / /
||,|| ||_||,| ////
==============================
Running with Kanela, the Kamon Instrumentation Agent :: (v1.0.6)`
jstack output
`2020-08-06 18:24:15
Full thread dump OpenJDK 64-Bit Server VM (14.0.2+12 mixed mode, sharing):
Threads class SMR info:
_java_thread_list=0x00007f29e4002010, length=12, elements={
0x00007f2a3002e800, 0x00007f2a30ac7800, 0x00007f2a30ac9800, 0x00007f2a30acf800,
0x00007f2a30ad1800, 0x00007f2a30ad3800, 0x00007f2a30ad5800, 0x00007f2a30ad7800,
0x00007f2a30b11000, 0x00007f2a3178a800, 0x00007f2a31b37800, 0x00007f29e4001000
}
"main" #1 prio=5 os_prio=0 cpu=1637.37ms elapsed=44.96s tid=0x00007f2a3002e800 nid=0x45 waiting on condition [0x00007f2a39920000]
java.lang.Thread.State: WAITING (parking)
at jdk.internal.misc.Unsafe.park([email protected]/Native Method)
"Reference Handler" #2 daemon prio=10 os_prio=0 cpu=0.25ms elapsed=44.91s tid=0x00007f2a30ac7800 nid=0x4c waiting on condition [0x00007f2a103ae000]
java.lang.Thread.State: RUNNABLE
at java.lang.ref.Reference.waitForReferencePendingList([email protected]/Native Method)
at java.lang.ref.Reference.processPendingReferences([email protected]/Reference.java:241)
at java.lang.ref.Reference$ReferenceHandler.run([email protected]/Reference.java:213)
"Finalizer" #3 daemon prio=8 os_prio=0 cpu=0.34ms elapsed=44.91s tid=0x00007f2a30ac9800 nid=0x4d in Object.wait() [0x00007f2a1036d000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait([email protected]/Native Method)
"Signal Dispatcher" #4 daemon prio=9 os_prio=0 cpu=0.46ms elapsed=44.91s tid=0x00007f2a30acf800 nid=0x4e runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"Service Thread" #5 daemon prio=9 os_prio=0 cpu=0.26ms elapsed=44.91s tid=0x00007f2a30ad1800 nid=0x4f runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"C2 CompilerThread0" #6 daemon prio=9 os_prio=0 cpu=1336.62ms elapsed=44.91s tid=0x00007f2a30ad3800 nid=0x50 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
No compile task
"C1 CompilerThread0" #8 daemon prio=9 os_prio=0 cpu=786.11ms elapsed=44.91s tid=0x00007f2a30ad5800 nid=0x51 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
No compile task
"Sweeper thread" #9 daemon prio=9 os_prio=0 cpu=13.25ms elapsed=44.91s tid=0x00007f2a30ad7800 nid=0x52 runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"Common-Cleaner" #10 daemon prio=8 os_prio=0 cpu=0.33ms elapsed=44.87s tid=0x00007f2a30b11000 nid=0x53 in Object.wait() [0x00007f2a01ebc000]
java.lang.Thread.State: TIMED_WAITING (on object monitor)
at java.lang.Object.wait([email protected]/Native Method)
"tinylog-WritingThread" #12 prio=3 os_prio=0 cpu=188.64ms elapsed=43.93s tid=0x00007f2a3178a800 nid=0x56 sleeping [0x00007f2a016fe000]
java.lang.Thread.State: TIMED_WAITING (sleeping)
at java.lang.Thread.sleep([email protected]/Native Method)
at kanela.agent.libs.org.pmw.tinylog.WritingThread.run(Unknown Source)
"ExpiringMap-Expirer" #13 daemon prio=5 os_prio=0 cpu=2.41ms elapsed=43.25s tid=0x00007f2a31b37800 nid=0x57 waiting on condition [0x00007f2a0173d000]
java.lang.Thread.State: WAITING (parking)
at jdk.internal.misc.Unsafe.park([email protected]/Native Method)
"Attach Listener" #14 daemon prio=9 os_prio=0 cpu=0.39ms elapsed=0.10s tid=0x00007f29e4001000 nid=0x74 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"VM Thread" os_prio=0 cpu=6.60ms elapsed=44.91s tid=0x00007f2a30ac4800 nid=0x4b runnable
"GC Thread#0" os_prio=0 cpu=3.67ms elapsed=44.96s tid=0x00007f2a30088800 nid=0x46 runnable
"G1 Main Marker" os_prio=0 cpu=0.09ms elapsed=44.96s tid=0x00007f2a300a5800 nid=0x47 runnable
"G1 Conc#0" os_prio=0 cpu=0.05ms elapsed=44.96s tid=0x00007f2a300a7000 nid=0x48 runnable
"G1 Refine#0" os_prio=0 cpu=0.12ms elapsed=44.92s tid=0x00007f2a30a3e800 nid=0x49 runnable
"G1 Young RemSet Sampling" os_prio=0 cpu=9.19ms elapsed=44.92s tid=0x00007f2a30a40000 nid=0x4a runnable
JNI global refs: 9, weak refs: 0
Found one Java-level deadlock:
"main":
waiting for ownable synchronizer 0x00000007db14ad28, (a java.util.concurrent.locks.ReentrantLock$NonfairSync),
which is held by "ExpiringMap-Expirer"
"ExpiringMap-Expirer":
waiting for ownable synchronizer 0x00000007d7c6aed8, (a java.util.concurrent.locks.ReentrantReadWriteLock$NonfairSync),
which is held by "main"
Java stack information for the threads listed above:
"main":
at jdk.internal.misc.Unsafe.park([email protected]/Native Method)
Found 1 deadlock.`
Kanela v15 doesn't works with java 1.8, trying with java 9 everything works, may be an issue with the java version when you publish the artifact?
Exception in thread "main" java.lang.UnsupportedClassVersionError: kanela/agent/Kanela has been compiled by a more recent version of the Java Runtime (class file version 53.0), this version of the Java Runtime only recognizes class file versions up to 52.0
at java.lang.ClassLoader.defineClass1(Native Method)
at java.lang.ClassLoader.defineClass(ClassLoader.java:763)
at java.security.SecureClassLoader.defineClass(SecureClassLoader.java:142)
at java.net.URLClassLoader.defineClass(URLClassLoader.java:467)
at java.net.URLClassLoader.access$100(URLClassLoader.java:73)
at java.net.URLClassLoader$1.run(URLClassLoader.java:368)
at java.net.URLClassLoader$1.run(URLClassLoader.java:362)
at java.security.AccessController.doPrivileged(Native Method)
at java.net.URLClassLoader.findClass(URLClassLoader.java:361)
at java.lang.ClassLoader.loadClass(ClassLoader.java:424)
at sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:349)
at java.lang.ClassLoader.loadClass(ClassLoader.java:357)
at sun.instrument.InstrumentationImpl.loadClassAndStartAgent(InstrumentationImpl.java:304)
at sun.instrument.InstrumentationImpl.loadClassAndCallPremain(InstrumentationImpl.java:401)
FATAL ERROR in native method: processing of -javaagent failed
Java: 8.0.265.hs-adpt
From build.sbt
val akkaVersion = "2.6.5"
val akkaStreamsVersion = "2.5.31"
val akkaHttpVersion = "10.1.11"
val KamonVersion = "2.1.4"
....
libraryDependencies ++= {
......
"io.kamon" %% "kamon-bundle" % KamonVersion,
"io.kamon" %% "kamon-core" % KamonVersion,
"io.kamon" %% "kamon-status-page" % KamonVersion,
"io.kamon" %% "kamon-prometheus" % KamonVersion,
"io.kamon" %% "kamon-akka" % KamonVersion,
"io.kamon" %% "kamon-akka-http" % KamonVersion,
"io.kamon" %% "kamon-system-metrics" % KamonVersion % Runtime
}
Where "io.kamon" %% "kamon-bundle" % KamonVersion, related to kanela-agent v1.0.6.
Running the application locally with sbt, works fine (JDK: 8.0.265.hs-adpt)
kanel-agentenabled, akka remote does not work and fails deserializing the protobuf message:2021-01-21 13:05:03.920 [cluster-akka.actor.default-dispatcher-19] WARN akka.remote.artery.Deserializer .$anonfun$applyOrElse$2(90) - Failed to deserialize message from [unknown] with serializer id [17] and manifest [d]. java.lang.IllegalArgumentException: newPosition < 0: (-857778078 < 0)
kanel-agent is disabled, it works fine@ivantopo WDYT?
To-DO list in order to release the first version:
kamon-agent with sbt-javaagent / sbt-kamon-agentThe interval at which the profiler samples stack traces should be randomized within its given
interval in order to avoid periodicy bias.
resources:
http://plv.colorado.edu/papers/mytkowicz-pldi10.pdf
It's great that Kanela supports the zipkin B3 headers, but it would be fantastic if it also supported the newer and interoperable W3C trace context https://www.w3.org/TR/trace-context/
React
A declarative, efficient, and flexible JavaScript library for building user interfaces.
๐ Vue.js is a progressive, incrementally-adoptable JavaScript framework for building UI on the web.
Typescript
TypeScript is a superset of JavaScript that compiles to clean JavaScript output.
An Open Source Machine Learning Framework for Everyone
Django
The Web framework for perfectionists with deadlines.
Laravel
A PHP framework for web artisans
Bring data to life with SVG, Canvas and HTML. ๐๐๐
JavaScript (JS) is a lightweight interpreted programming language with first-class functions.
Some thing interesting about web. New door for the world.
A server is a program made to process requests and deliver data to clients.
Machine learning is a way of modeling and interpreting data that allows a piece of software to respond intelligently.
Some thing interesting about visualization, use data art
Some thing interesting about game, make everyone happy.
Facebook
We are working to build community through open source technology. NB: members must have two-factor auth.
Microsoft
Open source projects and samples from Microsoft.
Google
Google โค๏ธ Open Source for everyone.
Alibaba
Alibaba Open Source for everyone
D3
Data-Driven Documents codes.
Tencent
China tencent open source team.