dragonwell-project / dragonwell21

GNU General Public License v2.0
66 stars 19 forks source link

[upstream]TestZGCWithCDS.java#ZGenerational 运行大概率失败 #6

Closed sendaoYan closed 2 months ago

sendaoYan commented 11 months ago

https://tone.aliyun-inc.com/ws/xesljfzh/test_result/244256?tab=2

【环境准备】

wget -O binary.tar.gz https://dragonwell.oss-cn-shanghai.aliyuncs.com/test-59/OpenJDK21U-jdk_x64_linux_dragonwell_2023-11-02-02-07.tar.gz
wget -O test-image.tar.gz https://dragonwell.oss-cn-shanghai.aliyuncs.com/test-59/OpenJDK21U-testimage_x64_linux_dragonwell_2023-11-02-02-07.tar.gz
wget -O jtreg.zip https://compiler-ci-bucket.oss-cn-hangzhou.aliyuncs.com/jdk/tools/jtreg-7.3.1.zip
git clone https://github.com/dragonwell-project/dragonwell21.git -b wip_dragonwell_standard_merge_branch jdk-repo

mkdir binary-download 
tar xzvf binary.tar.gz -C binary-download ; cd binary-download && export JAVA_HOME=$PWD ; export PATH=$JAVA_HOME/bin:$PATH ; export TEST_JDK_HOME=$JAVA_HOME &&cd -
make test-image ; tar xzvf test-image.tar.gz -C test-image
unzip jtreg.zip; cd jtreg ; export JT_HOME=$PWD ; export PATH=$PWD/bin:$PATH ; cd -

test=\
jdk-repo/test/hotspot/jtreg/runtime/cds/appcds/TestZGCWithCDS.java#ZGenerational

args='-Xmixed'
native='-nativepath:./test-image/hotspot/jtreg/native'
dir="jt-work" ; rm -rf $dir ; mkdir -p $dir ; time seq 20 | xargs -i -n 1 -P 2 bash -c "jtreg -w tmp -nr -v:fail,error $native  $args $test &> $dir/test_{} ; grep 'Test results: passed: 1' -L $dir/test_{}"

失败概率很高.运行了20次,失败了18次. 错误情况有3种: TEST RESULT: Failed. Execution failed: main' threw exception: java.lang.RuntimeException: 'Unable to use shared archive.' missing from stdout/stderr TEST RESULT: Failed. Execution failed:main' threw exception: java.lang.RuntimeException: 'Hello World' missing from stdout/stderr TEST RESULT: Failed. Execution failed: `main' threw exception: java.lang.RuntimeException: 'Dumping shared data to file:' missing from stdout/stderr

【对比测试】

dragonwell21 release无

temurin21 同样问题 wget https://github.com/adoptium/temurin21-binaries/releases/download/jdk-21.0.1%2B12/OpenJDK21U-jdk_x64_linux_hotspot_21.0.1_12.tar.gz

[root@VM20190228-137 t21]# java -version; java -Xinternalversion
openjdk version "21.0.1" 2023-10-17 LTS
OpenJDK Runtime Environment Temurin-21.0.1+12 (build 21.0.1+12-LTS)
OpenJDK 64-Bit Server VM Temurin-21.0.1+12 (build 21.0.1+12-LTS, mixed mode, sharing)
OpenJDK 64-Bit Server VM (21.0.1+12-LTS) for linux-amd64 JRE (21.0.1+12-LTS), built on 2023-10-17T00:00:00Z by "admin" with gcc 11.2.0

【用例日志】

Tone完整日志:

ACTION: driver -- Failed. Execution failed: `main' threw exception: java.lang.RuntimeException: 'Dumping shared data to file:' missing from stdout/stderr
REASON: User specified action: run driver TestZGCWithCDS -XX:+ZGenerational
TIME:   2.384 seconds
messages:
command: driver TestZGCWithCDS -XX:+ZGenerational
reason: User specified action: run driver TestZGCWithCDS -XX:+ZGenerational
started: Tue Nov 14 10:14:58 CST 2023
Mode: othervm
finished: Tue Nov 14 10:15:00 CST 2023
elapsed time (seconds): 2.384
configuration:
STDOUT:
0. Dump with ZGC
Command line: [/root/d21/binary-download/bin/java -cp /root/d21/tmp/classes/runtime/cds/appcds/TestZGCWithCDS_ZGenerational.d:/root/d21/jdk-repo/test/hotspot/jtreg/runtime/cds/appcds:/root/d21/tmp/classes/test/lib:/root/d21/jdk-repo/test/lib:/root/d21/tmp/classes/test/hotspot/jtreg/runtime/cds/appcds:/root/d21/jtreg/lib/javatest.jar:/root/d21/jtreg/lib/jtreg.jar -Xmixed -cp /root/d21/tmp/scratch/hello.jar -Xshare:dump -Xlog:cds -XX:SharedArchiveFile=/root/d21/tmp/scratch/appcds-10h14m58s492.jsa -XX:ExtraSharedClassListFile=/root/d21/tmp/scratch/runtime.cds.appcds.TestZGCWithCDS.java#ZGenerational-test.classlist -XX:+UseZGC -XX:+ZGenerational -Xlog:cds ]
[2023-11-14T02:14:58.538430650Z] Gathering output for process 2547543
[ELAPSED: 1408 ms]
[logging stdout to /root/d21/tmp/scratch/runtime.cds.appcds.TestZGCWithCDS.java#ZGenerational-0000-dump.stdout]
[logging stderr to /root/d21/tmp/scratch/runtime.cds.appcds.TestZGCWithCDS.java#ZGenerational-0000-dump.stderr]
[STDERR]

[2023-11-14T02:14:59.950884899Z] Waiting for completion for process 2547543
[2023-11-14T02:14:59.951046909Z] Waiting for completion finished for process 2547543
[2023-11-14T02:14:59.951206480Z] Waiting for completion for process 2547543
[2023-11-14T02:14:59.951294051Z] Waiting for completion finished for process 2547543
1. Run with same args of dump
Command line: [/root/d21/binary-download/bin/java -cp /root/d21/tmp/classes/runtime/cds/appcds/TestZGCWithCDS_ZGenerational.d:/root/d21/jdk-repo/test/hotspot/jtreg/runtime/cds/appcds:/root/d21/tmp/classes/test/lib:/root/d21/jdk-repo/test/lib:/root/d21/tmp/classes/test/hotspot/jtreg/runtime/cds/appcds:/root/d21/jtreg/lib/javatest.jar:/root/d21/jtreg/lib/jtreg.jar -Xmixed -Xshare:on -showversion -XX:SharedArchiveFile=/root/d21/tmp/scratch/appcds-10h14m58s492.jsa -Dtest.timeout.factor=1.0 -cp /root/d21/tmp/scratch/hello.jar -XX:+UnlockDiagnosticVMOptions -XX:VerifyArchivedFields=1 -XX:+UseZGC -XX:+ZGenerational -Xlog:cds Hello ]
[2023-11-14T02:14:59.954384263Z] Gathering output for process 2547646
[ELAPSED: 230 ms]
[logging stdout to /root/d21/tmp/scratch/runtime.cds.appcds.TestZGCWithCDS.java#ZGenerational-0001-exec.stdout]
[logging stderr to /root/d21/tmp/scratch/runtime.cds.appcds.TestZGCWithCDS.java#ZGenerational-0001-exec.stderr]
[STDERR]
openjdk version "21.0.1" 2023-10-17
OpenJDK Runtime Environment (Alibaba Dragonwell Standard Edition)-21.0.1.0.1+12-GA (build 21.0.1)
OpenJDK 64-Bit Server VM (Alibaba Dragonwell Standard Edition)-21.0.1.0.1+12-GA (build 21.0.1, mixed mode, sharing)

[2023-11-14T02:15:00.184804830Z] Waiting for completion for process 2547646
[2023-11-14T02:15:00.184994959Z] Waiting for completion finished for process 2547646
[2023-11-14T02:15:00.185125908Z] Waiting for completion for process 2547646
[2023-11-14T02:15:00.185220805Z] Waiting for completion finished for process 2547646
2. Run with +UseCompressedOops +UseCompressedClassPointers
Command line: [/root/d21/binary-download/bin/java -cp /root/d21/tmp/classes/runtime/cds/appcds/TestZGCWithCDS_ZGenerational.d:/root/d21/jdk-repo/test/hotspot/jtreg/runtime/cds/appcds:/root/d21/tmp/classes/test/lib:/root/d21/jdk-repo/test/lib:/root/d21/tmp/classes/test/hotspot/jtreg/runtime/cds/appcds:/root/d21/jtreg/lib/javatest.jar:/root/d21/jtreg/lib/jtreg.jar -Xmixed -Xshare:on -showversion -XX:SharedArchiveFile=/root/d21/tmp/scratch/appcds-10h14m58s492.jsa -Dtest.timeout.factor=1.0 -cp /root/d21/tmp/scratch/hello.jar -XX:+UnlockDiagnosticVMOptions -XX:VerifyArchivedFields=1 -XX:-UseZGC -XX:+UseCompressedOops -XX:+UseCompressedClassPointers -Xlog:cds Hello ]
[2023-11-14T02:15:00.188312022Z] Gathering output for process 2547701
[ELAPSED: 15 ms]
[logging stdout to /root/d21/tmp/scratch/runtime.cds.appcds.TestZGCWithCDS.java#ZGenerational-0002-exec.stdout]
[logging stderr to /root/d21/tmp/scratch/runtime.cds.appcds.TestZGCWithCDS.java#ZGenerational-0002-exec.stderr]
[STDERR]

[2023-11-14T02:15:00.203190175Z] Waiting for completion for process 2547701
[2023-11-14T02:15:00.203322805Z] Waiting for completion finished for process 2547701
[2023-11-14T02:15:00.203452857Z] Waiting for completion for process 2547701
[2023-11-14T02:15:00.203530452Z] Waiting for completion finished for process 2547701
3. Run with -UseCompressedOops -UseCompressedClassPointers
Command line: [/root/d21/binary-download/bin/java -cp /root/d21/tmp/classes/runtime/cds/appcds/TestZGCWithCDS_ZGenerational.d:/root/d21/jdk-repo/test/hotspot/jtreg/runtime/cds/appcds:/root/d21/tmp/classes/test/lib:/root/d21/jdk-repo/test/lib:/root/d21/tmp/classes/test/hotspot/jtreg/runtime/cds/appcds:/root/d21/jtreg/lib/javatest.jar:/root/d21/jtreg/lib/jtreg.jar -Xmixed -Xshare:on -showversion -XX:SharedArchiveFile=/root/d21/tmp/scratch/appcds-10h14m58s492.jsa -Dtest.timeout.factor=1.0 -cp /root/d21/tmp/scratch/hello.jar -XX:+UnlockDiagnosticVMOptions -XX:VerifyArchivedFields=1 -XX:+UseSerialGC -XX:-UseCompressedOops -XX:-UseCompressedClassPointers -Xlog:cds Hello ]
[2023-11-14T02:15:00.205499835Z] Gathering output for process 2547710
[ELAPSED: 10 ms]
[logging stdout to /root/d21/tmp/scratch/runtime.cds.appcds.TestZGCWithCDS.java#ZGenerational-0003-exec.stdout]
[logging stderr to /root/d21/tmp/scratch/runtime.cds.appcds.TestZGCWithCDS.java#ZGenerational-0003-exec.stderr]
[STDERR]

[2023-11-14T02:15:00.215860046Z] Waiting for completion for process 2547710
[2023-11-14T02:15:00.216041249Z] Waiting for completion finished for process 2547710
[2023-11-14T02:15:00.216205304Z] Waiting for completion for process 2547710
[2023-11-14T02:15:00.216339642Z] Waiting for completion finished for process 2547710
4. Run with -UseCompressedOops +UseCompressedClassPointers
Command line: [/root/d21/binary-download/bin/java -cp /root/d21/tmp/classes/runtime/cds/appcds/TestZGCWithCDS_ZGenerational.d:/root/d21/jdk-repo/test/hotspot/jtreg/runtime/cds/appcds:/root/d21/tmp/classes/test/lib:/root/d21/jdk-repo/test/lib:/root/d21/tmp/classes/test/hotspot/jtreg/runtime/cds/appcds:/root/d21/jtreg/lib/javatest.jar:/root/d21/jtreg/lib/jtreg.jar -Xmixed -Xshare:on -showversion -XX:SharedArchiveFile=/root/d21/tmp/scratch/appcds-10h14m58s492.jsa -Dtest.timeout.factor=1.0 -cp /root/d21/tmp/scratch/hello.jar -XX:+UnlockDiagnosticVMOptions -XX:VerifyArchivedFields=1 -XX:+UseSerialGC -XX:-UseCompressedOops -XX:+UseCompressedClassPointers -Xlog:cds Hello ]
[2023-11-14T02:15:00.218837434Z] Gathering output for process 2547714
[ELAPSED: 87 ms]
[logging stdout to /root/d21/tmp/scratch/runtime.cds.appcds.TestZGCWithCDS.java#ZGenerational-0004-exec.stdout]
[logging stderr to /root/d21/tmp/scratch/runtime.cds.appcds.TestZGCWithCDS.java#ZGenerational-0004-exec.stderr]
[STDERR]
openjdk version "21.0.1" 2023-10-17
OpenJDK Runtime Environment (Alibaba Dragonwell Standard Edition)-21.0.1.0.1+12-GA (build 21.0.1)
OpenJDK 64-Bit Server VM (Alibaba Dragonwell Standard Edition)-21.0.1.0.1+12-GA (build 21.0.1, mixed mode, sharing)

[2023-11-14T02:15:00.305984265Z] Waiting for completion for process 2547714
[2023-11-14T02:15:00.306219019Z] Waiting for completion finished for process 2547714
[2023-11-14T02:15:00.306350087Z] Waiting for completion for process 2547714
[2023-11-14T02:15:00.306426375Z] Waiting for completion finished for process 2547714
5. Run with +UseCompressedOops -UseCompressedClassPointers
Command line: [/root/d21/binary-download/bin/java -cp /root/d21/tmp/classes/runtime/cds/appcds/TestZGCWithCDS_ZGenerational.d:/root/d21/jdk-repo/test/hotspot/jtreg/runtime/cds/appcds:/root/d21/tmp/classes/test/lib:/root/d21/jdk-repo/test/lib:/root/d21/tmp/classes/test/hotspot/jtreg/runtime/cds/appcds:/root/d21/jtreg/lib/javatest.jar:/root/d21/jtreg/lib/jtreg.jar -Xmixed -Xshare:on -showversion -XX:SharedArchiveFile=/root/d21/tmp/scratch/appcds-10h14m58s492.jsa -Dtest.timeout.factor=1.0 -cp /root/d21/tmp/scratch/hello.jar -XX:+UnlockDiagnosticVMOptions -XX:VerifyArchivedFields=1 -XX:+UseSerialGC -XX:+UseCompressedOops -XX:-UseCompressedClassPointers -Xlog:cds Hello ]
[2023-11-14T02:15:00.308560034Z] Gathering output for process 2547732
[ELAPSED: 11 ms]
[logging stdout to /root/d21/tmp/scratch/runtime.cds.appcds.TestZGCWithCDS.java#ZGenerational-0005-exec.stdout]
[logging stderr to /root/d21/tmp/scratch/runtime.cds.appcds.TestZGCWithCDS.java#ZGenerational-0005-exec.stderr]
[STDERR]

[2023-11-14T02:15:00.319955575Z] Waiting for completion for process 2547732
[2023-11-14T02:15:00.320073372Z] Waiting for completion finished for process 2547732
[2023-11-14T02:15:00.320178137Z] Waiting for completion for process 2547732
[2023-11-14T02:15:00.320266236Z] Waiting for completion finished for process 2547732
6. Run with +UseCompressedOops +UseCompressedClassPointers
Command line: [/root/d21/binary-download/bin/java -cp /root/d21/tmp/classes/runtime/cds/appcds/TestZGCWithCDS_ZGenerational.d:/root/d21/jdk-repo/test/hotspot/jtreg/runtime/cds/appcds:/root/d21/tmp/classes/test/lib:/root/d21/jdk-repo/test/lib:/root/d21/tmp/classes/test/hotspot/jtreg/runtime/cds/appcds:/root/d21/jtreg/lib/javatest.jar:/root/d21/jtreg/lib/jtreg.jar -Xmixed -Xshare:on -showversion -XX:SharedArchiveFile=/root/d21/tmp/scratch/appcds-10h14m58s492.jsa -Dtest.timeout.factor=1.0 -cp /root/d21/tmp/scratch/hello.jar -XX:+UnlockDiagnosticVMOptions -XX:VerifyArchivedFields=1 -XX:+UseSerialGC -XX:+UseCompressedOops -XX:+UseCompressedClassPointers -Xlog:cds Hello ]
[2023-11-14T02:15:00.322332354Z] Gathering output for process 2547736
[ELAPSED: 10 ms]
[logging stdout to /root/d21/tmp/scratch/runtime.cds.appcds.TestZGCWithCDS.java#ZGenerational-0006-exec.stdout]
[logging stderr to /root/d21/tmp/scratch/runtime.cds.appcds.TestZGCWithCDS.java#ZGenerational-0006-exec.stderr]
[STDERR]

[2023-11-14T02:15:00.333053532Z] Waiting for completion for process 2547736
[2023-11-14T02:15:00.333165038Z] Waiting for completion finished for process 2547736
[2023-11-14T02:15:00.333290192Z] Waiting for completion for process 2547736
[2023-11-14T02:15:00.333380544Z] Waiting for completion finished for process 2547736
7. Dump with -UseCompressedOops -UseCompressedClassPointers
Command line: [/root/d21/binary-download/bin/java -cp /root/d21/tmp/classes/runtime/cds/appcds/TestZGCWithCDS_ZGenerational.d:/root/d21/jdk-repo/test/hotspot/jtreg/runtime/cds/appcds:/root/d21/tmp/classes/test/lib:/root/d21/jdk-repo/test/lib:/root/d21/tmp/classes/test/hotspot/jtreg/runtime/cds/appcds:/root/d21/jtreg/lib/javatest.jar:/root/d21/jtreg/lib/jtreg.jar -Xmixed -cp /root/d21/tmp/scratch/hello.jar -Xshare:dump -Xlog:cds -XX:SharedArchiveFile=/root/d21/tmp/scratch/appcds-10h15m00s337.jsa -XX:ExtraSharedClassListFile=/root/d21/tmp/scratch/runtime.cds.appcds.TestZGCWithCDS.java#ZGenerational-test.classlist -XX:+UseSerialGC -XX:-UseCompressedOops -XX:+UseCompressedClassPointers -Xlog:cds ]
[2023-11-14T02:15:00.340572433Z] Gathering output for process 2547741
[ELAPSED: 112 ms]
[logging stdout to /root/d21/tmp/scratch/runtime.cds.appcds.TestZGCWithCDS.java#ZGenerational-0007-dump.stdout]
[logging stderr to /root/d21/tmp/scratch/runtime.cds.appcds.TestZGCWithCDS.java#ZGenerational-0007-dump.stderr]
[STDERR]

[2023-11-14T02:15:00.452948245Z] Waiting for completion for process 2547741
[2023-11-14T02:15:00.453089246Z] Waiting for completion finished for process 2547741
[2023-11-14T02:15:00.453208030Z] Waiting for completion for process 2547741
[2023-11-14T02:15:00.453291278Z] Waiting for completion finished for process 2547741
STDERR:
 stdout: [[0.004s][info][cds] Core region alignment: 4096
[0.057s][info][cds] JVM_StartThread() ignored: java.lang.ref.Reference$ReferenceHandler
[0.057s][info][cds] JVM_StartThread() ignored: java.lang.ref.Finalizer$FinalizerThread
[0.099s][error][cds] Unable to open file /root/d21/tmp/scratch/hello.jar.
[0.099s][error][cds] An error has occurred while processing the shared archive file.
Error occurred during initialization of VM
Unable to use shared archive.
];
 stderr: []
 exitValue = 1

java.lang.RuntimeException: 'Dumping shared data to file:' missing from stdout/stderr
        at jdk.test.lib.process.OutputAnalyzer.shouldContain(OutputAnalyzer.java:221)
        at TestZGCWithCDS.main(TestZGCWithCDS.java:147)
        at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103)
        at java.base/java.lang.reflect.Method.invoke(Method.java:580)
        at com.sun.javatest.regtest.agent.MainWrapper$MainTask.run(MainWrapper.java:138)
        at java.base/java.lang.Thread.run(Thread.java:1583)

JavaTest Message: Test threw exception: java.lang.RuntimeException: 'Dumping shared data to file:' missing from stdout/stderr
JavaTest Message: shutting down test

STATUS:Failed.`main' threw exception: java.lang.RuntimeException: 'Dumping shared data to file:' missing from stdout/stderr

【版本信息】

[root@VM20190228-137 d21]# uname -a ; cat /etc/os-release ; free -h; lscpu| head -n 25;java -version; java -Xinternalversion
Linux VM20190228-137 5.10.134-14.al8.x86_64 #1 SMP Thu Apr 27 16:46:29 CST 2023 x86_64 x86_64 x86_64 GNU/Linux
NAME="Alibaba Cloud Linux"
VERSION="3 (Soaring Falcon)"
ID="alinux"
ID_LIKE="rhel fedora centos anolis"
VERSION_ID="3"
PLATFORM_ID="platform:al8"
PRETTY_NAME="Alibaba Cloud Linux 3 (Soaring Falcon)"
ANSI_COLOR="0;31"
HOME_URL="https://www.aliyun.com/"

              total        used        free      shared  buff/cache   available
Mem:           15Gi       618Mi       446Mi       778Mi        14Gi        13Gi
Swap:            0B          0B          0B
Architecture:        x86_64
CPU op-mode(s):      32-bit, 64-bit
Byte Order:          Little Endian
CPU(s):              4
On-line CPU(s) list: 0-3
Thread(s) per core:  2
Core(s) per socket:  1
Socket(s):           2
NUMA node(s):        1
Vendor ID:           GenuineIntel
BIOS Vendor ID:      Alibaba Cloud
CPU family:          6
Model:               85
Model name:          Intel(R) Xeon(R) Platinum 8163 CPU @ 2.50GHz
BIOS Model name:     pc-i440fx-2.1
Stepping:            4
CPU MHz:             2500.012
BogoMIPS:            5000.02
Hypervisor vendor:   KVM
Virtualization type: full
L1d cache:           32K
L1i cache:           32K
L2 cache:            1024K
L3 cache:            33792K
NUMA node0 CPU(s):   0-3
openjdk version "21.0.1" 2023-10-17
OpenJDK Runtime Environment (Alibaba Dragonwell Standard Edition)-21.0.1.0.1+12-GA (build 21.0.1)
OpenJDK 64-Bit Server VM (Alibaba Dragonwell Standard Edition)-21.0.1.0.1+12-GA (build 21.0.1, mixed mode, sharing)
OpenJDK 64-Bit Server VM (21.0.1) for linux-amd64 JRE (21.0.1), built on 2023-10-17T00:00:00Z by "dragonwell" with gcc 11.2.0
sendaoYan commented 11 months ago

主干版本没有问题,用例没有发生变化

image

sendaoYan commented 11 months ago

jdk21u一样报错 image

sendaoYan commented 9 months ago

已经有PR : https://github.com/openjdk/jdk21u-dev/pull/126

sendaoYan commented 9 months ago

https://aone.alibaba-inc.com/v2/project/355606/bug/54566311# 《[dragonwell21][TESTBUG]TestZGCWithCDS.java#ZGenerational报错SoftMaxHeapSize must be less than or equal to the maximum heap size》

sendaoYan commented 8 months ago

https://code.alibaba-inc.com/os-quality/tone-matrix-compiler/codereview/15561580

sendaoYan commented 8 months ago

image

还未合入jdk21u代码仓

sendaoYan commented 8 months ago

https://code.alibaba-inc.com/os-quality/tone-matrix-compiler/codereview/15602424

sendaoYan commented 7 months ago

上游jdk21u-dev https://tone.aliyun-inc.com/ws/xesljfzh/test_result/290162 pass

sendaoYan commented 2 months ago

应该已经合入dragonwell21,先关闭