java/lang/ref/FinalizeOverride timeout #9651

pshipton · 2020-05-22T12:43:21Z

https://ci.eclipse.org/openj9/job/Test_openjdk11_j9_sanity.openjdk_ppc64le_linux_Nightly/61
java/lang/ref/FinalizeOverride.java

00:41:03  ACTION: main -- Error. Agent error: java.lang.Exception: Agent 35 timed out with a timeout of 960 seconds; check console log for any additional details
00:41:03  REASON: Assumed action based on file name: run main FinalizeOverride 
00:41:03  TIME:   962.632 seconds
00:41:03  messages:
00:41:03  command: main FinalizeOverride
00:41:03  reason: Assumed action based on file name: run main FinalizeOverride 
00:41:03  Mode: agentvm
00:41:03  Agent id: 35
00:41:03  Timeout refired 960 times
00:41:03  Timeout information:
00:41:03  Running jstack on process 31842
00:41:03  2020-05-22T01:39:09.394211345
00:41:03  Virtual machine: 31842 JVM information:
00:41:03  JRE 11 Linux ppc64le-64-Bit Compressed References 20200521_395 (JIT enabled, AOT enabled)
00:41:03  OpenJ9   - 561026fca
00:41:03  OMR      - 00689235c
00:41:03  JCL      - cfce36dfff5 based on jdk-11.0.8+3
00:41:03  
00:41:03  "main" prio=5 Id=1 WAITING
00:41:03  	at java.base@11.0.8-internal/java.lang.Object.wait(Native Method)
00:41:03  	at java.base@11.0.8-internal/java.lang.Object.wait(Object.java:221)
00:41:03  	at java.base@11.0.8-internal/java.lang.Thread.join(Thread.java:716)
00:41:03  	- locked java.lang.Thread@4043657b
00:41:03  	at app//com.sun.javatest.regtest.agent.MainActionHelper.runClass(MainActionHelper.java:184)
00:41:03  	at app//com.sun.javatest.regtest.agent.AgentServer.doMain(AgentServer.java:301)
00:41:03  	at app//com.sun.javatest.regtest.agent.AgentServer.run(AgentServer.java:232)
00:41:03  	at app//com.sun.javatest.regtest.agent.AgentServer.main(AgentServer.java:69)
00:41:03  
00:41:03  "JIT Compilation Thread-000" prio=10 Id=3 RUNNABLE
00:41:03  
00:41:03  "JIT Compilation Thread-001 Suspended" prio=10 Id=4 RUNNABLE
00:41:03  
00:41:03  "JIT Compilation Thread-002 Suspended" prio=10 Id=5 RUNNABLE
00:41:03  
00:41:03  "JIT Compilation Thread-003 Suspended" prio=10 Id=6 RUNNABLE
00:41:03  
00:41:03  "JIT Compilation Thread-004 Suspended" prio=10 Id=7 RUNNABLE
00:41:03  
00:41:03  "JIT Compilation Thread-005 Suspended" prio=10 Id=8 RUNNABLE
00:41:03  
00:41:03  "JIT Compilation Thread-006 Suspended" prio=10 Id=9 RUNNABLE
00:41:03  
00:41:03  "JIT Diagnostic Compilation Thread-007 Suspended" prio=10 Id=10 RUNNABLE
00:41:03  
00:41:03  "JIT-SamplerThread" prio=10 Id=11 TIMED_WAITING
00:41:03  
00:41:03  "IProfiler" prio=5 Id=12 RUNNABLE
00:41:03  
00:41:03  "Common-Cleaner" prio=8 Id=2 TIMED_WAITING
00:41:03  	at java.base@11.0.8-internal/java.lang.Object.wait(Native Method)
00:41:03  	at java.base@11.0.8-internal/java.lang.Object.wait(Object.java:221)
00:41:03  	at java.base@11.0.8-internal/java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:138)
00:41:03  	- locked java.lang.ref.ReferenceQueue@e8d74150
00:41:03  	at java.base@11.0.8-internal/jdk.internal.ref.CleanerImpl.run(CleanerImpl.java:148)
00:41:03  	at java.base@11.0.8-internal/java.lang.Thread.run(Thread.java:836)
00:41:03  	at java.base@11.0.8-internal/jdk.internal.misc.InnocuousThread.run(InnocuousThread.java:134)
00:41:03  
00:41:03  "Concurrent Mark Helper" prio=1 Id=13 RUNNABLE
00:41:03  
00:41:03  "Finalizer thread" prio=5 Id=14 RUNNABLE
00:41:03  
00:41:03  "GC Slave" prio=5 Id=15 RUNNABLE
00:41:03  
00:41:03  "GC Slave" prio=5 Id=16 RUNNABLE
00:41:03  
00:41:03  "GC Slave" prio=5 Id=17 RUNNABLE
00:41:03  
00:41:03  "GC Slave" prio=5 Id=18 RUNNABLE
00:41:03  
00:41:03  "GC Slave" prio=5 Id=19 RUNNABLE
00:41:03  
00:41:03  "GC Slave" prio=5 Id=20 RUNNABLE
00:41:03  
00:41:03  "GC Slave" prio=5 Id=21 RUNNABLE
00:41:03  
00:41:03  "Attach API wait loop" prio=10 Id=24 RUNNABLE
00:41:03  	at java.base@11.0.8-internal/openj9.internal.tools.attach.target.IPC.waitSemaphore(Native Method)
00:41:03  	at java.base@11.0.8-internal/openj9.internal.tools.attach.target.CommonDirectory.waitSemaphore(CommonDirectory.java:259)
00:41:03  	at java.base@11.0.8-internal/openj9.internal.tools.attach.target.WaitLoop.waitForNotification(WaitLoop.java:66)
00:41:03  	at java.base@11.0.8-internal/openj9.internal.tools.attach.target.WaitLoop.run(WaitLoop.java:154)
00:41:03  
00:41:03  "pool-1-thread-1" prio=5 Id=25 TIMED_WAITING
00:41:03  	at java.base@11.0.8-internal/jdk.internal.misc.Unsafe.park(Native Method)
00:41:03  	at java.base@11.0.8-internal/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:234)
00:41:03  	at java.base@11.0.8-internal/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2123)
00:41:03  	at java.base@11.0.8-internal/java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1182)
00:41:03  	at java.base@11.0.8-internal/java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:899)
00:41:03  	at java.base@11.0.8-internal/java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1054)
00:41:03  	at java.base@11.0.8-internal/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1114)
00:41:03  	at java.base@11.0.8-internal/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
00:41:03  	at java.base@11.0.8-internal/java.lang.Thread.run(Thread.java:836)
00:41:03  
00:41:03  "AgentVMThread" prio=5 Id=26 TIMED_WAITING
00:41:03  	at java.base@11.0.8-internal/java.lang.Thread.sleep(Native Method)
00:41:03  	at java.base@11.0.8-internal/java.lang.Thread.sleep(Thread.java:966)
00:41:03  	at app//FinalizeOverride.test(FinalizeOverride.java:75)
00:41:03  	at app//FinalizeOverride.main(FinalizeOverride.java:52)
00:41:03  	at java.base@11.0.8-internal/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
00:41:03  	at java.base@11.0.8-internal/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
00:41:03  	at java.base@11.0.8-internal/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
00:41:03  	at java.base@11.0.8-internal/java.lang.reflect.Method.invoke(Method.java:566)
00:41:03  	at app//com.sun.javatest.regtest.agent.MainActionHelper$AgentVMRunnable.run(MainActionHelper.java:298)
00:41:03  	at java.base@11.0.8-internal/java.lang.Thread.run(Thread.java:836)
00:41:03  
00:41:03  "Attachment 44538" prio=10 Id=27 RUNNABLE
00:41:03  	at java.base@11.0.8-internal/openj9.internal.tools.attach.target.DiagnosticUtils.dumpAllThreadsImpl(Native Method)
00:41:03  	at java.base@11.0.8-internal/openj9.internal.tools.attach.target.DiagnosticUtils.getThreadInfo(DiagnosticUtils.java:233)
00:41:03  	at app//openj9.internal.tools.attach.target.DiagnosticUtils$$Lambda$66/00000000F4005C80.apply(Unknown Source)
00:41:03  	at java.base@11.0.8-internal/openj9.internal.tools.attach.target.DiagnosticUtils.executeDiagnosticCommand(DiagnosticUtils.java:169)
00:41:03  	at java.base@11.0.8-internal/openj9.internal.tools.attach.target.Attachment.doCommand(Attachment.java:249)
00:41:03  	at java.base@11.0.8-internal/openj9.internal.tools.attach.target.Attachment.run(Attachment.java:160)
00:41:03  
00:41:03  "file lock watchdog" prio=10 Id=28 TIMED_WAITING
00:41:03  	at java.base@11.0.8-internal/java.lang.Object.wait(Native Method)
00:41:03  	at java.base@11.0.8-internal/java.lang.Object.wait(Object.java:221)
00:41:03  	at java.base@11.0.8-internal/java.util.TimerThread.mainLoop(Timer.java:553)
00:41:03  	- locked java.util.TaskQueue@793acdc7
00:41:03  	at java.base@11.0.8-internal/java.util.TimerThread.run(Timer.java:506)
00:41:03  
00:41:03  
00:41:03  --- Timeout information end.

The text was updated successfully, but these errors were encountered:

pshipton · 2020-06-01T14:20:03Z

https://ci.eclipse.org/openj9/job/Test_openjdk11_j9_sanity.openjdk_x86-64_linux_cm_Nightly/19
01:33:20 at app//FinalizeOverride.test(FinalizeOverride.java:75)
01:33:20 at app//FinalizeOverride.main(FinalizeOverride.java:52)

https://ci.eclipse.org/openj9/job/Test_openjdk14_j9_sanity.openjdk_ppc64le_linux_Nightly/1
01:02:28 at app//FinalizeOverride.test(FinalizeOverride.java:75)
01:02:28 at app//FinalizeOverride.main(FinalizeOverride.java:51)

pshipton · 2020-06-07T22:05:12Z

https://ci.eclipse.org/openj9/job/Test_openjdk14_j9_sanity.openjdk_x86-64_linux_Nightly/9
01:31:01 at app//FinalizeOverride.test(FinalizeOverride.java:75)
01:31:01 at app//FinalizeOverride.main(FinalizeOverride.java:52)

pshipton · 2020-06-10T14:04:34Z

https://ci.eclipse.org/openj9/job/Test_openjdk11_j9_sanity.openjdk_x86-64_linux_xl_Nightly/58
01:07:06 at app//FinalizeOverride.test(FinalizeOverride.java:75)
01:07:06 at app//FinalizeOverride.main(FinalizeOverride.java:52)

https://ci.eclipse.org/openj9/job/Test_openjdk14_j9_sanity.openjdk_x86-64_linux_Nightly/12
01:54:10 at app//FinalizeOverride.test(FinalizeOverride.java:75)
01:54:10 at app//FinalizeOverride.main(FinalizeOverride.java:51)

pshipton · 2020-06-10T15:06:27Z

Ran a grinder to get a successful result. https://ci.eclipse.org/openj9/job/Grinder/907

Base.finalize() sum += 10
Subclass.finalize() sum += 0
SubSubclass.finalize() sum +=30
PublicFinalize.finalize() sum += 40+40*100
Base.finalize() sum += 50
Base.finalize() sum += 60

pshipton · 2020-06-10T15:11:32Z

@dmitripivkine can you pls take a look.

pshipton · 2020-06-10T17:26:41Z

Unfortunately, although the test contains printlns which might help diagnose the problem, the failure result doesn't show any System.out or System.err output even though System.out would contain some output.

pshipton · 2020-06-10T17:59:33Z

@smlambert @llxia to proceed to diagnose this, we need to capture a core file when the test times out. Do you know how we could do that, or do we have the source to the test harness used to run the openjdk tests that we could modify to send a kill -QUIT signal to the test process? I see the test harness runs jstack on the test atm when a timeout occurs.

llxia · 2020-06-10T18:52:39Z

@sophia-guo do you happen to know anything that could help us diagnose in this case?

smlambert · 2020-06-10T19:48:02Z

References for openjdk regression test harness (jtreg):
https://openjdk.java.net/jtreg/index.html
https://openjdk.java.net/jtreg/tag-spec.html

You could potentially set a vm.opts or java.opts that would create a core at end of test run (which is at the point the test times out)

System property	Environment variable	Notes
test.vm.opts	TESTVMOPTS	Additional VM options for all JVMs used in the test.
test.java.opts	TESTJAVAOPTS	Additional VM options for all invocations of the main Java launcher used in the test. (i.e.excluding JDK tools like "javac".)

smlambert · 2020-06-10T19:49:40Z

There is also sometimes additional info in the .jtr files in the test_output artifact, have you looked at those?

pshipton · 2020-06-10T20:40:42Z

There is also sometimes additional info in the .jtr files in the test_output artifact, have you looked at those?

Yes, we've analyzed the available information and determined the next step is to get a core file to proceed further.

You could potentially set a vm.opts or java.opts that would create a core at end of test run (which is at the point the test times out)

The test fails intermittently. We need a solution that can be enabled for all testing until we get the core file we need. The test harness already has some handling for timeouts, i.e. running jstack, but it's not enough to figure out the cause of the problem. Probably in general it would be good to capture core files on timeouts to help diagnose the problems. I'm surprised the openjdk tests aren't already trying to do something like that. Although perhaps they are but it doesn't apply to OpenJ9.

smlambert · 2020-06-10T20:57:28Z

The source for jtreg lives here: https://hg.openjdk.java.net/code-tools/jtreg
we build it here: https://ci.adoptopenjdk.net/view/Dependencies/job/jtreg

sophia-guo · 2020-06-10T21:00:11Z

What is the corefile name format? We have set to obtain files with following name format if tests fail or error.
JTREG_BASIC_OPTIONS += -retain:fail,error,.dmp,javacore.,heapdump.,.trc

pshipton · 2020-06-10T21:09:22Z

.dmp should cover it, the cores are named core.*.dmp. There is no core file generated atm, we're not failing to capture it.

The source for jtreg lives here

I'll take a look and see if I can make the required mods. I don't expect openjdk is going to take mods to capture OpenJ9 core files. thinking we'll need to mirror this to git and modify it.

smlambert · 2020-06-10T21:16:10Z

We allow for passing in custom jtreg binaries (needed to do this for zOS), so if you build it, there is a way to use a specialized one, though I would caution against this as a 'long-term' plan, but it may help to resolve this particular instance.

pshipton · 2020-06-10T21:35:06Z

Although I don't see it in the doc, looking at the code it seems there is support for a custom timeout handler, using -th <classname> or -timeoutHandler <classname>. I've created the handler we need, need to see if I can get it working in practice.

pshipton · 2020-06-10T23:56:25Z

It's working.
-timeoutHandler:openj9.jtreg.CoreDumpTimeoutHandler -timeoutHandlerDir:/home/peter/oj9coredumpth.jar

Timeout information:
Running jcmd on process 18627
Dump written to /home/peter/test_output/scratch/0/core.20200610.195421.18627.0001.dmp
--- Timeout information end.

Although it shows scratch/0, at the end the core is actually in java/lang/ref/FinalizeOverride where you'd expect.

pshipton · 2020-06-11T00:02:18Z

If I can get a few pointers for where to put the code and whether we need a build.xml or a jenkins job, we can modify the OpenJ9 sanity.openjdk to use it.

smlambert · 2020-06-11T02:21:05Z

Look at internal server, Test_openjdk11_j9_sanity.openjdk_s390x_zos_Personal/32/consoleFull
as an example

If you set an environment variable JTREG_URL to a URL where your custom jtreg build is, it will get used instead of the default location where we pick it up from (at AdoptOpenJDK).
JTREG_URL=someLinkToYourJtregBuild

JTREG_URL=https://artifactoryServer/artifactory/sys-rt-generic-local/UploadFile/buildId/yourCustomJtreg.tar.gz

You can use the UploadFile job to push your custom jtreg build to artifactory for use.

pshipton · 2020-06-11T02:46:24Z

I don't have a custom jtreg build. The timeout handler works with the existing jtreg.jar, and is a separate jar file. I'd like to deliver the code somewhere (Oracle copyright and GPL license, with my modifications) and build the new jar, and have it available when running openjdk tests, so we can add command line arguments to use it (permanently).

smlambert · 2020-06-11T02:49:07Z

I get it now... so I guess you need to figure out where you are going to land your code first. I will stop replying in git issues now, as I am clearly too tired to read them clearly. :)

pshipton · 2020-06-11T02:51:49Z

I guess you need to figure out where you are going to land your code first.

I was hoping you would have a spot for it, but if not I could put it into https://github.com/ibmruntimes/openj9-openjdk-jdk, or at least start a discussion about doing that.

oj9coredumpth.zip

pshipton · 2020-06-11T03:07:24Z

Does this look good?

https://github.com/ibmruntimes/openj9-openjdk-jdk/compare/openj9...pshipton:tohandler?expand=1

pshipton · 2020-06-11T20:57:57Z

@smlambert if the previous commit looks ok to you, I'll go ahead and create the PR and ask for a review. Would we then create a jenkins build to create the jar file?

smlambert · 2020-06-12T03:06:18Z

Yes, that looks good, we can create a Jenkins job at ci.eclipse.org/openj9 (https://ci.eclipse.org/openj9/view/Infrastructure/job/Build_JDK_Timeout_Handler/) then can fetch the jar in a target in the openjdk-tests/openjdk/build.xml file.

pshipton · 2024-02-09T14:31:26Z

https://openj9-jenkins.osuosl.org/job/Test_openjdk8_j9_sanity.openjdk_s390x_linux_Nightly_testList_0/158
jdk_lang_0
java/lang/ref/FinalizeOverride.java

https://openj9-artifactory.osuosl.org/artifactory/ci-openj9/Test/Test_openjdk8_j9_sanity.openjdk_s390x_linux_Nightly_testList_0/158/openjdk_test_output.tar.gz

00:44:57  "AgentVMThread" Id=23 RUNNABLE
00:44:57  	at java.lang.Runtime.gc(Native Method)
00:44:57  	at java.lang.System.gc(System.java:391)
00:44:57  	at FinalizeOverride.test(FinalizeOverride.java:64)
00:44:57  	at FinalizeOverride.main(FinalizeOverride.java:53)

pshipton · 2024-02-09T14:32:03Z

Either we got unlucky, or this seems to be failing much more often all of a sudden.

pshipton · 2024-02-09T17:33:30Z

@dmitripivkine can you pls take a look since the recent failures seem to be stuck in the gc.

dmitripivkine · 2024-02-12T18:57:55Z

Threads in the system:

    !j9vmthread 0x1add800 publicFlags=101 privateFlags=1008 inNative=0 // main
    !j9vmthread 0x1adfd00 publicFlags=1 privateFlags=101a inNative=0 // JIT Compilation Thread-000
    !j9vmthread 0x1ae2300 publicFlags=1 privateFlags=101a inNative=0 // JIT Compilation Thread-001 Suspended
    !j9vmthread 0x1ae4900 publicFlags=1 privateFlags=101a inNative=0 // JIT Compilation Thread-002 Suspended
    !j9vmthread 0x1ae6e00 publicFlags=1 privateFlags=101a inNative=0 // JIT Compilation Thread-003 Suspended
    !j9vmthread 0x1ae9400 publicFlags=1 privateFlags=101a inNative=0 // JIT Compilation Thread-004 Suspended
    !j9vmthread 0x1aeba00 publicFlags=1 privateFlags=101a inNative=0 // JIT Compilation Thread-005 Suspended
    !j9vmthread 0x1aee000 publicFlags=1 privateFlags=101a inNative=0 // JIT Compilation Thread-006 Suspended
    !j9vmthread 0x1af0500 publicFlags=1 privateFlags=101a inNative=0 // JIT Diagnostic Compilation Thread-007 Suspended
    !j9vmthread 0x1af2b00 publicFlags=1 privateFlags=101a inNative=0 // JIT-SamplerThread
    !j9vmthread 0x1af5100 publicFlags=1 privateFlags=101a inNative=0 // IProfiler
    !j9vmthread 0x1bbd700 publicFlags=1 privateFlags=1a inNative=0 // Concurrent Mark Helper
    !j9vmthread 0x1bbfc00 publicFlags=1 privateFlags=1a inNative=0 // GC Worker
    !j9vmthread 0x1bc2200 publicFlags=1 privateFlags=1a inNative=0 // GC Worker
    !j9vmthread 0x1bc4800 publicFlags=1 privateFlags=1a inNative=0 // GC Worker
    !j9vmthread 0x1bd5600 publicFlags=1 privateFlags=2 inNative=0 // Attach API wait loop
    !j9vmthread 0x1bd6e00 publicFlags=1 privateFlags=20081a inNative=0 // Finalizer thread
    !j9vmthread 0x1bf2d00 publicFlags=a0001 privateFlags=2 inNative=0 // pool-1-thread-1
    !j9vmthread 0x1d1b000 publicFlags=1 privateFlags=0 inNative=0 // AgentVMThread <---
    !j9vmthread 0x1d2d000 publicFlags=41020 privateFlags=2 inNative=0 // Attachment portNumber: 33267 <-- exclusiveAccessState = 0x0000000000000002 
    !j9vmthread 0x1d1ff00 publicFlags=101 privateFlags=2 inNative=0 // file lock watchdog

For reference - related Public flags:

J9_PUBLIC_FLAGS_THREAD_WAITING 0x100
J9_PUBLIC_FLAGS_THREAD_PARKED 0x20000
J9_PUBLIC_FLAGS_THREAD_TIMED 0x80000

J9_PUBLIC_FLAGS_NOT_COUNTED_BY_SAFE_POINT 0x4000
J9_PUBLIC_FLAGS_NOT_AT_SAFE_POINT 0x1000
J9_PUBLIC_FLAGS_VM_ACCESS 0x20

"AgentVMThread" is waiting on attempt to acquire Exclusive access for GC:

3XMTHREADINFO      "AgentVMThread" J9VMThread:0x0000000001D1B000, omrthread_t:0x000003FF2C008730, java/lang/Thread:0x000000002E1C3290, state:R, prio=5
3XMJAVALTHREAD            (java/lang/Thread getId:0x17, isDaemon:false)
3XMJAVALTHRCCL            sun/misc/Launcher$AppClassLoader(0x000000000E33A878)
3XMTHREADINFO1            (native thread ID:0x74598, native priority:0x5, native policy:UNKNOWN, vmstate:CW, vm thread flags:0x00000001)
3XMTHREADINFO2            (native stack address range from:0x000003FF9A0C0000, to:0x000003FF9A100000, size:0x40000)
3XMCPUTIME               CPU usage total: 209.760254485 secs, current category="Application"
3XMHEAPALLOC             Heap bytes allocated since last GC cycle=0 (0x0)
3XMTHREADINFO3           Java callstack:
4XESTACKTRACE                at java/lang/Runtime.gc(Native Method)
4XESTACKTRACE                at java/lang/System.gc(System.java:391(Compiled Code))
4XESTACKTRACE                at FinalizeOverride.test(FinalizeOverride.java:64(Compiled Code))
4XESTACKTRACE                at FinalizeOverride.main(FinalizeOverride.java:53)
4XESTACKTRACE                at sun/reflect/NativeMethodAccessorImpl.invoke0(Native Method)
4XESTACKTRACE                at sun/reflect/NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
4XESTACKTRACE                at sun/reflect/DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43(Compiled Code))
4XESTACKTRACE                at java/lang/reflect/Method.invoke(Method.java:503(Compiled Code))
4XESTACKTRACE                at com/sun/javatest/regtest/agent/MainActionHelper$AgentVMRunnable.run(MainActionHelper.java:298)
4XESTACKTRACE                at java/lang/Thread.run(Thread.java:826)
3XMTHREADINFO3           Native callstack:
4XENATIVESTACK                (0x000003FF9ADADA62 [libj9prt29.so+0x2da62]) <-- <protectedBacktrace+34>
4XENATIVESTACK                (0x000003FF9ADB2B00 [libj9prt29.so+0x32b00]) <-- <omrsig_protect+984>
4XENATIVESTACK                (0x000003FF9ADADFCC [libj9prt29.so+0x2dfcc]) <-- <omrintrospect_backtrace_thread_raw+188>
4XENATIVESTACK                (0x000003FF9ADB2B00 [libj9prt29.so+0x32b00]) <-- <omrsig_protect+984>
4XENATIVESTACK                (0x000003FF9ADAD8DC [libj9prt29.so+0x2d8dc]) <-- <omrintrospect_backtrace_thread+132>
4XENATIVESTACK                (0x000003FF9ADAEFFA [libj9prt29.so+0x2effa]) <-- <upcall_handler+290>
4XENATIVESTACK                (0x000003FF9A0FD300 [<unknown>+0x0])
4XENATIVESTACK               pthread_cond_wait+0x226 (0x000003FF9B98E81E [libpthread.so.0+0xe81e]) ???
4XENATIVESTACK                (0x000003FF9AD07B0E [libj9thr29.so+0x7b0e]) <-- <monitor_wait_original+814>
4XENATIVESTACK               omrthread_monitor_wait+0x60 (0x000003FF9AD0B668 [libj9thr29.so+0xb668]) <-- <omrthread_monitor_wait+96>
4XENATIVESTACK                (0x000003FF9AF07D3A [libj9vm29.so+0x87d3a]) <-- <internalAcquireVMAccessNoMutexWithMask+138>
4XENATIVESTACK                (0x000003FF9AF07B10 [libj9vm29.so+0x87b10]) <-- <internalAcquireVMAccess+120>
4XENATIVESTACK                (0x000003FF98D308A6 [libj9gc29.so+0x308a6]) <j9gc_modron_global_collect_with_overrides+238>
4XENATIVESTACK                (0x000003FF98A64E94 [libjclse29.so+0x64e94]) <-- <JVM_GC_Impl+156>
4XENATIVESTACK                (0x000003FF83E77A8C [<unknown>+0x0])

However currently Exclusive is owned by "Attachment portNumber: 42301":

3XMTHREADINFO      "Attachment portNumber: 42301" J9VMThread:0x0000000001D2D000, omrthread_t:0x000003FF2C010430, java/lang/Thread:0x000000002E1C8FD0, state:R, prio=10
3XMJAVALTHREAD            (java/lang/Thread getId:0x1A, isDaemon:true)
3XMJAVALTHRCCL            sun/misc/Launcher$AppClassLoader(0x000000000E33A878)
3XMTHREADINFO1            (native thread ID:0x76C96, native priority:0xA, native policy:UNKNOWN, vmstate:R, vm thread flags:0x00041020)
3XMTHREADINFO2            (native stack address range from:0x000003FF99FC0000, to:0x000003FF9A000000, size:0x40000)
3XMCPUTIME               CPU usage total: 0.068635371 secs, current category="Application"
3XMHEAPALLOC             Heap bytes allocated since last GC cycle=0 (0x0)
3XMTHREADINFO3           Java callstack:
4XESTACKTRACE                at openj9/internal/tools/attach/target/DiagnosticUtils.triggerDumpsImpl(Native Method)
4XESTACKTRACE                at openj9/internal/tools/attach/target/DiagnosticUtils.doDump(DiagnosticUtils.java:328)
4XESTACKTRACE                at openj9/internal/tools/attach/target/DiagnosticUtils$$Lambda$5/0x0000000000000000.apply(Bytecode PC:4)
4XESTACKTRACE                at openj9/internal/tools/attach/target/DiagnosticUtils.executeDiagnosticCommand(DiagnosticUtils.java:185)
4XESTACKTRACE                at openj9/internal/tools/attach/target/Attachment.doCommand(Attachment.java:238)
4XESTACKTRACE                at openj9/internal/tools/attach/target/Attachment.run(Attachment.java:149)
3XMTHREADINFO3           Native callstack:
4XENATIVESTACK               protectedBacktrace+0x22 (0x000003FF9ADADA62 [libj9prt29.so+0x2da62])
4XENATIVESTACK               omrsig_protect+0x3d8 (0x000003FF9ADB2B00 [libj9prt29.so+0x32b00])
4XENATIVESTACK               omrintrospect_backtrace_thread_raw+0xbc (0x000003FF9ADADFCC [libj9prt29.so+0x2dfcc])
4XENATIVESTACK               omrsig_protect+0x3d8 (0x000003FF9ADB2B00 [libj9prt29.so+0x32b00])
4XENATIVESTACK               omrintrospect_backtrace_thread+0x84 (0x000003FF9ADAD8DC [libj9prt29.so+0x2d8dc])
4XENATIVESTACK               setup_native_thread+0x21a (0x000003FF9ADAEA7A [libj9prt29.so+0x2ea7a]) <----
4XENATIVESTACK               omrintrospect_threads_startDo_with_signal+0x3fa (0x000003FF9ADAFC8A [libj9prt29.so+0x2fc8a])
4XENATIVESTACK               omrsig_protect+0x3d8 (0x000003FF9ADB2B00 [libj9prt29.so+0x32b00])
4XENATIVESTACK               _ZN18JavaCoreDumpWriter28writeThreadsWithNativeStacksEv+0x396 (0x000003FF9A11BBDE [libj9dmp29.so+0x1bbde]) <----
4XENATIVESTACK               protectedWriteThreadsWithNativeStacks+0x18 (0x000003FF9A11C438 [libj9dmp29.so+0x1c438])
4XENATIVESTACK               omrsig_protect+0x3d8 (0x000003FF9ADB2B00 [libj9prt29.so+0x32b00])
4XENATIVESTACK               _ZN18JavaCoreDumpWriter18writeThreadSectionEv+0x164 (0x000003FF9A1187A4 [libj9dmp29.so+0x187a4])
4XENATIVESTACK               protectedWriteSection+0x34 (0x000003FF9A11347C [libj9dmp29.so+0x1347c])
4XENATIVESTACK               omrsig_protect+0x3d8 (0x000003FF9ADB2B00 [libj9prt29.so+0x32b00])
4XENATIVESTACK               _ZN18JavaCoreDumpWriterC2EPKcP16J9RASdumpContextP14J9RASdumpAgent+0x496 (0x000003FF9A114626 [libj9dmp29.so+0x14626])
4XENATIVESTACK               runJavadump+0x2a (0x000003FF9A11F02A [libj9dmp29.so+0x1f02a])
4XENATIVESTACK               doJavaDump+0x4c (0x000003FF9A1058D4 [libj9dmp29.so+0x58d4])
4XENATIVESTACK               protectedDumpFunction+0x26 (0x000003FF9A104E5E [libj9dmp29.so+0x4e5e])
4XENATIVESTACK               omrsig_protect+0x3d8 (0x000003FF9ADB2B00 [libj9prt29.so+0x32b00])
4XENATIVESTACK               runDumpFunction+0x6e (0x000003FF9A1089BE [libj9dmp29.so+0x89be])
4XENATIVESTACK               runDumpAgent+0x1b4 (0x000003FF9A108BB4 [libj9dmp29.so+0x8bb4])
4XENATIVESTACK               createAndRunOneOffDumpAgent+0x160 (0x000003FF9A109308 [libj9dmp29.so+0x9308])
4XENATIVESTACK               triggerOneOffDump+0xd0 (0x000003FF9A121540 [libj9dmp29.so+0x21540])
4XENATIVESTACK               Java_com_ibm_jvm_Dump_triggerDumpsImpl+0x1ee (0x000003FF98A13CF6 [libjclse29.so+0x13cf6])
4XENATIVESTACK               ffi_call_SYSV+0x98 (0x000003FF9B07DB18 [libj9vm29.so+0x1fdb18])
4XENATIVESTACK               ffi_call+0xa2 (0x000003FF9B07D52A [libj9vm29.so+0x1fd52a])
4XENATIVESTACK               _ZN32VM_BytecodeInterpreterCompressed3runEP10J9VMThread+0x13b2c (0x000003FF9AF29DDC [libj9vm29.so+0xa9ddc])
4XENATIVESTACK               bytecodeLoopCompressed+0xee (0x000003FF9AF1629E [libj9vm29.so+0x9629e])
4XENATIVESTACK               c_cInterpreter+0x64 (0x000003FF9AFFA504 [libj9vm29.so+0x17a504])

This thread is in JavaCoreDumpWriter->writeThreadsWithNativeStacks() attempting setup_native_thread()
This thread has number of Public flags set:

 J9_PUBLIC_FLAGS_NOT_COUNTED_BY_SAFE_POINT 0x4000
J9_PUBLIC_FLAGS_NOT_AT_SAFE_POINT 0x1000
J9_PUBLIC_FLAGS_VM_ACCESS 0x20

@pshipton I am not sure where / why thread "Attachment portNumber: 42301" is waiting. Also I am not sure is it actual test problem or thread is in the process of generating javacore post failure.

pshipton · 2024-02-12T20:16:38Z

"Attachment portNumber: 42301" is the thread used to trigger the diagnostic dumps, it's in the process of creating the diagnostics. Whereas AgentVMThread seems to be stuck in Runtime.gc(), presumably it was stuck there long enough to timeout the test, which caused the timeout handler to use AttachAPI to connect via "Attachment portNumber: 42301" and trigger dumps.

dmitripivkine · 2024-02-12T20:24:46Z

Ok, thank you for clarification. AgentVMThread seems is attempting to get Exclusive and waiting on omr thread monitor.

dmitripivkine · 2024-02-12T20:38:02Z

Looking to the source of internalAcquireVMAccessNoMutexWithMask(). It can wait on vm->exclusiveAccessMutex as well as vmThread->publicFlagsMutex. Both of them are un owned at the moment.

dmitripivkine · 2024-02-13T00:41:26Z

I wondering this might be not a hang in AgentVMThread, but large number of System GCs back to back this thread suddenly initiated. And now, we have two Global collections under single call umbrella. It makes the situation worse.

pshipton · 2024-02-13T18:56:04Z

Yes, the test is looping waiting for finalization.

        while (finalizedCount.get() != (count+1)) {
            System.gc();
            System.runFinalization();
        }

dmitripivkine · 2024-02-13T21:14:41Z

DDR can not walk thread java stack unfortunately

dmitripivkine · 2024-02-14T17:02:01Z

Found better DDR tool:

<1d1b000> JIT frame: bp = 0x0000000001D33268, pc = 0x000003FF83F2B824, unwindSP = 0x0000000001D33218, cp = 0x0000000001D197B0, arg0EA = 0x0000000001D33278, jitInfo = 0x000003FF819968F8
<1d1b000> 	Method: FinalizeOverride.test(Ljava/lang/Object;I)V !j9method 0x0000000001D19DF8
<1d1b000> 	Bytecode index = 32, inlineDepth = 0, PC offset = 0xFFFFFFFFFFFF342E
<1d1b000> 	stackMap=0x000003FF81996AB0, slots=I16(0x0002) parmBaseOffset=I16(0x0010), parmSlots=U16(0x0001), localBaseOffset=I16(0x0000)
<1d1b000> 	Described JIT args starting at 0x0000000001D33278 for U16(0x0001) slots
<1d1b000> 		O-Slot: : a0[0x0000000001D33278] = 0x000000002E1C5FB0 <-- FinalizeOverride$NoOverride
<1d1b000> 	Described JIT temps starting at 0x0000000001D33268 for IDATA(0x0000000000000000) slots
<1d1b000> 	JIT-RegisterMap = UDATA(0x0000000000000040)
<1d1b000> 		JIT-RegisterMap-O-Slot[0x0000000001D331C8] = 0x0000000000000000 (jit_r6)
<1d1b000> 		JIT-RegisterMap-I-Slot[0x0000000001D331D0] = UDATA(0x0000000000000005) (jit_r7)
<1d1b000> 		JIT-RegisterMap-I-Slot[0x0000000001D331D8] = UDATA(0x0000000000001022) (jit_r8)
<1d1b000> 		JIT-RegisterMap-I-Slot[0x0000000001D331E0] = UDATA(0x000000000000003C) (jit_r9)
<1d1b000> 		JIT-RegisterMap-I-Slot[0x0000000001D331E8] = UDATA(0x000000002E254890) (jit_r10)
<1d1b000> 		JIT-RegisterMap-I-Slot[0x0000000001D331F0] = UDATA(0x000000002E250C30) (jit_r11)
<1d1b000> 		JIT-RegisterMap-I-Slot[0x0000000001D331F8] = UDATA(0x0000000000000001) (jit_r12)
<1d1b000> 	JIT-Frame-RegisterMap[0x0000000001D33230] = UDATA(0x000000002E254A00) (jit_r6)
<1d1b000> 	JIT-Frame-RegisterMap[0x0000000001D33238] = UDATA(0x0000000000000000) (jit_r7)
<1d1b000> 	JIT-Frame-RegisterMap[0x0000000001D33240] = UDATA(0x0000000001C38500) (jit_r8)
<1d1b000> 	JIT-Frame-RegisterMap[0x0000000001D33248] = UDATA(0x000000002E2547A0) (jit_r9)
<1d1b000> 	JIT-Frame-RegisterMap[0x0000000001D331E8] = UDATA(0x000000002E254890) (jit_r10)
<1d1b000> 	JIT-Frame-RegisterMap[0x0000000001D331F0] = UDATA(0x000000002E250C30) (jit_r11)
<1d1b000> 	JIT-Frame-RegisterMap[0x0000000001D331F8] = UDATA(0x0000000000000001) (jit_r12)

> !j9object 0x000000002E1C5FB0
!J9Object 0x000000002E1C5FB0 {
	struct J9Class* clazz = !j9class 0x1D1DB00 // FinalizeOverride$NoOverride
	Object flags = 0x00000000;
	I lockword = 0x00000000 (offset = 0) (java/lang/Object) <hidden>
	I value = 0x0000003C (offset = 4) (FinalizeOverride$Base)
	I finalizeLink = 0x2E17B060 (offset = 8) (FinalizeOverride$Base) <hidden>
}

Object FinalizeOverride$NoOverride is alive, it is referenced from o-slot.
GC tracks this object in Unfinalized list indeed:

> !gccheck unfinalized:all:scan | grep -i 2E1C5FB0
    <000000002E1AC468 000000002E1AD720 000000002E1AD2B0 000000002E175340 000000002E175418 000000002E1C5FB0 000000002E17B060 000000002E177F10 >

dmitripivkine · 2024-02-20T19:16:24Z

@hzongaro I guess this is another case where -Xjit:enableAggressiveLiveness might help. Or does it?

pshipton · 2024-02-20T20:01:32Z

For some reason we run FinalizeOverride with -Xjit:enableAggressiveLiveness on jdk11+, but not for jdk8. We've seen few failures on jdk8, but then got one in November, one 3 weeks, and one 2 weeks ago.

See also #18893
and #18600

pshipton · 2024-02-20T20:17:23Z

Looking at the weekly Semeru build results, it seems the FinalizeOverride test is recently mostly failing on jdk11+ even with -Xjit:enableAggressiveLiveness. We weren't running the special.openjdk suite that contains this test across all platform until this past week (ibmruntimes/ci-jenkins-pipelines#206). Looking at one variant on xmac, the failure history is

FAILED 2024-02-17
FAILED 2024-01-27
PASSED 2024-01-20
PASSED 2024-01-06
FAILED 2023-12-30
PASSED 2023-12-23
PASSED 2023-12-16
PASSED 2023-12-09

JasonFengJ9 · 2024-02-23T21:51:58Z

Also observed at JDK22 aarch64_linux

19:19:16  variation: -Xjit:enableAggressiveLiveness -XX:-JITServerTechPreviewMessage Mode150
19:19:16  JVM_OPTIONS:  -Xjit:enableAggressiveLiveness -XX:-JITServerTechPreviewMessage -XX:+UseCompressedOops -Xverbosegclog 

19:35:47  TEST: java/lang/ref/FinalizeOverride.java

19:35:47  stderr:
19:35:47  JVMDUMP034I User requested System dump using '/home/jenkins/workspace/Test_openjdk22_j9_special.openjdk_aarch64_linux_Personal/aqa-tests/TKG/output_17086475045520/jdk_lang_ref_FinalizeOverride_j9_0/work/scratch/0/core.20240222.193535.1934462.0001.dmp' through com.ibm.jvm.Dump.systemDumpToFile
19:35:47  JVMDUMP010I System dump written to /home/jenkins/workspace/Test_openjdk22_j9_special.openjdk_aarch64_linux_Personal/aqa-tests/TKG/output_17086475045520/jdk_lang_ref_FinalizeOverride_j9_0/work/scratch/0/core.20240222.193535.1934462.0001.dmp
19:35:47  JVMDUMP034I User requested Java dump using '/home/jenkins/workspace/Test_openjdk22_j9_special.openjdk_aarch64_linux_Personal/aqa-tests/TKG/output_17086475045520/jdk_lang_ref_FinalizeOverride_j9_0/work/scratch/0/javacore.20240222.193538.1934462.0002.txt' through com.ibm.jvm.Dump.javaDumpToFile
19:35:47  JVMDUMP010I Java dump written to /home/jenkins/workspace/Test_openjdk22_j9_special.openjdk_aarch64_linux_Personal/aqa-tests/TKG/output_17086475045520/jdk_lang_ref_FinalizeOverride_j9_0/work/scratch/0/javacore.20240222.193538.1934462.0002.txt
19:35:47  
19:35:47  TEST RESULT: Error. Agent error: java.lang.Exception: Agent 2 timed out with a timeout of 960 seconds; check console log for any additional details
19:35:47  --------------------------------------------------
19:35:47  Test results: error: 1
19:36:14  Report written to /home/jenkins/workspace/Test_openjdk22_j9_special.openjdk_aarch64_linux_Personal/aqa-tests/TKG/output_17086475045520/jdk_lang_ref_FinalizeOverride_j9_0/report/html/report.html
19:36:14  Results written to /home/jenkins/workspace/Test_openjdk22_j9_special.openjdk_aarch64_linux_Personal/aqa-tests/TKG/output_17086475045520/jdk_lang_ref_FinalizeOverride_j9_0/work
19:36:14  Error: Some tests failed or other problems occurred.
19:36:14  -----------------------------------
19:36:14  jdk_lang_ref_FinalizeOverride_j9_0_FAILED

llxia · 2024-03-06T13:48:12Z

Temporarily disabled jdk_lang_ref_FinalizeOverride_j9 via adoptium/aqa-tests#5124

JasonFengJ9 · 2024-03-21T20:32:36Z

Seen in JDK17 aarch64_linux milestone 1 build

dmitripivkine · 2024-03-25T17:46:35Z

Seen in JDK17 aarch64_linux milestone 1 build

There is still be the same picture: the object test is waiting to be finalized has a hard root from o-slot despite -Xjit:enableAggressiveLiveness is specified. In the stack for (AgentVMThread):

<382600> JIT frame: bp = 0x0000000000388848, pc = 0x0000FFFF56653BC0, unwindSP = 0x00000000003887C0, cp = 0x0000000000380570, arg0EA = 0x0000000000388858, jitInfo = 0x0000FFFF540FCDF8
<382600> 	Method: FinalizeOverride.test(Ljava/lang/Object;I)V !j9method 0x0000000000380C00
<382600> 	Bytecode index = 2, inlineDepth = 0, PC offset = 0xFFFFFFFFFFFFF7DC
<382600> 	stackMap=0x0000FFFF540FCFF2, slots=I16(0x0002) parmBaseOffset=I16(0x0010), parmSlots=U16(0x0001), localBaseOffset=I16(0xFFF8)
<382600> 	Described JIT args starting at 0x0000000000388858 for U16(0x0001) slots
<382600> 		O-Slot: : a0[0x0000000000388858] = 0x00000000FFEFCC58 <--- object test waiting to be finalized
<382600> 	Described JIT temps starting at 0x0000000000388840 for IDATA(0x0000000000000001) slots
<382600> 		I-Slot: : t0[0x0000000000388840] = 0x0000000000388878
<382600> 	JIT-RegisterMap = UDATA(0x0000000000000000)
<382600> 	JIT-Frame-RegisterMap[0x00000000003887E8] = UDATA(0x00000000000CCD00) (jit_r21)
<382600> 	JIT-Frame-RegisterMap[0x00000000003887F0] = UDATA(0x00000000FFFFFFFF) (jit_r22)
<382600> 	JIT-Frame-RegisterMap[0x00000000003887F8] = UDATA(0x0000000000000000) (jit_r23)
<382600> 	JIT-Frame-RegisterMap[0x0000000000388800] = UDATA(0x0000000000000314) (jit_r24)
<382600> 	JIT-Frame-RegisterMap[0x0000000000388808] = UDATA(0x0000000000000314) (jit_r25)
<382600> 	JIT-Frame-RegisterMap[0x0000000000388810] = UDATA(0x00000000FFEF1760) (jit_r26)
<382600> 	JIT-Frame-RegisterMap[0x0000000000388818] = UDATA(0x0000000000000000) (jit_r27)
<382600> 	JIT-Frame-RegisterMap[0x0000000000388820] = UDATA(0x0000000000000000) (jit_r28)

> !j9object 0x00000000FFEFCC58
!J9Object 0x00000000FFEFCC58 {
	struct J9Class* clazz = !j9class 0x39EA00 // FinalizeOverride$PublicFinalize
	Object flags = 0x00000000;
	I lockword = 0x00000000 (offset = 0) (java/lang/Object) <hidden>
	I value = 0x00000028 (offset = 4) (FinalizeOverride$Base)
	I finalizeLink = 0x00000000 (offset = 8) (FinalizeOverride$Base) <hidden>
}

dmitripivkine · 2024-03-25T17:50:31Z

There is one more failure for the same test in this build. Again, the same:

<ffff8c6dcc00> JIT frame: bp = 0x0000FFFECC00AE48, pc = 0x0000FFFF45CC02E8, unwindSP = 0x0000FFFECC00AE00, cp = 0x0000FFFF8C65F6A0, arg0EA = 0x0000FFFECC00AE58, jitInfo = 0x0000FFFF26D2AFB8
<ffff8c6dcc00> 	Method: FinalizeOverride.test(Ljava/lang/Object;I)V !j9method 0x0000FFFF8C65FD00
<ffff8c6dcc00> 	Bytecode index = 41, inlineDepth = 0, PC offset = 0xFFFFFFFFFFFFF79C
<ffff8c6dcc00> 	stackMap=0x0000FFFF26D2B131, slots=I16(0x0002) parmBaseOffset=I16(0x0010), parmSlots=U16(0x0001), localBaseOffset=I16(0xFFF8)
<ffff8c6dcc00> 	Described JIT args starting at 0x0000FFFECC00AE58 for U16(0x0001) slots
<ffff8c6dcc00> 		O-Slot: : a0[0x0000FFFECC00AE58] = 0x0000FFFF7EE62ED8 <--------------
<ffff8c6dcc00> 	Described JIT temps starting at 0x0000FFFECC00AE40 for IDATA(0x0000000000000001) slots
<ffff8c6dcc00> 		I-Slot: : t0[0x0000FFFECC00AE40] = 0x0000FFFECC00AE78
<ffff8c6dcc00> 	JIT-RegisterMap = UDATA(0x0000000000000000)
<ffff8c6dcc00> 	JIT-Frame-RegisterMap[0x0000FFFECC00ADA0] = UDATA(0x0000FFFF8C1A4500) (jit_r21)
<ffff8c6dcc00> 	JIT-Frame-RegisterMap[0x0000FFFECC00ADA8] = UDATA(0x00000000FFFFFFFF) (jit_r22)
<ffff8c6dcc00> 	JIT-Frame-RegisterMap[0x0000FFFECC00ADB0] = UDATA(0x0000000000000000) (jit_r23)
<ffff8c6dcc00> 	JIT-Frame-RegisterMap[0x0000FFFECC00ADB8] = UDATA(0x0000000000000314) (jit_r24)
<ffff8c6dcc00> 	JIT-Frame-RegisterMap[0x0000FFFECC00ADC0] = UDATA(0x0000000000000314) (jit_r25)
<ffff8c6dcc00> 	JIT-Frame-RegisterMap[0x0000FFFECC00ADC8] = UDATA(0x0000000000000000) (jit_r26)
<ffff8c6dcc00> 	JIT-Frame-RegisterMap[0x0000FFFECC00ADD0] = UDATA(0x0000FFFF8C492F00) (jit_r27)
<ffff8c6dcc00> 	JIT-Frame-RegisterMap[0x0000FFFECC00AE28] = UDATA(0x0000FFFED0028410) (jit_r28)

> !j9object 0x0000FFFF7EE62ED8
!J9Object 0x0000FFFF7EE62ED8 {
	struct J9Class* clazz = !j9class 0xFFFECC00F200 // FinalizeOverride$SubSubclass
	Object flags = 0x00000000;
	J lockword = 0x0000000000000000 (offset = 0) (java/lang/Object) <hidden>
	I value = 0x0000001E (offset = 16) (FinalizeOverride$Base)
	J finalizeLink = 0x0000000000000000 (offset = 8) (FinalizeOverride$Base) <hidden>
}

pshipton · 2024-04-08T03:12:24Z

https://openj9-jenkins.osuosl.org/job/Test_openjdk8_j9_sanity.openjdk_s390x_linux_Release_testList_1/29/

dmitripivkine · 2024-04-09T18:51:56Z

https://openj9-jenkins.osuosl.org/job/Test_openjdk8_j9_sanity.openjdk_s390x_linux_Release_testList_1/29/

For the record: this test doesn't have -Xjit:enableAggressiveLiveness option added.
The picture is the same - an object teas waiting to be finalized is stored in O-slot and can not be collected.

pshipton added the test failure label May 22, 2020

pshipton mentioned this issue Jun 2, 2020

Verify LVTT entries refer to existing variables #9587

Merged

pshipton changed the title ~~java/lang/ref/FinalizeOverride timeout running jstack~~ java/lang/ref/FinalizeOverride timeout Jun 10, 2020

pshipton added this to the Release 0.21 (Java 8, 11, 14) July refresh milestone Jun 10, 2020

pshipton added the comp:gc label Jun 10, 2020

tajila mentioned this issue Feb 13, 2024

OpenJDK util/concurrent/locks/LockSupport/ParkLoops timeout #14752

Closed

pshipton mentioned this issue Feb 20, 2024

jdk_lang_ref_FinalizeOverride_j9_0_FAILED Agent error: java.lang.Exception: Agent 2 timed out #18600

Closed

LongyuZhang mentioned this issue Mar 5, 2024

Temporarily disable jdk_lang_ref_FinalizeOverride_j9 test adoptium/aqa-tests#5124

Merged

hzongaro modified the milestones: Release 0.44 (Java 8, 11, 17, 21) Apr refresh, Release 0.46 (Java 8, 11, 17, 21, 22) July refresh Mar 15, 2024

This was referenced Mar 27, 2024

OpenJDK java/lang/Thread/virtual/Collectable.java timeout #18463

Open

jdk_io_1_FAILED java/io/Serializable/subclassGC/SubclassGC.java java.lang.Error #19246

Open

hzongaro modified the milestones: Release 0.46 (Java 8, 11, 17, 21, 22) July refresh, Release 0.48 (Java 8, 11, 17, 21, 23) October refresh Jun 14, 2024

java/lang/ref/FinalizeOverride timeout #9651

java/lang/ref/FinalizeOverride timeout #9651

Comments

pshipton commented May 22, 2020

pshipton commented Jun 1, 2020 • edited Loading

pshipton commented Jun 7, 2020 • edited Loading

pshipton commented Jun 10, 2020 • edited Loading

pshipton commented Jun 10, 2020

pshipton commented Jun 10, 2020 • edited Loading

pshipton commented Jun 10, 2020

pshipton commented Jun 10, 2020

llxia commented Jun 10, 2020

smlambert commented Jun 10, 2020

smlambert commented Jun 10, 2020 • edited Loading

pshipton commented Jun 10, 2020

smlambert commented Jun 10, 2020

sophia-guo commented Jun 10, 2020

pshipton commented Jun 10, 2020

smlambert commented Jun 10, 2020

pshipton commented Jun 10, 2020 • edited Loading

pshipton commented Jun 10, 2020 • edited Loading

pshipton commented Jun 11, 2020 • edited Loading

smlambert commented Jun 11, 2020 • edited Loading

pshipton commented Jun 11, 2020

smlambert commented Jun 11, 2020

pshipton commented Jun 11, 2020

pshipton commented Jun 11, 2020

pshipton commented Jun 11, 2020

smlambert commented Jun 12, 2020 • edited Loading

pshipton commented Feb 9, 2024

pshipton commented Feb 9, 2024

pshipton commented Feb 9, 2024

dmitripivkine commented Feb 12, 2024

pshipton commented Feb 12, 2024 • edited Loading

dmitripivkine commented Feb 12, 2024

dmitripivkine commented Feb 12, 2024

dmitripivkine commented Feb 13, 2024

pshipton commented Feb 13, 2024

dmitripivkine commented Feb 13, 2024

dmitripivkine commented Feb 14, 2024 • edited Loading

dmitripivkine commented Feb 20, 2024

pshipton commented Feb 20, 2024 • edited Loading

pshipton commented Feb 20, 2024 • edited Loading

JasonFengJ9 commented Feb 23, 2024

llxia commented Mar 6, 2024

JasonFengJ9 commented Mar 21, 2024

dmitripivkine commented Mar 25, 2024

dmitripivkine commented Mar 25, 2024

pshipton commented Apr 8, 2024

dmitripivkine commented Apr 9, 2024

pshipton commented Jun 1, 2020 •

edited

Loading

pshipton commented Jun 7, 2020 •

edited

Loading

pshipton commented Jun 10, 2020 •

edited

Loading

pshipton commented Jun 10, 2020 •

edited

Loading

smlambert commented Jun 10, 2020 •

edited

Loading

pshipton commented Jun 10, 2020 •

edited

Loading

pshipton commented Jun 10, 2020 •

edited

Loading

pshipton commented Jun 11, 2020 •

edited

Loading

smlambert commented Jun 11, 2020 •

edited

Loading

smlambert commented Jun 12, 2020 •

edited

Loading

pshipton commented Feb 12, 2024 •

edited

Loading

dmitripivkine commented Feb 14, 2024 •

edited

Loading

pshipton commented Feb 20, 2024 •

edited

Loading

pshipton commented Feb 20, 2024 •

edited

Loading