[jboss-dev-forums] [Design of JBoss Profiler] - Profiler Not Recording Time
wstrater@yahoo.com
do-not-reply at jboss.com
Mon Dec 8 15:45:05 EST 2008
I am having troubles getting output. I tried Beta3 and SVN revision 517.
I exported and built the code:
[webuser at bri-devweb01 tmp]$ svn export http://anonsvn.jboss.org/repos/jbossprofiler/branches/JBossProfiler2
[webuser at bri-devweb01 tmp]$ svn info http://anonsvn.jboss.org/repos/jbossprofiler/branches/JBossProfiler2
Path: JBossProfiler2
URL: http://anonsvn.jboss.org/repos/jbossprofiler/branches/JBossProfiler2
Repository Root: http://anonsvn.jboss.org/repos/jbossprofiler
Repository UUID: 98652012-b443-0410-9899-d25f17a0cfe6
Revision: 517
Node Kind: directory
Last Changed Author: jesper.pedersen
Last Changed Rev: 517
Last Changed Date: 2008-12-04 20:55:20 -0500 (Thu, 04 Dec 2008)
I copied the jars and properties to the bin directory:
[webuser at bri-devweb01 jboss-profiler]$ ls -l /usr/local/jboss/bin/jboss-profiler*
-rw-r--r-- 1 webuser webuser 61650 Dec 5 14:19 /usr/local/jboss/bin/jboss-profiler.jar
-rw-r--r-- 1 webuser webuser 5125 Dec 5 14:19 /usr/local/jboss/bin/jboss-profiler-plugins.jar
-rw-r--r-- 1 webuser webuser 486 Dec 8 10:47 /usr/local/jboss/bin/jboss-profiler.properties
[webuser at bri-devweb01 jboss-profiler]$ ls -l /usr/local/jboss/bin/javas*
-rw-r--r-- 1 webuser webuser 471005 Dec 8 09:51 /usr/local/jboss/bin/javassist.jar
[tomcat at bri-devweb01 jboss-profiler]$ ls -l /usr/local/jboss/server/default/deploy/jboss-prof*
-rw-r--r-- 1 webuser webuser 11107 Dec 5 14:25 /usr/local/jboss/server/default/deploy/jboss-profiler.sar
[webuser at bri-devweb01 jboss-profiler]$ cat /usr/local/jboss/bin/jboss-profiler.properties
enable=yes
cpu=yes
memory=yes
includes=com.company.*
excludes=*
visibility=private
save=yes
startup=yes
repository=no
remote=yes
store=memory
location=/home2/weblogs/profiler
host=localhost
port=5400
ejb=no
servlet=yes
jsf=no
jmx=no
rmi=yes
corba=no
plugin.1=org.jboss.profiler.plugins.Hibernate
plugin.2=org.jboss.profiler.plugins.Seam
[webuser at bri-devweb01 jboss-profiler]$
I update the run.conf.
[webuser at bri-devweb01 jboss-profiler]$ grep PROFILE /usr/local/jboss/bin/run.conf
PROFILER="/usr/local/jboss/bin/jboss-profiler.properties"
The following is from the console log upon startup. You can see the profiler is configured as an agent in the JAVA_OPTS.
=========================================================================
JBoss Bootstrap Environment
JBOSS_HOME: /usr/local/jboss
JAVA: /usr/local/java/bin/java
JAVA_OPTS: -Dprogram.name=run.sh -server -javaagent:/usr/local/jboss/bin/jboss-profiler.jar -Djboss-profiler.properties=/usr/local/jboss/bin/jboss-profiler.properties -Dcom.sun.management.jmxremote.port=9004 -Djava.net.preferIPv4Stack=true
CLASSPATH: /usr/local/jboss/bin/run.jar:/usr/local/java/lib/tools.jar
=========================================================================
JBOSS_HOME: /usr/local/jboss
JBoss Profiler 2.0.Beta4 (Sun Microsystems Inc. 1.5.0_03)
JBoss Profiler depends on external communication module
11:30:29,143 INFO [Server] Starting JBoss (MX MicroKernel)...
11:30:29,144 INFO [Server] Release ID: JBoss [Trinity] 4.2.3.GA (build: SVNTag=JBoss_4_2_3_GA date=200807181417)
11:30:29,146 INFO [Server] Home Dir: /usr/local/jboss-4.2.3.GA
11:30:29,146 INFO [Server] Home URL: file:/usr/local/jboss-4.2.3.GA/
11:30:29,147 INFO [Server] Patch URL: null
11:30:29,147 INFO [Server] Server Name: default
11:30:29,147 INFO [Server] Server Home Dir: /usr/local/jboss-4.2.3.GA/server/default
11:30:29,148 INFO [Server] Server Home URL: file:/usr/local/jboss-4.2.3.GA/server/default/
11:30:29,148 INFO [Server] Server Log Dir: /usr/local/jboss-4.2.3.GA/server/default/log
11:30:29,148 INFO [Server] Server Temp Dir: /usr/local/jboss-4.2.3.GA/server/default/tmp
11:30:29,148 INFO [Server] Root Deployment Filename: jboss-service.xml
11:30:29,564 INFO [ServerInfo] Java version: 1.5.0_03,Sun Microsystems Inc.
11:30:29,564 INFO [ServerInfo] Java VM: Java HotSpot(TM) Server VM 1.5.0_03-b07,Sun Microsystems Inc.
11:30:29,565 INFO [ServerInfo] OS-System: Linux 2.4.21-57.ELsmp,i386
It should be noted that /usr/local/jboss and /usr/local/jboss-profile are symbolic links to /usr/local/jboss-4.2.3.GA and /usr/local/jboss-profiler-2.0.svn-517.
The following are the entries in the JBoss console output.
[webuser at bri-devweb01 jboss-profiler]$ grep Profiler /home2/weblogs/jboss_console.log
JBoss Profiler 2.0.Beta4 (Sun Microsystems Inc. 1.5.0_03)
JBoss Profiler depends on external communication module
11:30:39,218 INFO [Profiler] JBoss Profiler: ProfilerMBean started
11:30:39,219 INFO [Communicator] JBoss Profiler: Communicator for JBoss Profiler 2.0.Beta4
11:30:39,228 INFO [Communicator] JBoss Profiler: Socket=0.0.0.0:5400
The following from the JBoss server log.
[webuser at bri-devweb01 jboss-profiler]$ grep Profiler /home2/weblogs/jboss_server.log
[webuser at bri-devweb01 jboss-profiler]$
I ran the following client commands. (The last grep is the opposite of the previous to confirm the pattern.)
[webuser at bri-devweb01 jboss-profiler]$ java -jar jboss-profiler-client.jar list
com.company.*
org.apache.jsp.*
[webuser at bri-devweb01 jboss-profiler]$ java -jar jboss-profiler-client.jar startProfiler
[webuser at bri-devweb01 jboss-profiler]$ java -jar jboss-profiler-client.jar stopProfiler
[webuser at bri-devweb01 jboss-profiler]$ java -jar jboss-profiler-client.jar listSnapshots
1: 08 December 2008 11:31:33:778 -> 08 December 2008 11:32:27:890
[webuser at bri-devweb01 jboss-profiler]$ java -jar jboss-profiler-client.jar getSnapshot 1
[webuser at bri-devweb01 jboss-profiler]$ ls -l 20081208113133778-20081208113227890
total 1224
drwxrwxr-x 2 webuser webuser 4096 Dec 8 11:32 caller
drwxrwxr-x 2 webuser webuser 405504 Dec 8 11:32 classes
-rw-rw-r-- 1 webuser webuser 404426 Dec 8 11:32 classes.txt
-rw-rw-r-- 1 webuser webuser 42 Dec 8 11:32 hotspots.txt
-rw-rw-r-- 1 webuser webuser 40 Dec 8 11:32 methods.txt
-rw-rw-r-- 1 webuser webuser 404629 Dec 8 11:32 overview.txt
-rw-rw-r-- 1 webuser webuser 33 Dec 8 11:32 packages.txt
drwxrwxr-x 2 webuser webuser 4096 Dec 8 11:32 threads
-rw-rw-r-- 1 webuser webuser 49 Dec 8 11:32 waittime.txt
[webuser at bri-devweb01 jboss-profiler]$ grep -v '0.00 ms' 20081208113133778-20081208113227890/overview.txt
>From : 08 December 2008 11:31:33:778
To : 08 December 2008 11:32:27:890
Total: 54112.00 ms
Threads:
========
Most time:
==========
Count Ms Avg % Method
Hotspots:
=========
Count Ms Avg % Method
Classes:
========
[webuser at bri-devweb01 jboss-profiler]$ grep '0.00 ms' 20081208113133778-20081208113227890/overview.txt | head
com.company.common.datastructures.Account POJO 0.00 ms
com.company.common.datastructures.Account$JaxbAccessorF_accountId POJO 0.00 ms
com.company.common.datastructures.Account$JaxbAccessorF_accountStatus POJO 0.00 ms
com.company.common.datastructures.Account$JaxbAccessorF_backendAccountIdentifier POJO 0.00 ms
com.company.common.datastructures.Account$JaxbAccessorF_backendAccountType POJO 0.00 ms
com.company.common.datastructures.Account$JaxbAccessorF_branchNumber POJO 0.00 ms
com.company.common.datastructures.Account$JaxbAccessorF_cards POJO 0.00 ms
com.company.common.datastructures.Account$JaxbAccessorF_employeeType POJO 0.00 ms
com.company.common.datastructures.AccountActionCode POJO 0.00 ms
com.company.common.datastructures.AccountId POJO 0.00 ms
[webuser at bri-devweb01 jboss-profiler]$ cat 20081208113133778-20081208113227890/methods.txt
Methods:
--------
Count Ms Avg % Method
[webuser at bri-devweb01 jboss-profiler]$
The location is empty but that is probably correct since I am using a memory store.
[webuser at bri-devweb01 jboss-profiler]$ ls -l /home2/weblogs/profiler
total 0
I use JMeter to run a test plan. You can see from the application log file that there was some activity with the classes that matches the includes entry. Also playing around with the includes does change the classes found in the snapshot report directory.
[webuser at bri-devweb01 jboss-profiler]$ grep '11:3' /home2/weblogs/jboss.log | grep commonLogic | grep EXECUTING
11:31:40,786 [ajp-0.0.0.0-9009-1] [com.company.servlets.ServletBase.commonLogic 429] VERBOSE [ ] - ***** EXECUTING CLASS: com.company.servlets.Login
11:31:50,183 [ajp-0.0.0.0-9009-1] [com.company.servlets.ServletBase.commonLogic 384] VERBOSE [ ] - ***** EXECUTING DISPATCHER: com.company.dispatchers.security.SecurityFSOCheckDispatcher
11:31:51,728 [ajp-0.0.0.0-9009-1] [com.company.servlets.ServletBase.commonLogic 384] VERBOSE [ ] - ***** EXECUTING DISPATCHER: com.company.dispatchers.login.LoginPrepareLoginDispatcher
11:31:56,088 [ajp-0.0.0.0-9009-1] [com.company.servlets.ServletBase.commonLogic 384] VERBOSE [ ] - ***** EXECUTING DISPATCHER: com.company.dispatchers.login.LoginSigninDispatcher
11:32:00,328 [ajp-0.0.0.0-9009-1] [com.company.servlets.ServletBase.commonLogic 384] VERBOSE [ ] - ***** EXECUTING DISPATCHER: com.company.dispatchers.transaction.HistoryLandingDispatcher
11:32:01,563 [ajp-0.0.0.0-9009-1] [com.company.servlets.ServletBase.commonLogic 384] VERBOSE [ ] - ***** EXECUTING DISPATCHER: com.company.dispatchers.transfer.TransferHistoryDispatcher
11:32:03,520 [ajp-0.0.0.0-9009-1] [com.company.servlets.ServletBase.commonLogic 384] VERBOSE [ ] - ***** EXECUTING DISPATCHER: com.company.dispatchers.relatedservices.HistoryDispatcher
11:32:06,353 [ajp-0.0.0.0-9009-1] [com.company.servlets.ServletBase.commonLogic 384] VERBOSE [ ] - ***** EXECUTING DISPATCHER: com.company.dispatchers.card.CardTransactionHistoryDispatcher
11:32:08,352 [ajp-0.0.0.0-9009-1] [com.company.servlets.ServletBase.commonLogic 384] VERBOSE [ ] - ***** EXECUTING DISPATCHER: com.company.dispatchers.accounts.ReviewWebsterAccountsDispatcher
11:32:10,172 [ajp-0.0.0.0-9009-1] [com.company.servlets.ServletBase.commonLogic 384] VERBOSE [ ] - ***** EXECUTING DISPATCHER: com.company.dispatchers.accountbalances.AccountBalanceDispatcher
11:32:12,138 [ajp-0.0.0.0-9009-1] [com.company.servlets.ServletBase.commonLogic 429] VERBOSE [ ] - ***** EXECUTING CLASS: com.company.servlets.Login
11:32:12,210 [ajp-0.0.0.0-9009-2] [com.company.servlets.ServletBase.commonLogic 429] VERBOSE [ ] - ***** EXECUTING CLASS: com.company.servlets.Content
11:32:13,487 [ajp-0.0.0.0-9009-1] [com.company.servlets.ServletBase.commonLogic 429] VERBOSE [ ] - ***** EXECUTING CLASS: com.company.servlets.Content
11:33:02,112 [ajp-0.0.0.0-9009-3] [com.company.servlets.ServletBase.commonLogic 429] VERBOSE [ ] - ***** EXECUTING CLASS: com.company.servlets.Login
I feel I am close but probably missing something obvious. I hope I provided enough info and would appreciate any help.
Wes.
View the original post : http://www.jboss.com/index.html?module=bb&op=viewtopic&p=4195161#4195161
Reply to the post : http://www.jboss.com/index.html?module=bb&op=posting&mode=reply&p=4195161
More information about the jboss-dev-forums
mailing list