On 4/29/16 01:56, Severin Gehwolf wrote:
Hi Serguei,
On Fri, 2016-04-29 at 01:34 -0700, serguei.spit...@oracle.com wrote:
Hi Severin,
The fix looks good in general.
I'm testing both fixes together at the moment.
That is JDK-8154529 and JDK-8153711? Yes, that's what I've done too.
A couple of questions...
It seems, there are more places where an invokerLock critical section is missed.
Right.
The following functions:
- invoker_enableInvokeRequests
This should be fixed with the patch for JDK-8154529
- invokeConstructor
- invokeStatic
- invokeNonvirtual
- invokeVirtual
- saveGlobalRef
Correct. The intent would be to fix the callsites of saveGlobalRef. If
we fix invoke* then saveGlobalRef should not be an issue. I didn't want
to include this in this fix since it's pretty hairy and would like to
fix this in incremental steps.
The first function is easy to fix.
The last 5 functions are called from the invoker_doInvoke() that we already had
a problem with.
I'm puzzled with the question: How to synchronize and avoid deadlocks at the
same time?
I'm not sure yet. Perhaps locking only while saveGlobalRef is being
called in invoke* functions will help.
I'm inclined to let your fix go (if the testing is Ok) and file one more bug on
the remaining sync issues.
Please keep me in the loop about your test results.
Both the JTreg com/sun/jdi and the co-located nsk.jdi tests are all passed.
I also ran the 4 previously failed tests in big loops of 1000 runs:
com/sun/jdi/InvokeTest.java
com/sun/jdi/InvokeHangTest.java
com/sun/jdi/InterfaceMethodsTest.java
com/sun/jdi/OomDebugTest.java (new test introduced in the webrev)
The OomDebugTest.java failed with a timeout (most likely, a deadlock).
Please, find the OomDebugTest.jtr file in attachments.
Thanks,
Serguei
Thanks for your help!
Cheers,
Severin
Thanks,
Serguei
On 4/28/16 02:00, Severin Gehwolf wrote:
On Tue, 2016-04-19 at 19:32 -0700, serguei.spit...@oracle.com wrote:
Hi Severin,
I postpone a push for this fix.
There are two nsk.jdi test failures (they look like deadlocks):
nsk/jdi/ObjectReference/invokeMethod/invokemethod012 FAIL(TIMEOUT)
nsk/jdi/Scenarios/invokeMethod/popframes001 FAIL(TIMEOUT)
and one jtreg sun/com/jdi failure (it looks like a deadlock too):
com/sun/jdi/InvokeHangTes.java
I'll double check if these failures are regressions caused by your fix
or not.
I confirm, the failures above are new regressions introduced by the fix.
The tests fail consistently with the fix and do not fail without the fix.
OK this was caused by the locking done in invoker_doInvoke(). Note that
holding either of them invoker lock or event handler lock causes this.
Here is a new webrev with those hunks removed. It's sufficient to grab
the locks again in invoke_completeInvokeRequest() when clearing the
global references in order to not get those failures we've seen when
the fix for JDK-4858370 was in place.
http://cr.openjdk.java.net/~sgehwolf/webrevs/JDK-8153711/webrev.02/
Testing done:
- com/sun/jdi/InvokeTest.java com/sun/jdi/InvokeHangTest.java and
sun/jdi/InterfaceMethodsTest.java does not fail in 1500 runs.
- regular com/sun/jdi test set: no regressions
Note that there are some rare cases where OomDebugTest times out which
seems to be caused by the GC, though. See the bug for details. Since
this problem is rare, it's still worthwhile having that test included.
If it turns out a problem in practice we could consider disabling the
test.
Thoughts?
Cheers,
Severin
#Test Results (version 2)
#Fri Apr 29 06:05:40 PDT 2016
#checksum:3e000f1cd4b3282c
#-----testdescription-----
$file=/var/tmp/sspitsyn/jdk9.2/jdk/test/com/sun/jdi/OomDebugTest.java
$root=/var/tmp/sspitsyn/jdk9.2/jdk/test
author=Severin Gehwolf <sgehw...@redhat.com>
keywords=bug8153711
library=..
run=USER_SPECIFIED build TestScaffold VMConnection TargetListener
TargetAdapter\nUSER_SPECIFIED compile -g OomDebugTest.java\nUSER_SPECIFIED main
OomDebugTest OomDebugTestTarget test1\nUSER_SPECIFIED main OomDebugTest
OomDebugTestTarget test2\nUSER_SPECIFIED main OomDebugTest OomDebugTestTarget
test3\nUSER_SPECIFIED main OomDebugTest OomDebugTestTarget
test4\nUSER_SPECIFIED main OomDebugTest OomDebugTestTarget test5\n
source=OomDebugTest.java
title=JDWP\: Memory Leak (global references not deleted after invokeMethod).
#-----environment-----
#-----testresult-----
description=file\:/var/tmp/sspitsyn/jdk9.2/jdk/test/com/sun/jdi/OomDebugTest.java
elapsed=129113 0\:02\:09.113
end=Fri Apr 29 06\:05\:40 PDT 2016
environment=regtest
execStatus=Error. Program
`/var/tmp/sspitsyn/jdk9.2/build/linux-x86_64-normal-server-fastdebug/images/jdk/bin/java'
timed out (timeout set to 120000ms, elapsed time was 121059ms).
hostname=sc11137378.us.oracle.com
javatestOS=Linux 3.2.0-55-generic (amd64)
javatestVersion=4.4
jtregVersion=jtreg 4.2 fcs b02
script=com.sun.javatest.regtest.RegressionScript
sections=script_messages build compile build main build main
start=Fri Apr 29 06\:03\:31 PDT 2016
test=com/sun/jdi/OomDebugTest.java
testJDK=/var/tmp/sspitsyn/jdk9.2/build/linux-x86_64-normal-server-fastdebug/images/jdk
user.name=sspitsyn
work=/var/tmp/sspitsyn/tst/jdk9.2/JTwork/com/sun/jdi
#section:script_messages
----------messages:(8/492)----------
JDK under test:
/var/tmp/sspitsyn/jdk9.2/build/linux-x86_64-normal-server-fastdebug/images/jdk
java version "9-internal"
Java(TM) SE Runtime Environment (fastdebug build
9-internal+0-2016-04-29-004440.sspitsyn.jdk9.2)
Java HotSpot(TM) 64-Bit Server VM (fastdebug build
9-internal+0-2016-04-29-004440.sspitsyn.jdk9.2, mixed mode)
Library ..; kind: packages
source directory: /var/tmp/sspitsyn/jdk9.2/jdk/test/com/sun
class directory: /var/tmp/sspitsyn/tst/jdk9.2/JTwork/classes/com/sun
#section:build
----------messages:(3/197)----------
command: build TestScaffold VMConnection TargetListener TargetAdapter
reason: User specified action: run build TestScaffold VMConnection
TargetListener TargetAdapter
elapsed time (seconds): 0.001
result: Passed. All files up to date
#section:compile
----------messages:(4/193)----------
command: compile -g
/var/tmp/sspitsyn/jdk9.2/jdk/test/com/sun/jdi/OomDebugTest.java
reason: User specified action: run compile -g OomDebugTest.java
Mode: othervm
elapsed time (seconds): 4.834
----------configuration:(5/230)----------
javac compilation environment
class path: /var/tmp/sspitsyn/jdk9.2/jdk/test/com/sun/jdi
/var/tmp/sspitsyn/tst/jdk9.2/JTwork/classes/com/sun/jdi
/var/tmp/sspitsyn/tst/jdk9.2/JTwork/classes/com/sun
----------rerun:(21/1470)*----------
DISPLAY=localhost:13.0 \\
HOME=/home/sspitsyn \\
JTREG_HOME=/java/re/jtreg/4.2/promoted/latest/binaries/jtreg \\
LANG=en_US.UTF-8 \\
PATH=/bin:/usr/bin \\
/var/tmp/sspitsyn/jdk9.2/build/linux-x86_64-normal-server-fastdebug/images/jdk/bin/javac
\\
-J-Dtest.src=/var/tmp/sspitsyn/jdk9.2/jdk/test/com/sun/jdi \\
-J-Dtest.src.path=/var/tmp/sspitsyn/jdk9.2/jdk/test/com/sun/jdi:/var/tmp/sspitsyn/jdk9.2/jdk/test/com/sun
\\
-J-Dtest.classes=/var/tmp/sspitsyn/tst/jdk9.2/JTwork/classes/com/sun/jdi \\
-J-Dtest.class.path=/var/tmp/sspitsyn/tst/jdk9.2/JTwork/classes/com/sun/jdi:/var/tmp/sspitsyn/tst/jdk9.2/JTwork/classes/com/sun
\\
-J-Dtest.vm.opts= \\
-J-Dtest.tool.vm.opts= \\
-J-Dtest.compiler.opts= \\
-J-Dtest.java.opts= \\
-J-Dtest.jdk=/var/tmp/sspitsyn/jdk9.2/build/linux-x86_64-normal-server-fastdebug/images/jdk
\\
-J-Dcompile.jdk=/var/tmp/sspitsyn/jdk9.2/build/linux-x86_64-normal-server-fastdebug/images/jdk
\\
-J-Dtest.timeout.factor=1.0 \\
-d /var/tmp/sspitsyn/tst/jdk9.2/JTwork/classes/com/sun/jdi \\
-sourcepath
/var/tmp/sspitsyn/jdk9.2/jdk/test/com/sun/jdi:/var/tmp/sspitsyn/jdk9.2/jdk/test/com/sun
\\
-classpath
/var/tmp/sspitsyn/jdk9.2/jdk/test/com/sun/jdi:/var/tmp/sspitsyn/tst/jdk9.2/JTwork/classes/com/sun/jdi:/var/tmp/sspitsyn/tst/jdk9.2/JTwork/classes/com/sun
\\
-g /var/tmp/sspitsyn/jdk9.2/jdk/test/com/sun/jdi/OomDebugTest.java
----------System.out:(0/0)----------
----------System.err:(0/0)----------
result: Passed. Compilation successful
#section:build
----------messages:(3/95)----------
command: build OomDebugTest
reason: Named class compiled on demand
elapsed time (seconds): 0.0
result: Passed. All files up to date
#section:main
----------messages:(4/175)----------
command: main OomDebugTest OomDebugTestTarget test1
reason: User specified action: run main OomDebugTest OomDebugTestTarget test1
Mode: othervm
elapsed time (seconds): 2.462
----------configuration:(0/0)----------
----------System.out:(43/2380)----------
vmOpts: '-Xmx40m'
javaOpts: ''
JVM version:9-internal
JDI version: 9.0
JVM description: Java Debug Interface (Reference Implementation) version 9.0
Java Debug Wire Protocol (Reference Implementation) version 9.0
JVM Debug Interface version 9.0
JVM version 9-internal (Java HotSpot(TM) 64-Bit Server VM, mixed mode, sharing)
DEBUG: OomDebugTestTarget.main
DEBUG: invoked constructor
DEBUG: ------------> Running test1
DEBUG: invoked 'void testMethod(FooCls)', foo ==
OomDebugTestTarget$FooCls@327471b5
DEBUG: Done invoking method via debugger.
DEBUG: invoked 'void testMethod(FooCls)', foo ==
OomDebugTestTarget$FooCls@4157f54e
DEBUG: Done invoking method via debugger.
DEBUG: invoked 'void testMethod(FooCls)', foo ==
OomDebugTestTarget$FooCls@90f6bfd
DEBUG: Done invoking method via debugger.
DEBUG: invoked 'void testMethod(FooCls)', foo ==
OomDebugTestTarget$FooCls@47f6473
DEBUG: Done invoking method via debugger.
DEBUG: invoked 'void testMethod(FooCls)', foo ==
OomDebugTestTarget$FooCls@15975490
DEBUG: Done invoking method via debugger.
DEBUG: Done invoking method via debugger.
DEBUG: Done invoking method via debugger.
DEBUG: invoked 'void testMethod(FooCls)', foo ==
OomDebugTestTarget$FooCls@6b143ee9
DEBUG: invoked 'void testMethod(FooCls)', foo ==
OomDebugTestTarget$FooCls@1936f0f5
DEBUG: Done invoking method via debugger.
DEBUG: invoked 'void testMethod(FooCls)', foo ==
OomDebugTestTarget$FooCls@6615435c
DEBUG: Done invoking method via debugger.
DEBUG: invoked 'void testMethod(FooCls)', foo ==
OomDebugTestTarget$FooCls@4909b8da
DEBUG: Done invoking method via debugger.
DEBUG: invoked 'void testMethod(FooCls)', foo ==
OomDebugTestTarget$FooCls@3a03464
DEBUG: invoked 'void testMethod(FooCls)', foo ==
OomDebugTestTarget$FooCls@2d3fcdbd
DEBUG: Done invoking method via debugger.
DEBUG: invoked 'void testMethod(FooCls)', foo ==
OomDebugTestTarget$FooCls@617c74e5
DEBUG: Done invoking method via debugger.
DEBUG: invoked 'void testMethod(FooCls)', foo ==
OomDebugTestTarget$FooCls@6537cf78
DEBUG: Done invoking method via debugger.
DEBUG: invoked 'void testMethod(FooCls)', foo ==
OomDebugTestTarget$FooCls@67b6d4ae
DEBUG: Done invoking method via debugger.
DEBUG: invoked 'void testMethod(FooCls)', foo ==
OomDebugTestTarget$FooCls@34b7bfc0
DEBUG: Done invoking method via debugger.
DEBUG: Finished running test 'test1'.
DEBUG: More tests to run. Coninuing.
----------System.err:(2/80)----------
[10ms] run args: [OomDebugTestTarget, test1, OomDebugTestTarget]
STATUS:Passed.
----------rerun:(19/1589)*----------
DISPLAY=localhost:13.0 \\
HOME=/home/sspitsyn \\
JTREG_HOME=/java/re/jtreg/4.2/promoted/latest/binaries/jtreg \\
LANG=en_US.UTF-8 \\
PATH=/bin:/usr/bin \\
CLASSPATH=/var/tmp/sspitsyn/tst/jdk9.2/JTwork/classes/com/sun/jdi:/var/tmp/sspitsyn/jdk9.2/jdk/test/com/sun/jdi:/var/tmp/sspitsyn/tst/jdk9.2/JTwork/classes/com/sun:/var/tmp/sspitsyn/jdk9.2/jdk/test/com/sun:/net/scanas416.us.oracle.com/export/java_re2/misc/promoted/jtreg/4.2/fcs/b02/binaries/jtreg/lib/javatest.jar:/net/scanas416.us.oracle.com/export/java_re2/misc/promoted/jtreg/4.2/fcs/b02/binaries/jtreg/lib/jtreg.jar
\\
/var/tmp/sspitsyn/jdk9.2/build/linux-x86_64-normal-server-fastdebug/images/jdk/bin/java
\\
-Dtest.src=/var/tmp/sspitsyn/jdk9.2/jdk/test/com/sun/jdi \\
-Dtest.src.path=/var/tmp/sspitsyn/jdk9.2/jdk/test/com/sun/jdi:/var/tmp/sspitsyn/jdk9.2/jdk/test/com/sun
\\
-Dtest.classes=/var/tmp/sspitsyn/tst/jdk9.2/JTwork/classes/com/sun/jdi
\\
-Dtest.class.path=/var/tmp/sspitsyn/tst/jdk9.2/JTwork/classes/com/sun/jdi:/var/tmp/sspitsyn/tst/jdk9.2/JTwork/classes/com/sun
\\
-Dtest.vm.opts= \\
-Dtest.tool.vm.opts= \\
-Dtest.compiler.opts= \\
-Dtest.java.opts= \\
-Dtest.jdk=/var/tmp/sspitsyn/jdk9.2/build/linux-x86_64-normal-server-fastdebug/images/jdk
\\
-Dcompile.jdk=/var/tmp/sspitsyn/jdk9.2/build/linux-x86_64-normal-server-fastdebug/images/jdk
\\
-Dtest.timeout.factor=1.0 \\
com.sun.javatest.regtest.agent.MainWrapper
/var/tmp/sspitsyn/tst/jdk9.2/JTwork/com/sun/jdi/OomDebugTest.d/main.0.jta
OomDebugTestTarget test1
result: Passed. Execution successful
#section:build
----------messages:(3/95)----------
command: build OomDebugTest
reason: Named class compiled on demand
elapsed time (seconds): 0.0
result: Passed. All files up to date
#section:main
----------messages:(270/16605)----------
command: main OomDebugTest OomDebugTestTarget test2
reason: User specified action: run main OomDebugTest OomDebugTestTarget test2
Mode: othervm
Timeout information:
Running jstack on process 9040
2016-04-29 06:05:40
Full thread dump Java HotSpot(TM) 64-Bit Server VM
(9-internal+0-2016-04-29-004440.sspitsyn.jdk9.2 mixed mode):
"Attach Listener" #22 daemon prio=9 os_prio=0 tid=0x00007f6d80001000 nid=0x339a
runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
JavaThread state: _thread_blocked
Thread: 0x00007f6d80001000 [0x339a] State: _call_back _has_called_back 1
_at_poll_safepoint 0
JavaThread state: _thread_blocked
"Thread-1" #21 daemon prio=5 os_prio=0 tid=0x00007f6d60150800 nid=0x2404 in
Object.wait() [0x00007f6d5bdfc000]
java.lang.Thread.State: WAITING (on object monitor)
JavaThread state: _thread_blocked
Thread: 0x00007f6d60150800 [0x2404] State: _at_safepoint _has_called_back 0
_at_poll_safepoint 0
JavaThread state: _thread_blocked
at java.lang.Object.wait(java.base@9-internal/Native Method)
- waiting on <0x00000006d48042c0> (a com.sun.tools.jdi.EventQueueImpl)
at java.lang.Object.wait(java.base@9-internal/Object.java:516)
at
com.sun.tools.jdi.EventQueueImpl.removeUnfiltered(jdk.jdi@9-internal/EventQueueImpl.java:189)
- waiting to re-lock in wait() <0x00000006d48042c0> (a
com.sun.tools.jdi.EventQueueImpl)
at
com.sun.tools.jdi.EventQueueImpl.remove(jdk.jdi@9-internal/EventQueueImpl.java:96)
at
com.sun.tools.jdi.EventQueueImpl.remove(jdk.jdi@9-internal/EventQueueImpl.java:82)
at TestScaffold$EventHandler.run(TestScaffold.java:252)
at java.lang.Thread.run(java.base@9-internal/Thread.java:843)
"output reader" #20 prio=9 os_prio=0 tid=0x00007f6d60142000 nid=0x2403 runnable
[0x00007f6d5befc000]
java.lang.Thread.State: RUNNABLE
JavaThread state: _thread_in_native
Thread: 0x00007f6d60142000 [0x2403] State: _at_safepoint _has_called_back 0
_at_poll_safepoint 0
JavaThread state: _thread_in_native
at java.io.FileInputStream.readBytes(java.base@9-internal/Native Method)
at
java.io.FileInputStream.read(java.base@9-internal/FileInputStream.java:255)
at
java.io.BufferedInputStream.read1(java.base@9-internal/BufferedInputStream.java:284)
at
java.io.BufferedInputStream.read(java.base@9-internal/BufferedInputStream.java:345)
- locked <0x00000006d496e5c8> (a
java.lang.ProcessImpl$ProcessPipeInputStream)
at
sun.nio.cs.StreamDecoder.readBytes(java.base@9-internal/StreamDecoder.java:284)
at
sun.nio.cs.StreamDecoder.implRead(java.base@9-internal/StreamDecoder.java:326)
at
sun.nio.cs.StreamDecoder.read(java.base@9-internal/StreamDecoder.java:178)
- locked <0x00000006d48f64d0> (a java.io.InputStreamReader)
at
java.io.InputStreamReader.read(java.base@9-internal/InputStreamReader.java:185)
at
java.io.BufferedReader.fill(java.base@9-internal/BufferedReader.java:161)
at
java.io.BufferedReader.readLine(java.base@9-internal/BufferedReader.java:325)
- locked <0x00000006d48f64d0> (a java.io.InputStreamReader)
at
java.io.BufferedReader.readLine(java.base@9-internal/BufferedReader.java:390)
at VMConnection.dumpStream(VMConnection.java:254)
at VMConnection.access$000(VMConnection.java:35)
at VMConnection$1.run(VMConnection.java:287)
"output reader" #19 prio=9 os_prio=0 tid=0x00007f6d60140000 nid=0x2402 runnable
[0x00007f6d9410f000]
java.lang.Thread.State: RUNNABLE
JavaThread state: _thread_in_native
Thread: 0x00007f6d60140000 [0x2402] State: _at_safepoint _has_called_back 0
_at_poll_safepoint 0
JavaThread state: _thread_in_native
at java.io.FileInputStream.readBytes(java.base@9-internal/Native Method)
at
java.io.FileInputStream.read(java.base@9-internal/FileInputStream.java:255)
at
java.io.BufferedInputStream.read1(java.base@9-internal/BufferedInputStream.java:284)
at
java.io.BufferedInputStream.read(java.base@9-internal/BufferedInputStream.java:345)
- locked <0x00000006d4970688> (a
java.lang.ProcessImpl$ProcessPipeInputStream)
at
sun.nio.cs.StreamDecoder.readBytes(java.base@9-internal/StreamDecoder.java:284)
at
sun.nio.cs.StreamDecoder.implRead(java.base@9-internal/StreamDecoder.java:326)
at
sun.nio.cs.StreamDecoder.read(java.base@9-internal/StreamDecoder.java:178)
- locked <0x00000006d48b8f88> (a java.io.InputStreamReader)
at
java.io.InputStreamReader.read(java.base@9-internal/InputStreamReader.java:185)
at
java.io.BufferedReader.fill(java.base@9-internal/BufferedReader.java:161)
at
java.io.BufferedReader.readLine(java.base@9-internal/BufferedReader.java:325)
- locked <0x00000006d48b8f88> (a java.io.InputStreamReader)
at
java.io.BufferedReader.readLine(java.base@9-internal/BufferedReader.java:390)
at VMConnection.dumpStream(VMConnection.java:254)
at VMConnection.access$000(VMConnection.java:35)
at VMConnection$1.run(VMConnection.java:287)
"JDI Target VM Interface" #17 daemon prio=5 os_prio=0 tid=0x00007f6d60138800
nid=0x2400 runnable [0x00007f6d5bffe000]
java.lang.Thread.State: RUNNABLE
JavaThread state: _thread_in_native
Thread: 0x00007f6d60138800 [0x2400] State: _at_safepoint _has_called_back 0
_at_poll_safepoint 0
JavaThread state: _thread_in_native
at java.net.SocketInputStream.socketRead0(java.base@9-internal/Native
Method)
at
java.net.SocketInputStream.socketRead(java.base@9-internal/SocketInputStream.java:116)
at
java.net.SocketInputStream.read(java.base@9-internal/SocketInputStream.java:170)
at
java.net.SocketInputStream.read(java.base@9-internal/SocketInputStream.java:141)
at
java.net.SocketInputStream.read(java.base@9-internal/SocketInputStream.java:223)
at
com.sun.tools.jdi.SocketConnection.readPacket(jdk.jdi@9-internal/SocketTransportService.java:414)
- locked <0x00000006d49ba8c0> (a java.lang.Object)
at com.sun.tools.jdi.TargetVM.run(jdk.jdi@9-internal/TargetVM.java:118)
at java.lang.Thread.run(java.base@9-internal/Thread.java:843)
"JDI Internal Event Handler" #18 daemon prio=5 os_prio=0 tid=0x00007f6d60133000
nid=0x23fa in Object.wait() [0x00007f6d94211000]
java.lang.Thread.State: WAITING (on object monitor)
JavaThread state: _thread_blocked
Thread: 0x00007f6d60133000 [0x23fa] State: _at_safepoint _has_called_back 0
_at_poll_safepoint 0
JavaThread state: _thread_blocked
at java.lang.Object.wait(java.base@9-internal/Native Method)
- waiting on <0x00000006d4801290> (a com.sun.tools.jdi.EventQueueImpl)
at java.lang.Object.wait(java.base@9-internal/Object.java:516)
at
com.sun.tools.jdi.EventQueueImpl.removeUnfiltered(jdk.jdi@9-internal/EventQueueImpl.java:189)
- waiting to re-lock in wait() <0x00000006d4801290> (a
com.sun.tools.jdi.EventQueueImpl)
at
com.sun.tools.jdi.EventQueueImpl.removeInternal(jdk.jdi@9-internal/EventQueueImpl.java:124)
at
com.sun.tools.jdi.InternalEventHandler.run(jdk.jdi@9-internal/InternalEventHandler.java:54)
at java.lang.Thread.run(java.base@9-internal/Thread.java:843)
"process reaper" #14 daemon prio=10 os_prio=0 tid=0x00007f6d600e9800 nid=0x23ba
runnable [0x00007f6de404f000]
java.lang.Thread.State: RUNNABLE
JavaThread state: _thread_in_native
Thread: 0x00007f6d600e9800 [0x23ba] State: _at_safepoint _has_called_back 0
_at_poll_safepoint 0
JavaThread state: _thread_in_native
at
java.lang.ProcessHandleImpl.waitForProcessExit0(java.base@9-internal/Native
Method)
at
java.lang.ProcessHandleImpl.lambda$completion$2(java.base@9-internal/ProcessHandleImpl.java:133)
at
java.lang.ProcessHandleImpl$$Lambda$15/2007848456.run(java.base@9-internal/Unknown
Source)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@9-internal/ThreadPoolExecutor.java:1158)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@9-internal/ThreadPoolExecutor.java:632)
at java.lang.Thread.run(java.base@9-internal/Thread.java:843)
"MainThread" #13 prio=5 os_prio=0 tid=0x00007f6de0490000 nid=0x238e in
Object.wait() [0x00007f6d94310000]
java.lang.Thread.State: WAITING (on object monitor)
JavaThread state: _thread_blocked
Thread: 0x00007f6de0490000 [0x238e] State: _at_safepoint _has_called_back 0
_at_poll_safepoint 0
JavaThread state: _thread_blocked
at java.lang.Object.wait(java.base@9-internal/Native Method)
- waiting on <no object reference available>
at java.lang.Object.wait(java.base@9-internal/Object.java:516)
at
com.sun.tools.jdi.TargetVM.waitForReply(jdk.jdi@9-internal/TargetVM.java:300)
- waiting to re-lock in wait() <0x00000006d478d620> (a
com.sun.tools.jdi.Packet)
at
com.sun.tools.jdi.VirtualMachineImpl.waitForTargetReply(jdk.jdi@9-internal/VirtualMachineImpl.java:1088)
at
com.sun.tools.jdi.PacketStream.waitForReply(jdk.jdi@9-internal/PacketStream.java:69)
at
com.sun.tools.jdi.JDWP$ArrayType$NewInstance.waitForReply(jdk.jdi@9-internal/JDWP.java:3680)
at
com.sun.tools.jdi.JDWP$ArrayType$NewInstance.process(jdk.jdi@9-internal/JDWP.java:3656)
at
com.sun.tools.jdi.ArrayTypeImpl.newInstance(jdk.jdi@9-internal/ArrayTypeImpl.java:46)
at OomDebugTest.test2(OomDebugTest.java:207)
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:531)
at OomDebugTest.runTests(OomDebugTest.java:150)
at TestScaffold.startTests(TestScaffold.java:431)
at OomDebugTest.main(OomDebugTest.java:390)
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:531)
at
com.sun.javatest.regtest.agent.MainWrapper$MainThread.run(MainWrapper.java:110)
at java.lang.Thread.run(java.base@9-internal/Thread.java:843)
"Service Thread" #11 daemon prio=9 os_prio=0 tid=0x00007f6de0458800 nid=0x236c
runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
JavaThread state: _thread_blocked
Thread: 0x00007f6de0458800 [0x236c] State: _at_safepoint _has_called_back 0
_at_poll_safepoint 0
JavaThread state: _thread_blocked
"Common-Cleaner" #10 daemon prio=8 os_prio=0 tid=0x00007f6de033b800 nid=0x236b
in Object.wait() [0x00007f6d94615000]
java.lang.Thread.State: TIMED_WAITING (on object monitor)
JavaThread state: _thread_blocked
Thread: 0x00007f6de033b800 [0x236b] State: _at_safepoint _has_called_back 0
_at_poll_safepoint 0
JavaThread state: _thread_blocked
at java.lang.Object.wait(java.base@9-internal/Native Method)
- waiting on <no object reference available>
at
java.lang.ref.ReferenceQueue.remove(java.base@9-internal/ReferenceQueue.java:151)
- waiting to re-lock in wait() <0x00000006d4d3a870> (a
java.lang.ref.ReferenceQueue$Lock)
at
jdk.internal.ref.CleanerImpl.run(java.base@9-internal/CleanerImpl.java:148)
at java.lang.Thread.run(java.base@9-internal/Thread.java:843)
at
jdk.internal.misc.InnocuousThread.run(java.base@9-internal/InnocuousThread.java:122)
"Sweeper thread" #9 daemon prio=9 os_prio=0 tid=0x00007f6de02e1800 nid=0x2369
runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
JavaThread state: _thread_blocked
Thread: 0x00007f6de02e1800 [0x2369] State: _at_safepoint _has_called_back 0
_at_poll_safepoint 0
JavaThread state: _thread_blocked
"C1 CompilerThread2" #8 daemon prio=9 os_prio=0 tid=0x00007f6de02df000
nid=0x2368 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
JavaThread state: _thread_blocked
Thread: 0x00007f6de02df000 [0x2368] State: _at_safepoint _has_called_back 0
_at_poll_safepoint 0
JavaThread state: _thread_blocked
No compile task
"C2 CompilerThread1" #7 daemon prio=9 os_prio=0 tid=0x00007f6de02dc800
nid=0x2367 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
JavaThread state: _thread_blocked
Thread: 0x00007f6de02dc800 [0x2367] State: _at_safepoint _has_called_back 0
_at_poll_safepoint 0
JavaThread state: _thread_blocked
No compile task
"C2 CompilerThread0" #6 daemon prio=9 os_prio=0 tid=0x00007f6de02da000
nid=0x2366 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
JavaThread state: _thread_blocked
Thread: 0x00007f6de02da000 [0x2366] State: _at_safepoint _has_called_back 0
_at_poll_safepoint 0
JavaThread state: _thread_blocked
No compile task
"Signal Dispatcher" #5 daemon prio=9 os_prio=0 tid=0x00007f6de02d7800
nid=0x2365 runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
JavaThread state: _thread_blocked
Thread: 0x00007f6de02d7800 [0x2365] State: _at_safepoint _has_called_back 0
_at_poll_safepoint 0
JavaThread state: _thread_blocked
"Reference Pending List Locker" #4 daemon prio=9 os_prio=0
tid=0x00007f6de02d5800 nid=0x2364 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
JavaThread state: _thread_blocked
Thread: 0x00007f6de02d5800 [0x2364] State: _at_safepoint _has_called_back 0
_at_poll_safepoint 0
JavaThread state: _thread_blocked
"Finalizer" #3 daemon prio=8 os_prio=0 tid=0x00007f6de02af800 nid=0x2363 in
Object.wait() [0x00007f6d956fd000]
java.lang.Thread.State: WAITING (on object monitor)
JavaThread state: _thread_blocked
Thread: 0x00007f6de02af800 [0x2363] State: _at_safepoint _has_called_back 0
_at_poll_safepoint 0
JavaThread state: _thread_blocked
at java.lang.Object.wait(java.base@9-internal/Native Method)
- waiting on <0x00000006d4d09548> (a java.lang.ref.ReferenceQueue$Lock)
at
java.lang.ref.ReferenceQueue.remove(java.base@9-internal/ReferenceQueue.java:151)
- waiting to re-lock in wait() <0x00000006d4d09548> (a
java.lang.ref.ReferenceQueue$Lock)
at
java.lang.ref.ReferenceQueue.remove(java.base@9-internal/ReferenceQueue.java:172)
at
java.lang.ref.Finalizer$FinalizerThread.run(java.base@9-internal/Finalizer.java:216)
"Reference Handler" #2 daemon prio=10 os_prio=0 tid=0x00007f6de02ad800
nid=0x2362 in Object.wait() [0x00007f6d957fe000]
java.lang.Thread.State: WAITING (on object monitor)
JavaThread state: _thread_blocked
Thread: 0x00007f6de02ad800 [0x2362] State: _at_safepoint _has_called_back 0
_at_poll_safepoint 0
JavaThread state: _thread_blocked
at java.lang.Object.wait(java.base@9-internal/Native Method)
- waiting on <0x00000006d4d08c90> (a java.lang.ref.Reference$Lock)
at java.lang.Object.wait(java.base@9-internal/Object.java:516)
at
java.lang.ref.Reference.tryHandlePending(java.base@9-internal/Reference.java:193)
- waiting to re-lock in wait() <0x00000006d4d08c90> (a
java.lang.ref.Reference$Lock)
at
java.lang.ref.Reference$ReferenceHandler.run(java.base@9-internal/Reference.java:155)
"main" #1 prio=5 os_prio=0 tid=0x00007f6de001a000 nid=0x2353 in Object.wait()
[0x00007f6deabfd000]
java.lang.Thread.State: WAITING (on object monitor)
JavaThread state: _thread_blocked
Thread: 0x00007f6de001a000 [0x2353] State: _at_safepoint _has_called_back 0
_at_poll_safepoint 0
JavaThread state: _thread_blocked
at java.lang.Object.wait(java.base@9-internal/Native Method)
- waiting on <0x00000006d4b86768> (a java.lang.Thread)
at java.lang.Thread.join(java.base@9-internal/Thread.java:1352)
- waiting to re-lock in wait() <0x00000006d4b86768> (a java.lang.Thread)
at java.lang.Thread.join(java.base@9-internal/Thread.java:1426)
at com.sun.javatest.regtest.agent.MainWrapper.main(MainWrapper.java:74)
"VM Thread" os_prio=0 tid=0x00007f6de0299000 nid=0x2361 runnable
"GC Thread#0" os_prio=0 tid=0x00007f6de0037800 nid=0x2354 runnable
"GC Thread#1" os_prio=0 tid=0x00007f6de0039800 nid=0x2355 runnable
"GC Thread#2" os_prio=0 tid=0x00007f6de003b800 nid=0x2356 runnable
"GC Thread#3" os_prio=0 tid=0x00007f6de003d800 nid=0x2357 runnable
"G1 Main Marker" os_prio=0 tid=0x00007f6de008a800 nid=0x235d runnable
"G1 Marker#0" os_prio=0 tid=0x00007f6de008c800 nid=0x235e runnable
"G1 Refine#0" os_prio=0 tid=0x00007f6de0046000 nid=0x235b runnable
"G1 Refine#1" os_prio=0 tid=0x00007f6de0044000 nid=0x235a runnable
"G1 Refine#2" os_prio=0 tid=0x00007f6de0042000 nid=0x2359 runnable
"G1 Refine#3" os_prio=0 tid=0x00007f6de0040000 nid=0x2358 runnable
"G1 Young RemSet Sampling" os_prio=0 tid=0x00007f6de0048000 nid=0x235c runnable
"VM Periodic Task Thread" os_prio=0 tid=0x00007f6de045c000 nid=0x236e waiting
on condition
JNI global references: 337
--- Timeout information end.
elapsed time (seconds): 121.066
----------configuration:(0/0)----------
----------System.out:(24/1088)----------
vmOpts: '-Xmx40m'
javaOpts: ''
JVM version:9-internal
JDI version: 9.0
JVM description: Java Debug Interface (Reference Implementation) version 9.0
Java Debug Wire Protocol (Reference Implementation) version 9.0
JVM Debug Interface version 9.0
JVM version 9-internal (Java HotSpot(TM) 64-Bit Server VM, mixed mode, sharing)
DEBUG: OomDebugTestTarget.main
DEBUG: invoked constructor
DEBUG: ------------> Running test2
DEBUG: invoked 'void testPrimitive(byte[])', foo == [B@327471b5
DEBUG: Done invoking method via debugger.
DEBUG: invoked 'void testPrimitive(byte[])', foo == [B@4157f54e
DEBUG: Done invoking method via debugger.
DEBUG: invoked 'void testPrimitive(byte[])', foo == [B@90f6bfd
DEBUG: Done invoking method via debugger.
DEBUG: invoked 'void testPrimitive(byte[])', foo == [B@47f6473
DEBUG: Done invoking method via debugger.
DEBUG: invoked 'void testPrimitive(byte[])', foo == [B@15975490
DEBUG: Done invoking method via debugger.
DEBUG: invoked 'void testPrimitive(byte[])', foo == [B@6b143ee9
DEBUG: Done invoking method via debugger.
Timeout signalled after 120 seconds
----------System.err:(1/65)----------
[10ms] run args: [OomDebugTestTarget, test2, OomDebugTestTarget]
----------rerun:(19/1589)*----------
DISPLAY=localhost:13.0 \\
HOME=/home/sspitsyn \\
JTREG_HOME=/java/re/jtreg/4.2/promoted/latest/binaries/jtreg \\
LANG=en_US.UTF-8 \\
PATH=/bin:/usr/bin \\
CLASSPATH=/var/tmp/sspitsyn/tst/jdk9.2/JTwork/classes/com/sun/jdi:/var/tmp/sspitsyn/jdk9.2/jdk/test/com/sun/jdi:/var/tmp/sspitsyn/tst/jdk9.2/JTwork/classes/com/sun:/var/tmp/sspitsyn/jdk9.2/jdk/test/com/sun:/net/scanas416.us.oracle.com/export/java_re2/misc/promoted/jtreg/4.2/fcs/b02/binaries/jtreg/lib/javatest.jar:/net/scanas416.us.oracle.com/export/java_re2/misc/promoted/jtreg/4.2/fcs/b02/binaries/jtreg/lib/jtreg.jar
\\
/var/tmp/sspitsyn/jdk9.2/build/linux-x86_64-normal-server-fastdebug/images/jdk/bin/java
\\
-Dtest.src=/var/tmp/sspitsyn/jdk9.2/jdk/test/com/sun/jdi \\
-Dtest.src.path=/var/tmp/sspitsyn/jdk9.2/jdk/test/com/sun/jdi:/var/tmp/sspitsyn/jdk9.2/jdk/test/com/sun
\\
-Dtest.classes=/var/tmp/sspitsyn/tst/jdk9.2/JTwork/classes/com/sun/jdi
\\
-Dtest.class.path=/var/tmp/sspitsyn/tst/jdk9.2/JTwork/classes/com/sun/jdi:/var/tmp/sspitsyn/tst/jdk9.2/JTwork/classes/com/sun
\\
-Dtest.vm.opts= \\
-Dtest.tool.vm.opts= \\
-Dtest.compiler.opts= \\
-Dtest.java.opts= \\
-Dtest.jdk=/var/tmp/sspitsyn/jdk9.2/build/linux-x86_64-normal-server-fastdebug/images/jdk
\\
-Dcompile.jdk=/var/tmp/sspitsyn/jdk9.2/build/linux-x86_64-normal-server-fastdebug/images/jdk
\\
-Dtest.timeout.factor=1.0 \\
com.sun.javatest.regtest.agent.MainWrapper
/var/tmp/sspitsyn/tst/jdk9.2/JTwork/com/sun/jdi/OomDebugTest.d/main.1.jta
OomDebugTestTarget test2
result: Error. Program
`/var/tmp/sspitsyn/jdk9.2/build/linux-x86_64-normal-server-fastdebug/images/jdk/bin/java'
timed out (timeout set to 120000ms, elapsed time was 121059ms).
test result: Error. Program
`/var/tmp/sspitsyn/jdk9.2/build/linux-x86_64-normal-server-fastdebug/images/jdk/bin/java'
timed out (timeout set to 120000ms, elapsed time was 121059ms).
