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 Test Health Port Connection refused #19224

Open pshipton opened 6 months ago

pshipton commented 6 months ago

https://openj9-jenkins.osuosl.org/job/Test_openjdk8_j9_sanity.functional_s390x_linux_Nightly_testList_0/758 testJitserverArguments_0 

Testing: Test Health Port
Test start time: 2024/03/26 01:01:42 Eastern Standard Time
Running command: bash /home/jenkins/workspace/Test_openjdk8_j9_sanity.functional_s390x_linux_Nightly_testList_0/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/jitserver/jitserverScript.sh /home/jenkins/workspace/Test_openjdk8_j9_sanity.functional_s390x_linux_Nightly_testList_0/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/jitserver /home/jenkins/workspace/Test_openjdk8_j9_sanity.functional_s390x_linux_Nightly_testList_0/jdkbinary/j2sdk-image/bin "-Xjit" "-XX:+UseJITServer -Xjit:count=0,verbose={JITServer},verbose={JITServerConns},verbose={compilePerformance} -XX:-JITServerLocalSyncCompiles" false true
Time spent starting: 0 milliseconds
Time spent executing: 4111 milliseconds
Test result: FAILED
Output from test:
 [OUT] start running script
 [OUT] Starting /home/jenkins/workspace/Test_openjdk8_j9_sanity.functional_s390x_linux_Nightly_testList_0/jdkbinary/j2sdk-image/bin/jitserver -XX:JITServerPort=42327 -XX:JITServerHealthProbePort=46769  -Xjit 
 [OUT] 28224 ?        00:00:00 jitserver
 [OUT] JITSERVER EXISTS
 [OUT] 28224 ?        00:00:00 jitserver
 [OUT] JITSERVER STILL EXISTS
 [OUT] Terminating /home/jenkins/workspace/Test_openjdk8_j9_sanity.functional_s390x_linux_Nightly_testList_0/jdkbinary/j2sdk-image/bin/jitserver -XX:JITServerPort=42327 -XX:JITServerHealthProbePort=46769  -Xjit 
 [OUT] finished script
 [ERR] /home/jenkins/workspace/Test_openjdk8_j9_sanity.functional_s390x_linux_Nightly_testList_0/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/jitserver/jitserverconfig.sh: line 30: lsof: command not found
 [ERR] /home/jenkins/workspace/Test_openjdk8_j9_sanity.functional_s390x_linux_Nightly_testList_0/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/jitserver/jitserverconfig.sh: line 30: lsof: command not found
 [ERR] JITServer is currently a technology preview. Its use is not yet supported.
 [ERR] #JITServer: JITServer version: 1.59.0
 [ERR] #JITServer: JITServer Client Mode. Server address: localhost port: 42327. Connection Timeout 30000ms
 [ERR] #JITServer: Identifier for current client JVM: 2488259287746554816
 [ERR] 
 [ERR] #INFO:  _______________________________________
 [ERR] #INFO:  Version Information:
 [ERR] #INFO:       JIT Level  - j9jit_20240325_2120_jenkins
 [ERR] #INFO:       JVM Level  - 20240325_785
 [ERR] #INFO:       GC Level   - 1c38c8af009
 [ERR] #INFO:  
 [ERR] #INFO:  Processor Information:
 [ERR] #INFO:          Name: z15
 [ERR] #INFO:        Vendor: IBM
 [ERR] #INFO:       numProc: 4
 [ERR] #INFO:           DFP: 1
 [ERR] #INFO:           FPE: 1
 [ERR] #INFO:           HPR: 1
 [ERR] #INFO:            RI: 0
 [ERR] #INFO:            TX: 1
 [ERR] #INFO:           TXC: 1
 [ERR] #INFO:            VF: 1
 [ERR] #INFO:            GS: 1
 [ERR] #INFO:  
 [ERR] #INFO:  _______________________________________
 [ERR] #INFO:  AOT 
 [ERR] #INFO:  options specified:
 [ERR] #INFO:       samplingFrequency=2,numInterfaceCallCacheSlots=4
 [ERR] #INFO:  
 [ERR] #INFO:  options in effect:
 [ERR] #INFO:       count=1000
 [ERR] #INFO:       disableSuffixLogs
 [ERR] #INFO:       numInterfaceCallCacheSlots=4
 [ERR] #INFO:       samplingFrequency=2
 [ERR] #INFO:       verbose={options|compilePerformance|JITServer|JITServerConns}
 [ERR] #INFO:       compressedRefs shiftAmount=0
 [ERR] #INFO:  aggressivenessLevel=5
 [ERR] #INFO:  _______________________________________
 [ERR] #INFO:  JIT 
 [ERR] #INFO:  options specified:
 [ERR] #INFO:       count=0,verbose={JITServer},verbose={JITServerConns},verbose={compilePerformance}
 [ERR] ,disableSuffixLogs#INFO:  
 [ERR] #INFO:  options in effect:
 [ERR] #INFO:       count=0
 [ERR] #INFO:       disableSuffixLogs
 [ERR] #INFO:       numInterfaceCallCacheSlots=4
 [ERR] #INFO:       samplingFrequency=2
 [ERR] #INFO:       verbose={options|compilePerformance|JITServer|JITServerConns}
 [ERR] #INFO:       compressedRefs shiftAmount=0
 [ERR] #INFO:  aggressivenessLevel=5
 [ERR] #INFO:  StartTime: Mar 26 01:01:44 2024
 [ERR] #INFO:  Free Physical Memory: 5941 MB 
 [ERR] #INFO:  Shared Class Cache Information:
 [ERR] #INFO:   SCCname:sharedcc_jenkins   SCCpath:/home/jenkins/.cache/javasharedresources/C290M4F1A64P_sharedcc_jenkins_G43L00
 [ERR] #INFO:   SCC_stats_bytes: size=314572192 free=62616052 ROMClass=1330584 AOTCode=1589508 AOTData=288 JITHint=10648 JITProfile=0
 [ERR] #INFO:   SCC_stats_#:     ROMClasses=446 AOTMethods=1201 AOTDataEntries=1 AOTHints=412 AOTJitProfiles=0
 [ERR] #INFO:   AOT header compressedRefs shiftAmount=0
 [ERR] #INFO:  CPU entitlement = 400.00
 [ERR] #INFO:  Method java/lang/String.<clinit>()V will continue as interpreted
 [ERR] #INFO:  Method com/ibm/jit/JITHelpers.<clinit>()V will continue as interpreted
 [ERR] #INFO:  Method sun/misc/Unsafe.<clinit>()V will continue as interpreted
 [ERR] #INFO:  Method sun/reflect/Reflection.<clinit>()V will continue as interpreted
 [ERR] #INFO:  Method sun/misc/VM.<clinit>()V will continue as interpreted
 [ERR] #INFO:  Method java/util/Properties.<clinit>()V will continue as interpreted
 [ERR] #INFO:  Method java/lang/Float.<clinit>()V will continue as interpreted
 [ERR] #INFO:  Method java/lang/Class.<clinit>()V will continue as interpreted
 [ERR]  (cold) Compiling sun/reflect/Reflection.getCallerClass()Ljava/lang/Class;  OrdinaryMethod j9m=0000000000090ED8 remote t=0 compThreadID=0 memLimit=262144 KB freePhysicalMemory=5941 MB
 [ERR] #FAILURE:  JITServer::StreamFailure: Connect failed: Connection refused for sun/reflect/Reflection.getCallerClass()Ljava/lang/Class; @ cold
 [ERR] #JITServer: t=     0 Could not connect to a server. Next attempt in 2000 ms.
 [ERR] #JITServer: t=     0 Resetting activation policy to AGGRESSIVE because client has lost connection to server
 [ERR] #JITServer: compThreadID=0 JITServer StreamFailure: Generic stream failure
<output removed>
 [ERR] 
 [ERR] Eclipse OpenJ9 VM (build master-1c38c8af009, JRE 1.8.0 Linux s390x-64-Bit Compressed References 20240325_785 (JIT enabled, AOT enabled)
 [ERR] OpenJ9   - 1c38c8af009
 [ERR] OMR      - cbfcf7d9444
 [ERR] JCL      - a92e628703d based on jdk8u412-b06)
<output removed>
 [ERR] #INFO:  Method java/lang/Thread$State.<clinit>()V will continue as interpreted
 [ERR] #PERF:  Time spent in compilation thread =0 ms
 [ERR] #INFO:  Stopping compilation thread, vmThread pointer 0000000000071E00, thread ID 3
 [ERR] #PERF:  Time spent in compilation thread =0 ms
 [ERR] #INFO:  Stopping compilation thread, vmThread pointer 000000000006D300, thread ID 1
 [ERR] #PERF:  Time spent in compilation thread =0 ms
 [ERR] #INFO:  Stopping compilation thread, vmThread pointer 000000000006F900, thread ID 2
 [ERR] #PERF:  Time spent in compilation thread =0 ms
 [ERR] #INFO:  Stopping compilation thread, vmThread pointer 0000000000076A00, thread ID 5
 [ERR] #PERF:  Time spent in compilation thread =0 ms
 [ERR] #INFO:  Stopping compilation thread, vmThread pointer 0000000000079000, thread ID 6
 [ERR] #PERF:  Time spent in compilation thread =0 ms
 [ERR] #INFO:  Stopping compilation thread, vmThread pointer 0000000000074400, thread ID 4
 [ERR] #PERF:  Time spent in compilation thread =35 ms
 [ERR] #INFO:  Stopping compilation thread, vmThread pointer 000000000006AD00, thread ID 0
 [ERR] #PERF:  Time spent in compilation thread =0 ms
 [ERR] #INFO:  Stopping compilation thread, vmThread pointer 000000000007B500, thread ID 7
 [ERR] #JITServer: t=    50 Could not connect to a server. Next attempt in 2000 ms.
 [ERR] #JITServer: t=    50 Resetting activation policy to AGGRESSIVE because client has lost connection to server
 [ERR] #JITServer: JITServer StreamFailure (server unreachable before the termination message was sent): Connect failed: Connection refused
 [ERR]   % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
 [ERR]                                  Dload  Upload   Total   Spent    Left  Speed
 [ERR] 
 [ERR]   0     0    0     0    0     0      0      0 --:--:-- --:--:-- --:--:--     0
 [ERR]   0     0    0     0    0     0      0      0 --:--:-- --:--:-- --:--:--     0
 [ERR] curl: (7) Failed to connect to localhost port 46769 after 0 ms: Connection refused
 [ERR] /home/jenkins/workspace/Test_openjdk8_j9_sanity.functional_s390x_linux_Nightly_testList_0/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/jitserver/jitserverScript.sh: line 104: 28224 Killed                  $TEST_JDK_BIN/jitserver $JITSERVER_OPTIONS
>> Required condition was found: [Output match: (java|openjdk|semeru) version]
>> Failure condition was found: [Output match: Connection refused]
>> Failure condition was not found: [Output match: (Fatal|Unhandled) Exception]
>> Success condition was found: [Output match: JITSERVER EXISTS]
>> Success condition was found: [Output match: JITSERVER STILL EXISTS]
>> Failure condition was not found: [Output match: JITSERVER DOES NOT EXIST]
>> Failure condition was not found: [Output match: JITSERVER NO LONGER EXISTS]
pshipton commented 6 months ago

@mpirvu fyi

mpirvu commented 6 months ago

Just an observation: the output from the failed test shows:

 [ERR] /home/jenkins/workspace/Test_openjdk8_j9_sanity.functional_s390x_linux_Nightly_testList_0/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/jitserver/jitserverconfig.sh: line 30: lsof: command not found

So, the machine does not have lsof installed and the test harness will not be able to tell which ports are busy. This may result in "port is in use" type of errors, but this error here is different.

Another observation:

[ERR] JITServer is currently a technology preview. Its use is not yet supported.

I though we deleted those messages on all platforms.

mpirvu commented 6 months ago

The diagnostic info shows that the client cannot connect to the server for compilation requests:

[ERR] #FAILURE:  JITServer::StreamFailure: Connect failed: Connection refused for sun/reflect/Reflection.getCallerClass()Ljava/lang/Class; @ cold
....
 [ERR] #JITServer: t=    50 Could not connect to a server. Next attempt in 2000 ms.
 [ERR] #JITServer: t=    50 Resetting activation policy to AGGRESSIVE because client has lost connection to server
 [ERR] #JITServer: JITServer StreamFailure (server unreachable before the termination message was sent): Connect failed: Connection refused

The test fails because the output finds "Connection refused". It's not clear whether the health port is also refusing connections. Probably not. The server is still active, or at least it didn't crash because we can read its PID after the client finishes.