Startup succeeds, but profiling port is not opened.

Questions about YourKit Java Profiler
Post Reply
foodini
Posts: 4
Joined: Fri Nov 21, 2014 8:07 pm

Startup succeeds, but profiling port is not opened.

Post by foodini »

Context:
$ uname -a
Linux ###.com 2.6.50-t17.el5 #1 SMP Sat Oct 18 13:18:32 PDT 2014 x86_64 x86_64 x86_64 GNU/Linux

Trying to get remote profiling working so I can connect from my desktop to a dev/prod machine.

I've added the agent to the commandline, using the fully-qualified path:

Code: Select all

-agentpath:/.../libyjpagent.so=disablestacktelemetry,disableexceptiontelemetry,probe_disable=*,delay=45000,port=10001
The args came from running bin/yjp.sh -integrate. My project comes up and does what it is supposed to, serving user requests, etc., but there's no reporting - to stdout, stderr, or ~/.yjp/logs - from the agent.

Code: Select all

$ export JAVA_HOME=/usr/lib/jvm/java-1.7.0-openjdk
$ ./yjp.sh -attach 42145
[YourKit Java Profiler 2014 build 14112] Log file: /home/..../.yjp/log/yjp-45484.log
Attaching to process 42145 using default options
The profiler agent has attached. Waiting while it initializes...
The agent is loaded and is listening on port 10001.
You can connect to it from the profiler UI.
Looks good, right? There's nothing running at port 10001. The logs disagree:

Code: Select all

14112 - 0.002: Command line:
  /usr/lib/jvm/java-1.7.0-openjdk/bin/java
  -agentpath:/...../yjp-2014-build-14112/bin/linux-x86-64/libyjpagent.so=port=10001
...
...
14112 - 27.857: Profiler agent is listening on port 10001
...
...
14112 - 27.857: agentInit: OK
...
14112 - 146.305: startProfiling: 1
14112 - 146.305: startProfiling: OK
14112 - 175.933: SP: gc #0 5 ms=70 sz=3138 p=0 t=138
What's going on with the agent that is causing it to plug its ears like this?
foodini
Posts: 4
Joined: Fri Nov 21, 2014 8:07 pm

Re: Startup succeeds, but profiling port is not opened.

Post by foodini »

I should add that I frequently get this when I try to run the attach:

Code: Select all

$ ./yjp.sh -attach 3491
[YourKit Java Profiler 2014 build 14112] Log file: /home/..../.yjp/log/yjp-5693.log
Attaching to process 3491 using default options
com.yourkit.runtime.PresentableException: Command failed:
  exit code: 4
  stdout:
    PID: 3491
    path_to_agent: /...../yjp-2014-build-14112/bin/linux-x86-64/libyjpagent.so
    startupOptions:
    VirtualMachine: sun.tools.attach.LinuxAttachProvider@42a57993: 3491
    Waiting the agent to load...
    checking agent status...
    checking agent status...
    checking agent status...
    checking agent status...
    checking agent status...
    checking agent status...
    checking agent status...
    checking agent status...
    checking agent status...
    checking agent status...
    Timeout: VirtualMachine.loadAgentPath() has not finished in 10 seconds...
  stderr:
    [YourKit Java Profiler 2014 build 14112] Log file: /home/expandodo/.yjp/log/Attach-5823.log

	at com.yourkit.h.u.p.a(a:102)
	at com.yourkit.h.u.c.a(a:200)
	at com.yourkit.Main1.int(a:183)
	at com.yourkit.Main1.entry(a:271)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:483)
	at com.yourkit.Main$2.run(a:8)

Attach to a running JVM failed.

Solution: start JVM with the profiler agent instead of attaching it to a running JVM:
http://www.yourkit.com/docs/java/help/running_with_profiler.jsp
The "Solution" at the end implies that it thinks I'm trying to attach to a JVM that has not had the -agentpath provided. This suggests that whatever RPC endpoint yjp.sh expects the profiling agent to have created, it isn't there.
Anton Katilin
Posts: 6172
Joined: Wed Aug 11, 2004 8:37 am

Re: Startup succeeds, but profiling port is not opened.

Post by Anton Katilin »

Hi,

If I understand it right, you try to remotely profile your application. You enable profiling with -agentpath option (correct), check that the log file is created (correct), but cannot connect from the profiler UI to that instance.

If yes, please consider the following troubleshooting instructions:
http://www.yourkit.com/docs/java/help/c ... leshooting

If this doesn't help, could you please describe what you see on the UI side. What is the error message?

Regarding "yjp.sh -attach". It's a tool for the attach mode.
http://www.yourkit.com/docs/java/help/attach_wizard.jsp
Since you specify -agentpath, you load the agent from start. It's another mode, and, by the way, the recommended one.

"yjp.sh -agent" is just a frontend to corresponding JVM API which attaches specified agent to specified JVM instance.
Calling the command as "yjp.sh -attach <pid>" forces the attach call without checking whether the agent has already been loaded or not. I suppose that the issue you describe in your second post may be related with how JVM reacts to such re-attach. (Anyway, this should not harm the JVM with already loaded agent in now way.)

To check agent status it's better to explicitly check the agent log file existence and content, or run "yjp.sh -attach" without the pid parameter. The latter will list running JVMs and show their agent statuses.

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

Re: Startup succeeds, but profiling port is not opened.

Post by Anton Katilin »

An update:
The args came from running bin/yjp.sh -integrate. My project comes up and does what it is supposed to, serving user requests, etc., but there's no reporting - to stdout, stderr, or ~/.yjp/logs - from the agent.
Do you mean that after you specify the -agentpath and launch the application (and before you perform "yjp.sh -attach pid") no agent logs are created?

If so, the agent is not loaded because the JVM option -agentpath does not reach the JVM command line.
How do you specify -agentpath? If via an environment variable in a script, please ensure it's not later overridden.

Please also pay attention to the startup option "port=10001". It forces the agent to use port 10001, and if another agent is already listening on it, the profiled application won't start. Please consider not using the port option at all: the port will be chosen automatically from the default range:
http://www.yourkit.com/docs/java/help/s ... s.jsp#port
foodini
Posts: 4
Joined: Fri Nov 21, 2014 8:07 pm

Re: Startup succeeds, but profiling port is not opened.

Post by foodini »

Anton Katilin wrote:An update:
The args came from running bin/yjp.sh -integrate. My project comes up and does what it is supposed to, serving user requests, etc., but there's no reporting - to stdout, stderr, or ~/.yjp/logs - from the agent.
Do you mean that after you specify the -agentpath and launch the application (and before you perform "yjp.sh -attach pid") no agent logs are created?
That is correct. The agent logs are not in ~/.yph/logs until after I attempt to run the yjp.sh -attach [PID]. Having read through the docs, I was a bit unclear as to the behavior when the agent is loaded. Given that I saw no port opened, the docs seemed to suggest that I had to run the remote attachment tool to create an external port to interface with something the agent was only exporting to localhost. Since this has worked once or twice (out of about 100 attempts now), I stuck with that process.
Anton Katilin wrote:If so, the agent is not loaded because the JVM option -agentpath does not reach the JVM command line.
How do you specify -agentpath? If via an environment variable in a script, please ensure it's not later overridden.

Please also pay attention to the startup option "port=10001". It forces the agent to use port 10001, and if another agent is already listening on it, the profiled application won't start. Please consider not using the port option at all: the port will be chosen automatically from the default range:
http://www.yourkit.com/docs/java/help/s ... s.jsp#port
I've alternated between using a specified port and leaving the option off. The only times I've managed to connect the UI is when it was specified, though given my success rate, that doesn't really mean anything. In the future, I'll leave it off. It takes a while to set up each run, so here I'll use data from what is currently deployed:

I start the JVM with the command-line argument, rather than through the environment variable. Checking with "ps aux | grep agentpath", I get:

Code: Select all

9011     47883 96.1 14.5 30656464 9553676 ?    Sl   19:22   2:25 /usr/lib/jvm/java-1.7.0-openjdk/bin/java ............. -agentpath:/var/lib/............../libyjpagent.so=disablestacktelemetry,disableexceptiontelemetry,probe_disable=*,delay=10000,port=10003
I've had to cut out most of the command line, I'm afraid. The entire thing comes to 1520 characters, with 308 of that being the path of the .so. There's no ~/.yjp directory.
Anton Katilin
Posts: 6172
Joined: Wed Aug 11, 2004 8:37 am

Re: Startup succeeds, but profiling port is not opened.

Post by Anton Katilin »

Please try to remove the startup option "delay".

To explicitly specify the log directory location please use the option "logdir":

http://www.yourkit.com/docs/java/help/s ... ptions.jsp

Could please send entire log file to [email protected] if you cannot share it in the forum.
foodini
Posts: 4
Joined: Fri Nov 21, 2014 8:07 pm

Re: Startup succeeds, but profiling port is not opened.

Post by foodini »

Anton Katilin wrote:Please try to remove the startup option "delay".

To explicitly specify the log directory location please use the option "logdir":

http://www.yourkit.com/docs/java/help/s ... ptions.jsp

Could please send entire log file to [email protected] if you cannot share it in the forum.
I've removed the delay and set the logdir explicitly (to $HOME/.logs), made sure the directory existed and that it was writable by the process. I've also doublechecked that the process is not being chroot-jailed, but no log is being generated. I'll see if I can put together a more detailed report to email.
Anton Katilin
Posts: 6172
Joined: Wed Aug 11, 2004 8:37 am

Re: Startup succeeds, but profiling port is not opened.

Post by Anton Katilin »

Hi,

I've answered by email.

In short: it looks like the problem was that you put -agentpath to a wrong place (after -jar thus making it the application's option instead of a JVM option).

What you did (wrong): java <other options> -jar <name> -agentpath:<...>
What you should do instead: java <other options> -agentpath:<...> -jar <name>

Best regards,
Anton
Post Reply