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.23k stars 712 forks source link

cmdLineTester_criu_nonPortableRestore_7_FAILED testTimeCompensation() hang #19652

Open pshipton opened 4 weeks ago

pshipton commented 4 weeks ago

https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_sanity.functional_aarch64_linux_Nightly_testList_1/685 - cent8-aarch64-3 cmdLineTester_criu_nonPortableRestore_7

23:11:23  Testing: Create CRIU checkpoint image and restore once - testTimeCompensation
23:11:23  Test start time: 2024/06/06 23:11:23 Eastern Standard Time
23:11:23  Running command: bash /home/jenkins/workspace/Test_openjdk11_j9_sanity.functional_aarch64_linux_Nightly_testList_1/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu/criuScript.sh /home/jenkins/workspace/Test_openjdk11_j9_sanity.functional_aarch64_linux_Nightly_testList_1/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu /home/jenkins/workspace/Test_openjdk11_j9_sanity.functional_aarch64_linux_Nightly_testList_1/jdkbinary/j2sdk-image/bin/java " -Xgcpolicy:gencon -Xgcthreads64 -XX:CheckpointGCThreads=1  -Xtrace:print={j9jcl.533,j9vm.684-696,j9vm.699,j9vm.717-743} --add-exports java.base/openj9.internal.criu=ALL-UNNAMED" org.openj9.criu.TimeChangeTest testTimeCompensation 1 false false
23:11:23  Time spent starting: 2 milliseconds
23:16:23  ***[TEST INFO 2024/06/06 23:16:23] ProcessKiller detected a timeout after 300000 milliseconds!***
23:16:23  ***[TEST INFO 2024/06/06 23:16:23] executing /usr/bin/gdb -batch -x /tmp/debugger1702906961442638105.txt bash 3731370***
23:16:23  GDB OUT 0x0000ffffaf4c4778 in waitpid () from /lib64/libc.so.6
23:16:23  GDB OUT From                To                  Syms Read   Shared Object Library
23:16:23  GDB OUT 0x0000ffffaf5de010  0x0000ffffaf5eaa14  Yes (*)     /lib64/libtinfo.so.6
23:16:23  GDB OUT 0x0000ffffaf5a0cf0  0x0000ffffaf5a1974  Yes (*)     /lib64/libdl.so.2
23:16:23  GDB OUT 0x0000ffffaf440880  0x0000ffffaf530c50  Yes (*)     /lib64/libc.so.6
23:16:23  GDB OUT 0x0000ffffaf661080  0x0000ffffaf67bd88  Yes         /lib/ld-linux-aarch64.so.1
23:16:23  GDB OUT (*): Shared library is missing debugging information.
23:16:23  GDB OUT x0             0xffffffffffffffff  -1
23:16:23  GDB OUT x1             0xffffc61e4d30      281474005617968
23:16:23  GDB OUT x2             0x0                 0
23:16:23  GDB OUT x3             0x0                 0
23:16:23  GDB OUT x4             0x1                 1
23:16:23  GDB OUT x5             0xaaab227d87e0      187651994781664
23:16:23  GDB OUT x6             0x38f019            3731481
23:16:23  GDB OUT x7             0x0                 0
23:16:23  GDB OUT x8             0x104               260
23:16:23  GDB OUT x9             0xaaab227d2200      187651994755584
23:16:23  GDB OUT x10            0xffffaf69fb88      281473624701832
23:16:23  GDB OUT x11            0xaaaae83d9a48      187651017513544
23:16:23  GDB OUT x12            0x0                 0
23:16:23  GDB OUT x13            0xaaaae82fe2b8      187651016614584
23:16:23  GDB OUT x14            0x8                 8
23:16:23  GDB OUT x15            0x48                72
23:16:23  GDB OUT x16            0xaaaae83cee68      187651017469544
23:16:23  GDB OUT x17            0xffffaf4c4748      281473622755144
23:16:23  GDB OUT x18            0x0                 0
23:16:23  GDB OUT x19            0xffffffffffffffff  -1
23:16:23  GDB OUT x20            0xaaaae83d0000      187651017474048
23:16:23  GDB OUT x21            0xaaaae83cf000      187651017469952
23:16:23  GDB OUT x22            0xaaaae83cf000      187651017469952
23:16:23  GDB OUT x23            0x0                 0
23:16:23  GDB OUT x24            0x1                 1
23:16:23  GDB OUT x25            0xaaaae83cf000      187651017469952
23:16:23  GDB OUT x26            0xaaaae83d06c0      187651017475776
23:16:23  GDB OUT x27            0xaaaae83dce88      187651017526920
23:16:23  GDB OUT x28            0x0                 0
23:16:23  GDB OUT x29            0xffffc61e4c70      281474005617776
23:16:23  GDB OUT x30            0xaaaae82faf10      187651016601360
23:16:23  GDB OUT sp             0xffffc61e4c70      0xffffc61e4c70
23:16:23  GDB OUT pc             0xffffaf4c4778      0xffffaf4c4778 <waitpid+48>
23:16:23  GDB OUT cpsr           0x60001000          [ EL=0 C Z ]
23:16:23  GDB OUT fpsr           0x0                 0
23:16:23  GDB OUT fpcr           0x0                 0
23:16:23  GDB OUT   Id   Target Id              Frame 
23:16:23  GDB OUT * 1    process 3731370 "bash" 0x0000ffffaf4c4778 in waitpid () from /lib64/libc.so.6
23:16:23  GDB OUT 
23:16:23  GDB OUT Thread 1 (process 3731370):
23:16:23  GDB OUT #0  0x0000ffffaf4c4778 in waitpid () from /lib64/libc.so.6
23:16:23  GDB OUT No symbol table info available.
23:16:23  GDB OUT #1  0x0000aaaae82faf10 in waitchld.isra ()
23:16:23  GDB OUT No symbol table info available.
23:16:23  GDB OUT #2  0x0000aaaae82fc63c in wait_for ()
23:16:23  GDB OUT No symbol table info available.
23:16:23  GDB OUT #3  0x0000aaaae82eabcc in execute_command_internal ()
23:16:23  GDB OUT No symbol table info available.
23:16:23  GDB OUT #4  0x0000aaaae82e9d3c in execute_command_internal ()
23:16:23  GDB OUT No symbol table info available.
23:16:23  GDB OUT #5  0x0000aaaae82eae58 in execute_command ()
23:16:23  GDB OUT No symbol table info available.
23:16:23  GDB OUT #6  0x0000aaaae82e8ed0 in execute_command_internal ()
23:16:23  GDB OUT No symbol table info available.
23:16:23  GDB OUT #7  0x0000aaaae82e9d3c in execute_command_internal ()
23:16:23  GDB OUT No symbol table info available.
23:16:23  GDB OUT #8  0x0000aaaae82eae58 in execute_command ()
23:16:23  GDB OUT No symbol table info available.
23:16:23  GDB OUT #9  0x0000aaaae82e8728 in execute_command_internal ()
23:16:23  GDB OUT No symbol table info available.
23:16:23  GDB OUT #10 0x0000aaaae82eae58 in execute_command ()
23:16:23  GDB OUT No symbol table info available.
23:16:23  GDB OUT #11 0x0000aaaae82d293c in reader_loop ()
23:16:23  GDB OUT No symbol table info available.
23:16:23  GDB OUT #12 0x0000aaaae82d0ec0 in main ()
23:16:23  GDB OUT No symbol table info available.
23:16:23  GDB OUT Saved corefile core.3731370.1
23:16:23  GDB OUT [Inferior 1 (process 3731370) detached]
23:16:23  INFO: Running '/usr/bin/gdb' failed with rc = 1
23:16:23  GDB ERR warning: target file /proc/3731370/cmdline contained unexpected null characters
23:16:23  GDB ERR warning: Memory read failed for corefile section, 131072 bytes at 0xffffaf630000.
23:16:23  GDB ERR /tmp/debugger1702906961442638105.txt:6: Error in sourced command file:
23:16:23  GDB ERR Requires argument (inferior id(s) to detach)
23:16:23  
23:16:23  INFO: Sleep for 60000 millis before next capture.
23:17:24  ***[TEST INFO 2024/06/06 23:17:23] executing /usr/bin/gdb -batch -x /tmp/debugger1702906961442638105.txt bash 3731370***
23:17:24  GDB OUT 0x0000ffffaf4c4778 in waitpid () from /lib64/libc.so.6
23:17:24  GDB OUT From                To                  Syms Read   Shared Object Library
23:17:24  GDB OUT 0x0000ffffaf5de010  0x0000ffffaf5eaa14  Yes (*)     /lib64/libtinfo.so.6
23:17:24  GDB OUT 0x0000ffffaf5a0cf0  0x0000ffffaf5a1974  Yes (*)     /lib64/libdl.so.2
23:17:24  GDB OUT 0x0000ffffaf440880  0x0000ffffaf530c50  Yes (*)     /lib64/libc.so.6
23:17:24  GDB OUT 0x0000ffffaf661080  0x0000ffffaf67bd88  Yes         /lib/ld-linux-aarch64.so.1
23:17:24  GDB OUT (*): Shared library is missing debugging information.
23:17:24  GDB OUT x0             0xffffffffffffffff  -1
23:17:24  GDB OUT x1             0xffffc61e4d30      281474005617968
23:17:24  GDB OUT x2             0x0                 0
23:17:24  GDB OUT x3             0x0                 0
23:17:24  GDB OUT x4             0x1                 1
23:17:24  GDB OUT x5             0xaaab227d87e0      187651994781664
23:17:24  GDB OUT x6             0x38f019            3731481
23:17:24  GDB OUT x7             0x0                 0
23:17:24  GDB OUT x8             0x104               260
23:17:24  GDB OUT x9             0xaaab227d2200      187651994755584
23:17:24  GDB OUT x10            0xffffaf69fb88      281473624701832
23:17:24  GDB OUT x11            0xaaaae83d9a48      187651017513544
23:17:24  GDB OUT x12            0x0                 0
23:17:24  GDB OUT x13            0xaaaae82fe2b8      187651016614584
23:17:24  GDB OUT x14            0x8                 8
23:17:24  GDB OUT x15            0x48                72
23:17:24  GDB OUT x16            0xaaaae83cee68      187651017469544
23:17:24  GDB OUT x17            0xffffaf4c4748      281473622755144
23:17:24  GDB OUT x18            0x0                 0
23:17:24  GDB OUT x19            0xffffffffffffffff  -1
23:17:24  GDB OUT x20            0xaaaae83d0000      187651017474048
23:17:24  GDB OUT x21            0xaaaae83cf000      187651017469952
23:17:24  GDB OUT x22            0xaaaae83cf000      187651017469952
23:17:24  GDB OUT x23            0x0                 0
23:17:24  GDB OUT x24            0x1                 1
23:17:24  GDB OUT x25            0xaaaae83cf000      187651017469952
23:17:24  GDB OUT x26            0xaaaae83d06c0      187651017475776
23:17:24  GDB OUT x27            0xaaaae83dce88      187651017526920
23:17:24  GDB OUT x28            0x0                 0
23:17:24  GDB OUT x29            0xffffc61e4c70      281474005617776
23:17:24  GDB OUT x30            0xaaaae82faf10      187651016601360
23:17:24  GDB OUT sp             0xffffc61e4c70      0xffffc61e4c70
23:17:24  GDB OUT pc             0xffffaf4c4778      0xffffaf4c4778 <waitpid+48>
23:17:24  GDB OUT cpsr           0x60001000          [ EL=0 C Z ]
23:17:24  GDB OUT fpsr           0x0                 0
23:17:24  GDB OUT fpcr           0x0                 0
23:17:24  GDB OUT   Id   Target Id              Frame 
23:17:24  GDB OUT * 1    process 3731370 "bash" 0x0000ffffaf4c4778 in waitpid () from /lib64/libc.so.6
23:17:24  GDB OUT 
23:17:24  GDB OUT Thread 1 (process 3731370):
23:17:24  GDB OUT #0  0x0000ffffaf4c4778 in waitpid () from /lib64/libc.so.6
23:17:24  GDB OUT No symbol table info available.
23:17:24  GDB OUT #1  0x0000aaaae82faf10 in waitchld.isra ()
23:17:24  GDB OUT No symbol table info available.
23:17:24  GDB OUT #2  0x0000aaaae82fc63c in wait_for ()
23:17:24  GDB OUT No symbol table info available.
23:17:24  GDB OUT #3  0x0000aaaae82eabcc in execute_command_internal ()
23:17:24  GDB OUT No symbol table info available.
23:17:24  GDB OUT #4  0x0000aaaae82e9d3c in execute_command_internal ()
23:17:24  GDB OUT No symbol table info available.
23:17:24  GDB OUT #5  0x0000aaaae82eae58 in execute_command ()
23:17:24  GDB OUT No symbol table info available.
23:17:24  GDB OUT #6  0x0000aaaae82e8ed0 in execute_command_internal ()
23:17:24  GDB OUT No symbol table info available.
23:17:24  GDB OUT #7  0x0000aaaae82e9d3c in execute_command_internal ()
23:17:24  GDB OUT No symbol table info available.
23:17:24  GDB OUT #8  0x0000aaaae82eae58 in execute_command ()
23:17:24  GDB OUT No symbol table info available.
23:17:24  GDB OUT #9  0x0000aaaae82e8728 in execute_command_internal ()
23:17:24  GDB OUT No symbol table info available.
23:17:24  GDB OUT #10 0x0000aaaae82eae58 in execute_command ()
23:17:24  GDB OUT No symbol table info available.
23:17:24  GDB OUT #11 0x0000aaaae82d293c in reader_loop ()
23:17:24  GDB OUT No symbol table info available.
23:17:24  GDB OUT #12 0x0000aaaae82d0ec0 in main ()
23:17:24  GDB OUT No symbol table info available.
23:17:24  GDB OUT Saved corefile core.3731370.2
23:17:24  GDB OUT A debugging session is active.
23:17:24  GDB OUT 
23:17:24  GDB OUT   Inferior 1 [process 3731370] will be detached.
23:17:24  GDB OUT 
23:17:24  GDB OUT Quit anyway? (y or n) [answered Y; input not from terminal]
23:17:24  GDB OUT [Inferior 1 (process 3731370) detached]
23:17:24  ***[TEST INFO 2024/06/06 23:17:23] executing kill -ABRT 3731370***
23:17:24  ***[TEST INFO 2024/06/06 23:17:23] kill -ABRT signal sent***
23:17:24  Time spent executing: 360526 milliseconds
23:17:24  Test result: FAILED
23:17:24  Output from test:
23:17:24   [OUT] start running script
23:17:24   [OUT] export GLIBC_TUNABLES=glibc.cpu.hwcaps=-XSAVEC,-XSAVE,-AVX2,-ERMS,-AVX,-AVX_Fast_Unaligned_Load
23:17:24   [OUT] export LD_BIND_NOT=on
23:17:24   [OUT] /home/jenkins/workspace/Test_openjdk11_j9_sanity.functional_aarch64_linux_Nightly_testList_1/jdkbinary/j2sdk-image/bin/java -XX:+EnableCRIUSupport  -Xgcpolicy:gencon -Xgcthreads64 -XX:CheckpointGCThreads=1  -Xtrace:print={j9jcl.533,j9vm.684-696,j9vm.699,j9vm.717-743} --add-exports java.base/openj9.internal.criu=ALL-UNNAMED -cp /home/jenkins/workspace/Test_openjdk11_j9_sanity.functional_aarch64_linux_Nightly_testList_1/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu/criu.jar org.openj9.criu.TimeChangeTest testTimeCompensation 1
23:17:24   [ERR] /home/jenkins/workspace/Test_openjdk11_j9_sanity.functional_aarch64_linux_Nightly_testList_1/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu/criuScript.sh: line 41: 3731374 Killed                  $2 -XX:+EnableCRIUSupport $3 -cp "$1/criu.jar" $4 $5 $6 > testOutput 2>&1

There is a similar closed issue https://github.com/eclipse-openj9/openj9/issues/18471

pshipton commented 4 weeks ago

@tajila fyi

JasonFengJ9 commented 4 weeks ago

50x grinder - https://openj9-jenkins.osuosl.org/job/Grinder/3652/ - passed 5x same machine grinder - https://openj9-jenkins.osuosl.org/job/Grinder/3653/ - original failure not reproduced