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

testJitserverArguments_0_FAILED FAILURE: JITServer::StreamFailure: Connect failed: Connection refused #19151

Open JasonFengJ9 opened 8 months ago

JasonFengJ9 commented 8 months ago

Failure link

From an internal build(rhel8-aarch64-1):

openjdk version "1.8.0_412-beta"
IBM Semeru Runtime Open Edition (build 1.8.0_412-beta-202403132234-b05)
Eclipse OpenJ9 VM (build master-e5d99e177, JRE 1.8.0 Linux aarch64-64-Bit Compressed References 20240313_865 (JIT enabled, AOT enabled)
OpenJ9   - e5d99e177
OMR      - 66252485a
JCL      - 16aa7c249 based on jdk8u412-b05)

Rerun in Grinder - Change TARGET to run only the failed test targets.

Optional info

Failure output (captured from console output)

[2024-03-13T23:42:15.766Z] variation: NoOptions
[2024-03-13T23:42:15.766Z] JVM_OPTIONS:  

[2024-03-13T23:42:45.102Z] Testing: Test SSL success condition
[2024-03-13T23:42:45.102Z] Test start time: 2024/03/13 19:42:45 Eastern Standard Time
[2024-03-13T23:42:45.102Z] Running command: bash /home/jenkins/workspace/Test_openjdk8_j9_sanity.functional_aarch64_linux_testList_0/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/jitserver/jitserverScript.sh /home/jenkins/workspace/Test_openjdk8_j9_sanity.functional_aarch64_linux_testList_0/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/jitserver /home/jenkins/workspace/Test_openjdk8_j9_sanity.functional_aarch64_linux_testList_0/jdkbinary/j2sdk-image/bin "-Xjit" "-XX:+UseJITServer -Xjit:count=0,verbose={JITServer},verbose={JITServerConns},verbose={compilePerformance} -XX:-JITServerLocalSyncCompiles -XX:JITServerSSLRootCerts=cert.pem" false
[2024-03-13T23:42:45.102Z] Time spent starting: 2 milliseconds
[2024-03-13T23:42:50.043Z] Time spent executing: 4523 milliseconds
[2024-03-13T23:42:50.043Z] Test result: FAILED
[2024-03-13T23:42:50.043Z] Output from test:

[2024-03-13T23:42:50.043Z]  [ERR]  (cold) Compiling sun/reflect/Reflection.getCallerClass()Ljava/lang/Class;  OrdinaryMethod j9m=00000000000411D8 remote t=0 compThreadID=0 memLimit=262144 KB freePhysicalMemory=6744 MB
[2024-03-13T23:42:50.043Z]  [ERR] #FAILURE:  JITServer::StreamFailure: Connect failed: Connection refused for sun/reflect/Reflection.getCallerClass()Ljava/lang/Class; @ cold
[2024-03-13T23:42:50.043Z]  [ERR] #JITServer: t=     0 Could not connect to a server. Next attempt in 2000 ms.
[2024-03-13T23:42:50.043Z]  [ERR] #JITServer: t=     0 Resetting activation policy to AGGRESSIVE because client has lost connection to server
[2024-03-13T23:42:50.043Z]  [ERR] #JITServer: compThreadID=0 JITServer StreamFailure: Generic stream failure
[2024-03-13T23:42:50.043Z]  [ERR] ! (cold) sun/reflect/Reflection.getCallerClass()Ljava/lang/Class; Q_SZ=0 Q_SZI=0 QW=1 j9m=00000000000411D8 time=993us compilationStreamFailure memLimit=262144 KB freePhysicalMemory=6744 MB mem=[region=64 system=2048]KB compThreadID=0
[2024-03-13T23:42:50.043Z]  [ERR]  (cold) Compiling sun/reflect/Reflection.getCallerClass()Ljava/lang/Class;  OrdinaryMethod j9m=00000000000411D8  t=0 compThreadID=0 memLimit=262144 KB freePhysicalMemory=6744 MB
[2024-03-13T23:42:50.043Z]  [ERR] + (cold) sun/reflect/Reflection.getCallerClass()Ljava/lang/Class; @ 0000FFFF6B14002C-0000FFFF6B140158 OrdinaryMethod - Q_SZ=0 Q_SZI=0 QW=1 j9m=00000000000411D8 bcsz=2 sync JNI time=999us mem=[region=704 system=2048]KB compThreadID=0 CpuLoad=5%(0%avg) JvmCpu=0% queueTime=2367us
[2024-03-13T23:42:50.043Z]  [ERR] #INFO:  Method java/lang/Math.<clinit>()V will continue as interpreted

[2024-03-13T23:42:50.047Z]  [ERR] #JITServer: t=   131 Could not connect to a server. Next attempt in 2000 ms.
[2024-03-13T23:42:50.047Z]  [ERR] #JITServer: t=   131 Resetting activation policy to AGGRESSIVE because client has lost connection to server
[2024-03-13T23:42:50.047Z]  [ERR] #JITServer: JITServer StreamFailure (server unreachable before the termination message was sent): Connect failed: Connection refused
[2024-03-13T23:42:50.047Z]  [ERR] /home/jenkins/workspace/Test_openjdk8_j9_sanity.functional_aarch64_linux_testList_0/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/jitserver/jitserverScript.sh: line 97: 236879 Killed                  $TEST_JDK_BIN/jitserver $JITSERVER_OPTIONS
[2024-03-13T23:42:50.047Z] >> Success condition was found: [Output match: (java|openjdk|semeru) version]
[2024-03-13T23:42:50.047Z] >> Required condition was found: [Output match: JITServer Client Mode.]
[2024-03-13T23:42:50.047Z] >> Success condition was found: [Output match: Successfully initialized SSL context]
[2024-03-13T23:42:50.047Z] >> Required condition was not found: [Output match: SSL connection on socket]
[2024-03-13T23:42:50.047Z] >> Success condition was not found: [Output match: Connected to a server]
[2024-03-13T23:42:50.047Z] >> Failure condition was not found: [Output match: (Fatal|Unhandled) Exception]
[2024-03-13T23:42:50.047Z] >> Success condition was found: [Output match: JITSERVER EXISTS]
[2024-03-13T23:42:50.047Z] >> Success condition was found: [Output match: JITSERVER STILL EXISTS]
[2024-03-13T23:42:50.047Z] >> Failure condition was not found: [Output match: JITSERVER DOES NOT EXIST]
[2024-03-13T23:42:50.047Z] >> Failure condition was not found: [Output match: JITSERVER NO LONGER EXISTS]

[2024-03-13T23:44:07.212Z] ---TEST RESULTS---
[2024-03-13T23:44:07.212Z] Number of PASSED tests: 7 out of 8
[2024-03-13T23:44:07.212Z] Number of FAILED tests: 1 out of 8
[2024-03-13T23:44:07.212Z] 
[2024-03-13T23:44:07.212Z] ---SUMMARY OF FAILED TESTS---
[2024-03-13T23:44:07.212Z] Test SSL success condition
[2024-03-13T23:44:07.212Z] -----------------------------
[2024-03-13T23:44:07.212Z] 
[2024-03-13T23:44:07.212Z] -----------------------------------
[2024-03-13T23:44:07.212Z] testJitserverArguments_0_FAILED

50x internal grinder - 50/50 failed with [ERR] curl: (7) Failed to connect to localhost port 48170: Connection refused.

pshipton commented 8 months ago

@mpirvu fyi

JasonFengJ9 commented 8 months ago

JDK8 x86-64_linux_fips140_2(rhel8x86-rtp-rtfips6-1)

[2024-03-16T03:42:29.791Z] variation: NoOptions
[2024-03-16T03:42:29.791Z] JVM_OPTIONS:   -Dsemeru.fips=true

[2024-03-16T03:43:05.293Z] Testing: Test SSL success condition
[2024-03-16T03:43:05.293Z] Test start time: 2024/03/15 20:43:05 Pacific Standard Time
[2024-03-16T03:43:05.293Z] Running command: bash /home/jenkins/workspace/Test_openjdk8_j9_sanity.functional_x86-64_linux_fips140_2_testList_1/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/jitserver/jitserverScript.sh /home/jenkins/workspace/Test_openjdk8_j9_sanity.functional_x86-64_linux_fips140_2_testList_1/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/jitserver /home/jenkins/workspace/Test_openjdk8_j9_sanity.functional_x86-64_linux_fips140_2_testList_1/jdkbinary/j2sdk-image/bin "-Xjit" "-XX:+UseJITServer -Xjit:count=0,verbose={JITServer},verbose={JITServerConns},verbose={compilePerformance} -XX:-JITServerLocalSyncCompiles -XX:JITServerSSLRootCerts=cert.pem" false false
[2024-03-16T03:43:05.293Z] Time spent starting: 3 milliseconds
[2024-03-16T03:43:08.680Z] Time spent executing: 3362 milliseconds
[2024-03-16T03:43:08.680Z] Test result: FAILED
[2024-03-16T03:43:08.680Z] Output from test:
[2024-03-16T03:43:08.680Z]  [OUT] start running script
[2024-03-16T03:43:08.680Z]  [OUT] Generate SSL certificates
[2024-03-16T03:43:08.680Z]  [OUT] Creating SSL certificates
[2024-03-16T03:43:08.680Z]  [OUT] Certificates generated
[2024-03-16T03:43:08.680Z]  [OUT] Starting /home/jenkins/workspace/Test_openjdk8_j9_sanity.functional_x86-64_linux_fips140_2_testList_1/jdkbinary/j2sdk-image/bin/jitserver -XX:JITServerPort=57368 -XX:JITServerHealthProbePort=39608  -Xjit -XX:JITServerSSLKey=key.pem -XX:JITServerSSLCert=cert.pem
[2024-03-16T03:43:08.680Z]  [OUT] JITSERVER DOES NOT EXIST
[2024-03-16T03:43:08.680Z]  [OUT] finished script
[2024-03-16T03:43:08.680Z]  [ERR] Generating RSA private key, 2048 bit long modulus (2 primes)
[2024-03-16T03:43:08.680Z]  [ERR] ************************************************************************************************************************************************************************************************************************************************************************************************************************************+++++
[2024-03-16T03:43:08.680Z]  [ERR] ***********************************************************************************************************************************************************************************************************************************************************************************************************************************************************************************************************************************************************************************************************************************************************************************************************************************************************************************+++++
[2024-03-16T03:43:08.680Z]  [ERR] e is 65537 (0x010001)
[2024-03-16T03:43:08.680Z]  [ERR] Generating a RSA private key
[2024-03-16T03:43:08.680Z]  [ERR] *************+++++
[2024-03-16T03:43:08.680Z]  [ERR] **************************************************************************************************************************************************************************************************************************************************************************************************************************************************************************************************************+++++
[2024-03-16T03:43:08.680Z]  [ERR] writing new private key to 'wrongKey.pem'
[2024-03-16T03:43:08.680Z]  [ERR] -----
[2024-03-16T03:43:08.680Z]  [ERR] 
[2024-03-16T03:43:08.680Z]  [ERR] JITServer is ready to accept incoming requests
[2024-03-16T03:43:08.680Z]  [ERR] can't bind server address: Address already in use
[2024-03-16T03:43:08.680Z]  [ERR] Failed to open server socket on port 57368

[2024-03-16T03:44:26.200Z] ---TEST RESULTS---
[2024-03-16T03:44:26.200Z] Number of PASSED tests: 8 out of 9
[2024-03-16T03:44:26.200Z] Number of FAILED tests: 1 out of 9
[2024-03-16T03:44:26.200Z] 
[2024-03-16T03:44:26.200Z] ---SUMMARY OF FAILED TESTS---
[2024-03-16T03:44:26.200Z] Test SSL success condition
[2024-03-16T03:44:26.200Z] -----------------------------
[2024-03-16T03:44:26.200Z] 
[2024-03-16T03:44:26.200Z] -----------------------------------
[2024-03-16T03:44:26.200Z] testJitserverArguments_0_FAILED
mpirvu commented 8 months ago

This passes for me with a grinder using a nightly build: e.g: 1 run: https://hyc-runtimes-jenkins.swg-devops.com/job/Grinder/38854/ 25 runs: https://hyc-runtimes-jenkins.swg-devops.com/job/Grinder/38869/ 50 runs: https://hyc-runtimes-jenkins.swg-devops.com/job/Grinder/38870/ Though it fails with the original build: 20/25 failures:: https://hyc-runtimes-jenkins.swg-devops.com/job/Grinder/38867/

mpirvu commented 8 months ago

Regarding the failure from comment https://github.com/eclipse-openj9/openj9/issues/19151#issuecomment-2005074747, this happened because the server could not start because the port it wanted to use was already used by another process:

23:43:08   [ERR] JITServer is ready to accept incoming requests
23:43:08   [ERR] can't bind server address: Address already in use
23:43:08   [ERR] Failed to open server socket on port 57368