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

[upstream][dragonwell8][fastdebug][nightly]jdk/jfr/event/gc/stacktrace/TestDefNewAllocationPendingStackTrace.java intermittent fails java.lang.AssertionError: No matching stack trace found #677

Open
sendaoYan opened this issue Aug 25, 2024 · 5 comments
Open

[upstream][dragonwell8][fastdebug][nightly]jdk/jfr/event/gc/stacktrace/TestDefNewAllocationPendingStackTrace.java intermittent fails java.lang.AssertionError: No matching stack trace found #677

sendaoYan opened this issue Aug 25, 2024 · 5 comments
Assignees
@sendaoYan

Comments

@sendaoYan
Copy link
Collaborator

https://tone.aliyun-inc.com/ws/xesljfzh/test_result/358036?tab=1
【环境准备】

BINARY_URL=oss://compiler-ci-bucket/dragonwell8/CI/tar/20240822-112257-354-#521-linux.x86_64.fastdebug.master-afffb54106e85c2ea36a26422d920fa94fb7c0ad.tar.gz
JTREG_URL=oss://compiler-ci-bucket/jdk/tools/jtreg5.1-b01.zip
JDK_REPO=https://github.com/dragonwell-project/dragonwell8.git
JDK_BRANCH=master
cd ~/tone/tone-matrix-compiler/common;./ossutil.bin_$(arch) -i;cd -
alias oss="~/tone/tone-matrix-compiler/common/ossutil.bin_$(arch) -e oss-cn-hangzhou.aliyuncs.com -u jvm_dev-b  ~/tone/tone-matrix-compiler/common/ossutil_bin/ossutil -o download -f -r"

部署二进制：
oss $BINARY_URL -l ${BINARY_URL##*/}
mkdir bin-dragonwell8;tar -xf ${BINARY_URL##*/} -C bin-dragonwell8

部署jtreg工具：
oss $JTREG_URL -l ${JTREG_URL##*/};unzip ${JTREG_URL##*/}

部署用例repo
git clone -b $JDK_BRANCH $JDK_REPO jdk-repo-dragonwell8

执行以下命令：
cd bin-dragonwell8/j2sdk-image && export JAVA_HOME=$PWD ; export PATH=$JAVA_HOME/bin:$PATH ; export TEST_JDK_HOME=$JAVA_HOME && cd -
cd jtreg ;export JT_HOME=$PWD ; export PATH=$PWD/bin:$PATH;cd -

jtreg  -nr -v:fail,error -w tmp  -Xmixed  jdk-repo-dragonwell8/jdk/test/jdk/jfr/event/gc/stacktrace/TestDefNewAllocationPendingStackTrace.java

失败率9/3w，复现命令

function runJtreg() { jtreg -Xmixed  -ea -esa  -timeoutFactor:4 -v:fail,error,time,nopass -nr -w $dir/index-$1 $test &> $dir/$1.log ; if [[ 0 -ne $? ]] ; then echo -n "$1 " ; else rm -rf $dir/index-$1 $dir/$1.log ; fi ; } ; export -f runJtreg ; export dir="tmp-jtreg-"`basename
${test##* } .java | sed "s|#|_|"` ; rm -rf $dir ; mkdir -p $dir ; time seq 30000 | xargs -i -n 1 -P 16 bash -c "runJtreg {}" ; echo total fail number: `ls $dir/*.log 2> /dev/null | wc | awk '{print $1}'`
1435 7068 8441 9354 13989 17655 18010 18024 19404
real    521m1.829s
user    14379m51.955s
sys     1686m6.555s
total fail number: 9

【对比测试】
openjdk8 fastdebug 同样问题
531.log
jdk8u-dev-binary-x86_64-fastdebug.tar.xz

[dongzhichun@CompilerTest-x64-5 bin]$ ./java -version;./java -Xinternalversion
openjdk version "1.8.0_432-internal-fastdebug"
OpenJDK Runtime Environment (build 1.8.0_432-internal-fastdebug-_2024_08_06_03_18-b00)
OpenJDK 64-Bit Server VM (build 25.432-b00-fastdebug, mixed mode)
OpenJDK 64-Bit Server VM (25.432-b00-fastdebug) for linux-amd64 JRE (1.8.0_432-internal-_2024_08_06_03_18-b00), built on Aug  6 2024 03:19:49 by "dongzhichun" with gcc 10.2.1 20210130 (Red Hat 10.2.1-11)

【用例日志】
1435.log
index-1435.rar

STDOUT:
[GC (Allocation Failure) [DefNew: 540224K->2503K(607680K), 0.0855304 secs] 540224K->2503K(1958016K), 0.0913313 secs] [Times: user=0.17 sys=0.00, real=0.09 secs] 
Allocation num: 41701
GC detected: 1
JFR GC events found: 1
Event: jdk.AllocationRequiringGC {
  startTime = 13:58:40.618
  gcId = 0
  size = 24 bytes
  eventThread = "JFR Periodic Tasks" (javaThreadId = 25)
  stackTrace = [
    java.util.concurrent.CopyOnWriteArrayList.iterator() line: 1082
    jdk.jfr.internal.RequestEngine.run_requests(Collection) line: 216
    jdk.jfr.internal.RequestEngine.doPeriodic() line: 187
    jdk.jfr.internal.PlatformRecorder.periodicTask() line: 441
    jdk.jfr.internal.PlatformRecorder.lambda$startDiskMonitor$1() line: 388
    ...
  ]
}


Attempt: 0 out of 5: no matching stack trace found.
[GC (Allocation Failure) [DefNew: 542727K->2561K(607680K), 0.0550803 secs] 542727K->2561K(1958016K), 0.0562089 secs] [Times: user=0.06 sys=0.00, real=0.06 secs] 
Allocation num: 49888
GC detected: 2
JFR GC events found: 1
Event: jdk.AllocationRequiringGC {
  startTime = 13:58:41.221
  gcId = 1
  size = 24 bytes
  eventThread = "JFR Periodic Tasks" (javaThreadId = 25)
  stackTrace = [
    java.util.concurrent.CopyOnWriteArrayList.iterator() line: 1082
    jdk.jfr.internal.RequestEngine.run_requests(Collection) line: 216
    jdk.jfr.internal.RequestEngine.doPeriodic() line: 187
    jdk.jfr.internal.PlatformRecorder.periodicTask() line: 441
    jdk.jfr.internal.PlatformRecorder.lambda$startDiskMonitor$1() line: 388
    ...
  ]
}


Attempt: 1 out of 5: no matching stack trace found.
[GC (Allocation Failure) [DefNew: 542785K->2568K(607680K), 0.0535861 secs] 542785K->2568K(1958016K), 0.0538423 secs] [Times: user=0.07 sys=0.00, real=0.06 secs] 
Allocation num: 51463
GC detected: 3
JFR GC events found: 1
Event: jdk.AllocationRequiringGC {
  startTime = 13:58:41.474
  gcId = 2
  size = 24 bytes
  eventThread = "JFR Periodic Tasks" (javaThreadId = 25)
  stackTrace = [
    java.util.concurrent.CopyOnWriteArrayList.iterator() line: 1082
    jdk.jfr.internal.RequestEngine.run_requests(Collection) line: 216
    jdk.jfr.internal.RequestEngine.doPeriodic() line: 187
    jdk.jfr.internal.PlatformRecorder.periodicTask() line: 441
    jdk.jfr.internal.PlatformRecorder.lambda$startDiskMonitor$1() line: 388
    ...
  ]
}


Attempt: 2 out of 5: no matching stack trace found.
[GC (Allocation Failure) [DefNew: 542792K->2570K(607680K), 0.0729983 secs] 542792K->2570K(1958016K), 0.0737920 secs] [Times: user=0.07 sys=0.00, real=0.07 secs] 
Allocation num: 51455
GC detected: 4
JFR GC events found: 1
Event: jdk.AllocationRequiringGC {
  startTime = 13:58:41.719
  gcId = 3
  size = 24 bytes
  eventThread = "JFR Periodic Tasks" (javaThreadId = 25)
  stackTrace = [
    java.util.concurrent.CopyOnWriteArrayList.iterator() line: 1082
    jdk.jfr.internal.RequestEngine.run_requests(Collection) line: 216
    jdk.jfr.internal.RequestEngine.doPeriodic() line: 187
    jdk.jfr.internal.PlatformRecorder.periodicTask() line: 441
    jdk.jfr.internal.PlatformRecorder.lambda$startDiskMonitor$1() line: 388
    ...
  ]
}


Attempt: 3 out of 5: no matching stack trace found.
[GC (Allocation Failure) [DefNew: 542794K->2573K(607680K), 0.0673860 secs] 542794K->2573K(1958016K), 0.0680504 secs] [Times: user=0.07 sys=0.00, real=0.07 secs] 
Allocation num: 50955
GC detected: 5
JFR GC events found: 1
Event: jdk.AllocationRequiringGC {
  startTime = 13:58:41.922
  gcId = 4
  size = 24 bytes
  eventThread = "JFR Periodic Tasks" (javaThreadId = 25)
  stackTrace = [
    java.util.concurrent.CopyOnWriteArrayList.iterator() line: 1082
    jdk.jfr.internal.RequestEngine.run_requests(Collection) line: 216
    jdk.jfr.internal.RequestEngine.doPeriodic() line: 187
    jdk.jfr.internal.PlatformRecorder.periodicTask() line: 441
    jdk.jfr.internal.PlatformRecorder.lambda$startDiskMonitor$1() line: 388
    ...
  ]
}


Attempt: 4 out of 5: no matching stack trace found.
Heap
 def new generation   total 607680K, used 36533K [0x0000000080200000, 0x00000000a9550000, 0x0000000300150000)
  eden space 540224K,   6% used [0x0000000080200000, 0x0000000082329d60, 0x00000000a1190000)
  from space 67456K,   3% used [0x00000000a5370000, 0x00000000a55f36a8, 0x00000000a9550000)
  to   space 67456K,   0% used [0x00000000a1190000, 0x00000000a1190000, 0x00000000a5370000)
 tenured generation   total 1350336K, used 0K [0x0000000300150000, 0x0000000352800000, 0x0000000800000000)
   the space 1350336K,   0% used [0x0000000300150000, 0x0000000300150000, 0x0000000300150200, 0x0000000352800000)
 Metaspace       used 12382K, capacity 12834K, committed 13056K, reserved 1060864K
  class space    used 1325K, capacity 1448K, committed 1536K, reserved 1048576K
STDERR:
java.lang.AssertionError: No matching stack trace found
	at jdk.jfr.event.gc.stacktrace.AllocationStackTrace.testAllocEvent(AllocationStackTrace.java:398)
	at jdk.jfr.event.gc.stacktrace.AllocationStackTrace.testDefNewAllocEvent(AllocationStackTrace.java:178)
	at jdk.jfr.event.gc.stacktrace.TestDefNewAllocationPendingStackTrace.main(TestDefNewAllocationPendingStackTrace.java:39)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at com.sun.javatest.regtest.agent.MainWrapper$MainThread.run(MainWrapper.java:127)
	at java.lang.Thread.run(Thread.java:855)

JavaTest Message: Test threw exception: java.lang.AssertionError: No matching stack trace found
JavaTest Message: shutting down test

【版本信息】

[dongzhichun@CompilerTest-x64-3 dragonwell8-debug]$ uname -a ; cat /etc/os-release ; free -h ; lscpu | head -n 25 ; java -version ; java -Xinternalversion
Linux CompilerTest-x64-3 5.10.134-16.1.al8.x86_64 #1 SMP Thu Dec 7 14:11:24 UTC 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"
UPDATE_ID="9"
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:          123Gi       1.1Gi       120Gi       111Mi       1.7Gi       121Gi
Swap:            0B          0B          0B
Architecture:        x86_64
CPU op-mode(s):      32-bit, 64-bit
Byte Order:          Little Endian
CPU(s):              32
On-line CPU(s) list: 0-31
Thread(s) per core:  2
Core(s) per socket:  16
Socket(s):           1
NUMA node(s):        1
Vendor ID:           GenuineIntel
CPU family:          6
Model:               106
Model name:          Intel(R) Xeon(R) Platinum 8369B CPU @ 2.70GHz
Stepping:            6
CPU MHz:             3509.740
BogoMIPS:            5399.99
Hypervisor vendor:   KVM
Virtualization type: full
L1d cache:           48K
L1i cache:           32K
L2 cache:            1280K
L3 cache:            49152K
NUMA node0 CPU(s):   0-31
Flags:               fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush mmx fxsr sse sse2 ss ht syscall nx pdpe1gb rdtscp lm constant_tsc rep_good nopl nonstop_tsc cpuid aperfmperf tsc_known_freq pni pclmulqdq monitor ssse3 fma cx16 pcid sse4_1 sse4_2 x2apic movbe popcnt aes xsave avx f16c rdrand hypervisor lahf_lm abm 3dnowprefetch cpuid_fault invpcid_single ibrs_enhanced fsgsbase tsc_adjust bmi1 avx2 smep bmi2 erms invpcid avx512f avx512dq rdseed adx smap avx512ifma clflushopt clwb avx512cd sha_ni avx512bw avx512vl xsaveopt xsavec xgetbv1 xsaves wbnoinvd arat avx512vbmi pku ospke avx512_vbmi2 gfni vaes vpclmulqdq avx512_vnni avx512_bitalg avx512_vpopcntdq rdpid fsrm arch_capabilities
openjdk version "1.8.0_372-fastdebug"
OpenJDK Runtime Environment (Alibaba Dragonwell Extended Edition 8.19.20) (build 1.8.0_372-fastdebug-b01)
OpenJDK 64-Bit Server VM (Alibaba Dragonwell Extended Edition 8.19.20) (build 25.372-b01-fastdebug, mixed mode)
OpenJDK 64-Bit Server VM (25.372-b01-fastdebug) for linux-amd64 JRE (1.8.0_372-b01), built on Aug 22 2024 03:25:00 by "" with gcc 4.8.2 20140120 (Red Hat 4.8.2-15)
[dongzhichun@CompilerTest-x64-3 dragonwell8-debug]$
@sendaoYan sendaoYan self-assigned this Aug 25, 2024
@sendaoYan
Copy link
Collaborator Author

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

@sendaoYan
Copy link
Collaborator Author

https://bugs.openjdk.org/browse/JDK-8148052

@dzchun
Copy link

dzchun commented Aug 27, 2024

加上-XX:FlightRecorderOptions:stackdepth=256 -XX:NewSize=5M选项之后没问题

@sendaoYan
Copy link
Collaborator Author

加上-XX:FlightRecorderOptions:stackdepth=256 -XX:NewSize=5M选项之后没问题

@dzchun 帮我确认下TestG1HumongousAllocationPendingStackTrace.java这个用例，加上选项之前和加上选项之后的测试结果

@dzchun
Copy link

dzchun commented Aug 28, 2024

加上-XX:FlightRecorderOptions:stackdepth=256 -XX:NewSize=5M选项之后没问题

@dzchun 帮我确认下TestG1HumongousAllocationPendingStackTrace.java这个用例，加上选项之前和加上选项之后的测试结果

加上之前和加上之后都没问题

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@sendaoYan sendaoYan

Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@sendaoYan @dzchun