JDK-8161225 : Assert failure in JVMTI GetNamedModule at JPLISAgent.c line: 792
  • Type: Bug
  • Component: core-svc
  • Sub-Component: java.lang.instrument
  • Affected Version: 9
  • Priority: P3
  • Status: Resolved
  • Resolution: Fixed
  • Submitted: 2016-07-12
  • Updated: 2016-10-13
  • Resolved: 2016-09-21
The Version table provides details related to the release that this issue/RFE will be addressed.

Unresolved : Release in which this issue/RFE will be addressed.
Resolved: Release in which this issue/RFE has been resolved.
Fixed : Release in which this issue/RFE has been fixed. The release containing this fix may be available for download as an Early Access Release or a General Availability Release.

To download the current JDK release, click here.
JDK 9
9 b140Fixed
Related Reports
Relates :  
JDK-8167001 - [TESTBUG] java/lang/instrument/DaemonThread/TestDaemonThread.java fails when run by jprt
Relates :  
JDK-8159145 - Add JVMTI function GetNamedModule
Relates :  
JDK-7142035 - assert in j.l.instrument agents during shutdown when daemon thread is running
Sub Tasks
JDK-8161388 :  
quarantine java/lang/instrument/DaemonThread/TestDaemonThread.java - Resolved
Description
 stderr: [*** java.lang.instrument ASSERTION FAILED ***: "err == JVMTI_ERROR_NONE" with message error in the JVMTI GetNamedModule at JPLISAgent.c line: 792
]
 exitValue = 0

java.lang.RuntimeException: 'ASSERTION FAILED' found in stderr 

	at jdk.testlibrary.OutputAnalyzer.shouldNotContain(OutputAnalyzer.java:163)
	at TestDaemonThreadLauncher.main(TestDaemonThreadLauncher.java:34)
	at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(java.base@9-internal/Native Method)
	at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(java.base@9-internal/NativeMethodAccessorImpl.java:62)
	at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(java.base@9-internal/DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(java.base@9-internal/Method.java:533)
	at com.sun.javatest.regtest.agent.MainWrapper$MainThread.run(MainWrapper.java:110)
	at java.lang.Thread.run(java.base@9-internal/Thread.java:843)
Comments
That all makes sense to me. I'll put the fix in and also fix the lack of exitValue check in the test.
20-09-2016
I would think, this is a test bug. The assert in the JPLISAgent.c can be relaxed too considering that the retransformation is not going to proceed at the DEATH phase anyway. The macro check_phase_ret_blob(err, NULL) can be used here. The test main waits for 200 ms which is apparently not enough to complete the DaemonThread and Agent's work. Increasing the waiting timeout is not a good approach. It is better for the main thread to sync with the DaemonThread and wait until its work is finished. But it seems, this testing scenario was created intentionally. If so, then fixing the JPLISAgent.c assert is a right approach.
20-09-2016
And yes, it is indeed in the DEATH phase. BTW, the test needs to check the exitValue in case the subprocess crashes. I stuck an assert(false) in jvmti_GetNamedModule() to force an hs_err dump, and the test suddenly started passing every time.
20-09-2016
Chris, thank you for confirming that it is the DEATH phase!
20-09-2016
Ah, so if I enable logging then the JVM will use jvmtiEnterTrace.cpp instead? Yes, I figured it is the DEATH phase. Just want to verify and see what the overall state of things is when it happens.
20-09-2016
[ to: Chris ] It can be the DEATH phase only. The log_trace() is only generated in the jvmtiEnterTrace.cpp.
20-09-2016
BTW, the log_trace() calls you see in jvmtiEnter.xsl are not generated into jvmtiEnter.cpp. It looks like the $trace parameter is not setup.
20-09-2016
Ok. I'll try to figure out which phase we are in when the error is generated.
20-09-2016
[ to: Chris ] The check is in the build/*/hotspot/variant-server/gensrc/jvmtifiles/jvmtiEnter.cpp: static jvmtiError JNICALL 3185 jvmti_GetNamedModule(jvmtiEnv* env, 3186 jobject class_loader, 3187 const char* package_name, 3188 jobject* module_ptr) { . . . 3193 if(!JvmtiEnv::is_vm_live()) { 3194 return JVMTI_ERROR_WRONG_PHASE; 3195 } . . . Oops: Just found that Dan has posted it before me! :)
20-09-2016
Part of the JVM/TI API is generated at build time... from the JVM/TI spec itself... So in an existing build space look for: solaris-x86_64-normal-server-release/hotspot/variant-server/gensrc/jvmtifiles/jvmtiEnter.cpp: static jvmtiError JNICALL jvmti_GetNamedModule(jvmtiEnv* env, jobject class_loader, const char* package_name, jobject* module_ptr) { #if !INCLUDE_JVMTI return JVMTI_ERROR_NOT_AVAILABLE; #else if(!JvmtiEnv::is_vm_live()) { return JVMTI_ERROR_WRONG_PHASE; } Thread* this_thread = Thread::current_or_null(); if (this_thread == NULL || !this_thread->is_Java_thread()) { return JVMTI_ERROR_UNATTACHED_THREAD; } JavaThread* current_thread = (JavaThread*)this_thread; ThreadInVMfromNative __tiv(current_thread); VM_ENTRY_BASE(jvmtiError, jvmti_GetNamedModule , current_thread) debug_only(VMNativeEntryWrapper __vew;) CautiouslyPreserveExceptionMark __em(this_thread); JvmtiEnv* jvmti_env = JvmtiEnv::JvmtiEnv_from_jvmti_env(env); if (!jvmti_env->is_valid()) { return JVMTI_ERROR_INVALID_ENVIRONMENT; } jvmtiError err; if (package_name == NULL) { return JVMTI_ERROR_NULL_POINTER; } if (module_ptr == NULL) { return JVMTI_ERROR_NULL_POINTER; } err = jvmti_env->GetNamedModule(class_loader, package_name, module_ptr); return err; #endif // INCLUDE_JVMTI } It looks like GetNamedModule() can only be called during the live phase... Since the original failure logged by Joe ran for 42 seconds, I'm going to guess that GetNamedModule() was somehow called _after_ live phase so during VM shutdown... Look at the life cycle of the thread that is calling GetNamedModule()...
20-09-2016
It looks like JvmtiEnv::GetNamedModule can't possibly return JVMTI_ERROR_WRONG_PHASE, so I don't see how this is possible. Is there some other jvmti dispatch table that would direct (*jvmti)->GetNamedModule() to a method that returns JVMTI_ERROR_WRONG_PHASE? Maybe a table used for pre-initialized or shutdown state?
20-09-2016
Thanks, Chris! This helps a lot.
20-09-2016
This failure seems to be sporadic, and happens on all platforms. I'm seeing it fail with RBT runs about 25% of the time. I added a bit of debugging code and found that the error being returned is JVMTI_ERROR_WRONG_PHASE.
20-09-2016
I was not able to reproduce it with an RBT run. Will try to submit the jdk/test:jdk_instrument on all platforms.
13-07-2016
[ ~dcubed ] Thanks, Dan. I'm working to reproduce this test failure on linux-x64 aarch64 with the rbt.
13-07-2016
Removing the integration blocker as it is a minor issue in switch to new feature.
12-07-2016