Description
- Version: observed on v0.12, v4, and v5. Did not observe on v0.10. (details below)
- Platform: observed on both illumos and OS X Mountain Lion, both 32-bit and 64-bit (details below)
- Subsystem: net
Although it's not technically documented, a lot of code assumes that once a stream emits an 'error' event, it will not subsequently emit 'data' or 'end' events. This is pretty much necessary, because otherwise it's impossible for a stream consumer to know when a stream has come to rest and will emit no more events. I've reproduced a case where Node reliably emits an 'end' event after an 'error' event, which violates the expectations of code that assumes a stream has come to rest after 'error'.
To be really precise about where I tested it:
Works as expected on v0.10 (perhaps only because the 'end' event is emitted first):
- illumos: v0.10.43 (both 32-bit and 64-bit)
- OS X Mountain Lion: v0.10.28 (64-bit)
Does not work as expected on v0.12 and later:
- illumos: v0.12.12, v4.4.0, v5.9.0 (both 32-bit and 64-bit)
- OS X Mountain Lion: v0.12.2, v4.4.2, v5.10.0 (64-bit)
Here's a test case that's commented with what it's doing. I've tried to simplify it as much as possible, but since it's a race condition, it's tricky to get the timing just right.
/*
* test-stream.js: demonstrates a case where a Node stream can see an 'end'
* event after an 'error' event.
*
* This test case works as follows:
*
* (1) Set up a TCP server socket and connect to it using a TCP client.
* Server: set up listeners for 'end' and 'error'.
* Client: set up listener for 'error'.
*
* (2) Client: write 65536 bytes of data.
*
* (3) Pause one second. Behind the scenes, Node will detect that the
* server's socket has become readable and read all 65536 bytes. These
* will be buffered in JavaScript.
*
* (4) Server: read 65535 bytes of data from the Socket. There will be
* one byte left buffered on the Socket in JavaScript.
* Client: destroy the socket. This will send a FIN to the server.
*
* (5) Asynchronously (via setImmediate):
* Server: read 1 byte of data from the Socket. This will trigger Node
* to read from the underlying socket again, where it will read 0
* bytes, signifying the end of the stream.
*
* Server: write data to the socket. Since the socket is now
* disconnected, eventually these writes will report EPIPE/SIGPIPE.
* This generally happens synchronously with respect to the write()
* call, but the error will be emitted asynchronously.
*
* (6) Asynchronously (via setImmediate):
* Server: read another byte from the socket. At this point, we're
* reading past end-of-stream, and Node will schedule an 'end' event to
* be emitted, but an 'error' event has already been scheduled as well,
* so we'll see 'error' and then 'end', which should be invalid.
*/
var mod_net = require('net');
var mod_os = require('os');
/* IP address and port used for this test case. */
var ip = '127.0.0.1';
var port = 16404;
/* We'll use this buffer as a chunk of data. */
var bufsz = 64 * 1024;
var buf;
/* State for this test */
var server; /* server's listening socket */
var ssock; /* server's connection socket */
var csock; /* client socket */
var end = false; /* server has seen "end" on its connection socket */
var error = false; /* server has seen "error" on its connection socket */
function main()
{
console.log('versions:',
process.version, process.arch, mod_os.platform());
buf = new Buffer(bufsz);
buf.fill(0);
/*
* (1) Set up client and server.
*/
server = mod_net.createServer({ 'allowHalfOpen': true });
server.on('connection', function (s) {
console.log('server: client connected');
ssock = s;
ssock.on('end', function () {
console.log('server: saw "end" on client socket');
if (error) {
console.log('reproduced issue!');
process.abort();
}
end = true;
});
ssock.on('error', function (err) {
console.log('server: saw "error" on client socket', err);
if (error || end) {
console.log('bailing out after server error');
process.exit(0);
}
// ssock.read(1);
error = true;
});
/*
* (2) Client writes data.
*/
csock.write(buf);
/*
* (3) Pause until the server sees that data.
*/
ssock.once('readable', triggerIssue);
});
server.listen(port, function () {
console.log('server: listening');
csock = mod_net.createConnection(port, ip);
csock.on('connect', function () {
console.log('client: connected');
});
csock.on('end', function () {
console.log('client: saw "end" on server socket');
});
});
}
function triggerIssue()
{
console.log('triggering issue by destroying client socket');
/*
* (4) Read _most_ of the data from the socket and have the client
* destroy the socket.
*/
ssock.read(bufsz - 1);
csock.destroy();
setImmediate(function () {
/*
* (5) Read 1 byte of data from the socket and write data to it.
*/
ssock.read(1);
ssock.write(buf);
ssock.write(buf);
setImmediate(function () {
/*
* (6) Read one more byte.
*/
ssock.read(1);
});
});
}
main();
The detailed output for each test I ran is here:
https://gist.github.com/davepacheco/84d450d2c25f6212a99a984a8f089b4c