Intermittent test-tls-inception failure on windows

[gibfahn]

I'm getting this error on v4.3.1 while running the parallel test suite, it seems to happen about 30% of the time.

1..1
not ok 1 test-tls-inception.js
# 
# assert.js:89
#   throw new assert.AssertionError({
#   ^
# AssertionError: 'AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA == <Buffer 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 41 
#     at TLSSocket.<anonymous> (C:\gib\tmp\node\test\parallel\test-tls-inception.js:64:14)
#     at TLSSocket.<anonymous> (C:\gib\tmp\node\test\common.js:395:15)
#     at emitNone (events.js:72:20)
#     at TLSSocket.emit (events.js:166:7)
#     at endReadableNT (_stream_readable.js:905:12)
#     at nextTickCallbackWith2Args (node.js:437:9)
#     at process._tickCallback (node.js:351:17)
  ---
  duration_ms: 0.422
  ...

• Version: v4.3.1
• Platform: Windows 7 64 bit
• Command: python tools/test.py --mode=release --progress=tap parallel/test-tls-inception

Let me know if I forgot to include any info!

[mhdawson]

@santigimeno an FYI

[santigimeno]

@gibm can you add a console.log with the length of buf before the assertion at https://github.com/nodejs/node/blob/master/test/parallel/test-tls-inception.js#L64. Thanks

[gibfahn]

I added this on line 64,
console.log("Buffer length: " + buf.length)

And got this:
Buffer length: 376832

[santigimeno]

Thanks. I'm trying to reproduce it here, in the meantime, and this is a blind guess, but replacing socket.destroy with socket.end at https://github.com/nodejs/node/blob/master/test/parallel/test-tls-inception.js#L36 helps something?

[gibfahn]

That change does make a difference, the test now fails more intermittently (about 20% of the time), and now fails with:

1..1
not ok 1 test-tls-inception.js
# events.js:141
#       throw er; // Unhandled 'error' event
#       ^
#
# Error: read ECONNRESET
#     at exports._errnoException (util.js:870:11)
#     at TLSWrap.onread (net.js:544:26)
# Buffer length: 400000
  ---
  duration_ms: 0.428

[santigimeno]

@gibm I can't reproduce the original error :(. Taking the initial version of the test, if you reduce the size of the buffer from 400000 to 300000, does it make any difference? (With this change, the test still reproduces consistently the failure it was trying to fix originally)

[gibfahn]

@santigimeno Interesting that it isn't failing for you. So if you build v4.3.1 on a Windows 7 64bit machine and run python tools/test.py --mode=release --progress=tap parallel/test-tls-inception, say ten times, it never fails? It's failing pretty consistently for me.

Reducing the size of the buffer doesn't seem to make a difference either with socket.end() or socket.destroy(). I get the same errors.

[santigimeno]

@gibm Sorry for not pointing out before but I have no Windows to test on. I tested on Jessie 64 and OS X.

Looking at the commit that changed the buffer size: d00b9fc, I changed it because it made the error that was trying to fix reproducible in a consistent way in OS X #4195 (comment). Maybe we could revert to the original value of 4000 where the error also happened, though rarely, and probably fixes the Windows problem. Can you check that?

It's interesting to note that this test hasn't been failing on the CI since the change was included, maybe we could run a stress test job in the CI once is back online to see if it can be reproducible.

[gibfahn]

@santigimeno Oh I see, I haven't noticed any failures on any other platforms either! I've just tried running it 100 times successively for each buffer length. For length 4000 it didn't fail at all, for length 40,000 it failed five times (out of 100). For 400,000 it seems to fail about 50% of the time.

It'd be good to try to work out what the cause of the problem is, especially if 4,000 makes the test less useful for OSX.

Adding socket.on('error',function(err){ console.error(err)}) on https://github.com/nodejs/node/blob/master/test/parallel/test-tls-inception.js#L38 does stop the test from failing, which is odd, as I would have thought an ECONNRESET error would cause the assert to fail.

[santigimeno]

@gibm Yes that's odd. Maybe there's no real solution to the ECONNRESET error as it looks like the test is racey as it is now because both ends try close the connection and adding an error listener is the proper solution.

[santigimeno]

Maybe asking @indutny about this, as he was the creator of the test?

[MylesBorins]

try piping the error events from your various emitters to dev/null that will likely stop everything from exploding

edit: example --> https://github.com/nodejs/node/blob/master/test/parallel/test-debugger-util-regression.js#L55-L62

[gibfahn]

@thealphanerd Handling the error does make the test pass, however if there is an error, doesn't that mean that the test should be failing? I know the assert still passes which suggests otherwise, but just catching the error and then ignoring it feels like a bad idea.

socket.on('error', function (err) { console.error(err); });