VisualVm profiler and JBoss 7 problems
soltzu Nov 10, 2014 5:12 AMI've been struggling with this for a week so any help would be appreciated. I'm a complete n00b so keep that in mind.
I'm trying to profile my web application running on top of JBoss AS 7. Contents of the "version.txt" file in the $JBOSS_HOME directory:
JBoss Enterprise Application Platform - Version 6.1.1.GA
I start JBboss with the following standalone.conf:
## -*- shell-script -*- ######################################################
## ##
## JBoss Bootstrap Script Configuration ##
## ##
##############################################################################
#
# This file is optional; it may be removed if not needed.
#
#
# Specify the maximum file descriptor limit, use "max" or "maximum" to use
# the default, as queried by the system.
#
# Defaults to "maximum"
#
#MAX_FD="maximum"
#
# Specify the profiler configuration file to load.
#
# Default is to not load profiler configuration file.
#
#PROFILER=""
#
# Specify the location of the Java home directory. If set then $JAVA will
# be defined to $JAVA_HOME/bin/java, else $JAVA will be "java".
#
#JAVA_HOME="/opt/java/jdk"
#
# Specify the exact Java VM executable to use.
#
#JAVA=""
if [ "x$JBOSS_MODULES_SYSTEM_PKGS" = "x" ]; then
JBOSS_MODULES_SYSTEM_PKGS="org.jboss.byteman"
fi
# Uncomment the following line to prevent manipulation of JVM options
# by shell scripts.
#
#PRESERVE_JAVA_OPTS=true
#
# Specify options to pass to the Java VM.
#
if [ "x$JAVA_OPTS" = "x" ]; then
JAVA_OPTS="-Xms1303m -Xmx1303m -XX:MaxPermSize=256m -Djava.net.preferIPv4Stack=true"
JAVA_OPTS="$JAVA_OPTS -Djboss.modules.system.pkgs=$JBOSS_MODULES_SYSTEM_PKGS -Djava.awt.headless=true"
else
echo "JAVA_OPTS already set in environment; overriding default settings with values: $JAVA_OPTS"
fi
# Sample JPDA settings for remote socket debugging
#JAVA_OPTS="$JAVA_OPTS -agentlib:jdwp=transport=dt_socket,address=8787,server=y,suspend=n"
# Sample JPDA settings for shared memory debugging
#JAVA_OPTS="$JAVA_OPTS -agentlib:jdwp=transport=dt_shmem,server=y,suspend=n,address=jboss"
# Uncomment to not use JBoss Modules lockless mode
#JAVA_OPTS="$JAVA_OPTS -Djboss.modules.lockless=false"
# Uncomment to gather JBoss Modules metrics
#JAVA_OPTS="$JAVA_OPTS -Djboss.modules.metrics=true"
#For JaCoco code coverage the JaCoCoAgent is needed
JAVA_OPTS="$JAVA_OPTS -javaagent:$JBOSS_HOME/jacoco-agent.jar=destfile=$JBOSS_HOME/jacoco.exec"
When I start VisualVm and try to do a memory profiling with instrumentation, VisualVm shows a status bar indication saying "Profiler busy" and I can see a series of lines in the Jboss log saying:
Profiler Agent: 250 classes cached.
Then when the bar gets to 50%, something goes wrong and this is the output in the JBoss log:
Profiler Agent: JNI OnLoad Initializing...
Profiler Agent: JNI OnLoad Initialized successfully
15:28:46,156 INFO [stdout] (*** Profiler Agent Communication Thread) Profiler Agent: Waiting for connection on port 5140 (Protocol version: 13)
15:28:46,259 INFO [stdout] (*** Profiler Agent Communication Thread) Profiler Agent: Established connection with the tool
15:28:46,660 INFO [stdout] (*** Profiler Agent Communication Thread) Profiler Agent: Local accelerated session
Profiler Agent: 250 classes cached.
Profiler Agent: 250 classes cached.
Profiler Agent: 250 classes cached.
Profiler Agent: 250 classes cached.
Profiler Agent: 250 classes cached.
Profiler Agent: 250 classes cached.
Profiler Agent: 250 classes cached.
...
15:31:42,562 ERROR [stderr] (*** Profiler Agent Special Execution Thread 2) *** Profiler engine warning: class sun.reflect.GeneratedConstructorAccessor6 that should be instrumented is not loaded by target VM
15:31:42,573 ERROR [stderr] (*** Profiler Agent Special Execution Thread 2) *** Requested classloader: sun.reflect.DelegatingClassLoader@61c2d960, its class = class sun.reflect.DelegatingClassLoader, index = 55, hashcode = 1640159584
15:31:42,575 ERROR [stderr] (*** Profiler Agent Special Execution Thread 2) *** Profiler engine warning: target VM cannot load class to instrument sun.reflect.GeneratedConstructorAccessor6
15:31:42,577 ERROR [stderr] (*** Profiler Agent Special Execution Thread 2) *** probably it has been unloaded recently
15:31:42,589 ERROR [stderr] (*** Profiler Agent Special Execution Thread 2) *** Profiler engine warning: class sun.reflect.GeneratedSerializationConstructorAccessor2 that should be instrumented is not loaded by target VM
15:31:42,591 ERROR [stderr] (*** Profiler Agent Special Execution Thread 2) *** Requested classloader: sun.reflect.DelegatingClassLoader@3b875e0e, its class = class sun.reflect.DelegatingClassLoader, index = 81, hashcode = 998727182
...
15:31:43,991 ERROR [stderr] (*** Profiler Agent Special Execution Thread 2) *** Requested classloader: sun.reflect.DelegatingClassLoader@b34bf3, its class = class sun.reflect.DelegatingClassLoader, index = 166, hashcode = 11750387
15:31:43,992 ERROR [stderr] (*** Profiler Agent Special Execution Thread 2) *** Profiler engine warning: target VM cannot load class to instrument sun.reflect.GeneratedConstructorAccessor1
15:31:43,994 ERROR [stderr] (*** Profiler Agent Special Execution Thread 2) *** probably it has been unloaded recently
Profiler Agent: Redefining 100 classes at idx 0, out of total 500
Profiler Agent: Redefining 100 classes at idx 100, out of total 500
Profiler Agent: Redefining 100 classes at idx 200, out of total 500
Profiler Agent: Redefining 100 classes at idx 300, out of total 500
Profiler Agent: Redefining 100 classes at idx 400, out of total 500
15:31:44,104 ERROR [stderr] (*** Profiler Agent Special Execution Thread 2) Profiler Agent Error: Redefinition failed for classes:
...
15:31:58,744 ERROR [stderr] (*** Profiler Agent Special Execution Thread 2) sun.rmi.transport.tcp.TCPTransport$1
...
15:31:58,745 ERROR [stderr] (*** Profiler Agent Special Execution Thread 2) Profiler Agent Error: with message: Redefinition failed with error 64
15:31:58,746 ERROR [stderr] (*** Profiler Agent Special Execution Thread 2) Check JVMTI documentation for this error code.
15:31:58,785 ERROR [stderr] (*** Profiler Agent Special Execution Thread 2) Debug: writing class file: sun.nio.cs.Surrogate$Parser, into file: sun.nio.cs.Surrogate$Parser.class
15:31:58,792 ERROR [stderr] (*** Profiler Agent Special Execution Thread 2) Debug: writing class file: org.jboss.web.CoyoteLogger, into file: org.jboss.web.CoyoteLogger.class
15:31:58,795 ERROR [stderr] (*** Profiler Agent Special Execution Thread 2) Debug: writing class file: org.jboss.as.controller.SecurityActions$SetThreadContextClassLoaderAction, into file: org.jboss.as.controller.SecurityActions$SetThreadContextClassLoaderAction.class
15:31:58,796 ERROR [stderr] (*** Profiler Agent Special Execution Thread 2) Debug: writing class file: org.jboss.as.logging.CustomHandlerResourceDefinition$1, into file: org.jboss.as.logging.CustomHandlerResourceDefinition$1.class
...
15:32:27,965 ERROR [stderr] (*** Profiler Agent Special Execution Thread 2) Debug: writing class file: org.jboss.logmanager.config.HandlerConfigurationImpl$2, into file: org.jboss.logmanager.config.HandlerConfigurationImpl$2.class
For more information, my JVM arguments as shown in VisualVm:
-D[Standalone]
-XX:+UseCompressedOops
-Xms1303m
-Xmx1303m
-XX:MaxPermSize=256m
-Djava.net.preferIPv4Stack=true
-Djboss.modules.system.pkgs=org.jboss.byteman
-Djava.awt.headless=true
-javaagent:$JBOSS_HOME/jboss-eap-6.1/jacoco-agent.jar=destfile=$JBOSS_HOME/jboss-eap-6.1/jacoco.exec
-Dorg.jboss.boot.log.file=$JBOSS_HOME/jboss-eap-6.1/standalone/log/server.log
-Dlogging.configuration=file:$JBOSS_HOME/jboss-eap-6.1/standalone/configuration/logging.properties
And my System properties, also from VisualVm:
[Standalone]=
awt.toolkit=sun.lwawt.macosx.LWCToolkit
catalina.home=$JBOSS_HOME/jboss-eap-6.1/standalone/tmp
file.encoding=UTF-8
file.encoding.pkg=sun.io
file.separator=/
ftp.nonProxyHosts=local|*.local|169.254/16|*.169.254/16
gopherProxySet=false
http.nonProxyHosts=local|*.local|169.254/16|*.169.254/16
java.awt.graphicsenv=sun.awt.CGraphicsEnvironment
java.awt.headless=true
java.awt.printerjob=sun.lwawt.macosx.CPrinterJob
java.class.path=$JBOSS_HOME/jboss-eap-6.1/jboss-modules.jar:$JBOSS_HOME/jboss-eap-6.1/jacoco-agent.jar
java.class.version=51.0
java.endorsed.dirs=/Library/Java/JavaVirtualMachines/jdk1.7.0_71.jdk/Contents/Home/jre/lib/endorsed
java.ext.dirs=/Users/eagutom/Library/Java/Extensions:/Library/Java/JavaVirtualMachines/jdk1.7.0_71.jdk/Contents/Home/jre/lib/ext:/Library/Java/Extensions:/Network/Library/Java/Extensions:/System/Library/Java/Extensions:/usr/lib/java
java.home=/Library/Java/JavaVirtualMachines/jdk1.7.0_71.jdk/Contents/Home/jre
java.io.tmpdir=/var/folders/hl/zb5t5j1d3txfm_bmnz2bc8902gxcq8/T/
java.library.path=/Users/eagutom/Library/Java/Extensions:/Library/Java/Extensions:/Network/Library/Java/Extensions:/System/Library/Java/Extensions:/usr/lib/java:.
java.naming.factory.url.pkgs=org.jboss.as.naming.interfaces:org.jboss.ejb.client.naming
java.net.preferIPv4Stack=true
java.rmi.server.randomIDs=true
java.runtime.name=Java(TM) SE Runtime Environment
java.runtime.version=1.7.0_71-b14
java.specification.name=Java Platform API Specification
java.specification.vendor=Oracle Corporation
java.specification.version=1.7
java.util.logging.manager=org.jboss.logmanager.LogManager
java.vendor=Oracle Corporation
java.vendor.url=http://java.oracle.com/
java.vendor.url.bug=http://bugreport.sun.com/bugreport/
java.version=1.7.0_71
java.vm.info=mixed mode
java.vm.name=Java HotSpot(TM) 64-Bit Server VM
java.vm.specification.name=Java Virtual Machine Specification
java.vm.specification.vendor=Oracle Corporation
java.vm.specification.version=1.7
java.vm.vendor=Oracle Corporation
java.vm.version=24.71-b01
javax.management.builder.initial=org.jboss.as.jmx.PluggableMBeanServerBuilder
javax.xml.datatype.DatatypeFactory=__redirected.__DatatypeFactory
javax.xml.parsers.DocumentBuilderFactory=__redirected.__DocumentBuilderFactory
javax.xml.parsers.SAXParserFactory=__redirected.__SAXParserFactory
javax.xml.stream.XMLEventFactory=__redirected.__XMLEventFactory
javax.xml.stream.XMLInputFactory=__redirected.__XMLInputFactory
javax.xml.stream.XMLOutputFactory=__redirected.__XMLOutputFactory
javax.xml.transform.TransformerFactory=__redirected.__TransformerFactory
javax.xml.validation.SchemaFactory:http://www.w3.org/2001/XMLSchema=__redirected.__SchemaFactory
javax.xml.xpath.XPathFactory:http://java.sun.com/jaxp/xpath/dom=__redirected.__XPathFactory
jboss.home.dir=$JBOSS_HOME/jboss-eap-6.1
jboss.host.name=esekigala173
jboss.modules.dir=$JBOSS_HOME/jboss-eap-6.1/modules
jboss.modules.system.pkgs=org.jboss.byteman
jboss.node.name=esekigala173
jboss.qualified.host.name=esekigala173.ki.sw.ericsson.se
jboss.server.base.dir=$JBOSS_HOME/jboss-eap-6.1/standalone
jboss.server.config.dir=$JBOSS_HOME/jboss-eap-6.1/standalone/configuration
jboss.server.data.dir=$JBOSS_HOME/jboss-eap-6.1/standalone/data
jboss.server.deploy.dir=$JBOSS_HOME/jboss-eap-6.1/standalone/data/content
jboss.server.log.dir=$JBOSS_HOME/jboss-eap-6.1/standalone/log
jboss.server.name=esekigala173
jboss.server.persist.config=true
jboss.server.temp.dir=$JBOSS_HOME/jboss-eap-6.1/standalone/tmp
line.separator=\n
logging.configuration=file:$JBOSS_HOME/jboss-eap-6.1/standalone/configuration/logging.properties
module.path=$JBOSS_HOME/jboss-eap-6.1/modules
org.jboss.boot.log.file=$JBOSS_HOME/jboss-eap-6.1/standalone/log/server.log
org.jboss.resolver.warning=true
org.jboss.security.context.ThreadLocal=true
org.xml.sax.driver=__redirected.__XMLReaderFactory
os.arch=x86_64
os.name=Mac OS X
os.version=10.9.5
path.separator=:
socksNonProxyHosts=local|*.local|169.254/16|*.169.254/16
sun.arch.data.model=64
sun.boot.class.path=/Library/Java/JavaVirtualMachines/jdk1.7.0_71.jdk/Contents/Home/jre/lib/resources.jar:/Library/Java/JavaVirtualMachines/jdk1.7.0_71.jdk/Contents/Home/jre/lib/rt.jar:/Library/Java/JavaVirtualMachines/jdk1.7.0_71.jdk/Contents/Home/jre/lib/sunrsasign.jar:/Library/Java/JavaVirtualMachines/jdk1.7.0_71.jdk/Contents/Home/jre/lib/jsse.jar:/Library/Java/JavaVirtualMachines/jdk1.7.0_71.jdk/Contents/Home/jre/lib/jce.jar:/Library/Java/JavaVirtualMachines/jdk1.7.0_71.jdk/Contents/Home/jre/lib/charsets.jar:/Library/Java/JavaVirtualMachines/jdk1.7.0_71.jdk/Contents/Home/jre/lib/jfr.jar:/Library/Java/JavaVirtualMachines/jdk1.7.0_71.jdk/Contents/Home/jre/classes
sun.boot.library.path=/Library/Java/JavaVirtualMachines/jdk1.7.0_71.jdk/Contents/Home/jre/lib
sun.cpu.endian=little
sun.cpu.isalist=
sun.io.unicode.encoding=UnicodeBig
sun.java.command=$JBOSS_HOME/jboss-eap-6.1/jboss-modules.jar -mp $JBOSS_HOME/jboss-eap-6.1/modules -jaxpmodule javax.xml.jaxp-provider org.jboss.as.standalone -Djboss.home.dir=$JBOSS_HOME/jboss-eap-6.1 -Djboss.server.base.dir=$JBOSS_HOME/jboss-eap-6.1/standalone
sun.java.launcher=SUN_STANDARD
sun.jnu.encoding=UTF-8
sun.management.compiler=HotSpot 64-Bit Tiered Compilers
sun.os.patch.level=unknown
user.country=US
user.country.format=SE
user.dir=$JBOSS_HOME/jboss-eap-6.1/bin
user.home=/Users/eagutom
user.language=en
user.name=eagutom
user.timezone=Europe/...
I get a lot of classes written into the directory from where JBoss is started, I haven't got enough reputation to post the image.
I also get the following error in VisualVm:
> Redefinition failed with error 64
> Check JVMTI documentation for this error code
Finally, I just want to mentioned that I tried adding these lines to my standalone.conf with no effect:
1. JAVA_OPTS="$JAVA_OPTS -Xshare:off -Djboss.modules.system.pkgs=org.netbeans.lib.profiler.server -Dorg.osgi.framework.bootdelegation=org.netbeans.lib.profiler.server,org.netbeans.lib.profiler.server.*"
2. JAVA_OPTS="$JAVA_OPTS -Xbootclasspath/a:/Applications/NetBeans/NetBeans\ 8.0.app/Contents/Resources/NetBeans/profiler/lib/jfluid-server.jar"
3. JAVA_OPTS="$JAVA_OPTS -Xbootclasspath/a:$JAVA_HOME/lib/visualvm/profiler/lib/jfluid-server.jar"
Any clues of what I'm doing wrong? I can provide more info upon request since this is 100% reproducible.