eclipse-openj9 / openj9

Eclipse OpenJ9: A Java Virtual Machine for OpenJDK that's optimized for small footprint, fast start-up, and high throughput. Builds on Eclipse OMR (https://github.com/eclipse/omr) and combines with the Extensions for OpenJDK for OpenJ9 repo.
Other
3.29k stars 722 forks source link

AIX SharedClasses.SCM23.MultiThreadMultiCL hang #16073

Open pshipton opened 2 years ago

pshipton commented 2 years ago

https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly_testList_2/371 SharedClasses.SCM23.MultiThreadMultiCL_1

https://openj9-artifactory.osuosl.org/artifactory/ci-openj9/Test/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly_testList_2/371/system_test_output.tar.gz

STF 10:28:08.040 - **FAILED** Process MTM1 has timed out

5.MTM1.stdout

...
08:28:54 >> Loaded 6000 classes...
08:28:54 >> --> Threads 6000 to 6120 <--
08:28:54 >> --> Threads 6120 to 6240 <--
08:28:55 >> --> Threads 6240 to 6360 <--
08:28:55 >> --> Threads 6360 to 6480 <--
08:28:56 >> --> Threads 6480 to 6600 <--

5.MTM1.stderr

JVMDUMP039I Processing dump event "user", detail "" at 2022/10/07 10:28:08 - please wait.
JVMDUMP032I JVM requested System dump using '/home/jenkins/workspace/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly_testList_2/aqa-tests/TKG/output_1665127274126/SharedClasses.SCM23.MultiThreadMultiCL_1/20221007-082803-SharedClasses/results/core.20221007.102808.20775324.0001.dmp' in response to an event

From the core file the most interesting thread is:

  thread id: 78054021
   registers:
    cr     = 0x0000000000000000   ctr    = 0x0000000000000000   fpscr  = 0x0000000000000000   gpr0   = 0x0000000000000000
    gpr1   = 0x00000100259f99e0   gpr10  = 0x0000000000000000   gpr11  = 0x0000000000000000   gpr12  = 0x0000000000000000
    gpr13  = 0x0000000000000000   gpr14  = 0x0000000000000000   gpr15  = 0x0000000000000000   gpr16  = 0x0000000000000000
    gpr17  = 0x0000000000000000   gpr18  = 0x0000000000000000   gpr19  = 0x0000000000000000   gpr2   = 0x0000000000000000
    gpr20  = 0x0000000000000000   gpr21  = 0x0000000000000000   gpr22  = 0x0000000000000000   gpr23  = 0x0000000000000000
    gpr24  = 0x0000000000000000   gpr25  = 0x0000000000000000   gpr26  = 0x0000000000000000   gpr27  = 0x0000000000000000
    gpr28  = 0x0000000000000000   gpr29  = 0x0000000000000000   gpr3   = 0x0000000000000000   gpr30  = 0x0000000000000000
    gpr31  = 0x0000000000000000   gpr4   = 0x0000000000000000   gpr5   = 0x0000000000000000   gpr6   = 0x0000000000000000
    gpr7   = 0x0000000000000000   gpr8   = 0x0000000000000000   gpr9   = 0x0000000000000000   iar    = 0x0000000000000000
    lr     = 0x0000000000000000   msr    = 0x0000000000000000   xer    = 0x0000000000000000
   native stack sections:
    0x10010000000 to 0x1002b5fc1e0 (length 0x1b5fc1e0)
   native stack frames:
   properties:
    current effective priority=0     current/last signal taken=0
    processor on which I'm bound=0   processor usage=ffff0002
    scheduling policy=52             suspend count=1
    thread flags=8410404             thread state=5
    type of thread wait=1            wait channel=0
   associated Java thread: 
    name:          Thread-6496
    Thread object: java/lang/Thread @ 0x7fe648348
    Native info:   !j9vmthread 0x30255000  !stack 0x30255000
    Daemon:        false
    ID:            6526 (0x197e)
    Priority:      5
    Thread.State:  WAITING 
    JVMTI state:   ALIVE WAITING WAITING_INDEFINITELY IN_OBJECT_WAIT 
      waiting to be notified on: "Unknown monitor name" with ID 0x100237f3ef8 owner name: <unowned>
    Java stack frames: <no frames to print>
pshipton commented 2 years ago

@tajila fyi, this is new.

pshipton commented 1 year ago

https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly_testList_2/514 SharedClasses.SCM23.MultiThreadMultiCL_1

https://openj9-artifactory.osuosl.org/artifactory/ci-openj9/Test/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly_testList_2/514/system_test_output.tar.gz

STF 12:02:41.106 - Heartbeat: Process MTM4 is still running
STF 12:07:38.495 - **FAILED** Process MTM4 has timed out
STF 12:07:38.496 - Collecting dumps for: MTM4
native threads for address space
 process id: 20709882

  thread id: 118620669
   registers:
    cr     = 0x0000000000000000   ctr    = 0x0000000000000000   fpscr  = 0x0000000000000000   gpr0   = 0x0000000000000000
    gpr1   = 0x00000100270109f0   gpr10  = 0x0000000000000000   gpr11  = 0x0000000000000000   gpr12  = 0x0000000000000000
    gpr13  = 0x0000000000000000   gpr14  = 0x0000000000000000   gpr15  = 0x0000000000000000   gpr16  = 0x0000000000000000
    gpr17  = 0x0000000000000000   gpr18  = 0x0000000000000000   gpr19  = 0x0000000000000000   gpr2   = 0x0000000000000000
    gpr20  = 0x0000000000000000   gpr21  = 0x0000000000000000   gpr22  = 0x0000000000000000   gpr23  = 0x0000000000000000
    gpr24  = 0x0000000000000000   gpr25  = 0x0000000000000000   gpr26  = 0x0000000000000000   gpr27  = 0x0000000000000000
    gpr28  = 0x0000000000000000   gpr29  = 0x0000000000000000   gpr3   = 0x0000000000000000   gpr30  = 0x0000000000000000
    gpr31  = 0x0000000000000000   gpr4   = 0x0000000000000000   gpr5   = 0x0000000000000000   gpr6   = 0x0000000000000000
    gpr7   = 0x0000000000000000   gpr8   = 0x0000000000000000   gpr9   = 0x0000000000000000   iar    = 0x0000000000000000
    lr     = 0x0000000000000000   msr    = 0x0000000000000000   xer    = 0x0000000000000000
   native stack sections:
    0x10010000000 to 0x1002a10bd60 (length 0x1a10bd60)
   native stack frames:
   properties:
    current effective priority=0     current/last signal taken=0
    processor on which I'm bound=0   processor usage=ffff0004
    scheduling policy=52             suspend count=1
    thread flags=8410404             thread state=5
    type of thread wait=1            wait channel=0
   associated Java thread: 
    name:          Thread-1974
    Thread object: java/lang/Thread @ 0x7ff290f40
    Native info:   !j9vmthread 0x3040d800  !stack 0x3040d800
    Daemon:        false
    ID:            2007 (0x7d7)
    Priority:      5
    Thread.State:  WAITING 
    JVMTI state:   ALIVE WAITING WAITING_INDEFINITELY IN_OBJECT_WAIT 
      waiting to be notified on: "Unknown monitor name" with ID 0x1002722fff8 owner name: <unowned>
    Java stack frames: <no frames to print>
pshipton commented 1 year ago

@tajila fyi

pshipton commented 6 months ago

https://openj9-jenkins.osuosl.org/job/Test_openjdk8_j9_extended.system_ppc64_aix_Nightly_testList_2/784 SharedClasses.SCM23.MultiThreadMultiCL_1

https://openj9-artifactory.osuosl.org/artifactory/ci-openj9/Test/Test_openjdk8_j9_extended.system_ppc64_aix_Nightly_testList_2/784/system_test_output.tar.gz

03:17:56  MTM1 07:04:35 >> --> Threads 120 to 240 <--

05:18:01  STF 09:04:34.075 - **FAILED** Process MTM1 has timed out
  thread id: 107873249                                                                                                     registers:                                                                                                               cr     = 0x0000000000000000   ctr    = 0x0000000000000000   fpscr  = 0x0000000000000000   gpr0   = 0x0000000000000000
    gpr1   = 0x00000100245879f0   gpr10  = 0x0000000000000000   gpr11  = 0x0000000000000000   gpr12  = 0x0000000000000000
    gpr13  = 0x0000000000000000   gpr14  = 0x0000000000000000   gpr15  = 0x0000000000000000   gpr16  = 0x0000000000000000
    gpr17  = 0x0000000000000000   gpr18  = 0x0000000000000000   gpr19  = 0x0000000000000000   gpr2   = 0x0000000000000000
    gpr20  = 0x0000000000000000   gpr21  = 0x0000000000000000   gpr22  = 0x0000000000000000   gpr23  = 0x0000000000000000
    gpr24  = 0x0000000000000000   gpr25  = 0x0000000000000000   gpr26  = 0x0000000000000000   gpr27  = 0x0000000000000000
    gpr28  = 0x0000000000000000   gpr29  = 0x0000000000000000   gpr3   = 0x0000000000000000   gpr30  = 0x0000000000000000
    gpr31  = 0x0000000000000000   gpr4   = 0x0000000000000000   gpr5   = 0x0000000000000000   gpr6   = 0x0000000000000000
    gpr7   = 0x0000000000000000   gpr8   = 0x0000000000000000   gpr9   = 0x0000000000000000   iar    = 0x0000000000000000
    lr     = 0x0000000000000000   msr    = 0x0000000000000000   xer    = 0x0000000000000000
   native stack sections:
    0x10010000000 to 0x100285e35a0 (length 0x185e35a0)
   native stack frames:
   properties:
    current effective priority=0     current/last signal taken=0
    processor on which I'm bound=0   processor usage=ffff0001
    scheduling policy=52             suspend count=1
    thread flags=8410404             thread state=5
    type of thread wait=1            wait channel=0
   associated Java thread:
    name:          Thread-225
    Thread object: java/lang/Thread @ 0x6201c37b8
    Native info:   !j9vmthread 0x301d3a00  !stack 0x301d3a00
    Daemon:        false
    ID:            258 (0x102)
    Priority:      5
    Thread.State:  WAITING
    JVMTI state:   ALIVE WAITING WAITING_INDEFINITELY IN_OBJECT_WAIT
      waiting to be notified on: "Unknown monitor name" with ID 0x10023c8e940 owner name: <unowned>
    Java stack frames: <no frames to print>
id: 0x10023c8e940 name: Unknown monitor name
        waiting thread id: 107873249 name: Thread-225