You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@cassandra.apache.org by "Paulo Motta (JIRA)" <ji...@apache.org> on 2015/07/30 02:20:04 UTC

[jira] [Comment Edited] (CASSANDRA-9902) Windows dtest: invalid jolokia agent path

    [ https://issues.apache.org/jira/browse/CASSANDRA-9902?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14646961#comment-14646961 ] 

Paulo Motta edited comment on CASSANDRA-9902 at 7/30/15 12:19 AM:
------------------------------------------------------------------

The original error is caused by conflicting JDKs (namely 7 and 8) installed in the same system, which are normally switched by changing the {{$JAVA_HOME}} and adding {{$JAVA_HOME\bin}} to the {{$PATH}} environment variable. It may also necessary to update the registry when switching JDKs by running the following command on PowerShell:

{noformat}
Set-ItemProperty -Path 'Registry::HKEY_LOCAL_MACHINE\SOFTWARE\JavaSoft\Java Runtime Environment\' CurrentVersion 1.7
{noformat}

When "java" without the parent directory is called via python's {{subprocess.check_output}} on [cassandra-dtest/jmxutils.py|https://github.com/riptano/cassandra-dtest/blob/master/jmxutils.py#L80], the {{$PATH}} env var is not considered due to this [bug|http://bugs.python.org/issue8557], so instead, the java executable from {{c:\windows\system32\}} is picked, which can be pointing to another version. The simple fix is to use the {{$JAVA_HOME}} variable, if present, when invoking java, as done in this [v1|https://github.com/pauloricardomg/cassandra-dtest/tree/9902-v1] patch.

However, this is not all the fun, after this fix, the following error appears:
{noformat}
Failed to start jolokia agent (command was: C:\Program Files\Java\jdk1.7.0_76\bin\java -jar lib\jolokia-jvm-1.2.3-agent.jar --host 127.0.0.1 start 1992 --debug --verbose): Command '('C:\\Program Files\\Java\\jdk1.7.0_76\\bin\\java', '-jar', 'lib\\jolokia-jvm-1.2.3-agent.jar', '--host', '127.0.0.1', 'start', '1992', '--debug', '--verbose')' returned non-zero exit status 1
Exit status was: 1
Output was: java.util.ServiceConfigurationError: com.sun.tools.attach.spi.AttachProvider: Provider sun.tools.attach.WindowsAttachProvider could not be instantiated
InvocationTarget class com.sun.tools.attach.VirtualMachine (command: start) : null
java.lang.reflect.InvocationTargetException
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:606)
        at org.jolokia.jvmagent.client.util.VirtualMachineHandler.attachVirtualMachine(VirtualMachineHandler.java:66)
        at org.jolokia.jvmagent.client.AgentLauncher.main(AgentLauncher.java:57)
Caused by: com.sun.tools.attach.AttachNotSupportedException: no providers installed
        at com.sun.tools.attach.VirtualMachine.attach(VirtualMachine.java:208)
        ... 6 more
{noformat}

According to this [blog post|http://wayne-adams.blogspot.com.br/2011/10/jdi-three-ways-to-attach-to-java.html], this issue happens when the tools.jar is not loaded by the JRE. After inspecting the jolokia [vm instantiation code|https://github.com/rhuss/jolokia/blob/aadf5c19c2052bdfa2bad470c55f4c15c1005d26/agent/jvm/src/main/java/org/jolokia/jvmagent/client/util/VirtualMachineHandler.java], I found that the {{com.sun.tools.attach.VirtualMachine}} class is [dynamically loaded|https://github.com/rhuss/jolokia/blob/aadf5c19c2052bdfa2bad470c55f4c15c1005d26/agent/jvm/src/main/java/org/jolokia/jvmagent/client/util/ToolsClassFinder.java] from the tools.jar, however when {{VirtualMachine.attach}} [is called|https://github.com/rhuss/jolokia/blob/aadf5c19c2052bdfa2bad470c55f4c15c1005d26/agent/jvm/src/main/java/org/jolokia/jvmagent/client/util/VirtualMachineHandler.java#L66], the JVM is not able to load the {{sun.tools.attach.WindowsAttachProvider}} class because the tools.jar is not on the classpath (so that's probably a bug with jolokia, or Java on Windows).

The simple fix is to explicitly add the tools.jar to the jolokia classpath, as suggested [here|https://github.com/rhuss/jolokia/blob/aadf5c19c2052bdfa2bad470c55f4c15c1005d26/agent/jvm/src/main/java/org/jolokia/jvmagent/client/util/VirtualMachineHandler.java#L206]. This was done in  [v2|https://github.com/pauloricardomg/cassandra-dtest/tree/9902-v2] patch.

Apparently this seems to make jolokia connect with the testing JVM, however, this makes the Cassandra JVM crash without java crash logs or heap dumps. The only thing we have is a windows crash log ([attached here|https://issues.apache.org/jira/secure/attachment/12747879/win-crashlogs.zip]), which indicates the JVM crashes because of a [Data Execution Prevention|https://technet.microsoft.com/en-us/library/cc738483%28v=ws.10%29.aspx] exception. There is a feature to [whitelist a program from DEP|http://windows.microsoft.com/en-us/windows7/Change-Data-Execution-Prevention-settings], but apparently it's not possible to disable DEP for 64-bit programs o_O.

I don't know what might be causing this, if a JVM option that is set by Cassandra or an actual Windows JVM bug. In order to simplify reproduction, I made a simple class to reproduce the issue ([VMAttach.java|https://issues.apache.org/jira/secure/attachment/12747880/VMAttach.java]), which receives the PID of a java process and tries to attach to it using sun attach tools (the same used by jolokia). In order to compile and run:

{noformat}
javac -cp "$ENV:JAVA_HOME\lib\tools.jar;." VMAttach.java
java -cp "$ENV:JAVA_HOME\lib\tools.jar;." VMAttach.java <pid>
{noformat}

When this program is run against a cassandra process/pid, it makes the cassandra process crash silently.

Could you please try reproducing this on your box [~JoshuaMcKenzie]? Do you have any idea of what might be causing this?


was (Author: pauloricardomg):
The original error is caused by conflicting JDKs (namely 7 and 8) installed in the same system, which are normally switched by changing the {{$JAVA_HOME}} and adding {{$JAVA_HOME\bin}} to the {{$PATH}} environment variable. It may also necessary to update the registry when switching JDKs by running the following command on PowerShell:

{noformat}
Set-ItemProperty -Path 'Registry::HKEY_LOCAL_MACHINE\SOFTWARE\JavaSoft\Java Runtime Environment\' CurrentVersion 1.7
{noformat}

When "java" without the parent directory is called via python's {{subprocess.check_output}} on [cassandra-dtest/jmxutils.py|https://github.com/riptano/cassandra-dtest/blob/master/jmxutils.py#L80], the {{$PATH}} env var is not considered due to this [bug|http://bugs.python.org/issue8557], so instead, the java executable from {{c:\windows\system32\}} is picked, which can be pointing to another version. The simple fix is to use the {{$JAVA_HOME}} variable, if present, as done in this [v1|https://github.com/pauloricardomg/cassandra-dtest/tree/9902-v1] patch.

However, this is not all the fun, after this fix, the following error appears:
{noformat}
Failed to start jolokia agent (command was: C:\Program Files\Java\jdk1.7.0_76\bin\java -jar lib\jolokia-jvm-1.2.3-agent.jar --host 127.0.0.1 start 1992 --debug --verbose): Command '('C:\\Program Files\\Java\\jdk1.7.0_76\\bin\\java', '-jar', 'lib\\jolokia-jvm-1.2.3-agent.jar', '--host', '127.0.0.1', 'start', '1992', '--debug', '--verbose')' returned non-zero exit status 1
Exit status was: 1
Output was: java.util.ServiceConfigurationError: com.sun.tools.attach.spi.AttachProvider: Provider sun.tools.attach.WindowsAttachProvider could not be instantiated
InvocationTarget class com.sun.tools.attach.VirtualMachine (command: start) : null
java.lang.reflect.InvocationTargetException
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:606)
        at org.jolokia.jvmagent.client.util.VirtualMachineHandler.attachVirtualMachine(VirtualMachineHandler.java:66)
        at org.jolokia.jvmagent.client.AgentLauncher.main(AgentLauncher.java:57)
Caused by: com.sun.tools.attach.AttachNotSupportedException: no providers installed
        at com.sun.tools.attach.VirtualMachine.attach(VirtualMachine.java:208)
        ... 6 more
{noformat}

According to this [blog post|http://wayne-adams.blogspot.com.br/2011/10/jdi-three-ways-to-attach-to-java.html], this issue happens when the tools.jar is not loaded by the JRE. After inspecting the jolokia [vm instatiation code|https://github.com/rhuss/jolokia/blob/aadf5c19c2052bdfa2bad470c55f4c15c1005d26/agent/jvm/src/main/java/org/jolokia/jvmagent/client/util/VirtualMachineHandler.java], I found that the {{com.sun.tools.attach.VirtualMachine}} class is [dynamically loaded|https://github.com/rhuss/jolokia/blob/aadf5c19c2052bdfa2bad470c55f4c15c1005d26/agent/jvm/src/main/java/org/jolokia/jvmagent/client/util/ToolsClassFinder.java] from the tools.jar, however when {{VirtualMachine.attach}} is called, the JVM is not able to load the {{sun.tools.attach.WindowsAttachProvider}} class because the tools.jar is not on the classpath (so that's probably a bug with jolokia, or Java on Windows).

The simple fix is to explicitly add the tools.jar to the jolokia classpath, as suggested [here|https://github.com/rhuss/jolokia/blob/aadf5c19c2052bdfa2bad470c55f4c15c1005d26/agent/jvm/src/main/java/org/jolokia/jvmagent/client/util/VirtualMachineHandler.java#L206]. This was done in  [v2|https://github.com/pauloricardomg/cassandra-dtest/tree/9902-v2] patch.

Apparently this seems to make jolokia connect with the testing JVM, however, this makes the Cassandra JVM crash without java crash logs or heap dumps. The only thing we have is a windows crash log ([attached here|https://issues.apache.org/jira/secure/attachment/12747879/win-crashlogs.zip]), which indicates the JVM crashes because of a [Data Execution Prevention|https://technet.microsoft.com/en-us/library/cc738483%28v=ws.10%29.aspx] exception. There is a feature to [whitelist a program from DEP|http://windows.microsoft.com/en-us/windows7/Change-Data-Execution-Prevention-settings], but apparently it's not possible to disable DEP for 64-bit programs o_O.

I don't know what might be causing this, if a JVM option that is set by Cassandra or an actual Windows JVM bug. In order to simplify reproduction, I made a simple class to reproduce the issue ([VMAttach.java|https://issues.apache.org/jira/secure/attachment/12747880/VMAttach.java]), which receives the PID of a java process and tries to attach to it using sun attach tools (the same used by jolokia). In order to compile and run:

{noformat}
javac -cp "$ENV:JAVA_HOME\lib\tools.jar;." VMAttach.java
java -cp "$ENV:JAVA_HOME\lib\tools.jar;." VMAttach.java <pid>
{noformat}

When this program is run against a cassandra process/pid, it makes the cassandra process crash silently.

Could you please try reproducing this on your box [~JoshuaMcKenzie]? Do you have any idea of what might be causing this?

> Windows dtest: invalid jolokia agent path
> -----------------------------------------
>
>                 Key: CASSANDRA-9902
>                 URL: https://issues.apache.org/jira/browse/CASSANDRA-9902
>             Project: Cassandra
>          Issue Type: Sub-task
>            Reporter: Joshua McKenzie
>            Assignee: Paulo Motta
>            Priority: Minor
>              Labels: Windows
>             Fix For: 2.2.x
>
>         Attachments: VMAttach.java, win-crashlogs.zip
>
>
> A variety of tests are failing with similar:
> {noformat}
> 05:39:07 ======================================================================
> 05:39:07 ERROR: change_durable_writes_test (configuration_test.TestConfiguration)
> 05:39:07 ----------------------------------------------------------------------
> 05:39:07 Traceback (most recent call last):
> 05:39:07   File "D:\jenkins\workspace\cassandra-2.2_dtest_win32\cassandra-dtest\configuration_test.py", line 63, in change_durable_writes_test
> 05:39:07     durable_init_size = commitlog_size(durable_node)
> 05:39:07   File "D:\jenkins\workspace\cassandra-2.2_dtest_win32\cassandra-dtest\configuration_test.py", line 127, in commitlog_size
> 05:39:07     with JolokiaAgent(node) as jmx:
> 05:39:07   File "D:\jenkins\workspace\cassandra-2.2_dtest_win32\cassandra-dtest\jmxutils.py", line 188, in __enter__
> 05:39:07     self.start()
> 05:39:07   File "D:\jenkins\workspace\cassandra-2.2_dtest_win32\cassandra-dtest\jmxutils.py", line 80, in start
> 05:39:07     subprocess.check_output(args, stderr=subprocess.STDOUT)
> 05:39:07   File "D:\Python27\lib\subprocess.py", line 573, in check_output
> 05:39:07     raise CalledProcessError(retcode, cmd, output=output)
> 05:39:07 CalledProcessError: Command '('java', '-jar', 'lib\\jolokia-jvm-1.2.3-agent.jar', '--host', '127.0.0.1', 'start', '3436')' returned non-zero exit status 2
> 05:39:07 -------------------- >> begin captured logging << --------------------
> 05:39:07 dtest: DEBUG: cluster ccm directory: d:\temp\dtest-kjkypw
> 05:39:07 --------------------- >> end captured logging << ---------------------
> {noformat}
> Likely related:
> {noformat}
> 20:54:46 Failed to start jolokia agent (command was: java -jar lib\jolokia-jvm-1.2.3-agent.jar --host 127.0.0.1 start 3436): Command '('java', '-jar', 'lib\\jolokia-jvm-1.2.3-agent.jar', '--host', '127.0.0.1', 'start', '3436')' returned non-zero exit status 2
> 20:54:46 Exit status was: 2
> 20:54:46 Output was: Error: Registry key 'Software\JavaSoft\Java Runtime Environment'\CurrentVersion'
> 20:54:46 has value '1.8', but '1.7' is required.
> 20:54:46 Error: could not find java.dll
> 20:54:46 Error: Could not find Java SE Runtime Environment.
> {noformat}
> And at the top of jmxutils.py we see:
> {code}
> JOLOKIA_JAR = os.path.join('lib', 'jolokia-jvm-1.2.3-agent.jar')
> {code}
> So that's not going to work out too well on Windows.



--
This message was sent by Atlassian JIRA
(v6.3.4#6332)