stream: certain sequence of Writable#write and Writable#end will not end stream

[awwright]

• Version: v12.10.0
• Platform: macOS
• Subsystem: stream

I ran into a problem where certain Connection: close HTTP responses were not being closed, when the response is a Content-Length response (as opposed to a chunked response), see #29609 and #29649 for background.

I've been able to isolate this bug to a problem in "stream" and/or the duplex pair implementation (used by the "tls" module and in tests):

'use strict';

const common = require('./test/common');
const makeDuplexPair = require('./test/common/duplexpair');

const { clientSide, serverSide } = makeDuplexPair();

serverSide.resume();
serverSide.on('end', function(buf){
  serverSide.write('out');
  serverSide.write('');
  serverSide.end();
});

clientSide.end();

clientSide.on('data', function(m){
  console.log(m.toString());
});
clientSide.on('end', common.mustCall(function(){
  console.log('(Connection closed)');
}));

Expected:

out
(Connection closed)

Actual:

out
Mismatched function calls. Expected exactly 1, actual 0.

A write call (empty or non-empty) followed by an empty write call causes this; note how removing either of the calls works around the bug.

I'm not sure if/when this was ever introduced, but this test fails in v10.16.3, v12.10.0, and master branch.

[ronag]

As far as I've been able to tell so far the second serverSide write will never complete because the clientSide doesn't read it out for whatever reason. Will try to dig further later tonight.

Also it seems to be related to the fact that it's an empty string. A quick fix would be to simply make empty buffers and strings a noop in Writable.write and Readable.push. However, I'm still very interested in whats going wrong here.

Also I'm not 100% convinced this is related to your http issue. But we can get to that. If I give you a patch can you build Node and run your HTTP case to see if it solves it?

[lpinca]

From a quick look it seems that _read() is not called for the empty chunk.

node/test/common/duplexpair.js

Lines 16 to 22 in 82f89ec

	_read() {
	const callback = this[kCallback];
	if (callback) {
	this[kCallback] = null;
	callback();
	}
	}

As a result the write of the empty chunk does not complete (the callback is not called) and this prevents _final() from being called and from pushing the null chunk on the client.

node/test/common/duplexpair.js

Lines 31 to 35 in 82f89ec

	_final(callback) {
	this[kOtherSide].on('end', callback);
	this[kOtherSide].push(null);
	}
	}

This is confirmed by the fact that 'finish' is not emitted

serverSide.on('finish', common.mustCall());

In #29649 it works with net.Socket because empty chunks are discarded.

node/lib/internal/stream_base_commons.js

Lines 196 to 198 in 82f89ec

	if (nread === 0) {
	return;
	}

A possible way to fix the issue is to not push empty chunks

diff --git a/test/common/duplexpair.js b/test/common/duplexpair.js
index 0783aeb861..ba46e20f5d 100644
--- a/test/common/duplexpair.js
+++ b/test/common/duplexpair.js
@@ -24,8 +24,13 @@ class DuplexSocket extends Duplex {
   _write(chunk, encoding, callback) {
     assert.notStrictEqual(this[kOtherSide], null);
     assert.strictEqual(this[kOtherSide][kCallback], null);
-    this[kOtherSide][kCallback] = callback;
-    this[kOtherSide].push(chunk);
+
+    if (chunk.length) {
+      this[kOtherSide][kCallback] = callback;
+      this[kOtherSide].push(chunk);
+    } else {
+      callback();
+    }
   }
 
   _final(callback) {

This is consistent with net.Socket behavior but I'm not sure if it masks a bug in Readable.prototype.read() implementation.

[lpinca]

cc: @nodejs/streams

[ronag]

This is consistent with net.Socket behavior but I'm not sure if it masks a bug in Readable.prototype.read() implementation.

For me it feels like it is masking a more fundamental problem. #29762 is my take on it but I'm out on deep water.

It looks to me like that we have logic to trigger read even on empty chunks, however that logic breaks down if the stream received EOF in the same tick.

[awwright]

@ronag The HTTP issue is being caused because the callback of Writable#write('', 'latin1', callback) is never called, so I think if this case is fixed so will the HTTP case. But either way, this problem will affect the HTTP one.

@lpinca I'll start using your patch to avoid empty push()es as a workaround, but yeah, streams should be able to handle empty pushes like this; or if this is a requirement, it should be documented somewhere.

HTTP is writing an empty string to "flush" the stream, is this strictly necessary?

node/lib/_http_outgoing.js

Lines 747 to 748 in db706da

	// Force a flush, HACK.
	this._send('', 'latin1', finish);

[ronag]

@awwright Can you try with #29762?

[awwright]

@ronag Seems to solve the issue for me, great work!