Using crypto functions inside TLS callbacks incorrectly causes TLS failure

[smfreegard]

Test case:

"use strict";
var fs = require('fs');
var tls = require('tls');
var crypto = require('crypto');

var options = {
    key: fs.readFileSync('./tls_key.pem'),
    cert: fs.readFileSync('./tls_cert.pem'),
}

var server = tls.createServer(options, function (client) {
        client.on('error', function (error) {
            console.log('client error: ' + error.message);
            console.log('stack trace: ' + error.stack);
            client.destroy();
        });
        client.write('secured!\n');
        var next = function () {
            client.write('finished!\n');
            client.end();
        }
        process.nextTick(function () {
            exports.doit(function () {
                next();
            });
        });
});

exports.doit = function (cb) {
    var cipher = 'aes128';
    var pass = 'foo';
    var decipher = crypto.createDecipher(cipher, pass);
    var w_dec = decipher.update('fbf973ea86243eae441ae1cb0722cfad975d3df85a8f329841fc26ea01d68ee44b43190fc81ba870aabf510ce4cbfed', 'hex', 'ascii');
    try {
        w_dec += decipher.final('ascii');
        console.log(w_dec);
    }
    catch (e) {
        console.log('decrypt error: ' + e);
    }
    if (cb) cb();
}

server.listen(3030);

Output:

$ openssl s_client -port 3030
secured!
decrypt error: TypeError: DecipherFinal fail
client error: 2799312:error:0606506D:digital envelope routines:EVP_DecryptFinal_ex:wrong final block length:../deps/openssl/openssl/crypto/evp/evp_enc.c:460:

stack trace: Error: 2799312:error:0606506D:digital envelope routines:EVP_DecryptFinal_ex:wrong final block length:../deps/openssl/openssl/crypto/evp/evp_enc.c:460:

    at CleartextStream._pusher (tls.js:656:24)
    at SlabBuffer.use (tls.js:199:18)
    at CleartextStream.CryptoStream._push (tls.js:483:33)
    at SecurePair.cycle (tls.js:880:20)
    at CleartextStream.CryptoStream.write (tls.js:267:13)
    at tls.createServer.next (/usr/lib/node_modules/Haraka/testcase_new.js:19:20)
    at /usr/lib/node_modules/Haraka/testcase_new.js:24:17
    at Object.exports.doit (/usr/lib/node_modules/Haraka/testcase_new.js:41:13)
    at /usr/lib/node_modules/Haraka/testcase_new.js:23:21
    at process.startup.processNextTick.process._tickCallback (node.js:244:9)

The EVP_DecryptFinal_ex error above relates to the caught decipher error and not to the TLS connection but it was reported on the TLS client error handlers incorrectly.

If you comment the code that calls the decipher functions then this works as expected. The code also works if the process.nextTick() is removed.

[taylorhughes]

I'm also seeing this, in the form of a long HTTPS request (uploading a large file to S3) failing simultaneously after a failed crypto decrypt.

The crypto decrypt and the HTTPS request are in totally different parts of the code and totally unrelated, but happening in the same node process.

This is easily reproducible on v0.8.15 (OS X 10.8 here, but seen often [mysteriously until now] in production).

[taylorhughes]

Here's my test case:

var crypto = require('crypto');
var tls = require('tls');


/* CREATE HTTP REQUEST */

var stream = tls.connect(443, 'avocado.io');
stream.on('secureConnect', function() {
  if (!stream.authorized) {
    console.log('error oh noes');
    return;
  }

  console.log('Connected');
  stream.setEncoding('utf-8');
}); null;
stream.on('data', function(data) {
  console.log('Got data:', (data+'').substring(0, 24));
}); null;

var length = 2000000;
var loops = 20;
stream.write('POST / HTTP/1.0\r\nHost: avocado.io\r\nContent-Length: ' + length + '\r\n\r\n');

for (var i = 0; i < loops / 2; i++) {
  var bytes = crypto.randomBytes(length / loops);
  stream.write(bytes);
}

/* CREATE BAD DECIPHER -- important that this is in a setTimeout() */

setTimeout(function() {
  var cipher = crypto.createDecipher('des-cbc', 'thing');
  var begin = cipher.update('invalid', 'base64', 'binary');
  try {
    var binaryString = begin + cipher.final('binary');
  } catch (e) {
    // TypeError: DecipherFinal fail
    console.log('Decipher failed:', e);
  }

  for (var i = 0; i < loops / 2; i++) {
    var bytes = crypto.randomBytes(length / loops);
    stream.write(bytes);
  }
  stream.write('\r\n\r\n');
}, 100);

Expected output:

Connected
Decipher failed: [TypeError: DecipherFinal fail]
Got data: HTTP/1.0 403 Forbidden

Actual output:

Connected
Decipher failed: [TypeError: DecipherFinal fail]
(uncaught exception crash)
Error: 139674330416960:error:0606506D:digital envelope routines:EVP_DecryptFinal_ex:wrong final block length:../deps/openssl/openssl/crypto/evp/evp_enc.c:460:

[kkoston]

Anything new in this topic? I'm getting the same error when reading the stream from Twitter API. Looks totally random. The Issue #139 is similar but I'm using the HTTPS request like Taylor so can not really do "ignoreTLS".

[smfreegard]

@kkoston I was able to work around this in my case.

Which version of node are you running? I noticed a while back that there was some stuff in the changelog for 0.10 that looked they might fix this issue (one was for clearing TLS errors from the stack IIRC) although I haven't tried my test case with 0.10 - yet.

[taylorhughes]

I did not find a fix for this. I just made the crypto decrypt failures happen less often (better input validation before the decrypt) to prevent the S3 requests from failing.

Just tried to repro in 0.10.12 and couldn't after a bunch of tries. Maybe it's fixed?

[kkoston]

Thanks guys, the node version I'm running is 0.6.12, it comes with Ubuntu 12.04 server. Will upgrade to the latest and post the results here.

[bnoordhuis]

Sorry, I forgot to close the issue. It should be fixed per c6e2db2 and 3a2b503.