JDK-8294881 : test/hotspot/jtreg/vmTestbase/nsk/jdi/VirtualMachine/dispose/dispose003/TestDescription.java fails
  • Type: Bug
  • Component: core-svc
  • Sub-Component: debugger
  • Priority: P4
  • Status: Resolved
  • Resolution: Fixed
  • OS: generic
  • CPU: generic
  • Submitted: 2022-10-06
  • Updated: 2023-10-11
  • Resolved: 2022-11-15
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 17 JDK 20
17.0.10Fixed 20 b24Fixed
Related Reports
Duplicate :  
JDK-8226587 - vmTestbase/nsk/jdi/VirtualMachine/dispose/dispose002/TestDescription.java failed with thread2 is alive
Relates :  
JDK-8289607 - Change hotspot/jtreg tests to not use Thread.suspend/resume
Relates :  
JDK-8249627 - Degrade Thread.suspend and Thread.resume
Relates :  
JDK-8226587 - vmTestbase/nsk/jdi/VirtualMachine/dispose/dispose002/TestDescription.java failed with thread2 is alive
Description
On AArch64, command to reproduce:
$ make run-test TEST="./test/hotspot/jtreg/vmTestbase/nsk/jdi/VirtualMachine/dispose/dispose003/TestDescription.java"

......

ACTION: main -- Failed. Execution failed: `main' threw exception: java.lang.NullPointerException: Cannot invoke "String.equals(Object)" because "<local1>" is null
REASON: User specified action: run main/othervm nsk.jdi.VirtualMachine.dispose.dispose003 -verbose -arch=${os.family}-${os.simpleArch} -waittime=5 -debugee.vmkind=java -transport.address=dynamic -debugee.vmkeys="${test.vm.opts} ${test.java.opts}"
TIME:   0.407 seconds
messages:
command: main nsk.jdi.VirtualMachine.dispose.dispose003 -verbose -arch=linux-aarch64 -waittime=5 -debugee.vmkind=java -transport.address=dynamic -debugee.vmkeys="-Xmx768m -XX:MaxRAMPercentage=3.125 -Djava.io.tmpdir=/home/realfyang/openjdk-jdk/build/linux-aarch64-server-release/test-support/jtreg_test_hotspot_jtreg_vmTestbase_nsk_jdi_VirtualMachine_dispose_dispose003_TestDescription_java/tmp -ea -esa "
reason: User specified action: run main/othervm nsk.jdi.VirtualMachine.dispose.dispose003 -verbose -arch=${os.family}-${os.simpleArch} -waittime=5 -debugee.vmkind=java -transport.address=dynamic -debugee.vmkeys="${test.vm.opts} ${test.java.opts}"
started: Thu Oct 06 10:17:40 CST 2022
Mode: othervm [/othervm specified]
finished: Thu Oct 06 10:17:41 CST 2022
elapsed time (seconds): 0.407
configuration:
STDOUT:
binder> VirtualMachineManager: version 20.0
binder> Finding connector: default
binder> LaunchingConnector:
binder>     name: com.sun.jdi.CommandLineLaunch
binder>     description: Launches target using Sun Java VM command line and attaches to it
binder>     transport: com.sun.tools.jdi.SunCommandLineLauncher$2@98aea6e
binder> Connector arguments:
binder>     main=nsk.jdi.VirtualMachine.dispose.dispose003a -vbs -verbose -arch=linux-aarch64 -waittime=5 -debugee.vmkind=java -transport.address=dynamic -debugee.vmkeys="-Xmx768m -XX:MaxRAMPercentage=3.125 -Djava.io.tmpdir=/home/realfyang/openjdk-jdk/build/linux-aarch64-server-release/test-support/jtreg_test_hotspot_jtreg_vmTestbase_nsk_jdi_VirtualMachine_dispose_dispose003_TestDescription_java/tmp -ea -esa " -pipe.port=38895
binder>     includevirtualthreads=y
binder>     quote=
binder>     home=/home/realfyang/openjdk-jdk/build/linux-aarch64-server-release/images/jdk
binder>     vmexec=java
binder>     suspend=true
binder>     options=-Xmx768m -XX:MaxRAMPercentage=3.125 -Djava.io.tmpdir=/home/realfyang/openjdk-jdk/build/linux-aarch64-server-release/test-support/jtreg_test_hotspot_jtreg_vmTestbase_nsk_jdi_VirtualMachine_dispose_dispose003_TestDescription_java/tmp -ea -esa
binder> Launching debugee
binder> Waiting for VM initialized
Initial VMStartEvent received: VMStartEvent in thread main
--> debugger: nsk.jdi.VirtualMachine.dispose.dispose003a debuggee launched
debugee.stderr> **> dispose003a: debuggee started!
--> debugger: 'ready' recieved
debugee.stderr> **> dispose003a: waiting for an instruction from the debugger ...

==> nsk/jdi/VirtualMachine/dispose/dispose003        TESTING BEGINS
debugee.stderr> **> dispose003a:        thread2 is created
debugee.stderr> **> dispose003a:        synchronized (waitnotifyObj) { enter
debugee.stderr> **> dispose003a:        before: test_thread.start()
debugee.stderr> **> dispose003a:        before:   waitnotifyObj.wait();
debugee.stderr> **> thread2: method 'run' enter
debugee.stderr> **> thread2: entered into block:  synchronized (waitnotifyObj)
debugee.stderr> **> dispose003a:        after:    waitnotifyObj.wait();
debugee.stderr> **> thread2: exited from block:  synchronized (waitnotifyObj)

==> nsk/jdi/VirtualMachine/dispose/dispose003  new checkready: #0
--> debugger: getting ThreadReference object
--> debugger:       suspending thread2
--> debugger:       vm.dispose()
--> debugger: ......forcing the main thread to leave synchronized block
--> debugger:       Waiting for thread2 is not alive
debugee.stderr> **> dispose003a: mainThread is out of: synchronized (lockingObject)
debugee.stderr> **> thread2: entered into block:  synchronized (lockingObject)
debugee.stderr> **> thread2: exited from block:  synchronized (lockingObject)
debugee.stderr> **> thread2: call to the method 'runt1'
debugee.stderr> **> thread2: method 'runt1': enter
--> debugger: ......sending to the debuggee: 'check_alive'
--> debugger:        expected reply: 'not_alive'
debugee.stderr> **> dispose003a: checking on: thread2.isAlive
debugee.stderr> **> thread2: method 'runt1': body: i0 == 1
debugee.stderr> **> thread2: method 'runt1': exit
debugee.stderr> **> thread2: returned from the method 'runt1'
debugee.stderr> **> thread2: method 'run' exit
debugee.stderr> Exception in thread "main" java.lang.UnsupportedOperationException
debugee.stderr>         at java.base/java.lang.Thread.resume(Thread.java:1837)
debugee.stderr>         at nsk.jdi.VirtualMachine.dispose.dispose003a.main(dispose003a.java:139)
STDERR:
java.lang.NullPointerException: Cannot invoke "String.equals(Object)" because "<local1>" is null
        at nsk.jdi.VirtualMachine.dispose.dispose003.lambda$runThis$0(dispose003.java:249)
        at jdk.test.lib.Utils.waitForCondition(Utils.java:590)
        at nsk.jdi.VirtualMachine.dispose.dispose003.runThis(dispose003.java:243)
        at nsk.jdi.VirtualMachine.dispose.dispose003.run(dispose003.java:77)
        at nsk.jdi.VirtualMachine.dispose.dispose003.main(dispose003.java:72)
        at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:104)
        at java.base/java.lang.reflect.Method.invoke(Method.java:578)
        at com.sun.javatest.regtest.agent.MainWrapper$MainThread.run(MainWrapper.java:125)
        at java.base/java.lang.Thread.run(Thread.java:1591)

JavaTest Message: Test threw exception: java.lang.NullPointerException: Cannot invoke "String.equals(Object)" because "<local1>" is null
JavaTest Message: shutting down test

STATUS:Failed.`main' threw exception: java.lang.NullPointerException: Cannot invoke "String.equals(Object)" because "<local1>" is null
rerun:
cd /home/realfyang/openjdk-jdk/build/linux-aarch64-server-release/test-support/jtreg_test_hotspot_jtreg_vmTestbase_nsk_jdi_VirtualMachine_dispose_dispose003_TestDescription_java/scratch/0 && \
HOME=/home/realfyang \
LANG=en_US.UTF-8 \
LC_ALL=C \
PATH=/bin:/usr/bin:/usr/sbin \
TEST_IMAGE_DIR=/home/realfyang/openjdk-jdk/build/linux-aarch64-server-release/images/test \
_JVM_DWARF_PATH=/home/realfyang/openjdk-jdk/build/linux-aarch64-server-release/images/symbols \
CLASSPATH=/home/realfyang/openjdk-jdk/test/hotspot/jtreg/vmTestbase/nsk/jdi/VirtualMachine/dispose/dispose003:/home/realfyang/openjdk-jdk/build/linux-aarch64-server-release/test-support/jtreg_test_hotspot_jtreg_vmTestbase_nsk_jdi_VirtualMachine_dispose_dispose003_TestDescription_java/classes/0/vmTestbase:/home/realfyang/openjdk-jdk/test/hotspot/jtreg/vmTestbase:/home/realfyang/openjdk-jdk/build/linux-aarch64-server-release/test-support/jtreg_test_hotspot_jtreg_vmTestbase_nsk_jdi_VirtualMachine_dispose_dispose003_TestDescription_java/classes/0/test/lib:/home/realfyang/openjdk-jdk/test/lib:/home/realfyang/tools/jtreg-7+1/lib/jtreg.jar \
    /home/realfyang/openjdk-jdk/build/linux-aarch64-server-release/images/jdk/bin/java \
        -Dtest.vm.opts='-Xmx768m -XX:MaxRAMPercentage=3.125 -Djava.io.tmpdir=/home/realfyang/openjdk-jdk/build/linux-aarch64-server-release/test-support/jtreg_test_hotspot_jtreg_vmTestbase_nsk_jdi_VirtualMachine_dispose_dispose003_TestDescription_java/tmp -ea -esa' \
        -Dtest.tool.vm.opts='-J-Xmx768m -J-XX:MaxRAMPercentage=3.125 -J-Djava.io.tmpdir=/home/realfyang/openjdk-jdk/build/linux-aarch64-server-release/test-support/jtreg_test_hotspot_jtreg_vmTestbase_nsk_jdi_VirtualMachine_dispose_dispose003_TestDescription_java/tmp -J-ea -J-esa' \
        -Dtest.compiler.opts= \
        -Dtest.java.opts= \
        -Dtest.jdk=/home/realfyang/openjdk-jdk/build/linux-aarch64-server-release/images/jdk \
        -Dcompile.jdk=/home/realfyang/openjdk-jdk/build/linux-aarch64-server-release/images/jdk \
        -Dtest.timeout.factor=4.0 \
        -Dtest.root=/home/realfyang/openjdk-jdk/test/hotspot/jtreg \
        -Dtest.name=vmTestbase/nsk/jdi/VirtualMachine/dispose/dispose003/TestDescription.java \
        -Dtest.file=/home/realfyang/openjdk-jdk/test/hotspot/jtreg/vmTestbase/nsk/jdi/VirtualMachine/dispose/dispose003/TestDescription.java \
        -Dtest.src=/home/realfyang/openjdk-jdk/test/hotspot/jtreg/vmTestbase/nsk/jdi/VirtualMachine/dispose/dispose003 \
        -Dtest.src.path=/home/realfyang/openjdk-jdk/test/hotspot/jtreg/vmTestbase/nsk/jdi/VirtualMachine/dispose/dispose003:/home/realfyang/openjdk-jdk/test/hotspot/jtreg/vmTestbase:/home/realfyang/openjdk-jdk/test/lib \
        -Dtest.classes=/home/realfyang/openjdk-jdk/build/linux-aarch64-server-release/test-support/jtreg_test_hotspot_jtreg_vmTestbase_nsk_jdi_VirtualMachine_dispose_dispose003_TestDescription_java/classes/0/vmTestbase/nsk/jdi/VirtualMachine/dispose/dispose003/TestDescription.d \
        -Dtest.class.path=/home/realfyang/openjdk-jdk/build/linux-aarch64-server-release/test-support/jtreg_test_hotspot_jtreg_vmTestbase_nsk_jdi_VirtualMachine_dispose_dispose003_TestDescription_java/classes/0/vmTestbase/nsk/jdi/VirtualMachine/dispose/dispose003/TestDescription.d:/home/realfyang/openjdk-jdk/build/linux-aarch64-server-release/test-support/jtreg_test_hotspot_jtreg_vmTestbase_nsk_jdi_VirtualMachine_dispose_dispose003_TestDescription_java/classes/0/vmTestbase:/home/realfyang/openjdk-jdk/build/linux-aarch64-server-release/test-support/jtreg_test_hotspot_jtreg_vmTestbase_nsk_jdi_VirtualMachine_dispose_dispose003_TestDescription_java/classes/0/test/lib \
        -Dtest.class.path.prefix=/home/realfyang/openjdk-jdk/test/hotspot/jtreg/vmTestbase/nsk/jdi/VirtualMachine/dispose/dispose003:/home/realfyang/openjdk-jdk/build/linux-aarch64-server-release/test-support/jtreg_test_hotspot_jtreg_vmTestbase_nsk_jdi_VirtualMachine_dispose_dispose003_TestDescription_java/classes/0/vmTestbase:/home/realfyang/openjdk-jdk/build/linux-aarch64-server-release/test-support/jtreg_test_hotspot_jtreg_vmTestbase_nsk_jdi_VirtualMachine_dispose_dispose003_TestDescription_java/classes/0/test/lib \
        -Xmx768m \
        -XX:MaxRAMPercentage=3.125 \
        -Djava.io.tmpdir=/home/realfyang/openjdk-jdk/build/linux-aarch64-server-release/test-support/jtreg_test_hotspot_jtreg_vmTestbase_nsk_jdi_VirtualMachine_dispose_dispose003_TestDescription_java/tmp \
        -ea \
        -esa \
        com.sun.javatest.regtest.agent.MainWrapper /home/realfyang/openjdk-jdk/build/linux-aarch64-server-release/test-support/jtreg_test_hotspot_jtreg_vmTestbase_nsk_jdi_VirtualMachine_dispose_dispose003_TestDescription_java/vmTestbase/nsk/jdi/VirtualMachine/dispose/dispose003/TestDescription.d/main.0.jta -verbose -arch=linux-aarch64 -waittime=5 -debugee.vmkind=java -transport.address=dynamic '-debugee.vmkeys="-Xmx768m -XX:MaxRAMPercentage=3.125 -Djava.io.tmpdir=/home/realfyang/openjdk-jdk/build/linux-aarch64-server-release/test-support/jtreg_test_hotspot_jtreg_vmTestbase_nsk_jdi_VirtualMachine_dispose_dispose003_TestDescription_java/tmp -ea -esa' "

TEST RESULT: Failed. Execution failed: `main' threw exception: java.lang.NullPointerException: Cannot invoke "String.equals(Object)" because "<local1>" is null
--------------------------------------------------
Test results: failed: 1
Comments
Fix request [17u] I backport this because we see this failing in our CI. No risk, only a test change. Clean backport. Tests pass. SAP nightly testing passed.
11-10-2023
A pull request was submitted for review. URL: https://git.openjdk.org/jdk17u-dev/pull/1868 Date: 2023-10-10 11:22:25 +0000
10-10-2023
Changeset: 216c6f63 Author: Leonid Mesnik <lmesnik@openjdk.org> Date: 2022-11-15 17:19:48 +0000 URL: https://git.openjdk.org/jdk/commit/216c6f63409e60604beb3c4f0e1e0661b1124f8f
15-11-2022
Here's the log file from my sightings in my jdk-20+23 macosx64-aarch64 stress runs: $ unzip -l jdk-20+23_macosx-aarch64.8294881.zip Archive: jdk-20+23_macosx-aarch64.8294881.zip Length Date Time Name --------- ---------- ----- ---- 25221 11-11-2022 11:22 jdk-20+23_2/failures.macosx-aarch64/TestDescription.jtr.release --------- ------- 25221 1 file
14-11-2022
Here's the log file from my sighting in my jdk-20+23 linux-x64 stress runs: $ unzip -l jdk-20+23_linux-x64.8294881.zip Archive: jdk-20+23_linux-x64.8294881.zip Length Date Time Name --------- ---------- ----- ---- 23631 2022-11-11 09:59 jdk-20+23_2/failures.linux-x86_64/TestDescription.jtr.release --------- ------- 23631 1 file
14-11-2022
Here's the log files from my sightings in my jdk-20+21 macosx64-aarch64 stress runs: $ unzip -l jdk-20+21_macosx-aarch64.8294881.zip Archive: jdk-20+21_macosx-aarch64.8294881.zip Length Date Time Name --------- ---------- ----- ---- 25119 10-27-2022 12:17 jdk-20+21_1/failures.macosx-aarch64/TestDescription.jtr.release 25211 10-27-2022 12:17 jdk-20+21_1/failures.macosx-aarch64/TestDescription.jtr.release.1 25339 10-28-2022 10:47 jdk-20+21_2/failures.macosx-aarch64/TestDescription.jtr.slowdebug --------- ------- 75669 3 files
10-11-2022
Here's the log file from my sighting in my jdk-20+21 linux-x64 stress runs: $ unzip -l jdk-20+21_linux-x64.8294881.zip Archive: jdk-20+21_linux-x64.8294881.zip Length Date Time Name --------- ---------- ----- ---- 23652 2022-10-28 10:28 jdk-20+21_2/failures.linux-x86_64/TestDescription.jtr.release --------- ------- 23652 1 file
10-11-2022
Here's the log files from my sightings in my jdk-20+20 linux-x64 stress runs: $ unzip -l jdk-20+20_linux.8294881.zip Archive: jdk-20+20_linux.8294881.zip Length Date Time Name --------- ---------- ----- ---- 23653 2022-10-20 14:08 jdk-20+20_1/failures.linux-x86_64/TestDescription.jtr.release 23630 2022-10-21 11:45 jdk-20+20_2/failures.linux-x86_64/TestDescription.jtr.release --------- ------- 47283 2 files
28-10-2022
A pull request was submitted for review. URL: https://git.openjdk.org/jdk/pull/10877 Date: 2022-10-27 01:03:59 +0000
27-10-2022
We see the issue in our nightly tests also on Linux x86_64, not only aarch64 .
26-10-2022
[~dcubed] It looks like we have two issues here. The first is the use of Thread.resume(). The exception that results is hiding the root cause of the test failure, which is the fact that the thread was not suppose to be alive in the first place. Since the thread is not suppose to be alive, normally the test does not call Thread.resume(): In the main test (the debugger) we have: pipe.println("check_alive"); String reply = pipe.readln(); if (reply.equals("alive")) { log3("ERROR: thread2 is alive"); return false; } else if (reply.equals("not_alive")) { log2(" thread2 is not alive"); return true; } else { In the debuggee we have: } else if (instruction.equals("check_alive")) { log1("checking on: thread2.isAlive"); if (test_thread.isAlive()) { test_thread.resume(); pipe.println("alive"); } else { pipe.println("not_alive"); } } else { So the expectation is that the thread will not be alive, and therefore resume() will not be called. If the resume() call had been removed (which is should be), then the test case would still have failed due to the thread having been alive when it is not suppose to be. So now the question is how did the filer trigger the thread to be alive.
10-10-2022
I also don't understand why the test passed in all three 'fastdebug' and 'slowdbug' bit runs: $ grep vmTestbase/nsk/jdi/VirtualMachine/dispose/dispose003/TestDescription.java jdk-20+18_?/logs.linux-x86_64/do_jdi_tests-* jdk-20+18_1/logs.linux-x86_64/do_jdi_tests-fastdebug.log:Passed: vmTestbase/nsk/jdi/VirtualMachine/dispose/dispose003/TestDescription.java jdk-20+18_1/logs.linux-x86_64/do_jdi_tests-release.log:TEST: vmTestbase/nsk/jdi/VirtualMachine/dispose/dispose003/TestDescription.java jdk-20+18_1/logs.linux-x86_64/do_jdi_tests-release.log: -J-Dtest.name=vmTestbase/nsk/jdi/VirtualMachine/dispose/dispose003/TestDescription.java \ jdk-20+18_1/logs.linux-x86_64/do_jdi_tests-release.log: -J-Dtest.file=/work/shared/bug_hunt/thread_SMR_stress/jdk20_exp.git/open/test/hotspot/jtreg/vmTestbase/nsk/jdi/VirtualMachine/dispose/dispose003/TestDescription.java \ Binary file jdk-20+18_1/logs.linux-x86_64/do_jdi_tests-release.log matches jdk-20+18_1/logs.linux-x86_64/do_jdi_tests-slowdebug.log:Passed: vmTestbase/nsk/jdi/VirtualMachine/dispose/dispose003/TestDescription.java jdk-20+18_2/logs.linux-x86_64/do_jdi_tests-fastdebug.log:Passed: vmTestbase/nsk/jdi/VirtualMachine/dispose/dispose003/TestDescription.java jdk-20+18_2/logs.linux-x86_64/do_jdi_tests-release.log:Passed: vmTestbase/nsk/jdi/VirtualMachine/dispose/dispose003/TestDescription.java jdk-20+18_2/logs.linux-x86_64/do_jdi_tests-slowdebug.log:Passed: vmTestbase/nsk/jdi/VirtualMachine/dispose/dispose003/TestDescription.java jdk-20+18_3/logs.linux-x86_64/do_jdi_tests-fastdebug.log:Passed: vmTestbase/nsk/jdi/VirtualMachine/dispose/dispose003/TestDescription.java jdk-20+18_3/logs.linux-x86_64/do_jdi_tests-release.log:TEST: vmTestbase/nsk/jdi/VirtualMachine/dispose/dispose003/TestDescription.java jdk-20+18_3/logs.linux-x86_64/do_jdi_tests-release.log: -J-Dtest.name=vmTestbase/nsk/jdi/VirtualMachine/dispose/dispose003/TestDescription.java \ jdk-20+18_3/logs.linux-x86_64/do_jdi_tests-release.log: -J-Dtest.file=/work/shared/bug_hunt/thread_SMR_stress/jdk20_exp.git/open/test/hotspot/jtreg/vmTestbase/nsk/jdi/VirtualMachine/dispose/dispose003/TestDescription.java \ Binary file jdk-20+18_3/logs.linux-x86_64/do_jdi_tests-release.log matches jdk-20+18_3/logs.linux-x86_64/do_jdi_tests-slowdebug.log:Passed: vmTestbase/nsk/jdi/VirtualMachine/dispose/dispose003/TestDescription.java
10-10-2022
Here's the log files from my sightings in my jdk-20+18 stress runs: $ unzip -l jdk-20+18_linux.8294881.zip Archive: jdk-20+18_linux.8294881.zip Length Date Time Name --------- ---------- ----- ---- 23652 2022-10-06 19:22 jdk-20+18_1/failures.linux-x86_64/TestDescription.jtr.release 23632 2022-10-08 14:22 jdk-20+18_3/failures.linux-x86_64/TestDescription.jtr.release --------- ------- 47284 2 files I don't quite understand why this test failure didn't reproduce in all three 'release' bits runs.
10-10-2022
These are the relevant recent bugs: JDK-8249627 Degrade Thread.suspend and Thread.resume JDK-8289607 Change hotspot/jtreg tests to not use Thread.suspend/resume For some reason, JDK-8289607 does not include any changes for this test: vmTestbase/nsk/jdi/VirtualMachine/dispose/dispose003/TestDescription.java
07-10-2022
Looks like we missed another test that uses Thread.resume(): debugee.stderr> Exception in thread "main" java.lang.UnsupportedOperationException debugee.stderr> at java.base/java.lang.Thread.resume(Thread.java:1837) debugee.stderr> at nsk.jdi.VirtualMachine.dispose.dispose003a.main(dispose003a.java:139)
07-10-2022