SSL connection timeout, iOS

[bushev]

Hello, Enrico!

First of all, I want to thank you for supporting this awesome project! It can really help to build a mobile application for NodeJS developers.

I having a trouble to connect to a MongoDB with SSL using an official driver.

The problem: My code works fine in a PC environment, but don't on jxcore (timeout error).

Platform: iOS (10)
Cordova CLI : 7.0.1
Xcode: 8.3.3

const mongodb     = require('mongodb');
const MongoClient = require('mongodb').MongoClient;

const url = `mongodb://testUser:[email protected]:23087,aws-us-east-1-portal.29.dblayer.com:23087/admin?ssl=true`;

MongoClient.connect(url, {
    loggerLevel: 'debug',
}, (err, db) => {
    if (err) return console.log(err);

    console.log('Connected correctly to server');

    db.admin().listDatabases().then((databases) => {
        console.log(databases);
    }).catch(err => {
        console.log(err);
    });
});

I got a timeout error:

[DEBUG-Connection:10281] 1504809351343 creating connection 0 with options [{"host":"aws-us-east-1-portal.28.dblayer.com","port":23087,"size":5,"keepAlive":true,"keepAliveInitialDelay":300000,"noDelay":true,"connectionTimeout":30000,"socketTimeout":360000,"ssl":true,"ca":null,"crl":null,"cert":null,"rejectUnauthorized":false,"promoteLongs":true,"promoteValues":true,"promoteBuffers":false,"checkServerIdentity":false}] { type: 'debug',
  message: 'creating connection 0 with options [{"host":"aws-us-east-1-portal.28.dblayer.com","port":23087,"size":5,"keepAlive":true,"keepAliveInitialDelay":300000,"noDelay":true,"connectionTimeout":30000,"socketTimeout":360000,"ssl":true,"ca":null,"crl":null,"cert":null,"rejectUnauthorized":false,"promoteLongs":true,"promoteValues":true,"promoteBuffers":false,"checkServerIdentity":false}]',
  className: 'Connection',
  pid: 10281,
  date: 1504809351343 }
[DEBUG-Connection:10281] 1504809351355 creating connection 1 with options [{"host":"aws-us-east-1-portal.29.dblayer.com","port":23087,"size":5,"keepAlive":true,"keepAliveInitialDelay":300000,"noDelay":true,"connectionTimeout":30000,"socketTimeout":360000,"ssl":true,"ca":null,"crl":null,"cert":null,"rejectUnauthorized":false,"promoteLongs":true,"promoteValues":true,"promoteBuffers":false,"checkServerIdentity":false}] { type: 'debug',
  message: 'creating connection 1 with options [{"host":"aws-us-east-1-portal.29.dblayer.com","port":23087,"size":5,"keepAlive":true,"keepAliveInitialDelay":300000,"noDelay":true,"connectionTimeout":30000,"socketTimeout":360000,"ssl":true,"ca":null,"crl":null,"cert":null,"rejectUnauthorized":false,"promoteLongs":true,"promoteValues":true,"promoteBuffers":false,"checkServerIdentity":false}]',
  className: 'Connection',
  pid: 10281,
  date: 1504809351355 }
[INFO-Server:10281] 1504809351966 server aws-us-east-1-portal.28.dblayer.com:23087 fired event connect out with message [object Object] { type: 'info',
  message: 'server aws-us-east-1-portal.28.dblayer.com:23087 fired event connect out with message [object Object]',
  className: 'Server',
  pid: 10281,
  date: 1504809351966 }
[DEBUG-Connection:10281] 1504809351991 writing buffer [030100000100000000000000d40700000400000061646d696e2e24636d640000000000ffffffff] to aws-us-east-1-portal.28.dblayer.com:23087 { type: 'debug',
  message: 'writing buffer [030100000100000000000000d40700000400000061646d696e2e24636d640000000000ffffffff] to aws-us-east-1-portal.28.dblayer.com:23087',
  className: 'Connection',
  pid: 10281,
  date: 1504809351991 }
[DEBUG-Connection:10281] 1504809351993 writing buffer [dc0000000869736d6173746572000103636c69656e7400c400000003647269766572002a000000026e616d6500070000006e6f64656a73000276657273696f6e0007000000322e322e33310000036f7300500000000274797065000700000044617277696e00026e616d650004000000696f730002617263686974656374757265000600000061726d3634000276657273696f6e000700000031362e372e30000002706c6174666f726d002b0000004e6f64652e6a732076302e31302e34302c204c452c206d6f6e676f64622d636f72653a20322e312e3135000000] to aws-us-east-1-portal.28.dblayer.com:23087 { type: 'debug',
  message: 'writing buffer [dc0000000869736d6173746572000103636c69656e7400c400000003647269766572002a000000026e616d6500070000006e6f64656a73000276657273696f6e0007000000322e322e33310000036f7300500000000274797065000700000044617277696e00026e616d650004000000696f730002617263686974656374757265000600000061726d3634000276657273696f6e000700000031362e372e30000002706c6174666f726d002b0000004e6f64652e6a732076302e31302e34302c204c452c206d6f6e676f64622d636f72653a20322e312e3135000000] to aws-us-east-1-portal.28.dblayer.com:23087',
  className: 'Connection',
  pid: 10281,
  date: 1504809351993 }
[INFO-Server:10281] 1504809352003 server aws-us-east-1-portal.29.dblayer.com:23087 fired event connect out with message [object Object] { type: 'info',
  message: 'server aws-us-east-1-portal.29.dblayer.com:23087 fired event connect out with message [object Object]',
  className: 'Server',
  pid: 10281,
  date: 1504809352003 }
[DEBUG-Connection:10281] 1504809352010 writing buffer [030100000200000000000000d40700000400000061646d696e2e24636d640000000000ffffffff] to aws-us-east-1-portal.29.dblayer.com:23087 { type: 'debug',
  message: 'writing buffer [030100000200000000000000d40700000400000061646d696e2e24636d640000000000ffffffff] to aws-us-east-1-portal.29.dblayer.com:23087',
  className: 'Connection',
  pid: 10281,
  date: 1504809352010 }
[DEBUG-Connection:10281] 1504809352011 writing buffer [dc0000000869736d6173746572000103636c69656e7400c400000003647269766572002a000000026e616d6500070000006e6f64656a73000276657273696f6e0007000000322e322e33310000036f7300500000000274797065000700000044617277696e00026e616d650004000000696f730002617263686974656374757265000600000061726d3634000276657273696f6e000700000031362e372e30000002706c6174666f726d002b0000004e6f64652e6a732076302e31302e34302c204c452c206d6f6e676f64622d636f72653a20322e312e3135000000] to aws-us-east-1-portal.29.dblayer.com:23087 { type: 'debug',
  message: 'writing buffer [dc0000000869736d6173746572000103636c69656e7400c400000003647269766572002a000000026e616d6500070000006e6f64656a73000276657273696f6e0007000000322e322e33310000036f7300500000000274797065000700000044617277696e00026e616d650004000000696f730002617263686974656374757265000600000061726d3634000276657273696f6e000700000031362e372e30000002706c6174666f726d002b0000004e6f64652e6a732076302e31302e34302c204c452c206d6f6e676f64622d636f72653a20322e312e3135000000] to aws-us-east-1-portal.29.dblayer.com:23087',
  className: 'Connection',
  pid: 10281,
  date: 1504809352011 }
[DEBUG-Connection:10281] 1504809386347 connection 0 for [aws-us-east-1-portal.28.dblayer.com:23087] timed out { type: 'debug',
  message: 'connection 0 for [aws-us-east-1-portal.28.dblayer.com:23087] timed out',
  className: 'Connection',
  pid: 10281,
  date: 1504809386347 }
[DEBUG-Server:10281] 1504809386356 destroy called on server aws-us-east-1-portal.28.dblayer.com:23087 { type: 'debug',
  message: 'destroy called on server aws-us-east-1-portal.28.dblayer.com:23087',
  className: 'Server',
  pid: 10281,
  date: 1504809386356 }
[DEBUG-Connection:10281] 1504809386364 connection 1 for [aws-us-east-1-portal.29.dblayer.com:23087] timed out { type: 'debug',
  message: 'connection 1 for [aws-us-east-1-portal.29.dblayer.com:23087] timed out',
  className: 'Connection',
  pid: 10281,
  date: 1504809386364 }
[DEBUG-Server:10281] 1504809386368 destroy called on server aws-us-east-1-portal.29.dblayer.com:23087 { type: 'debug',
  message: 'destroy called on server aws-us-east-1-portal.29.dblayer.com:23087',
  className: 'Server',
  pid: 10281,
  date: 1504809386368 }
[DEBUG-Connection:10281] 1504809386382 connection 0 with for [aws-us-east-1-portal.28.dblayer.com:23087] closed { type: 'debug',
  message: 'connection 0 with for [aws-us-east-1-portal.28.dblayer.com:23087] closed',
  className: 'Connection',
  pid: 10281,
  date: 1504809386382 }
[DEBUG-Connection:10281] 1504809386388 connection 1 with for [aws-us-east-1-portal.29.dblayer.com:23087] closed { type: 'debug',
  message: 'connection 1 with for [aws-us-east-1-portal.29.dblayer.com:23087] closed',
  className: 'Connection',
  pid: 10281,
  date: 1504809386388 }
{ [MongoError: no mongos proxy available]
  name: 'MongoError',
  message: 'no mongos proxy available',
  stack_reached_: true,
  stack_: 
   [ { _fileName: '/private/var/containers/Bundle/Application/A3AFE012-566E-4295-9B38-60EFD71D3ED7/ML.app/www/jxcore/node_modules/mongodb-core/lib/error.js',
       _functionName: '',
       _lineNumber: '42',
       _columnNumber: '24',
       _msg: '    at @/private/var/containers/Bundle/Application/A3AFE012-566E-4295-9B38-60EFD71D3ED7/ML.app/www/jxcore/node_modules/mongodb-core/lib/error.js:42:24' },
     { _fileName: 'module.js',
       _functionName: '$w.prototype._compile',
       _lineNumber: '621',
       _columnNumber: '8',
       _msg: '    at [email protected]:621:8' },
     { _fileName: 'module.js',
       _functionName: '$w._extensions[".js"]',
       _lineNumber: '651',
       _columnNumber: '1',
       _msg: '    at $w._extensions[".js"]@module.js:651:1' },
     { _fileName: 'module.js',
       _functionName: '$w.prototype.load',
       _lineNumber: '442',
       _columnNumber: '1',
       _msg: '    at [email protected]:442:1' },
     { _fileName: 'module.js',
       _functionName: '$w._load',
       _lineNumber: '407',
       _columnNumber: '1',
       _msg: '    at [email protected]:407:1' },
     { _fileName: 'module.js',
       _functionName: '$w.prototype.require',
       _lineNumber: '477',
       _columnNumber: '8',
       _msg: '    at [email protected]:477:8' },
     toString: [Function] ] }

[bushev]

UPD

Just updated OpenSSL to latest (1.0.2l) - unfortunately, the result is the same.

It seems on data event is never emitted on a tls socket.

UPD2

After deep investigation, I have found that problem was solved in iojs 3.0.0

UPD3
The same for SpiderMonkey build.

[bushev]

@enricogior, how realistic to fix TLS connection?

[enricogior]

Hi @bushev
sorry for the late reply, I've been very busy.
First of all, thank you very much for opening the issue.
When you said that you found the problem solved in iojs 3.0.0, to which commit are you referring?
Thank you.