Profiler4j - Profiling made easy

How profile a jboss´s application or a apache´s application, since it was not started from console?

I'll provide a tutorial soon but here follows some
basic tips you can try out. Also, I assume you use
windows and have installed Profiler4j in the default
path c:\profiler4j-1.0-beta2.

== JBoss ==

In the directory %JBOSS_HOME%\bin, add the following
line to the begining of run.bat:

set JAVA_OPTS=-javaagent:c:\profiler4j-1.0-beta2\agent.jar


== Tomcat (not a service) ==

* installed from a zip such as apache-tomcat-5.5.17.zip

In the directory %CATALINA_HOME%\bin, edit the file
catalina.bat and set the variable JAVA_OPTS as before
(at the begining of the file)

set JAVA_OPTS=-javaagent:c:\profiler4j-1.0-beta2\agent.jar

Execute startup.bat to run Tomcat as usual.

== Tomcat (installed as a service in windows) ==

In this case you must edit the JVM parameters using the
Apache Service Manager. For example, if you installed
Tomcat from the package apache-tomcat-5.5.17.exe you
must right-click the manager icon in the tray area and
select "Configure..." to view the "Apache Tomcat
Properties" dialog. Then, click the "Java" tab and add
the options in the "Java Options" field.

-javaagent:c:\profiler4j-1.0-beta2\agent.jar

Notice that the service won't be fully initialized
until you connect via the console application. If
needed you can pass the argument waitconn=false
(see homepage for other options).

I had this working locally as well as with a test remote machine at the office. But on my production server, I couldn't start Tomcat with the new Java option, but removing it fixed it. Now I can't remember how I had it the first time when it was working fine; I'm seeing the same problem even locally now. Tomcat just tries to start and never returns, eventually throwing an error that it took too long to try starting. Not much error feedback to go on.. Thougts? Thank you!

(1) Are you sure all applications start with a 1.5 JVM?

(2) Did you pass the argument waitconn=true to Profiler4j? If yes, then the JVM will not start completely until the console connects to the profiled JVM. Depending on the way you start the application (via eclipse, for instance) this wait will timeout sometime later with an error. However, I recommend you to activate this options whenever possible as it may perform
better.

Please send the STDOUT log if possible. It is very hard to reproduce this behavior without further
details.

(1) Running JRE 1.5.0_04
(2) I haven't used any arguments

Here's what I just did:
Completely uninstalled Tomcat
Installed Tomcat 5.5.9
Verified successful start of Tomcat in my browser
Stopped Tomcat
Opened Configure Tomcat from Start Menu
In Java Tab, Java Options:
added "-javaagent:C:\profiler4j-1.0-beta2\agent.jar"
Clicked Apply
In Windows Services > Apache Tomcat, clicked Start the service.
Startup progress bar slows and stops about halfway, then slowly progresses almost to end.
Error box comes up, "Could not start the Apache Tomcat service on Local Computer. Error 1053: The service did not respond to the start or control request in a timely fashion."
End process of "tomcat5.exe", which still says starting in Services.
Remove "-javaagent:C:\profiler4j-1.0-beta2\agent.jar" from Java options.
Click Apply.
Back in Services > Apache Tomcat, click Start.
Fires right up.
Tomcat stderr:

Jul 31, 2006 12:02:52 PM org.apache.coyote.http11.Http11Protocol init
INFO: Initializing Coyote HTTP/1.1 on http-80
Jul 31, 2006 12:02:53 PM org.apache.catalina.startup.Catalina load
INFO: Initialization processed in 2125 ms
Jul 31, 2006 12:02:53 PM org.apache.catalina.core.StandardService start
INFO: Starting service Catalina
Jul 31, 2006 12:02:53 PM org.apache.catalina.core.StandardEngine start
INFO: Starting Servlet Engine: Apache Tomcat/5.5.9
Jul 31, 2006 12:02:53 PM org.apache.catalina.core.StandardHost start
INFO: XML validation disabled
Jul 31, 2006 12:02:54 PM org.apache.coyote.http11.Http11Protocol start
INFO: Starting Coyote HTTP/1.1 on http-80
Jul 31, 2006 12:02:54 PM org.apache.jk.common.ChannelSocket init
INFO: JK: ajp13 listening on /0.0.0.0:8009
Jul 31, 2006 12:02:54 PM org.apache.jk.server.JkMain start
INFO: Jk running ID=0 time=0/32 config=null
Jul 31, 2006 12:02:54 PM org.apache.catalina.storeconfig.StoreLoader load
INFO: Find registry server-registry.xml at classpath resource
Jul 31, 2006 12:02:54 PM org.apache.catalina.startup.Catalina start
INFO: Server startup in 1484 ms
Jul 31, 2006 12:03:32 PM org.apache.coyote.http11.Http11Protocol pause
INFO: Pausing Coyote HTTP/1.1 on http-80
Jul 31, 2006 12:03:33 PM org.apache.catalina.core.StandardService stop
INFO: Stopping service Catalina
Jul 31, 2006 12:03:33 PM org.apache.coyote.http11.Http11Protocol destroy
INFO: Stopping Coyote HTTP/1.1 on http-80
Jul 31, 2006 12:15:38 PM org.apache.coyote.http11.Http11Protocol init
INFO: Initializing Coyote HTTP/1.1 on http-80
Jul 31, 2006 12:15:38 PM org.apache.catalina.startup.Catalina load
INFO: Initialization processed in 656 ms
Jul 31, 2006 12:15:38 PM org.apache.catalina.core.StandardService start
INFO: Starting service Catalina
Jul 31, 2006 12:15:38 PM org.apache.catalina.core.StandardEngine start
INFO: Starting Servlet Engine: Apache Tomcat/5.5.9
Jul 31, 2006 12:15:38 PM org.apache.catalina.core.StandardHost start
INFO: XML validation disabled
Jul 31, 2006 12:15:39 PM org.apache.coyote.http11.Http11Protocol start
INFO: Starting Coyote HTTP/1.1 on http-80
Jul 31, 2006 12:15:39 PM org.apache.jk.common.ChannelSocket init
INFO: JK: ajp13 listening on /0.0.0.0:8009
Jul 31, 2006 12:15:39 PM org.apache.jk.server.JkMain start
INFO: Jk running ID=0 time=0/31 config=null
Jul 31, 2006 12:15:39 PM org.apache.catalina.storeconfig.StoreLoader load
INFO: Find registry server-registry.xml at classpath resource
Jul 31, 2006 12:15:39 PM org.apache.catalina.startup.Catalina start
INFO: Server startup in 1031 ms

It worked fantastically in my office environment, I'm not sure what is different here.

Kimball

Try the following parameter:

-javaagent:C:\profiler4j-1.0-beta2\agent.jar=waitconn=false

This will tell Profiler4j to let the JVM start normally. By default, Profiler4j pauses the profiled application and waits for a connection from the remote console.

The problem, I guess, is that some JVM launchers such as Eclipse and TomcatServiceManager will allow the spawn process to be delayed only for a few seconds. If this timeout is reached an error is reported and the process is terminated.

Please let me know if this solves your problem.

Hello,
I run jboss-4.0.5.GA on WIN2000,
java version "1.6.0"
Java(TM) SE Runtime Environment (build 1.6.0-b105)
Java HotSpot(TM) Client VM (build 1.6.0-b105, mixed mode)

When start with Profiler4j in the Console I get a error dialog:
"Could not refresh memory info: I/O Error"
and console trace is:

D:\profiler4j>"C:\Program Files\Java\jre1.6.0_01\bin\java" -cp console.jar net.sf.profiler4j.console.Bootstrap
URL = jar:file:/D:/profiler4j/console.jar!/net/sf/profiler4j/console/Bootstrap.class
Decoded URL (charsetwindows-1252) = jar:file:/D:/profiler4j/console.jar!/net/sf/profiler4j/console/Bootstrap.class
Detected PROFILER4J_HOME is D:\profiler4j
urls[0] = file:/D:/profiler4j/lib/asm-all-2.2.2.jar
urls[1] = file:/D:/profiler4j/lib/javassist-3.1.jar
urls[2] = file:/D:/profiler4j/lib/jcommon-1.0.0.jar
urls[3] = file:/D:/profiler4j/lib/jdom.jar
urls[4] = file:/D:/profiler4j/lib/jfreechart-1.0.1.jar
urls[5] = file:/D:/profiler4j/lib/profiler4j-1.0-beta2.jar
Supports thread contention monitoring? true
Supports thread cpu time monitoring? true
net.sf.profiler4j.console.ClientException: I/O Error
at net.sf.profiler4j.console.Client.handleException(Client.java:288)
at net.sf.profiler4j.console.Client.expectOk(Client.java:279)
at net.sf.profiler4j.console.Client.sendAndWaitAck(Client.java:269)
at net.sf.profiler4j.console.Client.getMemoryInfo(Client.java:104)
at net.sf.profiler4j.console.ConsoleApp$1.actionPerformed(ConsoleApp.java:58)
at javax.swing.Timer.fireActionPerformed(Unknown Source)
at javax.swing.Timer$DoPostEvent.run(Unknown Source)
at java.awt.event.InvocationEvent.dispatch(Unknown Source)
at java.awt.EventQueue.dispatchEvent(Unknown Source)
at java.awt.EventDispatchThread.pumpOneEventForFilters(Unknown Source)
at java.awt.EventDispatchThread.pumpEventsForFilter(Unknown Source)
at java.awt.EventDispatchThread.pumpEventsForHierarchy(Unknown Source)
at java.awt.EventDispatchThread.pumpEvents(Unknown Source)
at java.awt.EventDispatchThread.pumpEvents(Unknown Source)
at java.awt.EventDispatchThread.run(Unknown Source)
Caused by: java.net.SocketException: Connection reset
at java.net.SocketInputStream.read(Unknown Source)
at java.io.BufferedInputStream.fill(Unknown Source)
at java.io.BufferedInputStream.read(Unknown Source)
at java.io.ObjectInputStream$PeekInputStream.peek(Unknown Source)
at java.io.ObjectInputStream$BlockDataInputStream.readBlockHeader(Unknown Source)
at java.io.ObjectInputStream$BlockDataInputStream.refill(Unknown Source)
at java.io.ObjectInputStream$BlockDataInputStream.read(Unknown Source)
at java.io.DataInputStream.readInt(Unknown Source)
at java.io.ObjectInputStream$BlockDataInputStream.readInt(Unknown Source)
at java.io.ObjectInputStream.readInt(Unknown Source)
at net.sf.profiler4j.console.Client.expectOk(Client.java:274)
... 13 more

and jboss trace is:

D:\jboss-4.0.5.GA\bin>"C:\Program Files\Java\jdk1.6.0\bin\java" -javaagent:d:\profiler4j\agent.jar -Dprogram.name=run.bat -server -Xms128m -Xmx512m -Dsun.r
mi.dgc.client.gcInterval=3600000 -Dsun.rmi.dgc.server.gcInterval=3600000 "-Djava.endorsed.dirs=D:\jboss-4.0.5.GA\bin\\..\lib\endorsed" -classpath "C:\Progr
am Files\Java\jdk1.6.0\lib\tools.jar;D:\jboss-4.0.5.GA\bin\\run.jar" org.jboss.Main
[PROFILER4J:0] +---------------------------------------+
[PROFILER4J:0] | Profiler4j 1.0-beta2 (build 27) |
[PROFILER4J:0] | Copyright 2006 Antonio S. R. Gomes |
[PROFILER4J:0] | See LICENSE-2.0.txt for more details |
[PROFILER4J:0] +---------------------------------------+
[PROFILER4J:0] Listening on port 7890...
[PROFILER4J:0] JVM waiting connection from Profiler4j Console...
[PROFILER4J:0] Serving connection from /127.0.0.1:1289
[PROFILER4J:1] Transforming class gnu.getopt.LongOpt
[PROFILER4J:1] Transforming class gnu.getopt.Getopt
09:58:56,125 INFO [Server] Starting JBoss (MX MicroKernel)...
09:58:56,125 INFO [Server] Release ID: JBoss [Zion] 4.0.5.GA (build: CVSTag=Branch_4_0 date=200610162339)
09:58:56,140 INFO [Server] Home Dir: D:\jboss-4.0.5.GA
09:58:56,140 INFO [Server] Home URL: file:/D:/jboss-4.0.5.GA/
09:58:56,140 INFO [Server] Patch URL: null
09:58:56,156 INFO [Server] Server Name: default
09:58:56,156 INFO [Server] Server Home Dir: D:\jboss-4.0.5.GA\server\default
09:58:56,156 INFO [Server] Server Home URL: file:/D:/jboss-4.0.5.GA/server/default/
09:58:56,156 INFO [Server] Server Log Dir: D:\jboss-4.0.5.GA\server\default\log
09:58:56,156 INFO [Server] Server Temp Dir: D:\jboss-4.0.5.GA\server\default\tmp
09:58:56,156 INFO [Server] Root Deployment Filename: jboss-service.xml
[PROFILER4J:0] Could not transform class org.jboss.dom4j.DocumentFactory
[PROFILER4J:0] Profiler stoppedread.run(Thread.java:619)art(ServerImpl.java:362)8)532)a:344))uctorAccessorImpl.java:27)


It seems as if Profiler4j shuts down because it can not transform org.jboss.dom4j.DocumentFactory?

Any ideas how to fix this?

Hi Antonio,

In our development project, we would like to use Profiler4j as our profiling tool. We use WebLogic 10 as our web server.
I couldn’t find any document on configuring Profiler4j to profile application running in WebLogic.
I tried Profiler4j as follows:
- Edited the startWebLogic.cmd file and added the following line in it:
set JAVA_OPTS=-javaagent:C:\LearningEdge\JavaProfile\profiler4j-1.0-beta2\agent.jar=waitconn=false

- Started WebLogic server

- Started Profile4j console as follows:

java -jar c:\profiler4j-1.0-beta2\console.jar

- In the Profiler4j console, invoked “Edit profiling project details” window I added

Host: localhost
Port: 7001

- Clicked on “Connect to remote JVM” in the console widnow.

I am getting the following error:

net.sf.profiler4j.console.ClientException: I/O Error
at net.sf.profiler4j.console.Client.handleException(Client.java:288)
at net.sf.profiler4j.console.Client.connect(Client.java:63)

…

Please help me and let me know whether I am going in the right track or not. If you could give me the complete steps to profile application running in WebLogic using Profiler4j, it will be very much helpful. Its very urgent. Please do the needful.

Thanks for your time.

Ravi K.

I have it working with Bea 9.2.... wasn't a problem, just added JAVA_OPTIONS to the start script (note the different name, it's not JAVA_OPTS). Another problem might have been that you tried to connect to 7001 (that's the http port of weblogic) instead of default profiler port 7890.

@culmat: I was having the same issue as you, with this JBoss stack trace:


[PROFILER4J:0] Could not transform class org.jboss.dom4j.DocumentFactory
[PROFILER4J:0] javassist.NotFoundException: org.jaxen.VariableContext
[PROFILER4J:0] at javassist.ClassPool.get(ClassPool.java:389)
[PROFILER4J:0] at javassist.bytecode.Descriptor.toCtClass(Descriptor.java:549)
[PROFILER4J:0] at javassist.bytecode.Descriptor.getParameterTypes(Descriptor.java:396)
[PROFILER4J:0] at javassist.CtBehavior.getParameterTypes(CtBehavior.java:176)
[PROFILER4J:0] at net.sf.profiler4j.agent.BytecodeTransformer.makeName(BytecodeTransformer.java:188)
[PROFILER4J:0] at net.sf.profiler4j.agent.BytecodeTransformer.transform(BytecodeTransformer.java:94)
[PROFILER4J:0] at net.sf.profiler4j.agent.Transformer.transform(Transformer.java:56)
[PROFILER4J:0] at sun.instrument.TransformerManager.transform(TransformerManager.java:169)
[PROFILER4J:0] at sun.instrument.InstrumentationImpl.transform(InstrumentationImpl.java:365)
[PROFILER4J:0] at java.lang.ClassLoader.defineClass1(Native Method)
[PROFILER4J:0] at java.lang.ClassLoader.defineClass(ClassLoader.java:620)
[PROFILER4J:0] at java.security.SecureClassLoader.defineClass(SecureClassLoader.java:124)
[PROFILER4J:0] at java.net.URLClassLoader.defineClass(URLClassLoader.java:260)
[PROFILER4J:0] at java.net.URLClassLoader.access$000(URLClassLoader.java:56)
[PROFILER4J:0] at java.net.URLClassLoader$1.run(URLClassLoader.java:195)
[PROFILER4J:0] at java.security.AccessController.doPrivileged(Native Method)
[PROFILER4J:0] at java.net.URLClassLoader.findClass(URLClassLoader.java:188)
[PROFILER4J:0] at java.lang.ClassLoader.loadClass(ClassLoader.java:306)
[PROFILER4J:0] at java.lang.ClassLoader.loadClass(ClassLoader.java:251)
[PROFILER4J:0] at java.lang.ClassLoader.loadClassInternal(ClassLoader.java:319)
[PROFILER4J:0] at org.jboss.dom4j.io.SAXReader.getDocumentFactory(SAXReader.java:645)
[PROFILER4J:0] at org.jboss.dom4j.io.SAXReader.createContentHandler(SAXReader.java:969)
[PROFILER4J:0] at org.jboss.dom4j.io.SAXReader.read(SAXReader.java:449)
[PROFILER4J:0] at org.jboss.dom4j.io.SAXReader.read(SAXReader.java:291)
[PROFILER4J:0] at org.jboss.mx.metadata.XMLMetaData.build(XMLMetaData.java:255)
[PROFILER4J:0] at org.jboss.mx.modelmbean.XMBean.<init>(XMBean.java:253)
[PROFILER4J:0] at org.jboss.mx.modelmbean.XMBean.<init>(XMBean.java:282)
[PROFILER4J:0] at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
[PROFILER4J:0] at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:39)
[PROFILER4J:0] at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:27)
[PROFILER4J:0] at java.lang.reflect.Constructor.newInstance(Constructor.java:513)
[PROFILER4J:0] at org.jboss.mx.server.MBeanServerImpl.instantiate(MBeanServerImpl.java:1233)
[PROFILER4J:0] at org.jboss.mx.server.MBeanServerImpl.instantiate(MBeanServerImpl.java:286)
[PROFILER4J:0] at org.jboss.mx.server.MBeanServerImpl.createMBean(MBeanServerImpl.java:344)
[PROFILER4J:0] at org.jboss.system.server.ServerImpl.createMBean(ServerImpl.java:532)
[PROFILER4J:0] at org.jboss.system.server.ServerImpl.doStart(ServerImpl.java:438)
[PROFILER4J:0] at org.jboss.system.server.ServerImpl.start(ServerImpl.java:362)
[PROFILER4J:0] at org.jboss.Main.boot(Main.java:200)
[PROFILER4J:0] at org.jboss.Main$1.run(Main.java:490)
[PROFILER4J:0] at java.lang.Thread.run(Thread.java:619)


I added an entry to the wrapper.conf classpath for dom4j.jar, and am definitely getting further now. Let's see if there are any more issues.


wrapper.java.classpath.5=c:\path\to\my\dom4j.jar
...
wrapper.java.additional.3=-javaagent:c:\profiler4j-1.0-beta2\agent.jar=waitconn=true

I strongly suggest you to try out the latest version available only in CVS. This version (beta-3) was not yet released but has improved a lot in certain areas related to stability. Please checkout and build it from source (you need only Ant to do that). After building it take a look at the files under .\target\profiler4j-1.0-beta3. Beta3 provides a way to skip problematic classes (those that cause trouble even when not instrumented) via the file .\target\profiler4j-1.0-beta3\p4j-exclusions.txt

I think it´s worth the effort. Some users have been using beta3 for some time and have reported very good results.


[]´s

--Antonio

I am a newbie at java and wanted to use the profiler however some classes are giving a problem during transformation. Does someone have the Beta3 version built and ready to go. I tried building it myself but without much luck.

Thanks.

I figured it out. Thanks anyway.

I got the same error, just download the source from CVS and build the profiler4j-1.0-beta3.
The problem is solved in the head version.