imperative icon indicating copy to clipboard operation
imperative copied to clipboard

https.request() sporadically fails

Open dronky opened this issue 2 years ago • 0 comments

Hello,

We have encountered an issue when sending requests via zowe Endevor CLI. Some requests fails sporadically. For example I have 5 subsequent Endevor generate actions and only 2 of them completed successfully:

C:\Users\am891653>zowe endevor generate ele PAYRPT31 --endevor-profile ca32 --ccid 'cli' --comment 'cli' --write-report & zowe endevor generate ele PAYRPT31 --endevor-profile ca32 --ccid 'cli' --comment 'cli' --write-report &zowe endevor generate ele PAYRPT31 --endevor-profile ca32 --ccid 'cli' --comment 'cli' --write-report &zowe endevor generate ele PAYRPT31 --endevor-profile ca32 --ccid 'cli' --comment 'cli' --write-report &zowe endevor generate ele PAYRPT31 --endevor-profile ca32 --ccid 'cli' --comment 'cli' --write-report
[INFO] Running on host: some.hostname:8888 instance: CMEWXY01 protocol: https rejectUnauthorized: false
[INFO] GENERATE executed in location: DEV/1/SYS1/SUB1 on element: PAYRPT31.TYP01
[INFO] Endevor reports written in ./endevor-report-2022-03-07-180232.txt
GENERATE of PAYRPT31.TYP01 finished with 0
[INFO] Running on host: some.hostname:8888 instance: CMEWXY01 protocol: https rejectUnauthorized: false
[INFO] GENERATE executed in location: DEV/1/SYS1/SUB1 on element: PAYRPT31.TYP01
[INFO] Endevor reports written in ./endevor-report-2022-03-07-180242.txt
[INFO] Running on host: some.hostname:8888 instance: CMEWXY01 protocol: https rejectUnauthorized: false
[INFO] GENERATE executed in location: DEV/1/SYS1/SUB1 on element: PAYRPT31.TYP01
[INFO] Endevor reports written in ./endevor-report-2022-03-07-180251.txt
[INFO] Running on host: some.hostname:8888 instance: CMEWXY01 protocol: https rejectUnauthorized: false
[INFO] GENERATE executed in location: DEV/1/SYS1/SUB1 on element: PAYRPT31.TYP01
[INFO] Endevor reports written in ./endevor-report-2022-03-07-180301.txt
[INFO] Running on host: some.hostname:8888 instance: CMEWXY01 protocol: https rejectUnauthorized: false
[INFO] GENERATE executed in location: DEV/1/SYS1/SUB1 on element: PAYRPT31.TYP01
[INFO] Endevor reports written in ./endevor-report-2022-03-07-180310.txt
GENERATE of PAYRPT31.TYP01 finished with 0

At a time of failure, I have following message in my Tomcat logs:

Mar 08, 2022 3:44:46 PM org.apache.tomcat.util.net.NioEndpoint$SocketProcessor doRun      
SEVERE:                                                                                   
java.lang.NullPointerException                                                            
.at com.ibm.jsse2.X.a(X.java:29)                                                          
.at com.ibm.jsse2.a2.a(a2.java:19)                                                        
.at com.ibm.jsse2.a2.access$900(a2.java:14)                                               
.at com.ibm.jsse2.a2$i.produce(a2$i.java:11)                                              
.at com.ibm.jsse2.p.produce(p.java:27)                                                    
.at com.ibm.jsse2.G$f.b(G$f.java:10)                                                      
.at com.ibm.jsse2.G$f.a(G$f.java:7)                                                       
.at com.ibm.jsse2.G$b.a(G$b.java:37)                                                      
.at com.ibm.jsse2.G$b.consume(G$b.java:16)                                                
.at com.ibm.jsse2.p.consume(p.java:23)                                                    
.at com.ibm.jsse2.aa.a(aa.java:173)                                                       
.at com.ibm.jsse2.bg$a$b.a(bg$a$b.java:3)                                                 
.at com.ibm.jsse2.bg$a$b.run(bg$a$b.java:4)                                               
.at java.security.AccessController.doPrivileged(AccessController.java:774)                
.at com.ibm.jsse2.bg$a.run(bg$a.java:23)                                                  
.at org.apache.tomcat.util.net.SecureNioChannel.tasks(SecureNioChannel.java:423)          
.at org.apache.tomcat.util.net.SecureNioChannel.handshakeUnwrap(SecureNioChannel.java:483)
.at org.apache.tomcat.util.net.SecureNioChannel.handshake(SecureNioChannel.java:238)      
.at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1394)   
.at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)       
.at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1160)       
.at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)       
.at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)    
.at java.lang.Thread.run(Thread.java:825)                                                 

When I disabled TLS v1.3 in my tomcat server.xml

<SSLHostConfig hostName="some.hostname"
             protocols="TLSv1,TLSv1.1,TLSv1.2">
  <Certificate certificateFile="keystore/temp/public-certificate.pem"
               certificateKeyFile="keystore/temp/private-key.key" />
</SSLHostConfig>

all my requests worked:

C:\Users\am891653>zowe endevor generate ele PAYRPT31 --endevor-profile ca32 --ccid 'cli' --comment 'cli' --write-report & zowe endevor generate ele PAYRPT31 --endevor-profile ca32 --ccid 'cli' --comment 'cli' --write-report &zowe endevor generate ele PAYRPT31 --endevor-profile ca32 --ccid 'cli' --comment 'cli' --write-report &zowe endevor generate ele PAYRPT31 --endevor-profile ca32 --ccid 'cli' --comment 'cli' --write-report &zowe endevor generate ele PAYRPT31 --endevor-profile ca32 --ccid 'cli' --comment 'cli' --write-report
[INFO] Running on host: some.hostname:8888 instance: CMEWXY01 protocol: https rejectUnauthorized: false
[INFO] GENERATE executed in location: DEV/1/SYS1/SUB1 on element: PAYRPT31.TYP01
[INFO] Endevor reports written in ./endevor-report-2022-03-07-180843.txt
GENERATE of PAYRPT31.TYP01 finished with 0
[INFO] Running on host: some.hostname:8888 instance: CMEWXY01 protocol: https rejectUnauthorized: false
[INFO] GENERATE executed in location: DEV/1/SYS1/SUB1 on element: PAYRPT31.TYP01
[INFO] Endevor reports written in ./endevor-report-2022-03-07-180854.txt
GENERATE of PAYRPT31.TYP01 finished with 0
[INFO] Running on host: some.hostname:8888 instance: CMEWXY01 protocol: https rejectUnauthorized: false
[INFO] GENERATE executed in location: DEV/1/SYS1/SUB1 on element: PAYRPT31.TYP01
[INFO] Endevor reports written in ./endevor-report-2022-03-07-180904.txt
GENERATE of PAYRPT31.TYP01 finished with 0
[INFO] Running on host: some.hostname:8888 instance: CMEWXY01 protocol: https rejectUnauthorized: false
[INFO] GENERATE executed in location: DEV/1/SYS1/SUB1 on element: PAYRPT31.TYP01
[INFO] Endevor reports written in ./endevor-report-2022-03-07-180913.txt
GENERATE of PAYRPT31.TYP01 finished with 0
[INFO] Running on host: some.hostname:8888 instance: CMEWXY01 protocol: https rejectUnauthorized: false
[INFO] GENERATE executed in location: DEV/1/SYS1/SUB1 on element: PAYRPT31.TYP01
[INFO] Endevor reports written in ./endevor-report-2022-03-07-180925.txt
GENERATE of PAYRPT31.TYP01 finished with 0

I was thinking that problem could be in SSLv2_3 method, I tried changing it to TLS_method and using minVersion and maxVersion, but it didn't help.

Captured error object:

{
  "mDetails": {
    "msg": "http(s) request error event called",
    "causeErrors": {
      "code": "ECONNRESET",
      "path": null,
      "host": "some.hostname",
      "port": 8888
    },
    "source": "client",
    "protocol": "https",
    "port": 8888,
    "host": "some.hostname",
    "basePath": "EndevorService/api/v2",
    "headers": [
      {
        "accept-encoding": "gzip,deflate"
      }
    ],
    "resource": "/CMEWXY01/reports/1646754284-5759156548149045-C1MSGS1",
    "request": "GET",
    "additionalDetails": "HTTP(S) client encountered an error. Request could not be initiated to host.
    Review connection details (host, port) and ensure correctness.
    
    Protocol:  https
    Host:      some.hostname
    Port:      8888
    Base Path: EndevorService/api/v2
    Resource:  /CMEWXY01/reports/1646754284-5759156548149045-C1MSGS1
    Request:   GET
    Headers:   [{\"accept-encoding\":\"gzip,deflate\"}]
    Payload:   undefined"
  },
  "mMessage": "http(s) request error event called"
}

It seems like a bug in https.request() or maybe incorrect implementation.

Node version: v14.15.4 Tomcat version: 9.0.14 Imperative Version: 4.7.6, I was testing older versions, issue still persist.

dronky avatar Mar 08 '22 16:03 dronky