Fully featured low overhead profiler for Java EE and Java SE platforms.
Ultimate profiling and monitoring solution for Gradle, Maven, Ant, JUnit and TestNG.
Easy to use performance and memory profiler for .NET framework.

Difficulty with getting profiling to work

Moderators: Vladimir Kondratyev, Anton Katilin

Difficulty with getting profiling to work

Postby dgshaver » Wed Oct 28, 2015 9:02 pm

Hi,

I'm a newbie user, so apologies in advance if I'm doing something silly.

I'm trying to profile a Java service on Windows. I added the -agentpath parameter to the end of the service command line (entire command line pasted below) and restarted the service:
-Xmx1000m -Dtempleton.log.dir=C:\apps\dist\hive-0.14.0.2.2.7.1-0004\hcatalog\logs -Dlog4j.configuration=file:C:\apps\dist\hive-0.14.0.2.2.7.1-0004\hcatalog\etc\webhcat\webhcat-log4j.properties -Dhadoop.log.dir=C:\apps\dist\hadoop-2.6.0.2.2.7.1-0004\logs -Dhadoop.log.file=hadoop.log -Dhadoop.home.dir=C:\apps\dist\hadoop-2.6.0.2.2.7.1-0004 -Dhadoop.id.str=HEADNODE0$ -Dhadoop.root.logger=INFO,console,DRFA,ETW,FilterLog -Djava.library.path=;C:\apps\dist\hadoop-2.6.0.2.2.7.1-0004\bin -Dhadoop.policy.file=hadoop-policy.xml -Djava.net.preferIPv4Stack=true -Detwlogger.component=templeton -Dtempleton.root.logger=DEBUG,standard,ETW,FilterLog,Anonymizer -Dwhitelist.filename=core-whitelist.res,hive-whitelist.res -DlogFilter.filename=TempletonLogFilters.xml -DpatternGroup.filename=TempletonPatternGroups.xml -classpath C:\apps\dist\hive-0.14.0.2.2.7.1-0004\hcatalog\etc\webhcat;C:\apps\dist\hive-0.14.0.2.2.7.1-0004\hcatalog;C:\apps\dist\hive-0.14.0.2.2.7.1-0004\hcatalog\share\webhcat\svr;C:\apps\dist\hive-0.14.0.2.2.7.1-0004\hcatalog\conf;C:\apps\dist\hive-0.14.0.2.2.7.1-0004\conf;C:\apps\dist\hive-0.14.0.2.2.7.1-0004\hcatalog\share\hcatalog\*;C:\apps\dist\hive-0.14.0.2.2.7.1-0004\hcatalog\share\webhcat\svr\*;C:\apps\dist\hive-0.14.0.2.2.7.1-0004\hcatalog\share\webhcat\svr\lib\*;C:\apps\dist\hive-0.14.0.2.2.7.1-0004\lib\*;C:\apps\dist\hadoop-2.6.0.2.2.7.1-0004\etc\hadoop;C:\apps\dist\hadoop-2.6.0.2.2.7.1-0004\share\hadoop\common\lib\*;C:\apps\dist\hadoop-2.6.0.2.2.7.1-0004\share\hadoop\common\*;C:\apps\dist\hadoop-2.6.0.2.2.7.1-0004\share\hadoop\hdfs;C:\apps\dist\hadoop-2.6.0.2.2.7.1-0004\share\hadoop\hdfs\lib\*;C:\apps\dist\hadoop-2.6.0.2.2.7.1-0004\share\hadoop\hdfs\*;C:\apps\dist\hadoop-2.6.0.2.2.7.1-0004\share\hadoop\yarn\lib\*;C:\apps\dist\hadoop-2.6.0.2.2.7.1-0004\share\hadoop\yarn\*;C:\apps\dist\hadoop-2.6.0.2.2.7.1-0004\share\hadoop\mapreduce\lib\*;C:\apps\dist\hadoop-2.6.0.2.2.7.1-0004\share\hadoop\mapreduce\*;C:\apps\dist\azureLogging\*;C:\apps\dist\tez-0.5.2.2.2.7.1-0004\conf\;C:\apps\dist\tez-0.5.2.2.2.7.1-0004\*;C:\apps\dist\tez-0.5.2.2.2.7.1-0004\lib\*; org.apache.hive.hcatalog.templeton.Main -agentpath:"D:\Program Files (x86)\YourKit Java Profiler 2015 build 15076\bin\win64\yjpagent.dll"

Upon restarting the service, it fails with no error message.

The load test works fine:

D:\>java -agentpath:"D:\Program Files (x86)\YourKit Java Profiler 2015 build 15076\bin\win64\yjpagent.dll"=help

[YourKit Java Profiler 2015 build 15076] Log file: D:\Users\root\.yjp\log\java-1
0032.log

YourKit Java Profiler 2015 build 15076 JVMTI agent usage: -agentpath:<path to ag
ent library>=[<option>, ...]

< . . . cut . . . >

Tried to start the service from the command line but still silent failure.

Any idea what the problem is?

Using the OpenJDK:
D:\>java -version
openjdk version "1.7.0_55"
OpenJDK Runtime Environment (Zulu 7.4.0.5-win64) (build 1.7.0_55-b13)
OpenJDK 64-Bit Server VM (Zulu 7.4.0.5-win64) (build 24.55-b03, mixed mode)

Thanks!
dgshaver
 
Posts: 3
Joined: Wed Oct 28, 2015 8:50 pm

Re: Difficulty with getting profiling to work

Postby Anton Katilin » Thu Oct 29, 2015 10:25 am

Hi,

Could you please provide the profiler agent log file <user home>/.yjp/log/<session name>-<pid>.log

Please note that the profiler does not officially support Zulu OpenJDK.

Please try running with Sun/Oracle Java instead.

Best regards
Anton
Anton Katilin
 
Posts: 5575
Joined: Wed Aug 11, 2004 8:37 am

Re: Difficulty with getting profiling to work

Postby dgshaver » Thu Oct 29, 2015 4:40 pm

Thanks Anton.

Looks like it's failing to attach with. Return code is 3. Here is the full log (apologies, didn't see an upload link):

15076 0.048: Command line:
D:\Program Files (x86)\YourKit Java Profiler 2015 build 15076\jre64\bin\javaw.exe
-XX:+HeapDumpOnOutOfMemoryError
-Xmx4G
-XX:PermSize=256m
-XX:MaxPermSize=256m
-jar
..\lib\yjp.jar
15076 0.048: Executable: D:\Program Files (x86)\YourKit Java Profiler 2015 build 15076\jre64\bin\javaw.exe
15076 0.048: Windows Server 2012 R2; version 6.3.9600; 64-bit process
15076 0.049: hid: 16022D999W6Z093YZU593253555186505WVUUX661Y 64-bit machine
15076 0.049: Today is 20151028
15076 0.049: full_build_stamp: 15076 201510231650
15076 0.049: Agent library path: D:\Program Files (x86)\YourKit Java Profiler 2015 build 15076\bin\win64\yjpagent.dll
15076 0.049:
---------------------------------------------------------------------
Product: YourKit Java Profiler 2015 build 15076
Build: 15076 on 201510231650
JDK: 1.8.0_65
VM: Java HotSpot(TM) 64-Bit Server VM
Vendor: Oracle Corporation
OS: Windows Server 2012 R2
OS version: 6.3
OS arch: amd64
Date and time: Wed Oct 28 19:45:27 GMT 2015
Properties:
awt.toolkit=sun.awt.windows.WToolkit
file.encoding.pkg=sun.io
file.encoding=Cp1252
file.separator=\
java.awt.graphicsenv=sun.awt.Win32GraphicsEnvironment
java.awt.printerjob=sun.awt.windows.WPrinterJob
java.class.path=..\lib\yjp.jar
java.class.version=52.0
java.endorsed.dirs=D:\Program Files (x86)\YourKit Java Profiler 2015 build 15076\jre64\lib\endorsed
java.ext.dirs=D:\Program Files (x86)\YourKit Java Profiler 2015 build 15076\jre64\lib\ext;D:\Windows\Sun\Java\lib\ext
java.home=D:\Program Files (x86)\YourKit Java Profiler 2015 build 15076\jre64
java.io.tmpdir=D:\Users\root\AppData\Local\Temp\2\
java.library.path=D:\Program Files (x86)\YourKit Java Profiler 2015 build 15076\jre64\bin;D:\Windows\Sun\Java\bin;D:\Windows\system32;D:\Windows;C:\apps\dist\hadoop-2.6.0.2.2.7.1-0004\bin;C:\apps\dist\java\bin;D:\Windows\system32;D:\Windows;D:\Windows\System32\Wbem;D:\Windows\System32\WindowsPowerShell\v1.0\;D:\Windows\system32;D:\Windows;D:\Windows\System32\Wbem;D:\Windows\System32\WindowsPowerShell\v1.0\;;E:\base\x64;E:\base\x86;E:\diagnostics\x64;;D:\Packages\GuestAgent\GuestAgent\LegacyRuntime\x64;D:\Packages\GuestAgent\GuestAgent\LegacyRuntime\x86;;D:\python27;.
java.runtime.name=Java(TM) SE Runtime Environment
java.runtime.version=1.8.0_65-b17
java.specification.name=Java Platform API Specification
java.specification.vendor=Oracle Corporation
java.specification.version=1.8
java.vendor.url.bug=http://bugreport.sun.com/bugreport/
java.vendor.url=http://java.oracle.com/
java.vendor=Oracle Corporation
java.version=1.8.0_65
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.8
java.vm.vendor=Oracle Corporation
java.vm.version=25.65-b01
line.separator=


os.arch=amd64
os.name=Windows Server 2012 R2
os.version=6.3
path.separator=;
sun.arch.data.model=64
sun.awt.enableExtraMouseButtons=true
sun.boot.class.path=D:\Program Files (x86)\YourKit Java Profiler 2015 build 15076\jre64\lib\resources.jar;D:\Program Files (x86)\YourKit Java Profiler 2015 build 15076\jre64\lib\rt.jar;D:\Program Files (x86)\YourKit Java Profiler 2015 build 15076\jre64\lib\sunrsasign.jar;D:\Program Files (x86)\YourKit Java Profiler 2015 build 15076\jre64\lib\jsse.jar;D:\Program Files (x86)\YourKit Java Profiler 2015 build 15076\jre64\lib\jce.jar;D:\Program Files (x86)\YourKit Java Profiler 2015 build 15076\jre64\lib\charsets.jar;D:\Program Files (x86)\YourKit Java Profiler 2015 build 15076\jre64\lib\jfr.jar;D:\Program Files (x86)\YourKit Java Profiler 2015 build 15076\jre64\classes
sun.boot.library.path=D:\Program Files (x86)\YourKit Java Profiler 2015 build 15076\jre64\bin
sun.cpu.endian=little
sun.cpu.isalist=amd64
sun.desktop=windows
sun.io.unicode.encoding=UnicodeLittle
sun.java.command=..\lib\yjp.jar
sun.java.launcher=SUN_STANDARD
sun.jnu.encoding=Cp1252
sun.management.compiler=HotSpot 64-Bit Tiered Compilers
sun.os.patch.level=
user.country=US
user.dir=D:\Program Files (x86)\YourKit Java Profiler 2015 build 15076\bin
user.home=D:\Users\root
user.language=en
user.name=root
user.script=
user.timezone=GMT
user.variant=
Environment:
ALLUSERSPROFILE=D:\ProgramData
APPDATA=D:\Users\root\AppData\Roaming
CLIENTNAME=DANSHA1
COMPUTERNAME=HEADNODE0
ComSpec=D:\Windows\system32\cmd.exe
CommonProgramFiles(x86)=D:\Program Files (x86)\Common Files
CommonProgramFiles=D:\Program Files\Common Files
CommonProgramW6432=D:\Program Files\Common Files
DATAFU_HOME=C:\apps\dist\datafu-1.2.0.2.2.7.1-0004
DATA_LOSS_STATE=0
FC_HOME=C:\apps\dist\failovercontroller-1.0.0
FP_NO_HOST_CHECK=NO
HADOOP_CLASSPATH=C:\apps\dist\azureLogging\*
HADOOP_CLIENT_OPTS=-Xmx1000m
HADOOP_COMMON_HOME=C:\apps\dist\hadoop-2.6.0.2.2.7.1-0004
HADOOP_CONF_DIR=C:\apps\dist\hadoop-2.6.0.2.2.7.1-0004\etc\hadoop
HADOOP_HDFS_HOME=C:\apps\dist\hadoop-2.6.0.2.2.7.1-0004
HADOOP_HOME=C:\apps\dist\hadoop-2.6.0.2.2.7.1-0004
HADOOP_MAPRED_HOME=C:\apps\dist\hadoop-2.6.0.2.2.7.1-0004
HADOOP_ROOT_LOGGER=INFO,console,DRFA,ETW,FilterLog
HADOOP_YARN_HOME=C:\apps\dist\hadoop-2.6.0.2.2.7.1-0004
HBASE_CLASSPATH=C:\apps\dist\azureLogging\*
HBASE_CONF_DIR=C:\apps\dist\hbase-0.98.4.2.2.7.1-0004-hadoop2\conf
HBASE_HOME=C:\apps\dist\hbase-0.98.4.2.2.7.1-0004-hadoop2
HBASE_ROOT_LOGGER=INFO,console,DRFA,ETW,FilterLog
HCAT_HOME=C:\apps\dist\hive-0.14.0.2.2.7.1-0004\hcatalog
HDFS_AUDIT_LOGGER=INFO,RFAAUDIT
HIVE_CONF_DIR=C:\apps\dist\hive-0.14.0.2.2.7.1-0004\conf
HIVE_HOME=C:\apps\dist\hive-0.14.0.2.2.7.1-0004
HIVE_LIB_DIR=C:\apps\dist\hive-0.14.0.2.2.7.1-0004\lib
HIVE_OPTS= -hiveconf hive.querylog.location=C:\apps\dist\hive-0.14.0.2.2.7.1-0004\logs\history -hiveconf hive.log.dir=C:\apps\dist\hive-0.14.0.2.2.7.1-0004\logs
HIVE_REPLACED=yes
HOMEDRIVE=D:
HOMEPATH=\Users\root
JAVA_HOME=C:\apps\dist\java
LOCALAPPDATA=D:\Users\root\AppData\Local
LOGONSERVER=\\HEADNODE0
MAHOUT_HOME=C:\apps\dist\mahout-0.9.0.2.2.7.1-0004
MA_LOGGING_HASH=f26ba47d-bc15-4f47-89b2-664a9c4ba310
NUMBER_OF_PROCESSORS=4
OOZIE_ROOT=C:\apps\dist\oozie-4.1.0.2.2.7.1-0004
OOZIE_URL=http://headnodehost:11000/oozie
OS=Windows_NT
PATHEXT=.COM;.EXE;.BAT;.CMD;.VBS;.VBE;.JS;.JSE;.WSF;.WSH;.MSC
PIG_HOME=C:\apps\dist\pig-0.14.0.2.2.7.1-0004
PROCESSOR_ARCHITECTURE=AMD64
PROCESSOR_IDENTIFIER=Intel64 Family 6 Model 45 Stepping 7, GenuineIntel
PROCESSOR_LEVEL=6
PROCESSOR_REVISION=2d07
PSModulePath=D:\Windows\system32\WindowsPowerShell\v1.0\Modules\;d:\Program Files\Microsoft Security Client\MpProvider\
PUBLIC=D:\Users\Public
PYTHON_CMD=D:\python27\python.exe
PYTHON_HOME=D:\python27
Path=C:\apps\dist\hadoop-2.6.0.2.2.7.1-0004\bin;C:\apps\dist\java\bin;D:\Windows\system32;D:\Windows;D:\Windows\System32\Wbem;D:\Windows\System32\WindowsPowerShell\v1.0\;D:\Windows\system32;D:\Windows;D:\Windows\System32\Wbem;D:\Windows\System32\WindowsPowerShell\v1.0\;;E:\base\x64;E:\base\x86;E:\diagnostics\x64;;D:\Packages\GuestAgent\GuestAgent\LegacyRuntime\x64;D:\Packages\GuestAgent\GuestAgent\LegacyRuntime\x86;;D:\python27
ProgramData=D:\ProgramData
ProgramFiles(x86)=D:\Program Files (x86)
ProgramFiles=D:\Program Files
ProgramW6432=D:\Program Files
SESSIONNAME=RDP-Tcp#1
SQOOP_HOME=C:\apps\dist\sqoop-1.4.5.2.2.7.1-0004
SystemDrive=D:
SystemRoot=D:\Windows
TEMP=D:\Users\root\AppData\Local\Temp\2
TEMPLETON_HOME=C:\apps\dist\hive-0.14.0.2.2.7.1-0004\hcatalog
TEZ_CLASSPATH=C:\apps\dist\tez-0.5.2.2.2.7.1-0004\conf\;C:\apps\dist\tez-0.5.2.2.2.7.1-0004\*;C:\apps\dist\tez-0.5.2.2.2.7.1-0004\lib\*
TEZ_HOME=C:\apps\dist\tez-0.5.2.2.2.7.1-0004
TMP=D:\Users\root\AppData\Local\Temp\2
USERDOMAIN=headnode0
USERDOMAIN_ROAMINGPROFILE=headnode0
USERNAME=root
USERPROFILE=D:\Users\root
WEBHCAT_CONF_DIR=C:\apps\dist\hive-0.14.0.2.2.7.1-0004\hcatalog\etc\webhcat
YARN_ROOT_LOGGER=INFO,console,DRFA,ETW,FilterLog
windir=D:\Windows
---------------------------------------------------------------------


15076 0.049: com.yourkit.Main1: starting...
15076 0.050: com.yourkit.Main1: number of args: 0
15076 0.181: com.yourkit.Main1: oomeDumperStatus: 1
15076 0.294: com.yourkit.g.f.a.a: FYI: native (current) LAF font: javax.swing.plaf.FontUIResource[family=Tahoma,name=Tahoma,style=plain,size=11]
15076 0.294: com.yourkit.g.f.a.a: FYI: metal font: javax.swing.plaf.FontUIResource[family=Dialog,name=Dialog,style=bold,size=12]
15076 0.300: com.yourkit.g.f.a.a: general font: javax.swing.plaf.FontUIResource[family=Segoe UI,name=Segoe UI,style=plain,size=12]
15076 0.300: com.yourkit.g.f.a.a: menu font: javax.swing.plaf.FontUIResource[family=Segoe UI,name=Segoe UI,style=plain,size=12]
15076 1.149: com.yourkit.g.i.c.c: ParallelExecutor: pool size 4
15076 1.257: shmem: Global\YOURKIT SHARE G: OK, isFirst=1
15076 1.257: shmem: Local\YOURKIT SHARE L: OK, isFirst=1
15076 1.282: shmem: Global\YOURKIT SHARE2 G: OK, isFirst=1
15076 1.282: shmem: Local\YOURKIT SHARE2 L: OK, isFirst=1
15076 1.302: shmem: Global\YOURKIT SHARE5 G: OK, isFirst=1
15076 1.303: shmem: Local\YOURKIT SHARE5 L: OK, isFirst=1
15076 1.524: com.yourkit.g.b6: marker: created D:\Users\root\.yjp\.yjp_20071015_ui55857
15076 76.176: com.yourkit.h.f$b: LWS-activate: code=200 text: payload=AM... result=ok
15076 1127.129: com.yourkit.g.u.a: Attaching agent to: PID=1604
15076 1127.174: com.yourkit.g.u.q: Process type: _BITNESS_UNKNOWN
15076 1127.183: com.yourkit.g.u.q: Process path: java.exe
15076 1127.184: com.yourkit.g.u.q: Trying to attach as to a 32-bit JVM:
D:\Program Files (x86)\YourKit Java Profiler 2015 build 15076\jre\bin\javaw.exe
-Xbootclasspath/a:D:\Program Files (x86)\YourKit Java Profiler 2015 build 15076\lib\tools.jar
-Dfile.encoding=UTF-8
-cp
D:\Program Files (x86)\YourKit Java Profiler 2015 build 15076\lib\yjp.jar
com.yourkit.Attach
1604
D:\Program Files (x86)\YourKit Java Profiler 2015 build 15076\bin\win32\yjpagent.dll
D:\Program Files (x86)\YourKit Java Profiler 2015 build 15076\bin\win64\yjpagent.dll

15076 1127.505: com.yourkit.g.u.q: Command failed:
exit code: 3
stdout:
PID: 1604
path_to_agent: D:\Program Files (x86)\YourKit Java Profiler 2015 build 15076\bin\win32\yjpagent.dll
startupOptions: D:\Program Files (x86)\YourKit Java Profiler 2015 build 15076\bin\win64\yjpagent.dll
com.sun.tools.attach.AttachNotSupportedException: Unable to attach to 64-bit process
at sun.tools.attach.WindowsVirtualMachine.openProcess(Native Method)
at sun.tools.attach.WindowsVirtualMachine.<init>(WindowsVirtualMachine.java:38)
at sun.tools.attach.WindowsAttachProvider.attachVirtualMachine(WindowsAttachProvider.java:52)
at com.sun.tools.attach.VirtualMachine.attach(VirtualMachine.java:195)
at com.yourkit.Attach.main(a:50)

15076 1127.506: com.yourkit.g.u.q: Trying to attach as to a 64-bit JVM:
D:\Program Files (x86)\YourKit Java Profiler 2015 build 15076\jre64\bin\javaw.exe
-Xbootclasspath/a:D:\Program Files (x86)\YourKit Java Profiler 2015 build 15076\lib\tools.jar
-Dfile.encoding=UTF-8
-cp
D:\Program Files (x86)\YourKit Java Profiler 2015 build 15076\lib\yjp.jar
com.yourkit.Attach
1604
D:\Program Files (x86)\YourKit Java Profiler 2015 build 15076\bin\win64\yjpagent.dll
D:\Program Files (x86)\YourKit Java Profiler 2015 build 15076\bin\win64\yjpagent.dll

15076 1127.915: com.yourkit.g.u.q: Command failed:
exit code: 2
stdout:
PID: 1604
path_to_agent: D:\Program Files (x86)\YourKit Java Profiler 2015 build 15076\bin\win64\yjpagent.dll
startupOptions: D:\Program Files (x86)\YourKit Java Profiler 2015 build 15076\bin\win64\yjpagent.dll
VirtualMachine: sun.tools.attach.WindowsAttachProvider@55f96302: 1604
Waiting the agent to load...
checking agent status...
Cannot attach profiler agent to JVM: AgentInitializationException, return value=3
com.sun.tools.attach.AgentInitializationException: Agent_OnAttach failed
at sun.tools.attach.HotSpotVirtualMachine.loadAgentLibrary(HotSpotVirtualMachine.java:47)
at sun.tools.attach.HotSpotVirtualMachine.loadAgentPath(HotSpotVirtualMachine.java:70)
at com.yourkit.Attach.main(a:81)

15076 1127.916: com.yourkit.g.u.a$7: com.yourkit.runtime.PresentableException: Cannot attach profiler agent to JVM as to a 32-bit process:

com.sun.tools.attach.AttachNotSupportedException: Unable to attach to 64-bit process

Cannot attach profiler agent to JVM as to a 64-bit process:

Cannot attach profiler agent to JVM: AgentInitializationException, return value=3
at com.yourkit.g.u.q.a(a:39)
at com.yourkit.g.u.a$7.a(a:3)
at com.yourkit.g.db$1.run(a:5)
at com.yourkit.g.db$b.run(a:12)

15076 1160.836: com.yourkit.e.bc: exiting now...
dgshaver
 
Posts: 3
Joined: Wed Oct 28, 2015 8:50 pm

Re: Difficulty with getting profiling to work

Postby Anton Katilin » Fri Oct 30, 2015 11:55 am

Hello,

I think I've found the problem.

Please see the command line in your original message. It ends with:
org.apache.hive.hcatalog.templeton.Main -agentpath:"D:\Program Files (x86)\YourKit Java Profiler 2015 build 15076\bin\win64\yjpagent.dll"

-agentpath is a JVM option, and should be placed among other VM options, i.e. before the class name org.apache.hive.hcatalog.templeton.Main. You placed it after the class name, thus making it the program's parameter, i.e. a parameter of main(). As the result, it was not applied.

Best regards,
Anton
Anton Katilin
 
Posts: 5575
Joined: Wed Aug 11, 2004 8:37 am

Re: Difficulty with getting profiling to work

Postby dgshaver » Fri Oct 30, 2015 3:48 pm

Ugh! Thanks Anton. Really appreciate the help.
dgshaver
 
Posts: 3
Joined: Wed Oct 28, 2015 8:50 pm


Return to Java Profiler

Who is online

Users browsing this forum: Bing [Bot] and 6 guests