RFR(s) 8153711: [REDO] JDWP: Memory Leak: GlobalRefs never deleted when processing invokeMethod command
serguei.spitsyn at oracle.com
serguei.spitsyn at oracle.com
Fri Apr 29 19:33:40 UTC 2016
On 4/29/16 01:56, Severin Gehwolf wrote:
> Hi Serguei,
>
> On Fri, 2016-04-29 at 01:34 -0700, serguei.spitsyn at 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.spitsyn at 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
>>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://mail.openjdk.java.net/pipermail/serviceability-dev/attachments/20160429/02184e3d/attachment-0001.html>
-------------- next part --------------
#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 <sgehwolf at 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 at 327471b5
DEBUG: Done invoking method via debugger.
DEBUG: invoked 'void testMethod(FooCls)', foo == OomDebugTestTarget$FooCls at 4157f54e
DEBUG: Done invoking method via debugger.
DEBUG: invoked 'void testMethod(FooCls)', foo == OomDebugTestTarget$FooCls at 90f6bfd
DEBUG: Done invoking method via debugger.
DEBUG: invoked 'void testMethod(FooCls)', foo == OomDebugTestTarget$FooCls at 47f6473
DEBUG: Done invoking method via debugger.
DEBUG: invoked 'void testMethod(FooCls)', foo == OomDebugTestTarget$FooCls at 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 at 6b143ee9
DEBUG: invoked 'void testMethod(FooCls)', foo == OomDebugTestTarget$FooCls at 1936f0f5
DEBUG: Done invoking method via debugger.
DEBUG: invoked 'void testMethod(FooCls)', foo == OomDebugTestTarget$FooCls at 6615435c
DEBUG: Done invoking method via debugger.
DEBUG: invoked 'void testMethod(FooCls)', foo == OomDebugTestTarget$FooCls at 4909b8da
DEBUG: Done invoking method via debugger.
DEBUG: invoked 'void testMethod(FooCls)', foo == OomDebugTestTarget$FooCls at 3a03464
DEBUG: invoked 'void testMethod(FooCls)', foo == OomDebugTestTarget$FooCls at 2d3fcdbd
DEBUG: Done invoking method via debugger.
DEBUG: invoked 'void testMethod(FooCls)', foo == OomDebugTestTarget$FooCls at 617c74e5
DEBUG: Done invoking method via debugger.
DEBUG: invoked 'void testMethod(FooCls)', foo == OomDebugTestTarget$FooCls at 6537cf78
DEBUG: Done invoking method via debugger.
DEBUG: invoked 'void testMethod(FooCls)', foo == OomDebugTestTarget$FooCls at 67b6d4ae
DEBUG: Done invoking method via debugger.
DEBUG: invoked 'void testMethod(FooCls)', foo == OomDebugTestTarget$FooCls at 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 at 9-internal/Native Method)
- waiting on <0x00000006d48042c0> (a com.sun.tools.jdi.EventQueueImpl)
at java.lang.Object.wait(java.base at 9-internal/Object.java:516)
at com.sun.tools.jdi.EventQueueImpl.removeUnfiltered(jdk.jdi at 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 at 9-internal/EventQueueImpl.java:96)
at com.sun.tools.jdi.EventQueueImpl.remove(jdk.jdi at 9-internal/EventQueueImpl.java:82)
at TestScaffold$EventHandler.run(TestScaffold.java:252)
at java.lang.Thread.run(java.base at 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 at 9-internal/Native Method)
at java.io.FileInputStream.read(java.base at 9-internal/FileInputStream.java:255)
at java.io.BufferedInputStream.read1(java.base at 9-internal/BufferedInputStream.java:284)
at java.io.BufferedInputStream.read(java.base at 9-internal/BufferedInputStream.java:345)
- locked <0x00000006d496e5c8> (a java.lang.ProcessImpl$ProcessPipeInputStream)
at sun.nio.cs.StreamDecoder.readBytes(java.base at 9-internal/StreamDecoder.java:284)
at sun.nio.cs.StreamDecoder.implRead(java.base at 9-internal/StreamDecoder.java:326)
at sun.nio.cs.StreamDecoder.read(java.base at 9-internal/StreamDecoder.java:178)
- locked <0x00000006d48f64d0> (a java.io.InputStreamReader)
at java.io.InputStreamReader.read(java.base at 9-internal/InputStreamReader.java:185)
at java.io.BufferedReader.fill(java.base at 9-internal/BufferedReader.java:161)
at java.io.BufferedReader.readLine(java.base at 9-internal/BufferedReader.java:325)
- locked <0x00000006d48f64d0> (a java.io.InputStreamReader)
at java.io.BufferedReader.readLine(java.base at 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 at 9-internal/Native Method)
at java.io.FileInputStream.read(java.base at 9-internal/FileInputStream.java:255)
at java.io.BufferedInputStream.read1(java.base at 9-internal/BufferedInputStream.java:284)
at java.io.BufferedInputStream.read(java.base at 9-internal/BufferedInputStream.java:345)
- locked <0x00000006d4970688> (a java.lang.ProcessImpl$ProcessPipeInputStream)
at sun.nio.cs.StreamDecoder.readBytes(java.base at 9-internal/StreamDecoder.java:284)
at sun.nio.cs.StreamDecoder.implRead(java.base at 9-internal/StreamDecoder.java:326)
at sun.nio.cs.StreamDecoder.read(java.base at 9-internal/StreamDecoder.java:178)
- locked <0x00000006d48b8f88> (a java.io.InputStreamReader)
at java.io.InputStreamReader.read(java.base at 9-internal/InputStreamReader.java:185)
at java.io.BufferedReader.fill(java.base at 9-internal/BufferedReader.java:161)
at java.io.BufferedReader.readLine(java.base at 9-internal/BufferedReader.java:325)
- locked <0x00000006d48b8f88> (a java.io.InputStreamReader)
at java.io.BufferedReader.readLine(java.base at 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 at 9-internal/Native Method)
at java.net.SocketInputStream.socketRead(java.base at 9-internal/SocketInputStream.java:116)
at java.net.SocketInputStream.read(java.base at 9-internal/SocketInputStream.java:170)
at java.net.SocketInputStream.read(java.base at 9-internal/SocketInputStream.java:141)
at java.net.SocketInputStream.read(java.base at 9-internal/SocketInputStream.java:223)
at com.sun.tools.jdi.SocketConnection.readPacket(jdk.jdi at 9-internal/SocketTransportService.java:414)
- locked <0x00000006d49ba8c0> (a java.lang.Object)
at com.sun.tools.jdi.TargetVM.run(jdk.jdi at 9-internal/TargetVM.java:118)
at java.lang.Thread.run(java.base at 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 at 9-internal/Native Method)
- waiting on <0x00000006d4801290> (a com.sun.tools.jdi.EventQueueImpl)
at java.lang.Object.wait(java.base at 9-internal/Object.java:516)
at com.sun.tools.jdi.EventQueueImpl.removeUnfiltered(jdk.jdi at 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 at 9-internal/EventQueueImpl.java:124)
at com.sun.tools.jdi.InternalEventHandler.run(jdk.jdi at 9-internal/InternalEventHandler.java:54)
at java.lang.Thread.run(java.base at 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 at 9-internal/Native Method)
at java.lang.ProcessHandleImpl.lambda$completion$2(java.base at 9-internal/ProcessHandleImpl.java:133)
at java.lang.ProcessHandleImpl$$Lambda$15/2007848456.run(java.base at 9-internal/Unknown Source)
at java.util.concurrent.ThreadPoolExecutor.runWorker(java.base at 9-internal/ThreadPoolExecutor.java:1158)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base at 9-internal/ThreadPoolExecutor.java:632)
at java.lang.Thread.run(java.base at 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 at 9-internal/Native Method)
- waiting on <no object reference available>
at java.lang.Object.wait(java.base at 9-internal/Object.java:516)
at com.sun.tools.jdi.TargetVM.waitForReply(jdk.jdi at 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 at 9-internal/VirtualMachineImpl.java:1088)
at com.sun.tools.jdi.PacketStream.waitForReply(jdk.jdi at 9-internal/PacketStream.java:69)
at com.sun.tools.jdi.JDWP$ArrayType$NewInstance.waitForReply(jdk.jdi at 9-internal/JDWP.java:3680)
at com.sun.tools.jdi.JDWP$ArrayType$NewInstance.process(jdk.jdi at 9-internal/JDWP.java:3656)
at com.sun.tools.jdi.ArrayTypeImpl.newInstance(jdk.jdi at 9-internal/ArrayTypeImpl.java:46)
at OomDebugTest.test2(OomDebugTest.java:207)
at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(java.base at 9-internal/Native Method)
at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(java.base at 9-internal/NativeMethodAccessorImpl.java:62)
at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(java.base at 9-internal/DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(java.base at 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 at 9-internal/Native Method)
at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(java.base at 9-internal/NativeMethodAccessorImpl.java:62)
at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(java.base at 9-internal/DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(java.base at 9-internal/Method.java:531)
at com.sun.javatest.regtest.agent.MainWrapper$MainThread.run(MainWrapper.java:110)
at java.lang.Thread.run(java.base at 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 at 9-internal/Native Method)
- waiting on <no object reference available>
at java.lang.ref.ReferenceQueue.remove(java.base at 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 at 9-internal/CleanerImpl.java:148)
at java.lang.Thread.run(java.base at 9-internal/Thread.java:843)
at jdk.internal.misc.InnocuousThread.run(java.base at 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 at 9-internal/Native Method)
- waiting on <0x00000006d4d09548> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(java.base at 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 at 9-internal/ReferenceQueue.java:172)
at java.lang.ref.Finalizer$FinalizerThread.run(java.base at 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 at 9-internal/Native Method)
- waiting on <0x00000006d4d08c90> (a java.lang.ref.Reference$Lock)
at java.lang.Object.wait(java.base at 9-internal/Object.java:516)
at java.lang.ref.Reference.tryHandlePending(java.base at 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 at 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 at 9-internal/Native Method)
- waiting on <0x00000006d4b86768> (a java.lang.Thread)
at java.lang.Thread.join(java.base at 9-internal/Thread.java:1352)
- waiting to re-lock in wait() <0x00000006d4b86768> (a java.lang.Thread)
at java.lang.Thread.join(java.base at 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 at 327471b5
DEBUG: Done invoking method via debugger.
DEBUG: invoked 'void testPrimitive(byte[])', foo == [B at 4157f54e
DEBUG: Done invoking method via debugger.
DEBUG: invoked 'void testPrimitive(byte[])', foo == [B at 90f6bfd
DEBUG: Done invoking method via debugger.
DEBUG: invoked 'void testPrimitive(byte[])', foo == [B at 47f6473
DEBUG: Done invoking method via debugger.
DEBUG: invoked 'void testPrimitive(byte[])', foo == [B at 15975490
DEBUG: Done invoking method via debugger.
DEBUG: invoked 'void testPrimitive(byte[])', foo == [B at 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).
More information about the serviceability-dev
mailing list