0 Replies Latest reply on Nov 10, 2014 5:12 AM by soltzu

    VisualVm profiler and JBoss 7 problems

    soltzu

      I'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.