Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

java/util/concurrent/BlockingQueue/ProducerConsumerLoops timeout #10158

Open
pshipton opened this issue Jul 14, 2020 · 8 comments
Open

java/util/concurrent/BlockingQueue/ProducerConsumerLoops timeout #10158

pshipton opened this issue Jul 14, 2020 · 8 comments
Labels
comp:jit prio:medium test failure
Milestone
Backlog

Comments

@pshipton
Copy link
Member

pshipton commented Jul 14, 2020 •
edited

https://ci.eclipse.org/openj9/job/Test_openjdk8_j9_sanity.openjdk_x86-64_linux_Nightly/117
java/util/concurrent/BlockingQueue/ProducerConsumerLoops.java
Core file available in artifacts, copied to /team/triage/openj9-10158

07:05:57  ACTION: main -- Error. Agent error: java.lang.Exception: Agent 3 timed out with a timeout of 28800 seconds; check console log for any additional details
07:05:57  REASON: User specified action: run main/timeout=3600 ProducerConsumerLoops 
07:05:57  TIME:   28806.986 seconds
07:05:57  messages:
07:05:57  command: main ProducerConsumerLoops
07:05:57  reason: User specified action: run main/timeout=3600 ProducerConsumerLoops 
07:05:57  Mode: agentvm
07:05:57  Agent id: 3
07:05:57  Timeout refired 28800 times
07:05:57  Timeout information:
07:05:57  Running jcmd on process 29011
07:05:57  Dump written to /home/jenkins/workspace/Test_openjdk8_j9_sanity.openjdk_x86-64_linux_Nightly/openjdk-tests/TKG/test_output_15946950832933/jdk_util_j9_0/work/scratch/0/core.20200714.080544.29011.0001.dmp
07:05:57  Running jstack on process 29011
07:05:57  2020-07-14T08:05:48.358
07:05:57  Virtual machine: 29011 JVM information:
07:05:57  JRE 1.8.0 Linux amd64-64-Bit Compressed References 20200713_445 (JIT enabled, AOT enabled)
07:05:57  OpenJ9   - 01cb796fc18
07:05:57  OMR      - 19153e91d16
07:05:57  JCL      - 1455ea2dbbb based on jdk8u262-b09
07:05:57  
07:05:57  "main" Id=1 WAITING
07:05:57  	at java.lang.Object.wait(Native Method)
07:05:57  	at java.lang.Object.wait(Object.java:218)
07:05:57  	at java.lang.Thread.join(Thread.java:703)
07:05:57  	- locked java.lang.Thread@5ed47643
07:05:57  	at com.sun.javatest.regtest.agent.MainActionHelper.runClass(MainActionHelper.java:184)
07:05:57  	at com.sun.javatest.regtest.agent.AgentServer.doMain(AgentServer.java:301)
07:05:57  	at com.sun.javatest.regtest.agent.AgentServer.run(AgentServer.java:232)
07:05:57  	at com.sun.javatest.regtest.agent.AgentServer.main(AgentServer.java:69)
07:05:57  
07:05:57  "JIT Compilation Thread-000" Id=2 RUNNABLE
07:05:57  
07:05:57  "JIT Compilation Thread-001 Suspended" Id=3 RUNNABLE
07:05:57  
07:05:57  "JIT Compilation Thread-002 Suspended" Id=4 RUNNABLE
07:05:57  
07:05:57  "JIT Compilation Thread-003 Suspended" Id=5 RUNNABLE
07:05:57  
07:05:57  "JIT Compilation Thread-004 Suspended" Id=6 RUNNABLE
07:05:57  
07:05:57  "JIT Compilation Thread-005 Suspended" Id=7 RUNNABLE
07:05:57  
07:05:57  "JIT Compilation Thread-006 Suspended" Id=8 RUNNABLE
07:05:57  
07:05:57  "JIT Diagnostic Compilation Thread-007 Suspended" Id=9 RUNNABLE
07:05:57  
07:05:57  "JIT-SamplerThread" Id=10 TIMED_WAITING
07:05:57  
07:05:57  "IProfiler" Id=11 RUNNABLE
07:05:57  
07:05:57  "Concurrent Mark Helper" Id=12 RUNNABLE
07:05:57  
07:05:57  "GC Slave" Id=13 RUNNABLE
07:05:57  
07:05:57  "GC Slave" Id=14 RUNNABLE
07:05:57  
07:05:57  "GC Slave" Id=15 RUNNABLE
07:05:57  
07:05:57  "Attach API wait loop" Id=18 TIMED_WAITING
07:05:57  	at java.lang.Thread.sleep(Native Method)
07:05:57  	at java.lang.Thread.sleep(Thread.java:953)
07:05:57  	at openj9.internal.tools.attach.target.WaitLoop.checkReplyAndCreateAttachment(WaitLoop.java:140)
07:05:57  	at openj9.internal.tools.attach.target.WaitLoop.waitForNotification(WaitLoop.java:117)
07:05:57  	at openj9.internal.tools.attach.target.WaitLoop.run(WaitLoop.java:154)
07:05:57  
07:05:57  "Finalizer thread" Id=19 RUNNABLE
07:05:57  
07:05:57  "pool-1-thread-1" Id=20 TIMED_WAITING
07:05:57  	at sun.misc.Unsafe.park(Native Method)
07:05:57  	at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
07:05:57  	at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
07:05:57  	at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1093)
07:05:57  	at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
07:05:57  	at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074)
07:05:57  	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
07:05:57  	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
07:05:57  	at java.lang.Thread.run(Thread.java:823)
07:05:57  
07:05:57  "ClassCache Reaper" Id=42 WAITING
07:05:57  	at java.lang.Object.wait(Native Method)
07:05:57  	at java.lang.Object.wait(Object.java:218)
07:05:57  	at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:138)
07:05:57  	- locked java.lang.ref.ReferenceQueue@acefa808
07:05:57  	at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:110)
07:05:57  	at java.io.ClassCache$Reaper.run(ClassCache.java:234)
07:05:57  	at java.lang.Thread.run(Thread.java:823)
07:05:57  
07:05:57  "AgentVMThread" Id=303 WAITING
07:05:57  	at sun.misc.Unsafe.park(Native Method)
07:05:57  	at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
07:05:57  	at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
07:05:57  	at java.util.concurrent.CyclicBarrier.dowait(CyclicBarrier.java:234)
07:05:57  	at java.util.concurrent.CyclicBarrier.await(CyclicBarrier.java:362)
07:05:57  	at ProducerConsumerLoops.oneRun(ProducerConsumerLoops.java:176)
07:05:57  	at ProducerConsumerLoops.oneTest(ProducerConsumerLoops.java:101)
07:05:57  	at ProducerConsumerLoops.main(ProducerConsumerLoops.java:73)
07:05:57  	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
07:05:57  	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
07:05:57  	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
07:05:57  	at java.lang.reflect.Method.invoke(Method.java:498)
07:05:57  	at com.sun.javatest.regtest.agent.MainActionHelper$AgentVMRunnable.run(MainActionHelper.java:298)
07:05:57  	at java.lang.Thread.run(Thread.java:823)
07:05:57  
07:05:57  "pool-4-thread-1" Id=304 WAITING
07:05:57  	at sun.misc.Unsafe.park(Native Method)
07:05:57  	at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
07:05:57  	at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:458)
07:05:57  	at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
07:05:57  	at java.util.concurrent.SynchronousQueue.put(SynchronousQueue.java:877)
07:05:57  	at ProducerConsumerLoops$Producer.run(ProducerConsumerLoops.java:128)
07:05:57  	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
07:05:57  	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
07:05:57  	at java.lang.Thread.run(Thread.java:823)
07:05:57  
07:05:57  "pool-4-thread-2" Id=305 WAITING
07:05:57  	at sun.misc.Unsafe.park(Native Method)
07:05:57  	at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
07:05:57  	at java.util.concurrent.SynchronousQueue$TransferQueue.awaitFulfill(SynchronousQueue.java:762)
07:05:57  	at java.util.concurrent.SynchronousQueue$TransferQueue.transfer(SynchronousQueue.java:695)
07:05:57  	at java.util.concurrent.SynchronousQueue.take(SynchronousQueue.java:924)
07:05:57  	at ProducerConsumerLoops$Consumer.run(ProducerConsumerLoops.java:152)
07:05:57  	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
07:05:57  	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
07:05:57  	at java.lang.Thread.run(Thread.java:823)
07:05:57  
07:05:57  "file lock watchdog" Id=308 TIMED_WAITING
07:05:57  	at java.lang.Object.wait(Native Method)
07:05:57  	at java.lang.Object.wait(Object.java:218)
07:05:57  	at java.util.TimerThread.mainLoop(Timer.java:552)
07:05:57  	- locked java.util.TaskQueue@c26f2ea4
07:05:57  	at java.util.TimerThread.run(Timer.java:505)
07:05:57  
07:05:57  "Attachment 40994" Id=309 RUNNABLE
07:05:57  	at openj9.internal.tools.attach.target.DiagnosticUtils.dumpAllThreadsImpl(Native Method)
07:05:57  	at openj9.internal.tools.attach.target.DiagnosticUtils.getThreadInfo(DiagnosticUtils.java:233)
07:05:57  	at openj9.internal.tools.attach.target.DiagnosticUtils$$Lambda$4/0000000000000000.apply(Unknown Source)
07:05:57  	at openj9.internal.tools.attach.target.DiagnosticUtils.executeDiagnosticCommand(DiagnosticUtils.java:169)
07:05:57  	at openj9.internal.tools.attach.target.Attachment.doCommand(Attachment.java:239)
07:05:57  	at openj9.internal.tools.attach.target.Attachment.run(Attachment.java:150)
07:05:57  
07:05:57  
07:05:57  --- Timeout information end.
@pshipton
Copy link
Member Author

https://ci.eclipse.org/openj9/job/Test_openjdk8_j9_sanity.openjdk_x86-64_linux_Nightly/179

@pshipton
Copy link
Member Author

https://ci.eclipse.org/openj9/job/Test_openjdk8_j9_sanity.openjdk_x86-64_linux_Nightly/301/

06:57:27  Timeout refired 28800 times
06:57:27  Timeout information:
06:57:27  Running jcmd on process 3006
06:57:27  Dump written to /home/jenkins/workspace/Test_openjdk8_j9_sanity.openjdk_x86-64_linux_Nightly/openjdk-tests/TKG/test_output_1611459763482/jdk_util_j9_0/work/scratch/1/core.20210124.075710.3006.0001.dmp
06:57:27  Running jstack on process 3006
06:57:27  2021-01-24T07:57:16.780
06:57:27  Virtual machine: 3006 JVM information:
06:57:27  JRE 1.8.0 Linux amd64-64-Bit Compressed References 20210123_637 (JIT enabled, AOT enabled)
06:57:27  OpenJ9   - 899bd1cdf05
06:57:27  OMR      - 4aa961a4ce1
06:57:27  JCL      - 0c150b30331 based on jdk8u282-b08
06:57:27  
06:57:27  "main" Id=1 WAITING
06:57:27  	at java.lang.Object.wait(Native Method)
06:57:27  	at java.lang.Object.wait(Object.java:218)
06:57:27  	at java.lang.Thread.join(Thread.java:703)
06:57:27  	at com.sun.javatest.regtest.agent.MainActionHelper.runClass(MainActionHelper.java:198)
06:57:27  	at com.sun.javatest.regtest.agent.AgentServer.doMain(AgentServer.java:305)
06:57:27  	at com.sun.javatest.regtest.agent.AgentServer.run(AgentServer.java:232)
06:57:27  	at com.sun.javatest.regtest.agent.AgentServer.main(AgentServer.java:69)
06:57:27  
06:57:27  "JIT Compilation Thread-000" Id=2 RUNNABLE
06:57:27  
06:57:27  "JIT Compilation Thread-001 Suspended" Id=3 RUNNABLE
06:57:27  
06:57:27  "JIT Compilation Thread-002 Suspended" Id=4 RUNNABLE
06:57:27  
06:57:27  "JIT Compilation Thread-003 Suspended" Id=5 RUNNABLE
06:57:27  
06:57:27  "JIT Compilation Thread-004 Suspended" Id=6 RUNNABLE
06:57:27  
06:57:27  "JIT Compilation Thread-005 Suspended" Id=7 RUNNABLE
06:57:27  
06:57:27  "JIT Compilation Thread-006 Suspended" Id=8 RUNNABLE
06:57:27  
06:57:27  "JIT Diagnostic Compilation Thread-007 Suspended" Id=9 RUNNABLE
06:57:27  
06:57:27  "JIT-SamplerThread" Id=10 TIMED_WAITING
06:57:27  
06:57:27  "IProfiler" Id=11 RUNNABLE
06:57:27  
06:57:27  "Concurrent Mark Helper" Id=12 RUNNABLE
06:57:27  
06:57:27  "GC Worker" Id=13 RUNNABLE
06:57:27  
06:57:27  "GC Worker" Id=14 RUNNABLE
06:57:27  
06:57:27  "GC Worker" Id=15 RUNNABLE
06:57:27  
06:57:27  "Attach API wait loop" Id=18 TIMED_WAITING
06:57:27  	at java.lang.Thread.sleep(Native Method)
06:57:27  	at java.lang.Thread.sleep(Thread.java:953)
06:57:27  	at openj9.internal.tools.attach.target.WaitLoop.checkReplyAndCreateAttachment(WaitLoop.java:140)
06:57:27  	at openj9.internal.tools.attach.target.WaitLoop.waitForNotification(WaitLoop.java:117)
06:57:27  	at openj9.internal.tools.attach.target.WaitLoop.run(WaitLoop.java:154)
06:57:27  
06:57:27  "Finalizer thread" Id=19 RUNNABLE
06:57:27  
06:57:27  "pool-1-thread-1" Id=20 TIMED_WAITING
06:57:27  	at sun.misc.Unsafe.park(Native Method)
06:57:27  	at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
06:57:27  	at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
06:57:27  	at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1093)
06:57:27  	at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
06:57:27  	at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074)
06:57:27  	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
06:57:27  	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
06:57:27  	at java.lang.Thread.run(Thread.java:823)
06:57:27  
06:57:27  "ClassCache Reaper" Id=29 WAITING
06:57:27  	at java.lang.Object.wait(Native Method)
06:57:27  	at java.lang.Object.wait(Object.java:218)
06:57:27  	at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:138)
06:57:27  	at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:110)
06:57:27  	at java.io.ClassCache$Reaper.run(ClassCache.java:234)
06:57:27  	at java.lang.Thread.run(Thread.java:823)
06:57:27  
06:57:27  "AgentVMThread" Id=404 WAITING
06:57:27  	at sun.misc.Unsafe.park(Native Method)
06:57:27  	at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
06:57:27  	at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
06:57:27  	at java.util.concurrent.CyclicBarrier.dowait(CyclicBarrier.java:234)
06:57:27  	at java.util.concurrent.CyclicBarrier.await(CyclicBarrier.java:362)
06:57:27  	at ProducerConsumerLoops.oneRun(ProducerConsumerLoops.java:176)
06:57:27  	at ProducerConsumerLoops.oneTest(ProducerConsumerLoops.java:101)
06:57:27  	at ProducerConsumerLoops.main(ProducerConsumerLoops.java:73)
06:57:27  	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
06:57:27  	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
06:57:27  	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
06:57:27  	at java.lang.reflect.Method.invoke(Method.java:498)
06:57:27  	at com.sun.javatest.regtest.agent.MainActionHelper$AgentVMRunnable.run(MainActionHelper.java:312)
06:57:27  	at java.lang.Thread.run(Thread.java:823)
06:57:27  
06:57:27  "pool-4-thread-1" Id=405 RUNNABLE
06:57:27  	at java.util.concurrent.SynchronousQueue$TransferQueue.transfer(SynchronousQueue.java:677)
06:57:27  	at java.util.concurrent.SynchronousQueue.put(SynchronousQueue.java:877)
06:57:27  	at ProducerConsumerLoops$Producer.run(ProducerConsumerLoops.java:128)
06:57:27  	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
06:57:27  	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
06:57:27  	at java.lang.Thread.run(Thread.java:823)
06:57:27  
06:57:27  "file lock watchdog" Id=408 TIMED_WAITING
06:57:27  	at java.lang.Object.wait(Native Method)
06:57:27  	at java.lang.Object.wait(Object.java:218)
06:57:27  	at java.util.TimerThread.mainLoop(Timer.java:552)
06:57:27  	at java.util.TimerThread.run(Timer.java:505)
06:57:27  
06:57:27  "Attachment 41817" Id=409 RUNNABLE
06:57:27  	at openj9.internal.tools.attach.target.DiagnosticUtils.dumpAllThreadsImpl(Native Method)
06:57:27  	at openj9.internal.tools.attach.target.DiagnosticUtils.getThreadInfo(DiagnosticUtils.java:245)
06:57:27  	at openj9.internal.tools.attach.target.DiagnosticUtils$$Lambda$4/0x0000000000000000.apply(Unknown Source)
06:57:27  	at openj9.internal.tools.attach.target.DiagnosticUtils.executeDiagnosticCommand(DiagnosticUtils.java:181)
06:57:27  	at openj9.internal.tools.attach.target.Attachment.doCommand(Attachment.java:239)
06:57:27  	at openj9.internal.tools.attach.target.Attachment.run(Attachment.java:150)
06:57:27  
06:57:27  
06:57:27  --- Timeout information end.

@pshipton
Copy link
Member Author

https://ci.eclipse.org/openj9/job/Test_openjdk8_j9_sanity.openjdk_x86-64_linux_Nightly/356/

07:48:17  Timeout refired 28800 times
07:48:17  Timeout information:
07:48:17  Running jcmd on process 2441
07:48:17  Dump written to /home/jenkins/workspace/Test_openjdk8_j9_sanity.openjdk_x86-64_linux_Nightly/openjdk-tests/TKG/output_16184559163871/jdk_util_1/work/scratch/0/core.20210415.084756.2441.0001.dmp
07:48:17  Running jstack on process 2441
07:48:17  2021-04-15T08:48:02.986
07:48:17  Virtual machine: 2441 JVM information:
07:48:17  JRE 1.8.0 Linux amd64-64-Bit Compressed References 20210414_693 (JIT enabled, AOT enabled)
07:48:17  OpenJ9   - 19fa4dcef01
07:48:17  OMR      - 2ccbf5e8ce2
07:48:17  JCL      - bf7a0585ab0 based on jdk8u292-b09
07:48:17  
07:48:17  "main" Id=1 WAITING
07:48:17  	at java.lang.Object.wait(Native Method)
07:48:17  	at java.lang.Object.wait(Object.java:218)
07:48:17  	at java.lang.Thread.join(Thread.java:701)
07:48:17  	at com.sun.javatest.regtest.agent.MainActionHelper.runClass(MainActionHelper.java:198)
07:48:17  	at com.sun.javatest.regtest.agent.AgentServer.doMain(AgentServer.java:306)
07:48:17  	at com.sun.javatest.regtest.agent.AgentServer.run(AgentServer.java:233)
07:48:17  	at com.sun.javatest.regtest.agent.AgentServer.main(AgentServer.java:70)
07:48:17  
07:48:17  "JIT Compilation Thread-000" Id=2 RUNNABLE
07:48:17  
07:48:17  "JIT Compilation Thread-001 Suspended" Id=3 RUNNABLE
07:48:17  
07:48:17  "JIT Compilation Thread-002 Suspended" Id=4 RUNNABLE
07:48:17  
07:48:17  "JIT Compilation Thread-003 Suspended" Id=5 RUNNABLE
07:48:17  
07:48:17  "JIT Compilation Thread-004 Suspended" Id=6 RUNNABLE
07:48:17  
07:48:17  "JIT Compilation Thread-005 Suspended" Id=7 RUNNABLE
07:48:17  
07:48:17  "JIT Compilation Thread-006 Suspended" Id=8 RUNNABLE
07:48:17  
07:48:17  "JIT Diagnostic Compilation Thread-007 Suspended" Id=9 RUNNABLE
07:48:17  
07:48:17  "JIT-SamplerThread" Id=10 TIMED_WAITING
07:48:17  
07:48:17  "IProfiler" Id=11 RUNNABLE
07:48:17  
07:48:17  "Concurrent Mark Helper" Id=12 RUNNABLE
07:48:17  
07:48:17  "GC Worker" Id=13 RUNNABLE
07:48:17  
07:48:17  "GC Worker" Id=14 RUNNABLE
07:48:17  
07:48:17  "GC Worker" Id=15 RUNNABLE
07:48:17  
07:48:17  "Attach API wait loop" Id=18 TIMED_WAITING
07:48:17  	at java.lang.Thread.sleep(Native Method)
07:48:17  	at java.lang.Thread.sleep(Thread.java:951)
07:48:17  	at openj9.internal.tools.attach.target.WaitLoop.checkReplyAndCreateAttachment(WaitLoop.java:140)
07:48:17  	at openj9.internal.tools.attach.target.WaitLoop.waitForNotification(WaitLoop.java:117)
07:48:17  	at openj9.internal.tools.attach.target.WaitLoop.run(WaitLoop.java:154)
07:48:17  
07:48:17  "Finalizer thread" Id=19 RUNNABLE
07:48:17  
07:48:17  "pool-1-thread-1" Id=20 TIMED_WAITING
07:48:17  	at sun.misc.Unsafe.park(Native Method)
07:48:17  	at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
07:48:17  	at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
07:48:17  	at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1093)
07:48:17  	at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
07:48:17  	at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074)
07:48:17  	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
07:48:17  	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
07:48:17  	at java.lang.Thread.run(Thread.java:821)
07:48:17  
07:48:17  "ClassCache Reaper" Id=42 WAITING
07:48:17  	at java.lang.Object.wait(Native Method)
07:48:17  	at java.lang.Object.wait(Object.java:218)
07:48:17  	at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:138)
07:48:17  	at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:110)
07:48:17  	at java.io.ClassCache$Reaper.run(ClassCache.java:234)
07:48:17  	at java.lang.Thread.run(Thread.java:821)
07:48:17  
07:48:17  "AgentVMThread" Id=311 WAITING
07:48:17  	at sun.misc.Unsafe.park(Native Method)
07:48:17  	at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
07:48:17  	at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
07:48:17  	at java.util.concurrent.CyclicBarrier.dowait(CyclicBarrier.java:234)
07:48:17  	at java.util.concurrent.CyclicBarrier.await(CyclicBarrier.java:362)
07:48:17  	at ProducerConsumerLoops.oneRun(ProducerConsumerLoops.java:176)
07:48:17  	at ProducerConsumerLoops.oneTest(ProducerConsumerLoops.java:101)
07:48:17  	at ProducerConsumerLoops.main(ProducerConsumerLoops.java:73)
07:48:17  	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
07:48:17  	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
07:48:17  	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
07:48:17  	at java.lang.reflect.Method.invoke(Method.java:498)
07:48:17  	at com.sun.javatest.regtest.agent.MainActionHelper$AgentVMRunnable.run(MainActionHelper.java:312)
07:48:17  	at java.lang.Thread.run(Thread.java:821)
07:48:17  
07:48:17  "pool-4-thread-2" Id=313 WAITING
07:48:17  	at sun.misc.Unsafe.park(Native Method)
07:48:17  	at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
07:48:17  	at java.util.concurrent.SynchronousQueue$TransferQueue.awaitFulfill(SynchronousQueue.java:762)
07:48:17  	at java.util.concurrent.SynchronousQueue$TransferQueue.transfer(SynchronousQueue.java:695)
07:48:17  	at java.util.concurrent.SynchronousQueue.put(SynchronousQueue.java:877)
07:48:17  	at ProducerConsumerLoops$Producer.run(ProducerConsumerLoops.java:128)
07:48:17  	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
07:48:17  	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
07:48:17  	at java.lang.Thread.run(Thread.java:821)
07:48:17  
07:48:17  "file lock watchdog" Id=316 TIMED_WAITING
07:48:17  	at java.lang.Object.wait(Native Method)
07:48:17  	at java.lang.Object.wait(Object.java:218)
07:48:17  	at java.util.TimerThread.mainLoop(Timer.java:552)
07:48:17  	at java.util.TimerThread.run(Timer.java:505)
07:48:17  
07:48:17  "Attachment 45219" Id=318 RUNNABLE
07:48:17  	at openj9.internal.tools.attach.target.DiagnosticUtils.dumpAllThreadsImpl(Native Method)
07:48:17  	at openj9.internal.tools.attach.target.DiagnosticUtils.getThreadInfo(DiagnosticUtils.java:245)
07:48:17  	at openj9.internal.tools.attach.target.DiagnosticUtils$$Lambda$4/0x0000000000000000.apply(Unknown Source)
07:48:17  	at openj9.internal.tools.attach.target.DiagnosticUtils.executeDiagnosticCommand(DiagnosticUtils.java:181)
07:48:17  	at openj9.internal.tools.attach.target.Attachment.doCommand(Attachment.java:239)
07:48:17  	at openj9.internal.tools.attach.target.Attachment.run(Attachment.java:150)
07:48:17  
07:48:17  
07:48:17  --- Timeout information end.

@pshipton
Copy link
Member Author

pshipton commented Nov 2, 2022

https://openj9-jenkins.osuosl.org/job/Test_openjdk8_j9_sanity.openjdk_x86-64_linux_Nightly/394
jdk_util_1
java/util/concurrent/BlockingQueue/ProducerConsumerLoops.java

https://openj9-artifactory.osuosl.org/artifactory/ci-openj9/Test/Test_openjdk8_j9_sanity.openjdk_x86-64_linux_Nightly/394/openjdk_test_output.tar.gz

07:47:20  Running jstack on process 13908
07:47:20  2022-11-02T07:47:10.756
07:47:20  Virtual machine: 13908 JVM information:
07:47:20  JRE 1.8.0 Linux amd64-64-Bit 20221101_417 (JIT enabled, AOT enabled)
07:47:20  OpenJ9   - fd7e4b9
07:47:20  OMR      - 29a6de3
07:47:20  JCL      - c7df71e based on jdk8u352-b08
07:47:20  
07:47:20  "main" Id=1 WAITING
07:47:20  	at java.lang.Object.wait(Native Method)
07:47:20  	at java.lang.Object.wait(Object.java:216)
07:47:20  	at java.lang.Thread.join(Thread.java:753)
07:47:20  	at java.lang.Thread.join(Thread.java:708)
07:47:20  	at com.sun.javatest.regtest.agent.MainActionHelper.runClass(MainActionHelper.java:184)
07:47:20  	at com.sun.javatest.regtest.agent.AgentServer.doMain(AgentServer.java:301)
07:47:20  	at com.sun.javatest.regtest.agent.AgentServer.run(AgentServer.java:232)
07:47:20  	at com.sun.javatest.regtest.agent.AgentServer.main(AgentServer.java:69)
07:47:20  
07:47:20  "JIT Compilation Thread-000" Id=2 RUNNABLE
07:47:20  
07:47:20  "JIT Compilation Thread-001 Suspended" Id=3 RUNNABLE
07:47:20  
07:47:20  "JIT Compilation Thread-002 Suspended" Id=4 RUNNABLE
07:47:20  
07:47:20  "JIT Compilation Thread-003 Suspended" Id=5 RUNNABLE
07:47:20  
07:47:20  "JIT Compilation Thread-004 Suspended" Id=6 RUNNABLE
07:47:20  
07:47:20  "JIT Compilation Thread-005 Suspended" Id=7 RUNNABLE
07:47:20  
07:47:20  "JIT Compilation Thread-006 Suspended" Id=8 RUNNABLE
07:47:20  
07:47:20  "JIT Diagnostic Compilation Thread-007 Suspended" Id=9 RUNNABLE
07:47:20  
07:47:20  "JIT-SamplerThread" Id=10 TIMED_WAITING
07:47:20  
07:47:20  "IProfiler" Id=11 RUNNABLE
07:47:20  
07:47:20  "Concurrent Mark Helper" Id=12 RUNNABLE
07:47:20  
07:47:20  "GC Worker" Id=13 RUNNABLE
07:47:20  
07:47:20  "GC Worker" Id=14 RUNNABLE
07:47:20  
07:47:20  "GC Worker" Id=15 RUNNABLE
07:47:20  
07:47:20  "Attach API wait loop" Id=18 RUNNABLE
07:47:20  	at openj9.internal.tools.attach.target.IPC.waitSemaphore(Native Method)
07:47:20  	at openj9.internal.tools.attach.target.CommonDirectory.waitSemaphore(CommonDirectory.java:264)
07:47:20  	at openj9.internal.tools.attach.target.WaitLoop.waitForNotification(WaitLoop.java:66)
07:47:20  	at openj9.internal.tools.attach.target.WaitLoop.run(WaitLoop.java:157)
07:47:20  
07:47:20  "Finalizer thread" Id=19 RUNNABLE
07:47:20  
07:47:20  "pool-1-thread-1" Id=20 TIMED_WAITING
07:47:20  	at sun.misc.Unsafe.park(Native Method)
07:47:20  	at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
07:47:20  	at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
07:47:20  	at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1093)
07:47:20  	at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
07:47:20  	at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074)
07:47:20  	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
07:47:20  	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
07:47:20  	at java.lang.Thread.run(Thread.java:826)
07:47:20  
07:47:20  "ClassByNameCache Reaper" Id=38 WAITING
07:47:20  	at java.lang.Object.wait(Native Method)
07:47:20  	at java.lang.Object.wait(Object.java:216)
07:47:20  	at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:137)
07:47:20  	at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:109)
07:47:20  	at java.io.ClassByNameCache$Reaper.run(ClassByNameCache.java:233)
07:47:20  	at java.lang.Thread.run(Thread.java:826)
07:47:20  
07:47:20  "AgentVMThread" Id=454 WAITING
07:47:20  	at sun.misc.Unsafe.park(Native Method)
07:47:20  	at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
07:47:20  	at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
07:47:20  	at java.util.concurrent.CyclicBarrier.dowait(CyclicBarrier.java:234)
07:47:20  	at java.util.concurrent.CyclicBarrier.await(CyclicBarrier.java:362)
07:47:20  	at ProducerConsumerLoops.oneRun(ProducerConsumerLoops.java:176)
07:47:20  	at ProducerConsumerLoops.oneTest(ProducerConsumerLoops.java:101)
07:47:20  	at ProducerConsumerLoops.main(ProducerConsumerLoops.java:73)
07:47:20  	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
07:47:20  	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
07:47:20  	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
07:47:20  	at java.lang.reflect.Method.invoke(Method.java:498)
07:47:20  	at com.sun.javatest.regtest.agent.MainActionHelper$AgentVMRunnable.run(MainActionHelper.java:298)
07:47:20  	at java.lang.Thread.run(Thread.java:826)
07:47:20  
07:47:20  "pool-4-thread-1" Id=455 RUNNABLE
07:47:20  	at java.util.concurrent.SynchronousQueue$TransferQueue.transfer(SynchronousQueue.java:676)
07:47:20  	at java.util.concurrent.SynchronousQueue.put(SynchronousQueue.java:877)
07:47:20  	at ProducerConsumerLoops$Producer.run(ProducerConsumerLoops.java:128)
07:47:20  	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
07:47:20  	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
07:47:20  	at java.lang.Thread.run(Thread.java:826)
07:47:20  
07:47:20  "file lock watchdog" Id=459 TIMED_WAITING
07:47:20  	at java.lang.Object.wait(Native Method)
07:47:20  	at java.lang.Object.wait(Object.java:216)
07:47:20  	at java.util.TimerThread.mainLoop(Timer.java:552)
07:47:20  	at java.util.TimerThread.run(Timer.java:505)
07:47:20  
07:47:20  "Attachment portNumber: 44442" Id=461 RUNNABLE
07:47:20  	at openj9.internal.tools.attach.target.DiagnosticUtils.dumpAllThreadsImpl(Native Method)
07:47:20  	at openj9.internal.tools.attach.target.DiagnosticUtils.getThreadInfo(DiagnosticUtils.java:245)
07:47:20  	at openj9.internal.tools.attach.target.DiagnosticUtils.executeDiagnosticCommand(DiagnosticUtils.java:181)
07:47:20  	at openj9.internal.tools.attach.target.Attachment.doCommand(Attachment.java:238)
07:47:20  	at openj9.internal.tools.attach.target.Attachment.run(Attachment.java:149)
07:47:20  
07:47:20  
07:47:20  --- Timeout information end.

@pshipton
Copy link
Member Author

pshipton commented Jan 23, 2023 •
edited

https://openj9-jenkins.osuosl.org/job/Test_openjdk8_j9_sanity.openjdk_x86-64_linux_Release/48 - cent7-x64-4
jdk_util_1
java/util/concurrent/BlockingQueue/MultipleProducersSingleConsumerLoops.java

https://openj9-artifactory.osuosl.org/artifactory/ci-openj9/Test/Test_openjdk8_j9_sanity.openjdk_x86-64_linux_Release/48/openjdk_test_output.tar.gz

05:36:43  ACTION: main -- Error. Agent error: java.lang.Exception: Agent 3 timed out with a timeout of 28800 seconds; check console log for any additional details
05:36:43  REASON: User specified action: run main/timeout=3600 MultipleProducersSingleConsumerLoops 
05:36:43  TIME:   28809.426 seconds
05:36:43  messages:
05:36:43  command: main MultipleProducersSingleConsumerLoops
05:36:43  reason: User specified action: run main/timeout=3600 MultipleProducersSingleConsumerLoops 
05:36:43  Mode: agentvm
05:36:43  Agent id: 3
05:36:43  Timeout refired 28800 times
05:36:43  Timeout information:
05:36:43  Running jcmd on process 23796
05:36:43  Dump written to /home/jenkins/workspace/Test_openjdk8_j9_sanity.openjdk_x86-64_linux_Release/aqa-tests/TKG/output_16743523211966/jdk_util_1/work/scratch/1/core.20230122.063629.23796.0001.dmp
05:36:43  Dump written to /home/jenkins/workspace/Test_openjdk8_j9_sanity.openjdk_x86-64_linux_Release/aqa-tests/TKG/output_16743523211966/jdk_util_1/work/scratch/1/javacore.20230122.063636.23796.0002.txt
05:36:43  Running jstack on process 23796
05:36:43  2023-01-22T06:36:36.936
05:36:43  Virtual machine: 23796 JVM information:
05:36:43  JRE 1.8.0 Linux amd64-64-Bit 20230122_57 (JIT enabled, AOT enabled)
05:36:43  OpenJ9   - e68fb24
05:36:43  OMR      - f491bbf
05:36:43  JCL      - eebde68 based on jdk8u362-b09
05:36:43  
05:36:43  "main" Id=1 WAITING
05:36:43  	at java.lang.Object.waitImpl(Native Method)
05:36:43  	at java.lang.Object.wait(Object.java:248)
05:36:43  	at java.lang.Object.wait(Object.java:216)
05:36:43  	at java.lang.Thread.join(Thread.java:753)
05:36:43  	at java.lang.Thread.join(Thread.java:708)
05:36:43  	at com.sun.javatest.regtest.agent.MainActionHelper.runClass(MainActionHelper.java:184)
05:36:43  	at com.sun.javatest.regtest.agent.AgentServer.doMain(AgentServer.java:301)
05:36:43  	at com.sun.javatest.regtest.agent.AgentServer.run(AgentServer.java:232)
05:36:43  	at com.sun.javatest.regtest.agent.AgentServer.main(AgentServer.java:69)
05:36:43  
05:36:43  "JIT Compilation Thread-000" Id=2 RUNNABLE
05:36:43  
05:36:43  "JIT Compilation Thread-001 Suspended" Id=3 RUNNABLE
05:36:43  
05:36:43  "JIT Compilation Thread-002 Suspended" Id=4 RUNNABLE
05:36:43  
05:36:43  "JIT Compilation Thread-003 Suspended" Id=5 RUNNABLE
05:36:43  
05:36:43  "JIT Compilation Thread-004 Suspended" Id=6 RUNNABLE
05:36:43  
05:36:43  "JIT Compilation Thread-005 Suspended" Id=7 RUNNABLE
05:36:43  
05:36:43  "JIT Compilation Thread-006 Suspended" Id=8 RUNNABLE
05:36:43  
05:36:43  "JIT Diagnostic Compilation Thread-007 Suspended" Id=9 RUNNABLE
05:36:43  
05:36:43  "JIT-SamplerThread" Id=10 TIMED_WAITING
05:36:43  
05:36:43  "IProfiler" Id=11 RUNNABLE
05:36:43  
05:36:43  "Concurrent Mark Helper" Id=12 RUNNABLE
05:36:43  
05:36:43  "GC Worker" Id=13 RUNNABLE
05:36:43  
05:36:43  "GC Worker" Id=14 RUNNABLE
05:36:43  
05:36:43  "GC Worker" Id=15 RUNNABLE
05:36:43  
05:36:43  "Attach API wait loop" Id=18 RUNNABLE
05:36:43  	at openj9.internal.tools.attach.target.IPC.waitSemaphore(Native Method)
05:36:43  	at openj9.internal.tools.attach.target.CommonDirectory.waitSemaphore(CommonDirectory.java:264)
05:36:43  	at openj9.internal.tools.attach.target.WaitLoop.waitForNotification(WaitLoop.java:66)
05:36:43  	at openj9.internal.tools.attach.target.WaitLoop.run(WaitLoop.java:157)
05:36:43  
05:36:43  "Finalizer thread" Id=19 RUNNABLE
05:36:43  
05:36:43  "pool-1-thread-1" Id=20 TIMED_WAITING
05:36:43  	at sun.misc.Unsafe.park(Native Method)
05:36:43  	at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
05:36:43  	at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
05:36:43  	at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1093)
05:36:43  	at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
05:36:43  	at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074)
05:36:43  	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
05:36:43  	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
05:36:43  	at java.lang.Thread.run(Thread.java:826)
05:36:43  
05:36:43  "ClassByNameCache Reaper" Id=29 WAITING
05:36:43  	at java.lang.Object.waitImpl(Native Method)
05:36:43  	at java.lang.Object.wait(Object.java:248)
05:36:43  	at java.lang.Object.wait(Object.java:216)
05:36:43  	at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:137)
05:36:43  	at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:109)
05:36:43  	at java.io.ClassByNameCache$Reaper.run(ClassByNameCache.java:233)
05:36:43  	at java.lang.Thread.run(Thread.java:826)
05:36:43  
05:36:43  "AgentVMThread" Id=443 WAITING
05:36:43  	at sun.misc.Unsafe.park(Native Method)
05:36:43  	at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
05:36:43  	at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
05:36:43  	at java.util.concurrent.CyclicBarrier.dowait(CyclicBarrier.java:234)
05:36:43  	at java.util.concurrent.CyclicBarrier.await(CyclicBarrier.java:362)
05:36:43  	at MultipleProducersSingleConsumerLoops.oneRun(MultipleProducersSingleConsumerLoops.java:178)
05:36:43  	at MultipleProducersSingleConsumerLoops.oneTest(MultipleProducersSingleConsumerLoops.java:104)
05:36:43  	at MultipleProducersSingleConsumerLoops.main(MultipleProducersSingleConsumerLoops.java:73)
05:36:43  	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
05:36:43  	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
05:36:43  	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
05:36:43  	at java.lang.reflect.Method.invoke(Method.java:498)
05:36:43  	at com.sun.javatest.regtest.agent.MainActionHelper$AgentVMRunnable.run(MainActionHelper.java:298)
05:36:43  	at java.lang.Thread.run(Thread.java:826)
05:36:43  
05:36:43  "pool-3-thread-2" Id=445 WAITING
05:36:43  	at sun.misc.Unsafe.park(Native Method)
05:36:43  	at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
05:36:43  	at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:458)
05:36:43  	at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
05:36:43  	at java.util.concurrent.SynchronousQueue.put(SynchronousQueue.java:877)
05:36:43  	at MultipleProducersSingleConsumerLoops$Producer.run(MultipleProducersSingleConsumerLoops.java:132)
05:36:43  	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
05:36:43  	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
05:36:43  	at java.lang.Thread.run(Thread.java:826)
05:36:43  
05:36:43  "file lock watchdog" Id=447 TIMED_WAITING
05:36:43  	at java.lang.Object.waitImpl(Native Method)
05:36:43  	at java.lang.Object.wait(Object.java:248)
05:36:43  	at java.lang.Object.wait(Object.java:216)
05:36:43  	at java.util.TimerThread.mainLoop(Timer.java:552)
05:36:43  	at java.util.TimerThread.run(Timer.java:505)
05:36:43  
05:36:43  "Attachment portNumber: 41556" Id=449 RUNNABLE
05:36:43  	at openj9.internal.tools.attach.target.DiagnosticUtils.dumpAllThreadsImpl(Native Method)
05:36:43  	at openj9.internal.tools.attach.target.DiagnosticUtils.getThreadInfo(DiagnosticUtils.java:245)
05:36:43  	at openj9.internal.tools.attach.target.DiagnosticUtils.executeDiagnosticCommand(DiagnosticUtils.java:181)
05:36:43  	at openj9.internal.tools.attach.target.Attachment.doCommand(Attachment.java:238)
05:36:43  	at openj9.internal.tools.attach.target.Attachment.run(Attachment.java:149)
05:36:43  
05:36:43  
05:36:43  --- Timeout information end.

5x x 5 grinder on jdk_util_1 https://openj9-jenkins.osuosl.org/job/Grinder/1848 - passed

@pshipton
Copy link
Member Author

https://openj9-jenkins.osuosl.org/job/Test_openjdk8_j9_sanity.openjdk_s390x_linux_Release/51/
jdk_util_0
java/util/concurrent/BlockingQueue/ProducerConsumerLoops.java

https://openj9-artifactory.osuosl.org/artifactory/ci-openj9/Test/Test_openjdk8_j9_sanity.openjdk_s390x_linux_Release/51/openjdk_test_output.tar.gz

06:09:31  Timeout refired 28800 times
06:09:31  Timeout information:
06:09:31  Running jcmd on process 3919979
06:09:31  Dump written to /home/jenkins/workspace/Test_openjdk8_j9_sanity.openjdk_s390x_linux_Release/aqa-tests/TKG/output_16779814609821/jdk_util_0/work/scratch/1/core.20230305.100903.3919979.0001.dmp
06:09:31  Dump written to /home/jenkins/workspace/Test_openjdk8_j9_sanity.openjdk_s390x_linux_Release/aqa-tests/TKG/output_16779814609821/jdk_util_0/work/scratch/1/javacore.20230305.100927.3919979.0002.txt
06:09:31  Running jstack on process 3919979
06:09:31  2023-03-05T10:09:29.232
06:09:31  Virtual machine: 3919979 JVM information:
06:09:31  JRE 1.8.0 Linux s390x-64-Bit Compressed References 20230304_65 (JIT enabled, AOT enabled)
06:09:31  OpenJ9   - e8f4c43d31d
06:09:31  OMR      - 4f98adcad48
06:09:31  JCL      - a1cfd8750f3 based on jdk8u372-b03
06:09:31  
06:09:31  "main" Id=1 WAITING
06:09:31  	at java.lang.Object.waitImpl(Native Method)
06:09:31  	at java.lang.Object.wait(Object.java:248)
06:09:31  	at java.lang.Object.wait(Object.java:216)
06:09:31  	at java.lang.Thread.join(Thread.java:753)
06:09:31  	at java.lang.Thread.join(Thread.java:708)
06:09:31  	at com.sun.javatest.regtest.agent.MainActionHelper.runClass(MainActionHelper.java:184)
06:09:31  	at com.sun.javatest.regtest.agent.AgentServer.doMain(AgentServer.java:301)
06:09:31  	at com.sun.javatest.regtest.agent.AgentServer.run(AgentServer.java:232)
06:09:31  	at com.sun.javatest.regtest.agent.AgentServer.main(AgentServer.java:69)
06:09:31  
06:09:31  "JIT Compilation Thread-000" Id=2 RUNNABLE
06:09:31  
06:09:31  "JIT Compilation Thread-001 Suspended" Id=3 RUNNABLE
06:09:31  
06:09:31  "JIT Compilation Thread-002 Suspended" Id=4 RUNNABLE
06:09:31  
06:09:31  "JIT Compilation Thread-003 Suspended" Id=5 RUNNABLE
06:09:31  
06:09:31  "JIT Compilation Thread-004 Suspended" Id=6 RUNNABLE
06:09:31  
06:09:31  "JIT Compilation Thread-005 Suspended" Id=7 RUNNABLE
06:09:31  
06:09:31  "JIT Compilation Thread-006 Suspended" Id=8 RUNNABLE
06:09:31  
06:09:31  "JIT Diagnostic Compilation Thread-007 Suspended" Id=9 RUNNABLE
06:09:31  
06:09:31  "JIT-SamplerThread" Id=10 TIMED_WAITING
06:09:31  
06:09:31  "IProfiler" Id=11 RUNNABLE
06:09:31  
06:09:31  "Concurrent Mark Helper" Id=12 RUNNABLE
06:09:31  
06:09:31  "GC Worker" Id=13 RUNNABLE
06:09:31  
06:09:31  "GC Worker" Id=14 RUNNABLE
06:09:31  
06:09:31  "GC Worker" Id=15 RUNNABLE
06:09:31  
06:09:31  "Attach API wait loop" Id=18 RUNNABLE
06:09:31  	at openj9.internal.tools.attach.target.IPC.waitSemaphore(Native Method)
06:09:31  	at openj9.internal.tools.attach.target.CommonDirectory.waitSemaphore(CommonDirectory.java:264)
06:09:31  	at openj9.internal.tools.attach.target.WaitLoop.waitForNotification(WaitLoop.java:66)
06:09:31  	at openj9.internal.tools.attach.target.WaitLoop.run(WaitLoop.java:157)
06:09:31  
06:09:31  "Finalizer thread" Id=19 RUNNABLE
06:09:31  
06:09:31  "pool-1-thread-1" Id=20 TIMED_WAITING
06:09:31  	at sun.misc.Unsafe.park(Native Method)
06:09:31  	at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
06:09:31  	at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
06:09:31  	at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1093)
06:09:31  	at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
06:09:31  	at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074)
06:09:31  	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
06:09:31  	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
06:09:31  	at java.lang.Thread.run(Thread.java:826)
06:09:31  
06:09:31  "ClassByNameCache Reaper" Id=44 WAITING
06:09:31  	at java.lang.Object.waitImpl(Native Method)
06:09:31  	at java.lang.Object.wait(Object.java:248)
06:09:31  	at java.lang.Object.wait(Object.java:216)
06:09:31  	at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:137)
06:09:31  	at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:109)
06:09:31  	at java.io.ClassByNameCache$Reaper.run(ClassByNameCache.java:233)
06:09:31  	at java.lang.Thread.run(Thread.java:826)
06:09:31  
06:09:31  "AgentVMThread" Id=462 WAITING
06:09:31  	at sun.misc.Unsafe.park(Native Method)
06:09:31  	at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
06:09:31  	at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
06:09:31  	at java.util.concurrent.CyclicBarrier.dowait(CyclicBarrier.java:234)
06:09:31  	at java.util.concurrent.CyclicBarrier.await(CyclicBarrier.java:362)
06:09:31  	at ProducerConsumerLoops.oneRun(ProducerConsumerLoops.java:176)
06:09:31  	at ProducerConsumerLoops.oneTest(ProducerConsumerLoops.java:101)
06:09:31  	at ProducerConsumerLoops.main(ProducerConsumerLoops.java:73)
06:09:31  	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
06:09:31  	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
06:09:31  	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
06:09:31  	at java.lang.reflect.Method.invoke(Method.java:498)
06:09:31  	at com.sun.javatest.regtest.agent.MainActionHelper$AgentVMRunnable.run(MainActionHelper.java:298)
06:09:31  	at java.lang.Thread.run(Thread.java:826)
06:09:31  
06:09:31  "pool-3-thread-5" Id=467 RUNNABLE
06:09:31  	at java.util.concurrent.SynchronousQueue$TransferQueue.transfer(SynchronousQueue.java:677)
06:09:31  	at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:438)
06:09:31  	at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
06:09:31  	at java.util.concurrent.SynchronousQueue.put(SynchronousQueue.java:877)
06:09:31  	at ProducerConsumerLoops$Producer.run(ProducerConsumerLoops.java:128)
06:09:31  
06:09:31  "file lock watchdog" Id=469 TIMED_WAITING
06:09:31  	at java.lang.Object.waitImpl(Native Method)
06:09:31  	at java.lang.Object.wait(Object.java:248)
06:09:31  	at java.lang.Object.wait(Object.java:216)
06:09:31  	at java.util.TimerThread.mainLoop(Timer.java:552)
06:09:31  	at java.util.TimerThread.run(Timer.java:505)
06:09:31  
06:09:31  "Attachment portNumber: 39905" Id=471 RUNNABLE
06:09:31  	at openj9.internal.tools.attach.target.DiagnosticUtils.dumpAllThreadsImpl(Native Method)
06:09:31  	at openj9.internal.tools.attach.target.DiagnosticUtils.getThreadInfo(DiagnosticUtils.java:245)
06:09:31  	at openj9.internal.tools.attach.target.DiagnosticUtils.executeDiagnosticCommand(DiagnosticUtils.java:181)
06:09:31  	at openj9.internal.tools.attach.target.Attachment.doCommand(Attachment.java:238)
06:09:31  	at openj9.internal.tools.attach.target.Attachment.run(Attachment.java:149)
06:09:31  
06:09:31  
06:09:31  --- Timeout information end.

@JasonFengJ9
Copy link
Member

JDK8 FIPS x86-64_linux 0.38(rhel8x64-fips2-1)

openjdk version "1.8.0_372"
IBM Semeru Runtime Open Edition (build 1.8.0_372-b07)
Eclipse OpenJ9 VM (build v0.38.0-release-d57d05932, JRE 1.8.0 Linux amd64-64-Bit Compressed References 20230504_650 (JIT enabled, AOT enabled)
OpenJ9   - d57d05932
OMR      - 855813495
JCL      - dd0ccb1fb5 based on jdk8u372-b07)

[2023-05-04T18:42:34.049Z] variation: -Xdump:system:none -Xdump:heap:none -Xdump:system:events=gpf+abort+traceassert+corruptcache Mode650
[2023-05-04T18:42:34.049Z] JVM_OPTIONS:  -Xdump:system:none -Xdump:heap:none -Xdump:system:events=gpf+abort+traceassert+corruptcache -XX:-UseCompressedOops  -Dsemeru.fips=true

[2023-05-05T02:43:35.472Z] TEST: java/util/concurrent/BlockingQueue/MultipleProducersSingleConsumerLoops.java

[2023-05-05T02:43:35.474Z] TEST RESULT: Error. Agent error: java.lang.Exception: Agent 4 timed out with a timeout of 28800 seconds; check console log for any additional details
[2023-05-05T02:43:35.474Z] --------------------------------------------------
[2023-05-05T02:43:35.474Z] Test results: passed: 650; error: 1
[2023-05-05T02:43:35.984Z] Report written to /home/jenkins/workspace/Test_openjdk8_j9_sanity.openjdk_x86-64_linux_fips_testList_0/aqa-tests/TKG/output_1683225409109/jdk_util_1/report/html/report.html
[2023-05-05T02:43:35.984Z] Results written to /home/jenkins/workspace/Test_openjdk8_j9_sanity.openjdk_x86-64_linux_fips_testList_0/aqa-tests/TKG/output_1683225409109/jdk_util_1/work
[2023-05-05T02:43:35.984Z] Error: Some tests failed or other problems occurred.
[2023-05-05T02:43:35.985Z] -----------------------------------
[2023-05-05T02:43:35.985Z] jdk_util_1_FAILED

@jdmpapin jdmpapin mentioned this issue Sep 7, 2023
Merged
@hzongaro
Copy link
Member

Moving this to the backlog for now, rather than moving it from release to release.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
comp:jit prio:medium test failure
Projects
None yet
Milestone
Backlog
Development

No branches or pull requests
4 participants
@0xdaryl @JasonFengJ9 @pshipton @hzongaro