devexperts / aprof Goto Github PK

View Code? Open in Web Editor NEW

218.0 23.0 39.0 657 KB

Java memory allocation profiler

Home Page: https://code.devexperts.com/display/AProf/

License: GNU General Public License v3.0

Java 100.00%

profiler java-agent allocation-profiling

aprof's Introduction

Aprof - Java Memory Allocation Profiler

What is it?

The Aprof project is a Java Memory Allocation Profiler with very low performance impact on profiled application. It acts as an agent which transforms class bytecode by inserting counter increments wherever memory allocation is done.

Download

Download binaries of the latest release here:

Using Aprof

The profiled application should be run with additional JVM argument:

java -javaagent:aprof.jar <your-application>

To get help on configuration parameters, run

java -jar aprof.jar

Do not rename agent file "aprof.jar"!

Documentation

Documentation can be found at the project's homepage: https://code.devexperts.com/display/AProf/

How it works

See presentation on Joker Conference 2014: http://www.slideshare.net/elizarov/aprof-jocker-2014

Feedback

Feel free to submit feature requests and bug reports at [email protected]

Licensing

This software is licensed under the terms of GPL 3.0 found in the file named "LICENSE". The distribution also contains binaries from the ASM project, licensed under terms found in the file named "LICENSE.asm".

aprof's People

Contributors

Stargazers

Watchers

aprof's Issues

VerifyError in Java 1.8.0_121

I'm trying to use aprof in Hadoop with Java 1.8.0_121, but the VerifyError occurs as follows. Are there any methods to fix it? Thanks!

Exception in thread "main" java.lang.VerifyError: Stack map does not match the one at exception handler 60
Exception Details:
  Location:
    org/apache/hadoop/util/Shell$1.<init>(Lorg/apache/hadoop/util/Shell;Ljava/io/BufferedReader;Ljava/lang/StringBuffer;)V @60: astore
  Reason:
    Current frame's flags are not assignable to stack map frame's.
  Current Frame:
    bci: @38
    flags: { flagThisUninit }
    locals: { uninitializedThis, 'org/apache/hadoop/util/Shell', 'java/io/BufferedReader', 'java/lang/StringBuffer', 'com/devexperts/aprof/LocationStack' }
    stack: { 'java/lang/Throwable' }
  Stackmap Frame:
    bci: @60
    flags: { }
    locals: { top, 'org/apache/hadoop/util/Shell', 'java/io/BufferedReader', 'java/lang/StringBuffer', 'com/devexperts/aprof/LocationStack' }
    stack: { 'java/lang/Throwable' }
  Bytecode:
    0x0000000: 013a 042a 2bb5 0001 2a2c b500 022a 2db5
    0x0000010: 0003 2a19 0459 c700 0a57 b800 5759 3a04
    0x0000020: 111b bbb6 005b b700 0419 0459 c700 0a57
    0x0000030: b800 5759 3a04 b600 5ea7 0018 3a05 1904
    0x0000040: 59c7 000a 57b8 0057 593a 04b6 005e 1905
    0x0000050: bfb1                                   
  Exception Handler Table:
    bci [38, 41] => handler: 60
  Stackmap Table:
    full_frame(@32,{UninitializedThis,Object[#42],Object[#48],Object[#51],Object[#83]},{UninitializedThis,Object[#83]})
    full_frame(@54,{Object[#14],Object[#42],Object[#48],Object[#51],Object[#83]},{Object[#83]})
    full_frame(@60,{Top,Object[#42],Object[#48],Object[#51],Object[#83]},{Object[#96]})
    full_frame(@75,{Top,Object[#42],Object[#48],Object[#51],Object[#83],Object[#96]},{Object[#83]})
    full_frame(@81,{Object[#14],Object[#42],Object[#48],Object[#51],Object[#83]},{})

	at sun.misc.Unsafe.allocateInstance(Native Method)
	at com.devexperts.aprof.AProfSizeUtil.getObjectSizeByClass(AProfSizeUtil.java:106)
	at com.devexperts.aprof.AProfOps.allocateSize(AProfOps.java:45)
	at org.apache.hadoop.util.Shell.runCommand(Shell.java:506)

java-allocation-instrumenter

Hi, I was just wondering if you were aware of https://code.google.com/p/java-allocation-instrumenter/ ?

If so, is there anything your aprof does that it doesn't?

Flame chart visualization

Like in async profiler. Are you considering to add it?

java.lang.VerifyError on start: Bad <init> method call from after the start of a try block

Trying to start cassandra 2.0 got VerifyError at the startup:

ERROR 14:59:24,243 [org.apache.cassandra.service.CassandraDaemon] Exception encountered during startup
java.lang.VerifyError: Bad <init> method call from after the start of a try block
Exception Details:
  Location:
    org/apache/cassandra/db/RowMutation.<init>(Ljava/lang/String;Ljava/nio/ByteBuffer;Lorg/apache/cassandra/db/ColumnFamily;)V @73: invokespecial
  Reason:
    Error exists in the bytecode
  Bytecode:
    0000000: 013a 042a 2b2c 2db6 003b 2d19 0459 c700
    0000010: 0a57 b801 a659 3a04 1120 ecb6 01af b800
    0000020: 4119 0459 c700 0a57 b801 a659 3a04 b601
    0000030: b2a7 0018 3a05 1904 59c7 000a 57b8 01a6
    0000040: 593a 04b6 01b2 1905 bfb7 0035 b1       
  Exception Handler Table:
    bci [30, 33] => handler: 52
  Stackmap Table:
    full_frame(@24,{UninitializedThis,Object[#258],Object[#264],Object[#60],Object[#419]},{UninitializedThis,Object[#258],Object[#264],Object[#286],Object[#60],Object[#419]})
    full_frame(@46,{UninitializedThis,Object[#258],Object[#264],Object[#60],Object[#419]},{UninitializedThis,Object[#258],Object[#264],Object[#113],Object[#419]})
    same_locals_1_stack_item_frame(@52,Object[#436])
    full_frame(@67,{UninitializedThis,Object[#258],Object[#264],Object[#60],Object[#419],Object[#436]},{Object[#419]})
    full_frame(@73,{UninitializedThis,Object[#258],Object[#264],Object[#60],Object[#419]},{UninitializedThis,Object[#258],Object[#264],Object[#113]})

    at org.apache.cassandra.net.MessagingService$2.<init>(MessagingService.java:258)
    at org.apache.cassandra.net.MessagingService.<clinit>(MessagingService.java:253)
    at org.apache.cassandra.service.StorageService.<init>(StorageService.java:293)

it looks like is fails to gen bytecode when new statement is constructor, like here:

    public RowMutation(String keyspaceName, ByteBuffer key)
    {
        this(keyspaceName, key, new HashMap<UUID, ColumnFamily>());
    }

    public RowMutation(String keyspaceName, ByteBuffer key, ColumnFamily cf)
    {
        this(keyspaceName, key, Collections.singletonMap(cf.id(), cf));
    }

make constructor instrumentation optional

return constructor instrumentation and make it optional to run under java8 with verification disabled

aprof does not work with Java 11

Bumping asm version to 7.1 allows building artifact but aprof-selftest fails with exception:

[INFO] --- maven-antrun-plugin:1.7:run (aprof-selftest) @ agent ---
[INFO] Executing tasks

main:
     [java] 2019-04-08T14:46:55.151+0300: aprof: Loading Aprof 33-SNAPSHOT, Copyright (C) 2002-2017 Devexperts LLC...
     [java] Exception in thread "main" java.lang.reflect.InvocationTargetException
     [java] 	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
     [java] 	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
     [java] 	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
     [java] 	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
     [java] 	at java.instrument/sun.instrument.InstrumentationImpl.loadClassAndStartAgent(InstrumentationImpl.java:513)
     [java] 	at java.instrument/sun.instrument.InstrumentationImpl.loadClassAndCallPremain(InstrumentationImpl.java:525)
     [java] Caused by: java.lang.VerifyError
     [java] 	at java.instrument/sun.instrument.InstrumentationImpl.redefineClasses0(Native Method)
     [java] 	at java.instrument/sun.instrument.InstrumentationImpl.redefineClasses(InstrumentationImpl.java:193)
     [java] 	at com.devexperts.aprof.AProfAgent.redefine(AProfAgent.java:211)
     [java] 	at com.devexperts.aprof.AProfAgent.go(AProfAgent.java:124)
     [java] 	at com.devexperts.aprof.AProfAgent.premain(AProfAgent.java:72)
     [java] 	... 6 more
     [java] FATAL ERROR in native method: processing of -javaagent failed

alex@Bubunta:~/aprof$ java -version
openjdk version "11.0.1" 2018-10-16
OpenJDK Runtime Environment (build 11.0.1+13-Ubuntu-3ubuntu118.04ppa1)
OpenJDK 64-Bit Server VM (build 11.0.1+13-Ubuntu-3ubuntu118.04ppa1, mixed mode, sharing)

Deadlock with custom ClassLoader

Found one Java-level deadlock:

"ZipFileCache Dispose":
waiting to lock monitor 0x39c1d47c (object 0x1af6bc50, a com.devexperts.aprof.transformer.ClassInfoCache),
which is held by "AWT-EventQueue-0"
"AWT-EventQueue-0":
waiting to lock monitor 0x39c1d08c (object 0x1f7db2c8, a java.lang.Object),
which is held by "ZipFileCache Dispose"

Java stack information for the threads listed above:

"ZipFileCache Dispose":
at com.devexperts.aprof.transformer.ClassInfoCache.getOrInitClassInfoMap(ClassInfoCache.java)
- waiting to lock <0x1af6bc50> (a com.devexperts.aprof.transformer.ClassInfoCache)
at com.devexperts.aprof.transformer.AProfTransformer.transformImpl(AProfTransformer.java:80)
at com.devexperts.aprof.transformer.AProfTransformer.transform(AProfTransformer.java:64)
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.lang.ClassLoader.defineClass(ClassLoader.java:642)
at com.intellij.util.lang.UrlClassLoader._defineClass(UrlClassLoader.java:195)
at com.intellij.util.lang.UrlClassLoader.defineClass(UrlClassLoader.java:191)
at com.intellij.util.lang.UrlClassLoader.findClass(UrlClassLoader.java:152)
at java.lang.ClassLoader.loadClass(ClassLoader.java:424)
- locked <0x1bb5ae40> (a com.intellij.util.lang.UrlClassLoader)
at java.lang.ClassLoader.loadClass(ClassLoader.java:357)
at gnu.trove.THashMap.values(THashMap.java:424)
at com.intellij.openapi.util.io.ZipFileCache.getFilesToClose(ZipFileCache.java:149)
- locked <0x1f7db2c8> (a java.lang.Object)
at com.intellij.openapi.util.io.ZipFileCache.access$000(ZipFileCache.java:54)
at com.intellij.openapi.util.io.ZipFileCache$1.run(ZipFileCache.java:79)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
"AWT-EventQueue-0":
at com.intellij.openapi.util.io.ZipFileCache.acquire(ZipFileCache.java:102)
- waiting to lock <0x1f7db2c8> (a java.lang.Object)
at com.intellij.util.lang.JarLoader.acquireZipFile(JarLoader.java:59)
at com.intellij.util.lang.JarLoader.(JarLoader.java:42)
at com.intellij.util.lang.ClassPath.getLoader(ClassPath.java:179)
at com.intellij.util.lang.ClassPath.getLoader(ClassPath.java:137)
- locked <0x1bd44828> (a com.intellij.util.lang.ClassPath)
at com.intellij.util.lang.ClassPath.getResource(ClassPath.java:98)
at com.intellij.util.lang.UrlClassLoader._getResource(UrlClassLoader.java:213)
at com.intellij.util.lang.UrlClassLoader.getResourceAsStream(UrlClassLoader.java:221)
at com.intellij.ide.plugins.cl.PluginClassLoader.getResourceAsStream(PluginClassLoader.java:160)
at com.intellij.ide.plugins.cl.PluginClassLoader.getResourceAsStream(PluginClassLoader.java:164)
at com.intellij.ide.plugins.cl.PluginClassLoader.getResourceAsStream(PluginClassLoader.java:164)
at com.intellij.ide.plugins.cl.PluginClassLoader.getResourceAsStream(PluginClassLoader.java:164)
at com.devexperts.aprof.transformer.ClassInfoCache.buildClassInfo(ClassInfoCache.java:225)
at com.devexperts.aprof.transformer.ClassInfoCache.getOrBuildClassInfo(ClassInfoCache.java:43)
- locked <0x1af6bc50> (a com.devexperts.aprof.transformer.ClassInfoCache)
at com.devexperts.aprof.transformer.ClassInfoCache.initTrackedClasses(ClassInfoCache.java:91)
at com.devexperts.aprof.transformer.ClassInfoCache.getOrInitClassInfoMap(ClassInfoCache.java:65)
- locked <0x1af6bc50> (a com.devexperts.aprof.transformer.ClassInfoCache)
at com.devexperts.aprof.transformer.AProfTransformer.transformImpl(AProfTransformer.java:80)
at com.devexperts.aprof.transformer.AProfTransformer.transform(AProfTransformer.java:64)
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.lang.ClassLoader.defineClass(ClassLoader.java:642)
at com.intellij.util.lang.UrlClassLoader._defineClass(UrlClassLoader.java:195)
at com.intellij.util.lang.UrlClassLoader.defineClass(UrlClassLoader.java:191)
at com.intellij.util.lang.UrlClassLoader._findClass(UrlClassLoader.java:167)
at com.intellij.ide.plugins.cl.PluginClassLoader.b(PluginClassLoader.java:124)
- locked <0x1d8ff338> (a com.intellij.ide.plugins.cl.PluginClassLoader)
at com.intellij.ide.plugins.cl.PluginClassLoader.a(PluginClassLoader.java:77)
at com.intellij.ide.plugins.cl.PluginClassLoader.loadClass(PluginClassLoader.java:66)
at java.lang.ClassLoader.loadClass(ClassLoader.java:357)
at java.lang.Class.forName0(Native Method)
at java.lang.Class.forName(Class.java:344)
at com.intellij.openapi.extensions.impl.ExtensionComponentAdapter.loadClass(ExtensionComponentAdapter.java:159)
at com.intellij.openapi.extensions.impl.ExtensionComponentAdapter.getComponentImplementation(ExtensionComponentAdapter.java:64)
at com.intellij.openapi.extensions.impl.ExtensionComponentAdapter.getComponentInstance(ExtensionComponentAdapter.java:71)
at com.intellij.openapi.extensions.impl.ExtensionComponentAdapter.getExtension(ExtensionComponentAdapter.java:122)
at com.intellij.openapi.extensions.impl.ExtensionPointImpl.processAdapters(ExtensionPointImpl.java:246)
at com.intellij.openapi.extensions.impl.ExtensionPointImpl.getExtensions(ExtensionPointImpl.java:195)
- locked <0x1e315560> (a com.intellij.openapi.extensions.impl.ExtensionPointImpl)
at com.intellij.openapi.extensions.Extensions.getExtensions(Extensions.java:110)
at com.intellij.openapi.extensions.Extensions.getExtensions(Extensions.java:96)
at com.intellij.openapi.components.impl.BasePathMacroManager.(BasePathMacroManager.java:48)
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
at java.lang.reflect.Constructor.newInstance(Constructor.java:408)
at org.picocontainer.defaults.InstantiatingComponentAdapter.newInstance(InstantiatingComponentAdapter.java:193)
at org.picocontainer.defaults.ConstructorInjectionComponentAdapter$1.run(ConstructorInjectionComponentAdapter.java:220)
at org.picocontainer.defaults.ThreadLocalCyclicDependencyGuard.observe(ThreadLocalCyclicDependencyGuard.java:53)
at org.picocontainer.defaults.ConstructorInjectionComponentAdapter.getComponentInstance(ConstructorInjectionComponentAdapter.java:248)
at org.picocontainer.defaults.DecoratingComponentAdapter.getComponentInstance(DecoratingComponentAdapter.java:60)
at org.picocontainer.defaults.CachingComponentAdapter.getComponentInstance(CachingComponentAdapter.java:58)
at com.intellij.util.pico.DefaultPicoContainer.getLocalInstance(DefaultPicoContainer.java:236)
at com.intellij.util.pico.DefaultPicoContainer.getInstance(DefaultPicoContainer.java:223)
at com.intellij.util.pico.DefaultPicoContainer.getComponentInstance(DefaultPicoContainer.java:210)
at org.picocontainer.defaults.BasicComponentParameter.resolveInstance(BasicComponentParameter.java:77)
at org.picocontainer.defaults.ComponentParameter.resolveInstance(ComponentParameter.java:114)
at org.picocontainer.defaults.ConstructorInjectionComponentAdapter.getConstructorArguments(ConstructorInjectionComponentAdapter.java:257)
at org.picocontainer.defaults.ConstructorInjectionComponentAdapter$1.run(ConstructorInjectionComponentAdapter.java:217)
at org.picocontainer.defaults.ThreadLocalCyclicDependencyGuard.observe(ThreadLocalCyclicDependencyGuard.java:53)
at org.picocontainer.defaults.ConstructorInjectionComponentAdapter.getComponentInstance(ConstructorInjectionComponentAdapter.java:248)
at org.picocontainer.defaults.DecoratingComponentAdapter.getComponentInstance(DecoratingComponentAdapter.java:60)
at org.picocontainer.defaults.CachingComponentAdapter.getComponentInstance(CachingComponentAdapter.java:58)
at com.intellij.util.pico.DefaultPicoContainer.getLocalInstance(DefaultPicoContainer.java:236)
at com.intellij.util.pico.DefaultPicoContainer.getInstance(DefaultPicoContainer.java:223)
at com.intellij.util.pico.DefaultPicoContainer.getComponentInstance(DefaultPicoContainer.java:210)
at org.picocontainer.alternatives.AbstractDelegatingMutablePicoContainer.getComponentInstance(AbstractDelegatingMutablePicoContainer.java:75)
at com.intellij.openapi.application.impl.ApplicationImpl.getStateStore(ApplicationImpl.java:179)
- locked <0x1d1faec0> (a com.intellij.openapi.application.impl.ApplicationImpl)
at com.intellij.openapi.application.impl.ApplicationImpl.load(ApplicationImpl.java:496)
at com.intellij.openapi.application.impl.ApplicationImpl.load(ApplicationImpl.java:492)
at com.intellij.idea.IdeaApplication.run(IdeaApplication.java:158)
at com.intellij.idea.MainImpl$1$1$1.run(MainImpl.java:66)
at java.awt.event.InvocationEvent.dispatch(InvocationEvent.java:311)
at java.awt.EventQueue.dispatchEventImpl(EventQueue.java:744)
at java.awt.EventQueue.access$400(EventQueue.java:97)
at java.awt.EventQueue$3.run(EventQueue.java:697)
at java.awt.EventQueue$3.run(EventQueue.java:691)
at java.security.AccessController.doPrivileged(Native Method)
at java.security.ProtectionDomain$1.doIntersectionPrivilege(ProtectionDomain.java:75)
at java.awt.EventQueue.dispatchEvent(EventQueue.java:714)
at com.intellij.ide.IdeEventQueue.dispatchEvent(IdeEventQueue.java:364)
at java.awt.EventDispatchThread.pumpOneEventForFilters(EventDispatchThread.java:201)
at java.awt.EventDispatchThread.pumpEventsForFilter(EventDispatchThread.java:116)
at java.awt.EventDispatchThread.pumpEventsForHierarchy(EventDispatchThread.java:105)
at java.awt.EventDispatchThread.pumpEvents(EventDispatchThread.java:101)
at java.awt.EventDispatchThread.pumpEvents(EventDispatchThread.java:93)
at java.awt.EventDispatchThread.run(EventDispatchThread.java:82)

Found 1 deadlock.

aprof not able to initialize the LocationStack

Hi team,

We tried to integrate JBoss 7 with aprof. During the process JVM exited within few mins throwing class not found error . JDK used 1.7 U45 .Have listed the error stack trace plz review and let us know

--> Wrapper Started as Daemon
STATUS | wrapper | 2018/03/26 11:57:25 | Java Service Wrapper Community Edition 64-bit 3.5.22
STATUS | wrapper | 2018/03/26 11:57:25 | Copyright (C) 1999-2013 Tanuki Software, Ltd. All Rights Reserved.
STATUS | wrapper | 2018/03/26 11:57:25 | http://wrapper.tanukisoftware.com
STATUS | wrapper | 2018/03/26 11:57:25 |
STATUS | wrapper | 2018/03/26 11:57:25 | Launching a JVM...
INFO | jvm 1 | 2018/03/26 11:57:27 | 2018-03-26T11:57:27.343-0700: aprof: Loading Aprof 32, Copyright (C) 2002-2017 Devexperts LLC...
INFO | jvm 1 | 2018/03/26 11:57:39 | 2018-03-26T11:57:39.425-0700: aprof: Writing dump to file aprof.txt...
INFO | jvm 1 | 2018/03/26 11:57:40 | 2018-03-26T11:57:40.151-0700: aprof: Writing dump to file aprof.txt... done
INFO | jvm 1 | 2018/03/26 11:57:40 | 2018-03-26T11:57:40.315-0700: aprof: Loaded in 12829 ms with 11088 ms in transformer (1741 ms other)
INFO | jvm 1 | 2018/03/26 11:57:42 | WrapperManager: Initializing...
INFO | jvm 1 | 2018/03/26 11:57:49 | WrapperSimpleApp:
INFO | jvm 1 | 2018/03/26 11:57:49 | WrapperSimpleApp Error: Encountered an error running main:
INFO | jvm 1 | 2018/03/26 11:57:49 | WrapperSimpleApp Error: java.lang.NoClassDefFoundError: com/devexperts/aprof/LocationStack
INFO | jvm 1 | 2018/03/26 11:57:49 | WrapperSimpleApp Error: at org.jboss.logmanager.LogManager.(LogManager.java:217)
INFO | jvm 1 | 2018/03/26 11:57:49 | WrapperSimpleApp Error: at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
INFO | jvm 1 | 2018/03/26 11:57:49 | WrapperSimpleApp Error: at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:57)
INFO | jvm 1 | 2018/03/26 11:57:49 | WrapperSimpleApp Error: at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
INFO | jvm 1 | 2018/03/26 11:57:49 | WrapperSimpleApp Error: at java.lang.reflect.Constructor.newInstance(Constructor.java:526)
INFO | jvm 1 | 2018/03/26 11:57:49 | WrapperSimpleApp Error: at java.lang.Class.newInstance(Class.java:374)
INFO | jvm 1 | 2018/03/26 11:57:49 | WrapperSimpleApp Error: at java.util.logging.LogManager$1.run(LogManager.java:184)
INFO | jvm 1 | 2018/03/26 11:57:49 | WrapperSimpleApp Error: at java.security.AccessController.doPrivileged(Native Method)
INFO | jvm 1 | 2018/03/26 11:57:49 | WrapperSimpleApp Error: at java.util.logging.LogManager.(LogManager.java:173)
INFO | jvm 1 | 2018/03/26 11:57:49 | WrapperSimpleApp Error: at org.jboss.modules.Main.main(Main.java:278)
INFO | jvm 1 | 2018/03/26 11:57:49 | WrapperSimpleApp Error: at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
INFO | jvm 1 | 2018/03/26 11:57:49 | WrapperSimpleApp Error: at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
INFO | jvm 1 | 2018/03/26 11:57:49 | WrapperSimpleApp Error: at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
INFO | jvm 1 | 2018/03/26 11:57:49 | WrapperSimpleApp Error: at java.lang.reflect.Method.invoke(Method.java:606)
INFO | jvm 1 | 2018/03/26 11:57:49 | WrapperSimpleApp Error: at org.tanukisoftware.wrapper.WrapperSimpleApp.run(WrapperSimpleApp.java:290)
INFO | jvm 1 | 2018/03/26 11:57:49 | WrapperSimpleApp Error: at java.lang.Thread.run(Thread.java:744)
INFO | jvm 1 | 2018/03/26 11:57:49 | WrapperSimpleApp Error: Caused by: java.lang.ClassNotFoundException: com.devexperts.aprof.LocationStack from [Module "org.jboss.logmanager:main" from local module loader @2c5ac6ce (roots: /x/web/STAGE2MA106834/fundingpolicyserv/standalone/modules,/x/opt/infra-jboss-as-7.1tls12/modules,/x/web/STAGE2MA106834/logs/fundingpolicyserv/logs)]
INFO | jvm 1 | 2018/03/26 11:57:49 | WrapperSimpleApp Error: at org.jboss.modules.ModuleClassLoader.findClass(ModuleClassLoader.java:190)
INFO | jvm 1 | 2018/03/26 11:57:49 | WrapperSimpleApp Error: at org.jboss.modules.ConcurrentClassLoader.performLoadClassUnchecked(ConcurrentClassLoader.java:468)
INFO | jvm 1 | 2018/03/26 11:57:49 | WrapperSimpleApp Error: at org.jboss.modules.ConcurrentClassLoader.performLoadClassChecked(ConcurrentClassLoader.java:456)
INFO | jvm 1 | 2018/03/26 11:57:49 | WrapperSimpleApp Error: at org.jboss.modules.ConcurrentClassLoader.performLoadClass(ConcurrentClassLoader.java:398)
INFO | jvm 1 | 2018/03/26 11:57:49 | WrapperSimpleApp Error: at org.jboss.modules.ConcurrentClassLoader.loadClass(ConcurrentClassLoader.java:120)
INFO | jvm 1 | 2018/03/26 11:57:49 | WrapperSimpleApp Error: ... 16 more
INFO | jvm 1 | 2018/03/26 11:57:51 | Exception in thread "Thread-1" java.lang.NoClassDefFoundError: Could not initialize class java.util.logging.LogManager
INFO | jvm 1 | 2018/03/26 11:57:51 | at java.util.logging.LogManager$Cleaner.run(LogManager.java:237)
INFO | jvm 1 | 2018/03/26 11:57:51 | 2018-03-26T11:57:50.948-0700: aprof: Shutting down...
INFO | jvm 1 | 2018/03/26 11:57:51 | 2018-03-26T11:57:50.949-0700: aprof: Writing dump to file aprof.txt...
INFO | jvm 1 | 2018/03/26 11:57:51 | 2018-03-26T11:57:51.396-0700: aprof: Writing dump to file aprof.txt... done
INFO | jvm 1 | 2018/03/26 11:57:51 | 2018-03-26T11:57:51.397-0700: aprof: Stopped after 11232 ms with 4584 ms in transformer (6648 ms other)
STATUS | wrapper | 2018/03/26 11:57:51 | <-- Wrapper Stopped

Thanks
Sattish

Percent format

I see this output:

SomeOtherClass.OtherMethod: 2,342,864 (6.93%) bytes in 48,242 (8.43%) objects (avg size 49 bytes)
SomeClass.SomeMethod:       5,491,856 (0.02%) bytes in 343,241 (0.10%) objects (avg size 16 bytes)

It is confused me. Why OtherMethod is 6.93 %, when SomeMethod is 0.02%, if 2,342,864 < 5,491,856?
Is it right that this percentage is calculated as

garbage_produced_by(SomeClass.SomeMethod) / total_produced_garbage(343,241 objects using SomeClass.SomeMethod) * 100 %

AProf failed to process simple enum class

We see this error in our logs, where it fails for a simple enum class.

2017-03-20T11:39:03.949-0500: aprof: #1932 Failed to process: com.devexperts.logging.LogLevel [in sun.misc.Launcher$AppClassLoader@414493378] with error

java.lang.RuntimeException
[Loaded java.lang.Throwable$PrintStreamOrWriter from /opt/java/jdk1.8.0_112/jre/lib/rt.jar]
[Loaded java.lang.Throwable$WrappedPrintWriter from /opt/java/jdk1.8.0_112/jre/lib/rt.jar]
[Loaded java.util.IdentityHashMap$KeySet from /opt/java/jdk1.8.0_112/jre/lib/rt.jar]
2017-03-20T11:39:03.956-0500: aprof: java.lang.RuntimeException
2017-03-20T11:39:03.962-0500: aprof: at org.objectweb.asm.MethodVisitor.visitTypeAnnotation(Unknown Source)
73201 1216 s 2 java.io.BufferedOutputStream::flush (12 bytes)
73202 1217 2 java.io.OutputStream::flush (1 bytes)
2017-03-20T11:39:03.962-0500: aprof: at org.objectweb.asm.ClassReader.b(Unknown Source)
73202 1218 ! 2 com.devexperts.aprof.util.FastFmtUtil::print2 (146 bytes)
2017-03-20T11:39:03.963-0500: aprof: at org.objectweb.asm.ClassReader.accept(Unknown Source)
2017-03-20T11:39:03.964-0500: aprof: at org.objectweb.asm.ClassReader.accept(Unknown Source)
2017-03-20T11:39:03.964-0500: aprof: at com.devexperts.aprof.transformer.AProfTransformer.transformImpl(AProfTransformer.java:103)
2017-03-20T11:39:03.964-0500: aprof: at com.devexperts.aprof.transformer.AProfTransformer.transform(AProfTransformer.java:64)
2017-03-20T11:39:03.964-0500: aprof: at sun.instrument.TransformerManager.transform(TransformerManager.java:188)
2017-03-20T11:39:03.964-0500: aprof: at sun.instrument.InstrumentationImpl.transform(InstrumentationImpl.java:428)
2017-03-20T11:39:03.964-0500: aprof: at java.lang.ClassLoader.defineClass1(Native Method)
2017-03-20T11:39:03.965-0500: aprof: at java.lang.ClassLoader.defineClass(ClassLoader.java:763)
73204 1219 ! 2 java.io.PrintWriter::println (27 bytes)
LogLevel.zip

73205 1220 ! 2 java.io.PrintWriter::newLine (66 bytes)
2017-03-20T11:39:03.965-0500: aprof: at java.security.SecureClassLoader.defineClass(SecureClassLoader.java:142)
2017-03-20T11:39:03.970-0500: aprof: at java.net.URLClassLoader.defineClass(URLClassLoader.java:467)
2017-03-20T11:39:03.970-0500: aprof: at java.net.URLClassLoader.access$100(URLClassLoader.java:73)
2017-03-20T11:39:03.970-0500: aprof: at java.net.URLClassLoader$1.run(URLClassLoader.java:368)
2017-03-20T11:39:03.970-0500: aprof: at java.net.URLClassLoader$1.run(URLClassLoader.java:362)
2017-03-20T11:39:03.970-0500: aprof: at java.security.AccessController.doPrivileged(Native Method)
2017-03-20T11:39:03.970-0500: aprof: at java.net.URLClassLoader.findClass(URLClassLoader.java:361)
2017-03-20T11:39:03.970-0500: aprof: at java.lang.ClassLoader.loadClass(ClassLoader.java:424)
2017-03-20T11:39:03.970-0500: aprof: at sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:331)
2017-03-20T11:39:03.970-0500: aprof: at java.lang.ClassLoader.loadClass(ClassLoader.java:357)
2017-03-20T11:39:03.970-0500: aprof: at com.devexperts.logging.LoggingGroup.(LoggingGroup.java:18)
2017-03-20T11:39:03.971-0500: aprof: at com.devexperts.logging.LoggingGroup.(LoggingGroup.java:10)
2017-03-20T11:39:03.971-0500: aprof: at com.devexperts.logging.DynamicLogging.getLogger(DynamicLogging.java:39)
2017-03-20T11:39:03.971-0500: aprof: at com.devexperts.tos.backend.scriptcalculator.ScriptCalculator.(ScriptCalculator.java:71)

AProfTransformer - java.lang.ArrayIndexOutOfBoundsException: 15

java.lang.ArrayIndexOutOfBoundsException: 15
at org.objectweb.asm.ClassReader.readLabel(Unknown Source)
at org.objectweb.asm.ClassReader.a(Unknown Source)
at org.objectweb.asm.ClassReader.a(Unknown Source)
at org.objectweb.asm.ClassReader.b(Unknown Source)
at org.objectweb.asm.ClassReader.accept(Unknown Source)
at org.objectweb.asm.ClassReader.accept(Unknown Source)
at com.devexperts.aprof.transformer.AProfTransformer.transformImpl(AProfTransformer.java:107)
at com.devexperts.aprof.transformer.AProfTransformer.transform(AProfTransformer.java:68)
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:763)
at java.security.SecureClassLoader.defineClass(SecureClassLoader.java:142)
at org.apache.catalina.loader.WebappClassLoaderBase.findClassInternal(WebappClassLoaderBase.java:2277)
at org.apache.catalina.loader.WebappClassLoaderBase.findClass(WebappClassLoaderBase.java:811)
at org.apache.catalina.loader.WebappClassLoaderBase.loadClass(WebappClassLoaderBase.java:1254)
at org.apache.catalina.loader.WebappClassLoaderBase.loadClass(WebappClassLoaderBase.java:1119)
at java.lang.ClassLoader.defineClass1(Native Method)
at java.lang.ClassLoader.defineClass(ClassLoader.java:763)
at java.security.SecureClassLoader.defineClass(SecureClassLoader.java:142)
at org.apache.catalina.loader.WebappClassLoaderBase.findClassInternal(WebappClassLoaderBase.java:2277)
at org.apache.catalina.loader.WebappClassLoaderBase.findClass(WebappClassLoaderBase.java:811)
at org.apache.catalina.loader.WebappClassLoaderBase.loadClass(WebappClassLoaderBase.java:1254)
at java.lang.ClassLoader.loadClass(ClassLoader.java:411)
at java.net.FactoryURLClassLoader.loadClass(URLClassLoader.java:814)
at java.lang.ClassLoader.loadClass(ClassLoader.java:357)
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 java.net.FactoryURLClassLoader.loadClass(URLClassLoader.java:814)
at java.lang.ClassLoader.loadClass(ClassLoader.java:357)

Unfortunately, I can not show you the code, it is commercial.
Java: 1.8.144
Tomcat: 8.5.16
Aprof: 32

#1 top location is <unknown>

#1 top location in my report is unknown, is there anything I can do to make it known? Since that's the #1 location I am pretty curious!

Top allocated data types with reverse location traces

char[]: 50,218,419,736 (40.15%) bytes in 415,001,837 (25.24%) objects (avg size 121 bytes)
java.util.Arrays.copyOf: 27,501,437,280 (21.98%) bytes in 190,261,033 (11.57%) objects (avg size 145 bytes)
java.lang.StringBuilder.append: 24,752,865,056 (19.79%) bytes in 179,664,087 (10.92%) objects (avg size 138 bytes)
unknown: 23,312,893,248 (18.64%) bytes in 176,612,875 (10.74%) objects (avg size 132 bytes)

java.lang.VerifyError: Stack map does not match the one at exception handler

I try to run aprof with Wildfly 8 (custom build, but does'nt matter). In short time after start Wildfly crash with message:

  [wildfly] =========================================================================
  [wildfly] 
  [wildfly]   JBoss Bootstrap Environment
  [wildfly] 
  [wildfly]   JBOSS_HOME: /media/data/Java/ws/jboss/tst/2/jboss-bas-8.2.1.krista20
  [wildfly] 
  [wildfly]   JAVA: /usr/lib/jvm/java-8-oracle/bin/java
  [wildfly] 
  [wildfly]   JAVA_OPTS:  -server -XX:+UseCompressedOops  -server -XX:+UseCompressedOops -Xbootclasspath/a:/media/data/Java/ws/jboss/tst/2/lib/asm-analysis.jar:/media/data/Java/ws/jboss/tst/2/lib/asm-commons.jar:/media/data/Java/ws/jboss/tst/2/lib/asm-tree.jar:/media/data/Java/ws/jboss/tst/2/lib/asm-util.jar:/media/data/Java/ws/jboss/tst/2/lib/asm.jar:/media/data/Java/ws/jboss/tst/2/lib/selftest.jar:/media/data/Java/ws/jboss/tst/2/lib/transformer.jar -javaagent:/media/data/Java/ws/jboss/tst/2/aprof.jar -Xms128m -Xmx1g -Djava.awt.headless=true -XX:NativeMemoryTracking=summary -Dru.krista.core.audit.storage.folder.src.sca=/media/data/Java/ws/jboss/tst/2/dir1 -Dru.krista.core.audit.storage.folder.dst.sca=/media/data/Java/ws/jboss/tst/2/dir2
  [wildfly] 
  [wildfly] =========================================================================
  [wildfly] 
  [wildfly] 2017-05-29T19:18:45.922+0300: aprof: Loading Aprof 31, Copyright (C) 2002-2017 Devexperts LLC...
  [wildfly] 2017-05-29T19:18:53.239+0300: aprof: Writing dump to file aprof.txt...
  [wildfly] 2017-05-29T19:18:53.754+0300: aprof: Writing dump to file aprof.txt... done
  [wildfly] 2017-05-29T19:18:53.813+0300: aprof: Loaded in 7846 ms with 6806 ms in transformer (1040 ms other)
  [wildfly] 19:18:56,171 INFO  [org.jboss.modules] (main) JBoss Modules version 1.3.3.Final
  [wildfly] java.lang.VerifyError: Stack map does not match the one at exception handler 40
  [wildfly] 2017-05-29T19:18:56.769+0300: aprof: Shutting down...Exception Details:
  [wildfly] 2017-05-29T19:18:56.770+0300: aprof: Writing dump to file aprof.txt...
  [wildfly] 
  [wildfly]   Location:
  [wildfly]     org/jboss/as/server/BootstrapImpl$ShutdownHook.<init>()V @40: astore_2
  [wildfly]   Reason:
  [wildfly]     Current frame's flags are not assignable to stack map frame's.
  [wildfly]   Current Frame:
  [wildfly]     bci: @20
  [wildfly]     flags: { flagThisUninit }
  [wildfly]     locals: { uninitializedThis, 'com/devexperts/aprof/LocationStack' }
  [wildfly]     stack: { 'java/lang/Throwable' }
  [wildfly]   Stackmap Frame:
  [wildfly]     bci: @40
  [wildfly]     flags: { }
  [wildfly]     locals: { top, 'com/devexperts/aprof/LocationStack' }
  [wildfly]     stack: { 'java/lang/Throwable' }
  [wildfly]   Bytecode:
  [wildfly]     0x0000000: 014c 2a2b 59c7 0009 57b8 008c 594c 111a
  [wildfly]     0x0000010: 46b6 008f b700 042b 59c7 0009 57b8 008c
  [wildfly]     0x0000020: 594c b600 92a7 0014 4d2b 59c7 0009 57b8
  [wildfly]     0x0000030: 008c 594c b600 922c bfb1               
  [wildfly]   Exception Handler Table:
  [wildfly]     bci [20, 23] => handler: 40
  [wildfly]   Stackmap Table:
  [wildfly]     full_frame(@14,{UninitializedThis,Object[#136]},{UninitializedThis,Object[#136]})
  [wildfly]     full_frame(@34,{Object[#27],Object[#136]},{Object[#136]})
  [wildfly]     full_frame(@40,{Top,Object[#136]},{Object[#49]})
  [wildfly]     full_frame(@52,{Top,Object[#136],Object[#49]},{Object[#136]})
  [wildfly]     full_frame(@57,{Object[#27],Object[#136]},{})
  [wildfly] 
  [wildfly]     at com.devexperts.aprof.AProfSizeUtil.getObjectSizeByClass(AProfSizeUtil.java:106)
  [wildfly]     at com.devexperts.aprof.AProfOps.allocateSize(AProfOps.java:45)
  [wildfly]     at org.jboss.as.server.BootstrapImpl.<init>(BootstrapImpl.java:60)
  [wildfly]     at org.jboss.as.server.Bootstrap$Factory.newInstance(Bootstrap.java:236)
  [wildfly]     at org.jboss.as.server.Main.main(Main.java:96)
  [wildfly]     at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
  [wildfly]     at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
  [wildfly]     at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
  [wildfly]     at java.lang.reflect.Method.invoke(Method.java:498)
  [wildfly]     at org.jboss.modules.Module.run(Module.java:312)
  [wildfly]     at org.jboss.modules.Main.main(Main.java:460)
  [wildfly] 2017-05-29T19:18:57.234+0300: aprof: Writing dump to file aprof.txt... done
  [wildfly] 2017-05-29T19:18:57.234+0300: aprof: Stopped after 3470 ms with 2331 ms in transformer (1139 ms other)
  [wildfly] Result: 1

It's sad, but it's not so easy to start Wildfly with aprof due to JBoss Modules system. But I have write some scripts to prepare and run Widlfy with aprof integration. I will attach it latter.

AProf exception in AProfOps.allocateSize

We received the following error in our logs after enabling aprof. We are using jdk 1.8.0_112:

`2017-04-19T09:17:57.943-0500: aprof: #1552 Failed to process: com.devexperts.tos.qdext.volatility.VolatilityContainer [in sun.misc.Launcher$AppClassLoader@414493378] with error

java.lang.RuntimeException
2017-04-19T09:17:57.943-0500: aprof: java.lang.RuntimeException
14419 1475 3 java.lang.StringBuilder::charAt (6 bytes)
14419 1476 3 java.lang.AbstractStringBuilder::charAt (49 bytes)
2017-04-19T09:17:57.943-0500: aprof: at org.objectweb.asm.MethodVisitor.visitTypeAnnotation(Unknown Source)
2017-04-19T09:17:57.943-0500: aprof: at org.objectweb.asm.ClassReader.b(Unknown Source)
2017-04-19T09:17:57.943-0500: aprof: at org.objectweb.asm.ClassReader.accept(Unknown Source)
2017-04-19T09:17:57.943-0500: aprof: at org.objectweb.asm.ClassReader.accept(Unknown Source)
2017-04-19T09:17:57.943-0500: aprof: at com.devexperts.aprof.transformer.AProfTransformer.transformImpl(AProfTransformer.java:103)
2017-04-19T09:17:57.943-0500: aprof: at com.devexperts.aprof.transformer.AProfTransformer.transform(AProfTransformer.java:64)
2017-04-19T09:17:57.943-0500: aprof: at sun.instrument.TransformerManager.transform(TransformerManager.java:188)
2017-04-19T09:17:57.943-0500: aprof: at sun.instrument.InstrumentationImpl.transform(InstrumentationImpl.java:428)
2017-04-19T09:17:57.943-0500: aprof: at java.lang.ClassLoader.defineClass1(Native Method)
2017-04-19T09:17:57.943-0500: aprof: at java.lang.ClassLoader.defineClass(ClassLoader.java:763)
2017-04-19T09:17:57.943-0500: aprof: at java.security.SecureClassLoader.defineClass(SecureClassLoader.java:142)
2017-04-19T09:17:57.943-0500: aprof: at java.net.URLClassLoader.defineClass(URLClassLoader.java:467)
2017-04-19T09:17:57.943-0500: aprof: at java.net.URLClassLoader.access$100(URLClassLoader.java:73)
2017-04-19T09:17:57.944-0500: aprof: at java.net.URLClassLoader$1.run(URLClassLoader.java:368)
2017-04-19T09:17:57.944-0500: aprof: at java.net.URLClassLoader$1.run(URLClassLoader.java:362)
2017-04-19T09:17:57.944-0500: aprof: at java.security.AccessController.doPrivileged(Native Method)
2017-04-19T09:17:57.944-0500: aprof: at java.net.URLClassLoader.findClass(URLClassLoader.java:361)
2017-04-19T09:17:57.944-0500: aprof: at java.lang.ClassLoader.loadClass(ClassLoader.java:424)
2017-04-19T09:17:57.944-0500: aprof: at sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:331)
2017-04-19T09:17:57.944-0500: aprof: at java.lang.ClassLoader.loadClass(ClassLoader.java:357)
2017-04-19T09:17:57.944-0500: aprof: at com.devexperts.tos.qdext.volatility.VolatilityObjField.(VolatilityObjField.java:39)
2017-04-19T09:17:57.944-0500: aprof: at sun.misc.Unsafe.allocateInstance(Native Method)
2017-04-19T09:17:57.944-0500: aprof: at com.devexperts.aprof.AProfSizeUtil.getObjectSizeByClass(AProfSizeUtil.java:102)
2017-04-19T09:17:57.944-0500: aprof: at com.devexperts.aprof.AProfOps.allocateSize(AProfOps.java:41)
`
This seems to be related to the following line in VolatilityObjField:
private static final String ILLEGAL_VALUE_MSG_TEMPLATE = "Illegal value: %s, must be " +
VolatilityContainer.class.getName();