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.28k stars 721 forks source link

OpenJDK BootstrapLogger/BootstrapLoggerTest crash vmState=0x00040000 #17349

Open pshipton opened 1 year ago

pshipton commented 1 year ago

https://openj9-jenkins.osuosl.org/job/Test_openjdk20_j9_sanity.openjdk_s390x_linux_Nightly/49 jdk_lang_j9_0 java/lang/System/LoggerFinder/internal/BootstrapLogger/BootstrapLoggerTest.java

https://openj9-artifactory.osuosl.org/artifactory/ci-openj9/Test/Test_openjdk20_j9_sanity.openjdk_s390x_linux_Nightly/49/openjdk_test_output.tar.gz

21:05:08  STDERR:
21:05:08  Testing: SECURE
21:05:08  Setting security manager
21:05:08  WARNING: A terminally deprecated method in java.lang.System has been called
21:05:08  WARNING: System::setSecurityManager has been called by BootstrapLoggerTest (file:/home/jenkins/workspace/Test_openjdk20_j9_sanity.openjdk_s390x_linux_Nightly/aqa-tests/TKG/output_16832443529850/jdk_lang_j9_0/work/classes/0/java/lang/System/LoggerFinder/internal/BootstrapLogger/BootstrapLoggerTest.d/)
21:05:08  WARNING: Please consider reporting this to the maintainers of BootstrapLoggerTest
21:05:08  WARNING: System::setSecurityManager will be removed in a future release
21:05:08  VM Booted: false
21:05:08  LogManager initialized: false
21:05:08  VM Booted: true
21:05:08  LogManager initialized: false
21:05:08  May 05, 2023 1:04:20 AM BootstrapLoggerTest main
21:05:08  INFO: LOG#4: VM now booted: true
21:05:08  May 05, 2023 1:04:20 AM jdk.internal.logger.BootstrapLogger$LogEvent log
21:05:08  INFO: Early message #1
21:05:08  May 05, 2023 1:04:20 AM jdk.internal.logger.BootstrapLogger$LogEvent log
21:05:08  WARNING: Early message #2
21:05:08  May 05, 2023 1:04:20 AM jdk.internal.logger.BootstrapLogger$LogEvent log
21:05:08  INFO: Early message #3
21:05:08  Unhandled exception
21:05:08  Type=Segmentation error vmState=0x00040000
21:05:08  J9Generic_Signal_Number=00000018 Signal_Number=0000000b Error_Value=00000000 Signal_Code=00000001
21:05:08  Handler1=000003FF8BAC96C8 Handler2=000003FF8B9B1998 InaccessibleAddress=0000000000000000
21:05:08  gpr0=0000000000000000 gpr1=0000000000000001 gpr2=0000000000000000 gpr3=0000000000000002
21:05:08  gpr4=000003FEF4008C10 gpr5=0000000000000000 gpr6=0000000000000002 gpr7=000000000000000A
21:05:08  gpr8=000003FEF4008C10 gpr9=000003FEF4008BE0 gpr10=000003FF8ADC2CD8 gpr11=000003FF8BD38C58
21:05:08  gpr12=0000000000000000 gpr13=00000000000000EB gpr14=000003FF8BAC29CE gpr15=000003FF8ADC29C8
21:05:08  psw=000003FF8BCA18DE mask=0705000180000000 fpc=00080000 bea=000003FF8BAC29C8
21:05:08  fpr0 000003fef00008f4 (f: 4026534144.000000, d: 2.170669e-311)
21:05:08  fpr1 000003ff8adc19a0 (f: 2329680384.000000, d: 2.171953e-311)
21:05:08  fpr2 0000000000000000 (f: 0.000000, d: 0.000000e+00)
21:05:08  fpr3 408a755555555555 (f: 1431655808.000000, d: 8.466667e+02)
21:05:08  fpr4 0000000000000007 (f: 7.000000, d: 3.458460e-323)
21:05:08  fpr5 3f7d8f891d50d1a2 (f: 491835808.000000, d: 7.216964e-03)
21:05:08  fpr6 000003fef0000960 (f: 4026534144.000000, d: 2.170669e-311)
21:05:08  fpr7 0000000000000000 (f: 0.000000, d: 0.000000e+00)
21:05:08  fpr8 0000000000000000 (f: 0.000000, d: 0.000000e+00)
21:05:08  fpr9 0000000000000000 (f: 0.000000, d: 0.000000e+00)
21:05:08  fpr10 000003ff8ad84000 (f: 2329427968.000000, d: 2.171953e-311)
21:05:08  fpr11 0000000000000000 (f: 0.000000, d: 0.000000e+00)
21:05:08  fpr12 0005fae7de6fa519 (f: 3731858688.000000, d: 8.316353e-309)
21:05:08  fpr13 000003feec01be68 (f: 3959537152.000000, d: 2.170636e-311)
21:05:08  fpr14 000003ff817465e0 (f: 2171889152.000000, d: 2.171875e-311)
21:05:08  fpr15 000003feec0b9dd8 (f: 3960184320.000000, d: 2.170636e-311)
21:05:08  Module=/home/jenkins/workspace/Test_openjdk20_j9_sanity.openjdk_s390x_linux_Nightly/openjdkbinary/j2sdk-image/lib/default/libj9vm29.so
21:05:08  Module_base_address=000003FF8BA80000
21:05:08  Target=2_90_20230504_52 (Linux 5.4.0-137-generic)
21:05:08  CPU=s390x (4 logical CPUs) (0x1f58f7000 RAM)
21:05:08  ----------- Stack Backtrace -----------
21:05:08  getSendSlotsFromSignature+0x1e (0x000003FF8BCA18DE [libj9vm29.so+0x2218de])
21:05:08  getNPEMessage+0x1786 (0x000003FF8BAC29CE [libj9vm29.so+0x429ce])
21:05:08  JVM_GetExtendedNPEMessage+0x164 (0x000003FF902A21D4 [libjvm.so+0x221d4])
21:05:08  ffi_call_SYSV+0x98 (0x000003FF8BD15498 [libj9vm29.so+0x295498])
21:05:08  ffi_call+0xa2 (0x000003FF8BD14EAA [libj9vm29.so+0x294eaa])
21:05:08  _ZN26VM_BytecodeInterpreterFull3runEP10J9VMThread+0x13a94 (0x000003FF8BB781E4 [libj9vm29.so+0xf81e4])
21:05:08  bytecodeLoopFull+0xee (0x000003FF8BB6473E [libj9vm29.so+0xe473e])
21:05:08  c_cInterpreter+0x64 (0x000003FF8BC8EFA4 [libj9vm29.so+0x20efa4])
21:05:08  ---------------------------------------
pshipton commented 1 year ago

@tajila @ChengJin01 fyi

tajila commented 1 year ago

@JasonFengJ9 Can you please take a look at this

JasonFengJ9 commented 1 year ago 
#12 <signal handler called>
#13 getSendSlotsFromSignature (signature=0x2 <error: Cannot access memory at address 0x2>) at /home/jenkins/workspace/Build_JDK20_s390x_linux_Nightly/openj9/runtime/util/sendslot.c:34
#14 0x000003ff8bac29ce in simulateStack (npeMsgData=0x3ff8adc2cd8) at /home/jenkins/workspace/Build_JDK20_s390x_linux_Nightly/openj9/runtime/vm/extendedMessageNPE.cpp:1625
#15 getNPEMessage (npeMsgData=<optimized out>) at /home/jenkins/workspace/Build_JDK20_s390x_linux_Nightly/openj9/runtime/vm/extendedMessageNPE.cpp:1349
#16 0x000003ff902a21d4 in JVM_GetExtendedNPEMessage (env=0x3ff8c58d400, throwableObj=0x3fef00088b0) at /home/jenkins/workspace/Build_JDK20_s390x_linux_Nightly/openj9/runtime/j9vm/javanextvmi.cpp:163
#17 0x000003ff8bd15498 in ffi_call_SYSV () from /home/jenkins/workspace/Test_openjdk20_j9_sanity.openjdk_s390x_linux_Nightly/openjdkbinary/j2sdk-image/lib/default/libj9vm29.so
#18 0x000003ff8bd14eaa in ffi_call (cif=<optimized out>, fn=<optimized out>, rvalue=<optimized out>, avalue=<optimized out>) at /home/jenkins/workspace/Build_JDK20_s390x_linux_Nightly/openj9/runtime/libffi/s390/ffi.c:532
#19 0x000003ff8bb781e4 in VM_BytecodeInterpreterFull::cJNICallout (isStatic=<optimized out>, function=<optimized out>, returnStorage=<optimized out>, returnType=<optimized out>, javaArgs=0x3ff00000000, receiverAddress=0x3fef00088b0, 
    _pc=<optimized out>, _sp=<optimized out>, this=<optimized out>) at /home/jenkins/workspace/Build_JDK20_s390x_linux_Nightly/openj9/runtime/vm/BytecodeInterpreter.hpp:2523
#20 VM_BytecodeInterpreterFull::callCFunction (returnType=<optimized out>, isStatic=<optimized out>, bp=<optimized out>, javaArgs=<optimized out>, receiverAddress=<optimized out>, jniMethodStartAddress=<optimized out>, _pc=<optimized out>, 
    _sp=<optimized out>, this=<optimized out>) at /home/jenkins/workspace/Build_JDK20_s390x_linux_Nightly/openj9/runtime/vm/BytecodeInterpreter.hpp:2341
#21 VM_BytecodeInterpreterFull::runJNINative (_pc=<optimized out>, _sp=<optimized out>, this=<optimized out>) at /home/jenkins/workspace/Build_JDK20_s390x_linux_Nightly/openj9/runtime/vm/BytecodeInterpreter.hpp:2231
#22 VM_BytecodeInterpreterFull::run (this=0x3ff8adc33e0, vmThread=<optimized out>) at /home/jenkins/workspace/Build_JDK20_s390x_linux_Nightly/openj9/runtime/vm/BytecodeInterpreter.hpp:10814

Apparently the signature=0x2 was bad and caused the segmentation error. https://github.com/eclipse-openj9/openj9/blob/746811daa8dd86959b1b37ab2d559e28c4feed6d/runtime/util/sendslot.c#L34

Running a 50x grinder - https://openj9-jenkins.osuosl.org/job/Grinder/2314/ - this failure wasn't reproduced

ThanHenderson commented 8 months ago

I am experiencing this pretty consistently locally when trying to run DayTrader benchmarks on OJDK MH builds for JDK11.

Edit for context: OpenJ9 SHA 5a29d29e07da20f0c8d45c0cba7b20a73069fa5f

ECLIPSE OMR SHA 0966eb360f6e0537e165426416051ac30c9afc65

JDK11 556d2a9dc7955cfa1e4bdd56b759224ca6c8cba6

ChengJin01 commented 8 months ago

FYI: @fengxue-IS

JasonFengJ9 commented 8 months ago

I am experiencing this pretty consistently locally when trying to run DayTrader benchmarks on OJDK MH builds for JDK11.

@ThanHenderson is there a way to reproduce the failure?

ThanHenderson commented 8 months ago

I am experiencing this pretty consistently locally when trying to run DayTrader benchmarks on OJDK MH builds for JDK11.

@ThanHenderson is there a way to reproduce the failure?

I was seeing it quite frequently, then it stopped occurring... I can try to reproduce.

ThanHenderson commented 8 months ago

@JasonFengJ9 Oh, I see. The problem arises when a shared class cache is misused. In my case I have a script that specifies the shared class cache name, and I was running the the same cache for different builds. I don't think there is an underlying problem with the VM.

pshipton commented 8 months ago

Except on Windows, if you attempt to use a shared cache that doesn't match the VM SHA, it should delete and recreate the cache.