search

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.27k stars 720 forks source link

JDK11 0.27.1 ClassLoadingTest_special_5m_20 j9mm.107 ASSERTION FAILED #13453

Open llxia opened 3 years ago

llxia commented 3 years ago

This was detected on AIX power10 (p10aix009.rtp.raleigh.ibm.com). Internal job cmd_test/213

===============================================
Running test ClassLoadingTest_special_5m_20 ...
===============================================
ClassLoadingTest_special_5m_20 Start Time: Fri Sep  3 14:26:20 2021 Epoch Time (ms): 1630693580013
"/home/jenkins/workspace/Grinder/openjdkbinary/j2sdk-image/bin/java" -Xshareclasses:destroyAll; "/home/jenkins/workspace/Grinder/openjdkbinary/j2sdk-image/bin/java" -Xshareclasses:groupAccess,destroyAll; echo "cache cleanup done";
JVMSHRC005I No shared class caches available
JVMSHRC005I No shared class caches available
cache cleanup done
variation: Mode614
JVM_OPTIONS:  -Xcompressedrefs -Xgcpolicy:gencon -Xjit:counts=- - - - - - 1 1 1 1000 250 250 - - - 10000 100000 10000,gcOnResolve,rtResolve,sampleInterval=2,scorchingSampleThreshold=10000,quickProfile -Xmn512k -Xcheck:gc:vmthreads:all:quiet -XX:+PortableSharedCache
{ itercnt=1; \
mkdir -p "/home/jenkins/workspace/Grinder/aqa-tests/TKG/../TKG/output_16306104143228/ClassLoadingTest_special_5m_20"; \
cd "/home/jenkins/workspace/Grinder/aqa-tests/TKG/../TKG/output_16306104143228/ClassLoadingTest_special_5m_20"; \
perl /home/jenkins/workspace/Grinder/aqa-tests/TKG/../../jvmtest/system/otherLoadTest/..//stf/stf.core/scripts/stf.pl -test-root="/home/jenkins/workspace/Grinder/aqa-tests/TKG/../../jvmtest/system/otherLoadTest/..//stf;/home/jenkins/workspace/Grinder/aqa-tests/TKG/../../jvmtest/system/otherLoadTest/..//aqa-systemtest;/home/jenkins/workspace/Grinder/aqa-tests/TKG/../../jvmtest/system/otherLoadTest/..//openj9-systemtest" -systemtest-prereqs="/home/jenkins/workspace/Grinder/aqa-tests/TKG/../../jvmtest/system/otherLoadTest/..//systemtest_prereqs" -java-args=' -Xcompressedrefs -Xgcpolicy:gencon -Xjit:counts="- - - - - - 1 1 1 1000 250 250 - - - 10000 100000 10000",gcOnResolve,rtResolve,sampleInterval=2,scorchingSampleThreshold=10000,quickProfile -Xmn512k -Xcheck:gc:vmthreads:all:quiet -XX:+PortableSharedCache' -results-root="/home/jenkins/workspace/Grinder/aqa-tests/TKG/../TKG/output_16306104143228/ClassLoadingTest_special_5m_20" -test=ClassloadingLoadTest -test-args="timeLimit=5m"; \
if [ $? -eq 0 ] ; then echo ""; echo "ClassLoadingTest_special_5m_20""_PASSED"; echo ""; cd /home/jenkins/workspace/Grinder/aqa-tests/TKG/..;  else echo ""; echo "ClassLoadingTest_special_5m_20""_FAILED"; echo ""; fi; } 2>&1 | tee -a "/home/jenkins/workspace/Grinder/aqa-tests/TKG/../TKG/output_16306104143228/TestTargetResult";
STF 14:26:20.232 - =========================   S T F   =========================
systemtest-prereqs has been processed, and set to: /home/jenkins/workspace/Grinder/jvmtest/system/systemtest_prereqsRetrieving amount of free space on drive containing /home/jenkins/workspace/Grinder/aqa-tests/TKG/../TKG/output_16306104143228/ClassLoadingTest_special_5m_20
There is 43291 Mb free
STF 14:26:20.262 - ==================   G E N E R A T I O N   ==================
STF 14:26:20.264 - Checking JVM: /home/jenkins/workspace/Grinder/openjdkbinary/j2sdk-image
STF 14:26:20.264 - Starting process to generate scripts: /home/jenkins/workspace/Grinder/openjdkbinary/j2sdk-image/bin/java  -Dlog4j.skipJansi=true -Djava.system.class.loader=net.adoptopenjdk.stf.runner.StfClassLoader -classpath /home/jenkins/workspace/Grinder/aqa-tests/TKG/../../jvmtest/system/otherLoadTest/..//systemtest_prereqs/log4j/log4j-api.jar:/home/jenkins/workspace/Grinder/aqa-tests/TKG/../../jvmtest/system/otherLoadTest/..//systemtest_prereqs/log4j/log4j-core.jar:/home/jenkins/workspace/Grinder/jvmtest/system/stf/stf.core/scripts/../bin net.adoptopenjdk.stf.runner.StfRunner -properties "/home/jenkins/workspace/Grinder/aqa-tests/TKG/../TKG/output_16306104143228/ClassLoadingTest_special_5m_20/20210903-142620-ClassloadingLoadTest/stf_parameters.properties, , /home/jenkins/workspace/Grinder/jvmtest/system/stf/stf.core/config/stf.properties" -testDir "/home/jenkins/workspace/Grinder/aqa-tests/TKG/../TKG/output_16306104143228/ClassLoadingTest_special_5m_20/20210903-142620-ClassloadingLoadTest"
GEN 14:26:21.862 - Found test. Project: 'openjdk.test.load' class: 'ClassloadingLoadTest.class' Dir: '/home/jenkins/workspace/Grinder/jvmtest/system/aqa-systemtest/openjdk.test.load/bin'
GEN 14:26:21.893 - Found test. Project: 'openjdk.test.load' class: 'net.adoptopenjdk.stf.ClassloadingLoadTest'
GEN Classpath directories used by project 'openjdk.test.load': 
GEN   /home/jenkins/workspace/Grinder/jvmtest/system/aqa-systemtest/openjdk.test.load/bin
GEN   /home/jenkins/workspace/Grinder/jvmtest/system/stf/stf.core/bin
GEN   /home/jenkins/workspace/Grinder/jvmtest/system/stf/stf.load/bin
GEN   /home/jenkins/workspace/Grinder/jvmtest/system/systemtest_prereqs/log4j/log4j-api.jar
GEN   /home/jenkins/workspace/Grinder/jvmtest/system/systemtest_prereqs/log4j/log4j-core.jar
GEN   /home/jenkins/workspace/Grinder/jvmtest/system/systemtest_prereqs/junit/junit.jar
GEN   /home/jenkins/workspace/Grinder/jvmtest/system/systemtest_prereqs/junit/hamcrest-core.jar
GEN 14:26:22.239 - Using Mode NoOptions. Values = ''
GEN 14:26:22.336 - 
GEN 14:26:22.336 - Test command summary:
GEN 14:26:22.337 -   Step  Stage   Command           Description
GEN 14:26:22.337 -  -----+--------+-----------------+------------
GEN 14:26:22.337 -     1  execute  Run java          Run classloading tests
STF 14:26:22.416 - 
STF 14:26:22.416 - Script generation completed
STF 14:26:22.416 - 
STF 14:26:22.417 - 
STF 14:26:22.417 - =======================   S E T U P   =======================
STF 14:26:22.417 - Running setup: perl /home/jenkins/workspace/Grinder/aqa-tests/TKG/../TKG/output_16306104143228/ClassLoadingTest_special_5m_20/20210903-142620-ClassloadingLoadTest/setUp.pl
STF 14:26:22.506 - SETUP stage completed
STF 14:26:22.513 - 
STF 14:26:22.513 - ====================   E X E C U T E -   ====================
STF 14:26:22.513 - Running execute: perl /home/jenkins/workspace/Grinder/aqa-tests/TKG/../TKG/output_16306104143228/ClassLoadingTest_special_5m_20/20210903-142620-ClassloadingLoadTest/execute.pl
STF 14:26:22.600 - 
STF 14:26:22.600 - Java version
STF 14:26:22.600 - Running: /home/jenkins/workspace/Grinder/openjdkbinary/j2sdk-image/bin/java -version
java version "11.0.12" 2021-07-20
IBM Semeru Runtime Certified Edition 11.0.12.1 (build 11.0.12+7)
Eclipse OpenJ9 VM 11.0.12.1 (build openj9-0.27.1, JRE 11 AIX ppc64-64-Bit Compressed References 20210828_134 (JIT enabled, AOT enabled)
OpenJ9   - c8200b180
OMR      - 3965a1655
JCL      - 821ace41e2 based on jdk-11.0.12+7)
STF 14:26:22.805 - 
STF 14:26:22.805 - +------ Step 1 - Run classloading tests
STF 14:26:22.805 - | Run foreground process
STF 14:26:22.805 - |   Program:     /home/jenkins/workspace/Grinder/openjdkbinary/j2sdk-image/bin/java
STF 14:26:22.805 - |   Mnemonic:    CLT
STF 14:26:22.805 - |   Echo:        ECHO_ON
STF 14:26:22.805 - |   Expectation: CLEAN_RUN within 1h5m
STF 14:26:22.805 - |
STF 14:26:22.807 - Running command: /home/jenkins/workspace/Grinder/openjdkbinary/j2sdk-image/bin/java -Djava.classloading.dir=/home/jenkins/workspace/Grinder/jvmtest/system/aqa-systemtest -Djava.version.number=11 --add-modules=java.rmi -Xcompressedrefs -Xgcpolicy:gencon -Xjit:counts="- - - - - - 1 1 1 1000 250 250 - - - 10000 100000 10000",gcOnResolve,rtResolve,sampleInterval=2,scorchingSampleThreshold=10000,quickProfile -Xmn512k -Xcheck:gc:vmthreads:all:quiet -XX:+PortableSharedCache -classpath /home/jenkins/workspace/Grinder/jvmtest/system/stf/stf.load/bin:/home/jenkins/workspace/Grinder/jvmtest/system/stf/stf.core/bin:/home/jenkins/workspace/Grinder/jvmtest/system/systemtest_prereqs/log4j/log4j-api.jar:/home/jenkins/workspace/Grinder/jvmtest/system/systemtest_prereqs/log4j/log4j-core.jar:/home/jenkins/workspace/Grinder/jvmtest/system/systemtest_prereqs/junit/junit.jar:/home/jenkins/workspace/Grinder/jvmtest/system/systemtest_prereqs/junit/hamcrest-core.jar:/home/jenkins/workspace/Grinder/jvmtest/system/aqa-systemtest/openjdk.test.classloading/bin net.adoptopenjdk.loadTest.LoadTest -resultsDir /home/jenkins/workspace/Grinder/aqa-tests/TKG/output_16306104143228/ClassLoadingTest_special_5m_20/20210903-142620-ClassloadingLoadTest/results -resultsPrefix 1.CLT. -timeLimit 5m -abortIfOutOfMemory false -reportFailureLimit 1 -abortAtFailureLimit 10 -maxTotalLogFileSpace 200M -maxSingleLogSize 1/25 -suite.classloading.threadCount 31 -suite.classloading.inventoryFile /home/jenkins/workspace/Grinder/aqa-tests/TKG/output_16306104143228/ClassLoadingTest_special_5m_20/20210903-142620-ClassloadingLoadTest/results/1.CLT.inventory/openjdk.test.load/config/inventories/classloading/classloading.xml -suite.classloading.inventoryExcludeFile none -suite.classloading.selection random -suite.classloading.seed -1 -suite.classloading.repeatCount 1 -suite.classloading.thinkingTime 0ms..0ms
STF 14:26:22.807 - Redirecting stderr to /home/jenkins/workspace/Grinder/aqa-tests/TKG/output_16306104143228/ClassLoadingTest_special_5m_20/20210903-142620-ClassloadingLoadTest/results/1.CLT.stderr
STF 14:26:22.807 - Redirecting stdout to /home/jenkins/workspace/Grinder/aqa-tests/TKG/output_16306104143228/ClassLoadingTest_special_5m_20/20210903-142620-ClassloadingLoadTest/results/1.CLT.stdout
STF 14:26:22.838 - Monitoring processes: CLT
CLT 14:26:27.603 - Load test parameters
CLT 14:26:27.620 -   Time limited         = true
CLT 14:26:27.631 -   Time limit         = 5m
CLT 14:26:27.632 -   abortIfOutOfMemory   = false
CLT 14:26:27.632 -   reportFailureLimit   = 1
CLT 14:26:27.632 -   abortAtFailureLimit  = 10
CLT 14:26:27.634 -   maxTotalLogFileSpace = 209715200
CLT 14:26:27.634 -   maxSingleLogSize     = 8388608
CLT 14:26:27.634 - Parameters for suite 0
CLT 14:26:27.634 -   Suite name     = classloading
CLT 14:26:27.635 -   Number threads = 31
CLT 14:26:27.635 -   Supplied seed  = -1
CLT 14:26:27.635 -   Inventory file = /home/jenkins/workspace/Grinder/aqa-tests/TKG/output_16306104143228/ClassLoadingTest_special_5m_20/20210903-142620-ClassloadingLoadTest/results/1.CLT.inventory/openjdk.test.load/config/inventories/classloading/classloading.xml
CLT 14:26:27.636 -   Exclude file   = none
CLT 14:26:27.637 -   Number tests   = -1
CLT 14:26:27.637 -   Repeat count   = 1
CLT 14:26:27.637 -   Thinking time  = 0ms..0ms
CLT 14:26:27.637 -   Selection mode = random
CLT 14:26:27.638 -   Actual seed    = 1629447464995
CLT 14:26:27.686 - Parsing inventory file. Root=/home/jenkins/workspace/Grinder/aqa-tests/TKG/output_16306104143228/ClassLoadingTest_special_5m_20/20210903-142620-ClassloadingLoadTest/results/1.CLT.inventory File=openjdk.test.load/config/inventories/classloading/classloading.xml
CLT 14:26:27.930 - Final test list:
CLT 14:26:27.933 -   0 ArbitraryJava[net.adoptopenjdk.test.classloading.deadlock.DeadlockTest runTest]  Weighting=1 
CLT 14:26:27.933 -   1 ArbitraryJava[net.adoptopenjdk.test.classloading.ClassMapHog run]  Weighting=1 
CLT 14:26:27.933 -   2 ArbitraryJava[net.adoptopenjdk.test.classloading.ClassHog run]  Weighting=1 
CLT 14:26:29.139 - Starting thread. Suite=0 thread=0
CLT 14:26:29.225 - Starting thread. Suite=0 thread=1
CLT 14:26:29.226 - Starting thread. Suite=0 thread=2
CLT 14:26:29.226 - Starting thread. Suite=0 thread=3
CLT 14:26:29.237 - Starting thread. Suite=0 thread=4
CLT 14:26:29.258 - Starting thread. Suite=0 thread=5
CLT 14:26:29.260 - Starting thread. Suite=0 thread=6
CLT 14:26:29.317 - Starting thread. Suite=0 thread=7
CLT 14:26:29.317 - Starting thread. Suite=0 thread=8
CLT 14:26:29.318 - Starting thread. Suite=0 thread=9
CLT 14:26:29.318 - Starting thread. Suite=0 thread=10
CLT 14:26:29.318 - Starting thread. Suite=0 thread=11
CLT 14:26:29.320 - Starting thread. Suite=0 thread=12
CLT 14:26:29.370 - Starting thread. Suite=0 thread=13
CLT 14:26:29.457 - Starting thread. Suite=0 thread=14
CLT 14:26:29.482 - Starting thread. Suite=0 thread=15
CLT 14:26:29.482 - Starting thread. Suite=0 thread=16
CLT 14:26:29.482 - Starting thread. Suite=0 thread=17
CLT 14:26:29.518 - Starting thread. Suite=0 thread=18
CLT 14:26:29.518 - Starting thread. Suite=0 thread=19
CLT 14:26:29.518 - Starting thread. Suite=0 thread=20
CLT 14:26:29.519 - Starting thread. Suite=0 thread=21
CLT 14:26:29.519 - Starting thread. Suite=0 thread=22
CLT 14:26:29.546 - Starting thread. Suite=0 thread=23
CLT 14:26:29.589 - Starting thread. Suite=0 thread=24
CLT 14:26:29.589 - Starting thread. Suite=0 thread=25
CLT 14:26:29.590 - Starting thread. Suite=0 thread=26
CLT 14:26:29.591 - Starting thread. Suite=0 thread=27
CLT 14:26:29.594 - Starting thread. Suite=0 thread=28
CLT 14:26:29.600 - Starting thread. Suite=0 thread=29
CLT 14:26:29.601 - Starting thread. Suite=0 thread=30
CLT 14:26:49.046 - Completed 6.7%. Number of tests started=381
CLT 14:27:09.090 - Completed 13.4%. Number of tests started=745 (+364)
CLT 14:27:29.017 - Completed 20.1%. Number of tests started=1127 (+382)
CLT 14:27:49.013 - Completed 26.8%. Number of tests started=1499 (+372)
CLT 14:28:09.071 - Completed 33.5%. Number of tests started=1897 (+398)
CLT 14:28:29.044 - Completed 40.2%. Number of tests started=2239 (+342)
CLT 14:28:49.008 - Completed 46.9%. Number of tests started=2594 (+355)
CLT 14:29:09.005 - Completed 53.6%. Number of tests started=2989 (+395)
CLT 14:29:29.008 - Completed 60.3%. Number of tests started=3382 (+393)
CLT 14:29:49.019 - Completed 67.0%. Number of tests started=3812 (+430)
CLT 14:30:09.028 - Completed 73.7%. Number of tests started=4204 (+392)
CLT stderr 18:30:09.153 0x30573900    j9mm.107    *   ** ASSERTION FAILED ** at /home/jenkins/workspace/build-scripts/jobs/jdk11u/jdk11u-aix-ppc64-openj9-IBM/workspace/build/src/openj9/runtime/gc_glue_java/MarkingDelegate.hpp:121: ((false && ((UDATA)0x99669966 == clazz->eyecatcher)))
CLT stderr JVMDUMP039I Processing dump event "traceassert", detail "" at 2021/09/03 14:30:09 - please wait.
CLT stderr JVMDUMP032I JVM requested System dump using '/home/jenkins/workspace/Grinder/aqa-tests/TKG/output_16306104143228/ClassLoadingTest_special_5m_20/20210903-142620-ClassloadingLoadTest/results/core.20210903.143009.12386584.0001.dmp' in response to an event
STF 14:30:11.131 - Found dump at: /home/jenkins/workspace/Grinder/aqa-tests/TKG/output_16306104143228/ClassLoadingTest_special_5m_20/20210903-142620-ClassloadingLoadTest/results/core.20210903.143009.12386584.0001.dmp
CLT stderr core file generated - /home/jenkins/workspace/Grinder/aqa-tests/TKG/output_16306104143228/ClassLoadingTest_special_5m_20/20210903-142620-ClassloadingLoadTest/results/core.20210903.143009.12386584.0001.dmp
STF 14:31:23.756 - Heartbeat: Process CLT is still running
CLT stderr JVMDUMP010I System dump written to /home/jenkins/workspace/Grinder/aqa-tests/TKG/output_16306104143228/ClassLoadingTest_special_5m_20/20210903-142620-ClassloadingLoadTest/results/core.20210903.143009.12386584.0001.dmp
CLT stderr JVMDUMP032I JVM requested Java dump using '/home/jenkins/workspace/Grinder/aqa-tests/TKG/output_16306104143228/ClassLoadingTest_special_5m_20/20210903-142620-ClassloadingLoadTest/results/javacore.20210903.143009.12386584.0002.txt' in response to an event
CLT stderr JVMDUMP010I Java dump written to /home/jenkins/workspace/Grinder/aqa-tests/TKG/output_16306104143228/ClassLoadingTest_special_5m_20/20210903-142620-ClassloadingLoadTest/results/javacore.20210903.143009.12386584.0002.txt
CLT stderr JVMDUMP032I JVM requested Snap dump using '/home/jenkins/workspace/Grinder/aqa-tests/TKG/output_16306104143228/ClassLoadingTest_special_5m_20/20210903-142620-ClassloadingLoadTest/results/Snap.20210903.143009.12386584.0003.trc' in response to an event
STF 14:33:44.842 - Found dump at: /home/jenkins/workspace/Grinder/aqa-tests/TKG/output_16306104143228/ClassLoadingTest_special_5m_20/20210903-142620-ClassloadingLoadTest/results/javacore.20210903.143009.12386584.0002.txt
STF 14:33:44.843 - Found dump at: /home/jenkins/workspace/Grinder/aqa-tests/TKG/output_16306104143228/ClassLoadingTest_special_5m_20/20210903-142620-ClassloadingLoadTest/results/Snap.20210903.143009.12386584.0003.trc
CLT stderr javacore file generated - /home/jenkins/workspace/Grinder/aqa-tests/TKG/output_16306104143228/ClassLoadingTest_special_5m_20/20210903-142620-ClassloadingLoadTest/results/javacore.20210903.143009.12386584.0002.txt
CLT stderr Snap file generated - /home/jenkins/workspace/Grinder/aqa-tests/TKG/output_16306104143228/ClassLoadingTest_special_5m_20/20210903-142620-ClassloadingLoadTest/results/Snap.20210903.143009.12386584.0003.trc
CLT stderr JVMDUMP010I Snap dump written to /home/jenkins/workspace/Grinder/aqa-tests/TKG/output_16306104143228/ClassLoadingTest_special_5m_20/20210903-142620-ClassloadingLoadTest/results/Snap.20210903.143009.12386584.0003.trc
CLT stderr JVMDUMP013I Processed dump event "traceassert", detail "".
STF 14:33:46.350 - **FAILED** Process CLT ended with exit code (255) and not the expected exit code/s (0)
llxia commented 3 years ago

FYI @pshipton @zl-wang

pshipton commented 3 years ago

@dmitripivkine fyi

dmitripivkine commented 3 years ago

@llxia I am looking to failed job and don't see link to artefacts. Do we have stored results for this failure?

dmitripivkine commented 3 years ago

Adding JIT label as well for visibility. This is assertion is Marking, so most likely heap consistency problem

llxia commented 3 years ago

p10aix009.rtp.raleigh.ibm.com is not configured properly so we cannot run the test pipeline. We used it for testing 0.27.1 temporarily as it is the only p10 that we have so far. Artifacts are on the p10aix009. I will try to see if I can upload them into the Artifacory server.

dmitripivkine commented 3 years ago

@llxia Thank you, I have files downloaded to /team/Dmitri/13453/

The reason for assertion is a stall pointer in the object:

> !j9object 0x1c2077c28
!J9Object 0x00000001C2077C28 {
    struct J9Class* clazz = !j9class 0x30052100 // java/util/HashMap
    Object flags = 0x00000010;
    I lockword = 0x00000008 (offset = 0) (java/lang/Object) <hidden>
    Ljava/util/Set; keySet = !fj9object 0x0 (offset = 4) (java/util/AbstractMap)
    Ljava/util/Collection; values = !fj9object 0x0 (offset = 8) (java/util/AbstractMap)
    [Ljava/util/HashMap$Node; table = !fj9object 0xffff0e90 (offset = 12) (java/util/HashMap) <--- uncompressed 0x7FFF87480
    Ljava/util/Set; entrySet = !fj9object 0x0 (offset = 16) (java/util/HashMap)
    I size = 0x00000010 (offset = 20) (java/util/HashMap)
    I modCount = 0x00000010 (offset = 24) (java/util/HashMap)
    I threshold = 0x00000018 (offset = 28) (java/util/HashMap)
    F loadFactor = 0x3F400000 (offset = 32) (java/util/HashMap)
}

This object is alive and marked:

> !markmap ismarked 0x1c2077c28
Object 0x00000001C2077C28 is marked

An address 0x7FFF87480 is located in reserved part of the Nursery and contain garbage:

0x7FFF87480 :  00700061 00720061 006d0023 00310000 [ .p.a.r.a.m.#.1.. ]
dmitripivkine commented 3 years ago

@0xdaryl FYI

dmitripivkine commented 3 years ago

Finding root path for this object

> !rootpathfindall 0x1c2077c28

========================================
net/adoptopenjdk/test/classloading/ClassMapHog@0x00000001C3040DA0
  java/util/HashMap@0x00000001C3041170
    java/util/HashMap$Node[]@0x00000001C116CB30 = { 0x0, 0x0, 0x1c3599e40, 0x0, 0x0, 0x1c1219258, 0x0, 0x1c3528620, 0x1c366bc90, 0x0, ...  }
      java/util/HashMap$Node@0x00000001C2077C00
        java/util/HashMap@0x00000001C2077C28

So top object is:

> !j9object 0x00000001C3040DA0
!J9Object 0x00000001C3040DA0 {
    struct J9Class* clazz = !j9class 0x30501B00 // net/adoptopenjdk/test/classloading/ClassMapHog
    Object flags = 0x00000020;
    I lockword = 0x00000008 (offset = 0) (java/lang/Object) <hidden>
    J objCount = 0x0000000000000000 (offset = 4) (net/adoptopenjdk/test/classloading/ClassMapHog)
    Z serialize = 0x00000000 (offset = 20) (net/adoptopenjdk/test/classloading/ClassMapHog)
    Ljava/util/HashMap; hmap = !fj9object 0x3860822e (offset = 12) (net/adoptopenjdk/test/classloading/ClassMapHog)
    I loopCount = 0x00000002 (offset = 24) (net/adoptopenjdk/test/classloading/ClassMapHog)
    Ljava/lang/String; parmlist = !fj9object 0x38066e09 (offset = 16) (net/adoptopenjdk/test/classloading/ClassMapHog)
}

It is referenced from java stack of the thread 0x30555200:

> !threads stackslots | grep -i 1C3040DA0
<30555200>  JIT-Resolve-RegisterMap[0x0000010028E1F828] = UDATA(0x00000001C3040DA0) (jit_r21)
<30555200>      JIT-RegisterMap-I-Slot[0x0000010028E1F828] = UDATA(0x00000001C3040DA0) (jit_r21)
<30555200>  JIT-Frame-RegisterMap[0x0000010028E1F828] = UDATA(0x00000001C3040DA0) (jit_r21)
<30555200>      JIT-RegisterMap-O-Slot[0x0000010028E1F828] = 0x00000001C3040DA0 (jit_r21)

Object is referenced from frame:

<30555200> JIT frame: bp = 0x0000000030566BA8, pc = 0x000001001444B270, unwindSP = 0x0000000030566A40, cp = 0x00000000305011D0, arg0EA = 0x0000000030566BB0, jitInfo = 0x0000010024EADC78
<30555200>  Method: net/adoptopenjdk/test/classloading/ClassMapHog.run()V !j9method 0x0000000030501D00
<30555200>  Bytecode index = 269, inlineDepth = 0, PC offset = 0x00000000000006F4
<30555200>  stackMap=0x0000010024EAE4C8, slots=I16(0x0001) parmBaseOffset=I16(0x0008), parmSlots=U16(0x0001), localBaseOffset=I16(0xFF60)
<30555200>  Described JIT args starting at 0x0000000030566BB0 for U16(0x0001) slots
<30555200>      I-Slot: : a0[0x0000000030566BB0] = 0x00000001C02E54F8
<30555200>  Described JIT temps starting at 0x0000000030566B08 for IDATA(0x0000000000000014) slots
<30555200> Address 0x0000010024EAFD17
<30555200> Num internal ptr map bytes U8(0x05)
<30555200> Address 0x0000010024EAFD18
<30555200> Index of first internal ptr I16(0x0013)
<30555200> Address 0x0000010024EAFD1A
<30555200> Offset of first internal ptr I16(0xFFF0)
<30555200> Address 0x0000010024EAFD1C
<30555200> Num distinct pinning arrays U8(0x02)
<30555200> Before object slot walk &address : 0x0000000030566B98 address : 0x00000001C212CF58 bp 0x0000000030566BA8 offset of first internal ptr I16(0xFFF0)
<30555200> After object slot walk for pinning array with &address : 0x0000000030566B98 old address 0x00000001C212CF58 new address 0x00000001C212CF58 displacement IDATA(0x0000000000000000)
<30555200> For pinning array U8(0x00) num internal pointer stack slots U8(0x00)
<30555200> Before object slot walk &address : 0x0000000030566BA0 address : 0x00000001C212CF70 bp 0x0000000030566BA8 offset of first internal ptr I16(0xFFF0)
<30555200> After object slot walk for pinning array with &address : 0x0000000030566BA0 old address 0x00000001C212CF70 new address 0x00000001C212CF70 displacement IDATA(0x0000000000000000)
<30555200> For pinning array U8(0x01) num internal pointer stack slots U8(0x00)
<30555200>      I-Slot: : t19[0x0000000030566B08] = 0x00000001C0323100
<30555200>      I-Slot: : t18[0x0000000030566B10] = 0x00000001C03230C8
<30555200>      I-Slot: : t17[0x0000000030566B18] = 0x000001001454D638
<30555200>      I-Slot: : t16[0x0000000030566B20] = 0x00000000C0320DE0
<30555200>      I-Slot: : t15[0x0000000030566B28] = 0x0000000900000000
<30555200>      I-Slot: : t14[0x0000000030566B30] = 0x00000000300C6F00
<30555200>      I-Slot: : t13[0x0000000030566B38] = 0x00000001C03230C8
<30555200>      I-Slot: : t12[0x0000000030566B40] = 0x00000001C0323100
<30555200>      O-Slot: : t11[0x0000000030566B48] = 0x00000001C2FF3E20
<30555200>      O-Slot: : t10[0x0000000030566B50] = 0x00000001C212CF88
<30555200>      I-Slot: : t9[0x0000000030566B58] = 0x000000003025DE00
<30555200>      I-Slot: : t8[0x0000000030566B60] = 0x00000001C00EAC18
<30555200>      I-Slot: : t7[0x0000000030566B68] = 0x0000000000000009
<30555200>      I-Slot: : t6[0x0000000030566B70] = 0x00000007FFFAB798
<30555200>      I-Slot: : t5[0x0000000030566B78] = 0x000000003025DE00
<30555200>      I-Slot: : t4[0x0000000030566B80] = 0x00000007FFFAB880
<30555200>      I-Slot: : t3[0x0000000030566B88] = 0x000000003025DE00
<30555200>      I-Slot: : t2[0x0000000030566B90] = 0x00000001C0000AE0
<30555200>      I-Slot: : t1[0x0000000030566B98] = 0x00000001C212CF58
<30555200>      I-Slot: : t0[0x0000000030566BA0] = 0x00000001C212CF70
<30555200>  JIT-RegisterMap = UDATA(0x00000000000066DD)
<30555200>      JIT-RegisterMap-O-Slot[0x0000000030566A18] = 0x00000001C0353478 (jit_r31)
<30555200>      JIT-RegisterMap-I-Slot[0x0000000030566A10] = UDATA(0x0000000000000000) (jit_r30)
<30555200>      JIT-RegisterMap-O-Slot[0x0000010028E1F868] = 0x00000001C03370C0 (jit_r29)
<30555200>      JIT-RegisterMap-O-Slot[0x0000010028E1F860] = 0x00000001C00C11F8 (jit_r28)
<30555200>      JIT-RegisterMap-O-Slot[0x0000010028E1F858] = 0x00000001C2FF3E20 (jit_r27)
<30555200>      JIT-RegisterMap-I-Slot[0x0000010028E1F850] = UDATA(0x000000000000000B) (jit_r26)
<30555200>      JIT-RegisterMap-O-Slot[0x0000010028E1F848] = 0x00000001C212CF88 (jit_r25)
<30555200>      JIT-RegisterMap-O-Slot[0x0000010028E1F840] = 0x00000001C3040D90 (jit_r24)
<30555200>      JIT-RegisterMap-I-Slot[0x0000010028E1F838] = UDATA(0x0000000030504700) (jit_r23)
<30555200>      JIT-RegisterMap-O-Slot[0x0000010028E1F830] = 0x00000001C00EAC18 (jit_r22)
<30555200>      JIT-RegisterMap-O-Slot[0x0000010028E1F828] = 0x00000001C3040DA0 (jit_r21) <-----------------
<30555200>      JIT-RegisterMap-I-Slot[0x0000010028E1F820] = UDATA(0x000000003025DE00) (jit_r20)
<30555200>      JIT-RegisterMap-I-Slot[0x0000010028E1F818] = UDATA(0x000000003025DE00) (jit_r19)
<30555200>      JIT-RegisterMap-O-Slot[0x0000010028E1F810] = 0x00000001C212CF98 (jit_r18)
<30555200>      JIT-RegisterMap-O-Slot[0x0000010028E1F808] = 0x00000001C0960CA8 (jit_r17)
<30555200>      JIT-RegisterMap-I-Slot[0x0000010028E1F800] = UDATA(0x0000000000000001) (jit_r16)
<30555200>  JIT-Frame-RegisterMap[0x0000000030566A70] = UDATA(0x0000000000000000) (jit_r16)
<30555200>  JIT-Frame-RegisterMap[0x0000000030566A78] = UDATA(0xFFFFFFFFFFFFFFFF) (jit_r17)
<30555200>  JIT-Frame-RegisterMap[0x0000000030566A80] = UDATA(0x0000000000000000) (jit_r18)
<30555200>  JIT-Frame-RegisterMap[0x0000000030566A88] = UDATA(0x09001000A09C4DC0) (jit_r19)
<30555200>  JIT-Frame-RegisterMap[0x0000000030566A90] = UDATA(0x0000000000000000) (jit_r20)
<30555200>  JIT-Frame-RegisterMap[0x0000000030566A98] = UDATA(0xCAD2BC9B817F20E4) (jit_r21)
<30555200>  JIT-Frame-RegisterMap[0x0000000030566AA0] = UDATA(0x0000000000000000) (jit_r22)
<30555200>  JIT-Frame-RegisterMap[0x0000000030566AA8] = UDATA(0x00000000A0000000) (jit_r23)
<30555200>  JIT-Frame-RegisterMap[0x0000000030566AB0] = UDATA(0x0000010028E1F8C0) (jit_r24)
<30555200>  JIT-Frame-RegisterMap[0x0000000030566AB8] = UDATA(0x0000000000000000) (jit_r25)
<30555200>  JIT-Frame-RegisterMap[0x0000000030566AC0] = UDATA(0x0000000030507000) (jit_r26)
<30555200>  JIT-Frame-RegisterMap[0x0000000030566AC8] = UDATA(0x00000001C02DEED8) (jit_r27)
<30555200>  JIT-Frame-RegisterMap[0x0000000030566AD0] = UDATA(0x00000007FFF9D160) (jit_r28)
<30555200>  JIT-Frame-RegisterMap[0x0000000030566AD8] = UDATA(0x00000007FFF9D160) (jit_r29)
<30555200>  JIT-Frame-RegisterMap[0x0000000030566AE0] = UDATA(0x0000000030501B00) (jit_r30)
<30555200>  JIT-Frame-RegisterMap[0x0000000030566AE8] = UDATA(0x00000007FFF9D160) (jit_r31)
mnalam-p commented 3 years ago

With the release available on IBM portal (jdk11-11.0.12+7) I was hitting another bug (__postP10GenericCopy) that was fixed and merged. As there is no official version that contains that fix, I tried to reproduce locally by using latest personal openj9 build.

OpenJDK Runtime Environment (build 11.0.13-internal+0-adhoc.jenkins.BuildJDK11ppc64aixPersonal)
Eclipse OpenJ9 VM (build master-ef609f1cf16, JRE 11 AIX ppc64-64-Bit Compressed References 20210915_748 (JIT enabled, AOT enabled)
OpenJ9   - ef609f1cf16
OMR      - c818b04c631
JCL      - ddc29ca7606 based on jdk-11.0.13+5)

Test passed for following scenarios -

Test was ran on the same P10 system.

pshipton commented 3 years ago

Closing assuming fixed, it can be re-opened if the problem is seen again.

pshipton commented 2 years ago

Another one, job_output.php?id=17203556 - ub20lertp1-8 Linux PPC LE 64bit Compressed Pointers] 80 Load_Level_2.abbs.5mins.Mode610 -Xcompressedrefs -Xjit -Xgcpolicy:gencon

Result store failed so there are no diagnostics.

j> 18:50:18 20211014 18:50:18 Thread Control Engine INFO: Starting JobSet Primary
j> 18:50:31 22:50:31.693 0x17ae00    j9mm.107    *   ** ASSERTION FAILED ** at ../../../gc_glue_java/MarkingDelegate.hpp:121: ((false && ((UDATA)0x99669966 == clazz->eyecatcher)))

100x grinder build_info.php?build_id=14736 - passed

zl-wang commented 2 years ago

@IBMJimmyk looks like a GCMap or missing write-barrier (less likely) issue. I encountered this same stale-pointer issue on AIX7.3 GA1.5 performance evaluation. Kevin and I couldn't nail it down yet. See if you can make more progress with this new core dump (kca has a few commands to help on this type of investigation).