moll / node-mitm

Intercept and mock outgoing Node.js network TCP connections and HTTP requests for testing. Intercepts and gives you a Net.Socket, Http.IncomingMessage and Http.ServerResponse to test and respond with. Super useful when testing code that hits remote servers.
Other
640 stars 48 forks source link

socket.end() is not firing event 'close' in mitm after node 12.16 #66

Closed timotheeg closed 4 years ago

timotheeg commented 4 years ago

Ending the socket in mitm 1.7.0 is no longer emitting a close event with node 12.16 (works up to 12.15)

Repro script:

const net = require('net');

mitm = require('mitm')();
mitm.on("connection", (socket) => {
    console.log('connection')
    setTimeout(() => {
        console.log('ending');
        socket.end();
    }, 100);
});

socket = net.connect(22, 'example.org')
socket.on('connect', () => console.log('connected'));
socket.on('end',     () => console.log('end'));
socket.on('close',   () => console.log('close'));

// dummy timer to keep process alive
setTimeout(() => console.log('done'), 500);

Outputs:

<=12.15 >=12.16
``` connection connected ending end close done ``` ``` connection connected ending end done ```

Expected: close event should still fire in node >=12.16.

moll commented 4 years ago

Hey! Thank you for the heads up. I'll take a look!

alexjeffburke commented 4 years ago

I think we also hit this in the unexpected-mitm module that uses mitm internally - at some point I was looking at the changes in the version of 12 that broke it and my hunt led me to this commit (if I take a version before it all worked): https://github.com/nodejs/node/commit/ed21d32a7c37d030ce4668415832a89dc8ead34c

I had hoped to use this to try to build a patch and ran out of time, but maybe that helps as a start.

moll commented 4 years ago

Hey, everyone! I found the close event started failing in v12.16.3 and my current guess is it was actually related to a change in WritableStream.prototype.end, rather than in the networking code. It's more likely to have been a latent bug in Mitm.js's code related to closing the socket. As I was and still am a little unclear on what the relationship between shutdown and close methods of the internal sockets is, I delegated both to closing the writable stream. Turned out calling WritableStream.prototype.end if a stream had already ended didn't call the given callback, and that caused InternalSocket.prototype.close to in turn not call back consistently. I ensured the callback gets fired every time and that seems to have fixed the problem.

I should really at some point have separate tests for all events the user-facing socket must emit, like you, @timotheeg, tested above manually with console.log.

The change itself is in https://github.com/moll/node-mitm/commit/f41a62f16dd53e473b8d36a5240edc46bb02e464#diff-300e7ee3fb2b1bc3beb9294b11d66477 and got released under Mitm.js v1.7.1 a minute ago.

Thanks again!

timotheeg commented 4 years ago

Many thanks @moll !