node-libcurl icon indicating copy to clipboard operation
node-libcurl copied to clipboard

sometimes an ssl error takes down whole process

Open SaulMoonves opened this issue 4 years ago • 19 comments

[Error: SSL peer certificate or SSH remote key was not OK] {                                                                                                                                                         
  code: 60,                                                                                                                                                                                                                                   
  isCurlError: true                                                                                                                                                                                                                           
}                                                                                                                                                                                                                                             
node:events:371                                                                                                        
      throw er; // Unhandled 'error' event                                                                                                                                                                                                    
      ^                                                                                                                
                                                                                                                       
Error: 140530677868480:error:140E0197:SSL routines:SSL_shutdown:shutdown while in init:../deps/openssl/openssl/ssl/ssl_lib.c:2130:
                                                                                                                       
Emitted 'error' event on TLSSocket instance at:                                                                                                                                                                                               
    at TLSSocket._emitTLSError (node:_tls_wrap:900:10)                                                                                                                                                                                        
    at TLSWrap.onerror (node:_tls_wrap:432:11) {                                                                       
  library: 'SSL routines',                              
  function: 'SSL_shutdown', 
  reason: 'shutdown while in init',                                                                                    
  code: 'ERR_SSL_SHUTDOWN_WHILE_IN_INIT'                   
}

I'm using curly inside a node fork process. when this error happens it does something that terminates the IPC between child and parent. Doesn't seem catchable, all I can do is detect the process had an error in the parent process, then force exit it and spawn a replacement. that works about 99% of the time, sometimes it just hangs and I find the process stalled when I look at it later, but that might be a node thing.

Inside the child process I'm calling 4 promises with curly in them and using Promise.all on them.

I can provide any other info needed.

host system ubuntu 20.04 amd64 libcurl: 7.68.0-1ubuntu2.5 curl output: curl 7.68.0 (x86_64-pc-linux-gnu) libcurl/7.68.0 OpenSSL/1.1.1f zlib/1.2.11 brotli/1.0.7 libidn2/2.2.0 libpsl/0.21.0 (+libidn2/2.2.0) libssh/0.9.3/openssl/zlib nghttp2/1.40.0 librtmp/2.3

SaulMoonves avatar Jul 23 '21 12:07 SaulMoonves

Hi @SaulMoonves, can you provide an example that is able to reproduce the issue?

JCMais avatar Jul 25 '21 18:07 JCMais

I will try, this error is killing me. Please give me time.

SaulMoonves avatar Jul 25 '21 19:07 SaulMoonves

Had to switch to disabling SSL verification for reasons, and that change made this problem go away. Closing since it seemed I was the only one who had the problem and now I don't.

SaulMoonves avatar Aug 01 '21 13:08 SaulMoonves

@SaulMoonves Could you reopen? I am experiencing the same issue

puckey avatar Aug 08 '21 12:08 puckey

@puckey could you share a small code sample that reproduces the problem? Even better if using Docker.

I'm not able to reproduce this issue.

JCMais avatar Aug 08 '21 16:08 JCMais

tracked down the issue to the pg library instead - will post an issue there. This issue can be closed again – sorry about that : )

puckey avatar Aug 10 '21 08:08 puckey

I am able to trace this to a combination of node-libcurl and pg after all..

Using Node v14.17.4 on Ubuntu 20.04.1 LTS (but can not reproduce locally on my mac)

I am requesting a url through https which does not support it:

curly.get('https://radio.infoo.ro:8600/;', {
    verbose: true,
    timeoutMs: 5000,
    sslVerifyPeer: true,
    followLocation: true
  });

gives the following result:

*   Trying 91.216.75.116:8600...
* Connected to radio.infoo.ro (91.216.75.116) port 8600 (#0)
* ALPN, offering h2
* ALPN, offering http/1.1
* successfully set certificate verify locations:
*  CAfile: /etc/ssl/certs/ca-certificates.crt
*  CApath: none
* OpenSSL SSL_connect: SSL_ERROR_SYSCALL in connection to radio.infoo.ro:8600 
* Closing connection 0
Something went wrong { error: [Error: SSL connect error] { code: 35, isCurlError: true } }

So far so good.

When I perform the query and at the same time perform an ssl postgres sql query using zapatos (which uses pg under the hood), the query / connection blows up:

(async () => {
  curly.get('https://radio.infoo.ro:8600/;').catch(error => {
    console.error(`Swallow ssl error`, { error });
  });
  await db.sql`select now()`.run(pool);
})();

will intermittently result in:

Swallow ssl error { error: [Error: SSL connect error] { code: 35, isCurlError: true } }
[Error: 139794875414400:error:140E0197:SSL routines:SSL_shutdown:shutdown while in init:../deps/openssl/openssl/ssl/ssl_lib.c:2094:
] {
  library: 'SSL routines',
  function: 'SSL_shutdown',
  reason: 'shutdown while in init',
  code: 'ERR_SSL_SHUTDOWN_WHILE_IN_INIT'
}

If I leave out the curl call, I never receive this ssl error.

puckey avatar Aug 10 '21 12:08 puckey

It seems that the pg native library shutdowns the SSL backend while it is still in use by the addon. Could you try using node.js own https module to see if the same happens?

JCMais avatar Aug 10 '21 12:08 JCMais

When I use the https module, the query is not interrupted (also tested this in a loop to make sure):

import https from 'https';
(async () => {
  const req = https.request('https://radio.infoo.ro:8600/;');
  req.on('error', e => {
    console.error(e);
  });
  req.end();
  console.log('db result', await db.sql`select now()`.run(pool));
})();

output:

db result [ { now: 2021-08-10T13:48:35.357Z } ]
Error: Client network socket disconnected before secure TLS connection was established
    at connResetException (internal/errors.js:628:14)
    at TLSSocket.onConnectEnd (_tls_wrap.js:1561:19)
    at TLSSocket.emit (events.js:412:35)
    at TLSSocket.emit (domain.js:470:12)
    at endReadableNT (internal/streams/readable.js:1317:12)
    at processTicksAndRejections (internal/process/task_queues.js:82:21) {
  code: 'ECONNRESET',
  path: null,
  host: 'radio.infoo.ro',
  port: 8600,
  localAddress: undefined
}

puckey avatar Aug 10 '21 13:08 puckey

Thanks @puckey!

Could you try the following one, without calling .end:

import https from 'https';
(async () => {
  https.get('https://radio.infoo.ro:8600/;', (res) => {
    res.on('data', (d) => {});
  }).on('error', (e) => {
    console.error(e);
  });
  console.log('db result', await db.sql`select now()`.run(pool));
})();

JCMais avatar Aug 10 '21 14:08 JCMais

Then I get:

Error: Client network socket disconnected before secure TLS connection was established
    at connResetException (internal/errors.js:628:14)
    at TLSSocket.onConnectEnd (_tls_wrap.js:1561:19)
    at TLSSocket.emit (events.js:412:35)
    at TLSSocket.emit (domain.js:470:12)
    at endReadableNT (internal/streams/readable.js:1317:12)
    at processTicksAndRejections (internal/process/task_queues.js:82:21) {
  code: 'ECONNRESET',
  path: null,
  host: 'radio.infoo.ro',
  port: 8600,
  localAddress: undefined
}
db result [ { now: 2021-08-10T14:24:07.390Z } ]

puckey avatar Aug 10 '21 14:08 puckey

Does the same error happens if you await the curly call?

JCMais avatar Aug 10 '21 14:08 JCMais

Then the error is still logged to the console, but it does not throw:

(async () => {
  while (true) {
    await curly.get('https://radio.infoo.ro:8600/;').catch(error => {
      console.error(`Swallow ssl error`, { error });
    });
    console.log(await db.sql`select now()`.run(pool));
  }
})();
Swallow ssl error { error: [Error: SSL connect error] { code: 35, isCurlError: true } }
[ { now: 2021-08-10T14:38:19.899Z } ]
Swallow ssl error { error: [Error: SSL connect error] { code: 35, isCurlError: true } }
[ { now: 2021-08-10T14:38:20.009Z } ]
[1628606300018] ERROR (27149 on radiogarden-NUC): 140083318781824:error:140E0197:SSL routines:SSL_shutdown:shutdown while in init:../deps/openssl/openssl/ssl/ssl_lib.c:2094:

    Error: 140083318781824:error:140E0197:SSL routines:SSL_shutdown:shutdown while in init:../deps/openssl/openssl/ssl/ssl_lib.c:2094:
    
Swallow ssl error { error: [Error: SSL connect error] { code: 35, isCurlError: true } }
[ { now: 2021-08-10T14:38:20.269Z } ]
Swallow ssl error { error: [Error: SSL connect error] { code: 35, isCurlError: true } }
[ { now: 2021-08-10T14:38:20.382Z } ]
[1628606300390] ERROR (27149 on radiogarden-NUC): 140083318781824:error:140E0197:SSL routines:SSL_shutdown:shutdown while in init:../deps/openssl/openssl/ssl/ssl_lib.c:2094:

    Error: 140083318781824:error:140E0197:SSL routines:SSL_shutdown:shutdown while in init:../deps/openssl/openssl/ssl/ssl_lib.c:2094:
    
Swallow ssl error { error: [Error: SSL connect error] { code: 35, isCurlError: true } }
[ { now: 2021-08-10T14:38:20.638Z } ]
Swallow ssl error { error: [Error: SSL connect error] { code: 35, isCurlError: true } }
[ { now: 2021-08-10T14:38:20.754Z } ]
[1628606300760] ERROR (27149 on radiogarden-NUC): 140083318781824:error:140E0197:SSL routines:SSL_shutdown:shutdown while in init:../deps/openssl/openssl/ssl/ssl_lib.c:2094:

    Error: 140083318781824:error:140E0197:SSL routines:SSL_shutdown:shutdown while in init:../deps/openssl/openssl/ssl/ssl_lib.c:2094:

puckey avatar Aug 10 '21 14:08 puckey

This does throw:

(async () => {
  while (true) {
    await curly.get('https://radio.infoo.ro:8600/;').catch(error => {
      console.error(`Swallow ssl error`, { error });
    });
  }
})();

(async () => {
  while (true) {
    console.log(await db.sql`select now()`.run(pool));
  }
})();

output:

[ { now: 2021-08-10T14:40:41.253Z } ]
Swallow ssl error { error: [Error: SSL connect error] { code: 35, isCurlError: true } }
[ { now: 2021-08-10T14:40:41.271Z } ]
[Error: 140710649628544:error:140E0197:SSL routines:SSL_shutdown:shutdown while in init:../deps/openssl/openssl/ssl/ssl_lib.c:2094:
] {
  library: 'SSL routines',
  function: 'SSL_shutdown',
  reason: 'shutdown while in init',
  code: 'ERR_SSL_SHUTDOWN_WHILE_IN_INIT'
}

puckey avatar Aug 10 '21 14:08 puckey

Thanks for all the code samples, I will try to reproduce it when I get some time this week. 👍

JCMais avatar Aug 10 '21 14:08 JCMais

It has been a while since I commented on this issue. I had no success trying to reproduce it when I tried.

When I was debugging this, I found that pg may use pg-native. which in turn uses libpq, which is a binding for the C library libpq. It could be the case that libpq is shutting down the SSL layer while libcurl is still using it. I am not sure why this does not happen with the Node.js client itself.

Any help or hints on what might be wrong are appreciated.

JCMais avatar Feb 12 '22 12:02 JCMais

This still happens to me, but only very infrequently now. In my current application I spawn a hundred or more promises doing (among other things) node-libcurl calls and put them all in a Promise.allSettled(promises), and the vast majority of the time it works as intended.

The promises also are doing pg queries too, the original case of the problem seemed to coincide with pg, but is fixed or greatly minimized now if that is the cause.

Just adding info in case it might be helpful. From my application's perspective it works good enough, in the rare case this happens I just retry and it usually works.

SaulMoonves avatar Feb 12 '22 14:02 SaulMoonves

I am having the same issue. I am using this sample

const { curly } = require('node-libcurl')
const { data } = await curly.post('http://httpbin.com/post', {
  postFields: JSON.stringify({ field: 'value' }),
  httpHeader: [
    'Content-Type: application/json',
    'Accept: application/json'
  ],
});

Please how do I disable ssl check?

adimscredit avatar Feb 12 '22 15:02 adimscredit

@adimscredit, you can use sslVerifyPeer: false if you want to disable the ssl check

rahulmahajannn avatar Dec 29 '22 05:12 rahulmahajannn

To keep the maintainability of this project, I am closing old tickets (sorry if your ticket was kept open for so long without feedback).

If the issue continues with the latest version of node-libcurl, please feel free to create a new ticket or re-open.

JCMais avatar Feb 13 '24 21:02 JCMais