Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

bufferSize of net.Socket sometimes returns double the actual value #34078

Closed
BTOdell opened this issue Jun 27, 2020 · 7 comments
Closed

bufferSize of net.Socket sometimes returns double the actual value #34078

BTOdell opened this issue Jun 27, 2020 · 7 comments
Labels
net Issues and PRs related to the net subsystem.

Comments

@BTOdell
Copy link

BTOdell commented Jun 27, 2020

  • Version: v14.4.0
  • Platform: Linux 97fdeff5e333 4.4.0-184-generic Ubuntu SMP x86_64 GNU/Linux
  • Subsystem: net

What steps will reproduce the bug?

I'm using the WebSocket library ws to handle connections from a browser over a VPN. The bufferedAmount property of ws uses the bufferSize property of the underlying net.Socket object (from the http.createServer function). I've narrowed the bug down to know the incorrect value is only coming from the bufferSize property in Node.js itself.

How often does it reproduce? Is there a required condition?

I'm able to reproduce it reliably in my Linux/Docker environment under certain (slow) network conditions.
This issue seems to happen when the socket is being written to quickly, to the point where write callbacks are getting delayed and batched up (several are called together in quick succession).

What is the expected behavior?

The bufferSize should never be greater than the actual number of bytes that were sent to the socket.

What do you see instead?

Each time I send a WebSocket packet, I add the length of the packet onto my own 'pending' queue and I remove it from the queue when I receive the send/write callback. After I send the data to the WebSocket, I query the bufferSize property and the writableLength property of the underlying TCP socket.

Using this TS code:

console.log("Old pending size: " + this.pending.reduce((prev, curr) => prev + curr.byteLength, 0));
console.log("Sending data of length: " + dataByteLength);
this.socket.send(data, cb);
this.pending.unshift(newPendingRecord);
console.log("New pending size: " + this.pending.reduce((prev, curr) => prev + curr.byteLength, 0));
...
const pending: DataRecord[] = this.pending;
const pendingBytes: number = pending.reduce((prev, curr) => prev + curr.byteLength, 0);
const sock: Socket = (this.socket as any)._socket; // get the underlying TCP socket from the WebSocket
const bufferSize: number = sock.bufferSize;
const bytesSent: number = pendingBytes - bufferSize;
console.log("Pending bytes (" + pendingBytes + ") - bufferSize (" + bufferSize + ") = " + bytesSent);
console.log("writableLength: " + sock.writableLength);

I get this output:

Old pending size: 0
Sending data of length: 56205
New pending size: 56205
Pending bytes (56205) - bufferSize (112418) = -56213
writableLength: 56209

Additional information

I tracked down the code in Node.js that implements the bufferSize property: https://github.com/nodejs/node/blob/master/lib/net.js#L544

Using the printed value of writableLength (56209), that means the value of this[kLastWriteQueueSize] is also 56209. My guess is that one of the values is not getting cleared at the right time. Maybe it's because the Node.js event loop is getting held up by all of the other write requests? I don't know enough about Node.js internals to keep debugging this issue further.

@lpinca
Copy link
Member

lpinca commented Jun 27, 2020

Please write a reproducible test case in JavaScript using only net.Server and net.Socket with the actual and expected behavior.

@lpinca lpinca added the net Issues and PRs related to the net subsystem. label Jun 27, 2020
@ronag
Copy link
Member

ronag commented Jun 27, 2020

kLastWriteQueueSize looks a bit suspicious to me. Though I don't have a full understanding of it. Someone more familiar with it that confirm that it looks correct? I'm not sure what the difference between bufferSize and writableLength represents?

@ronag
Copy link
Member

ronag commented Jun 27, 2020

@BTOdell: Is there are reason why you are not using writableLength instead? Could you try if that works better for you?

@ronag ronag mentioned this issue Jun 27, 2020
4 tasks
@lpinca
Copy link
Member

lpinca commented Jun 27, 2020

@ronag see discussion on websockets/ws#492

@ronag
Copy link
Member

ronag commented Jun 27, 2020

Quickly scanned through, seems to be the same issue?

@lpinca
Copy link
Member

lpinca commented Jun 27, 2020

Yes, it was to answer your question about why @BTOdell was using socket.bufferSize instead of socket.writableLength. It's because they found the issue in ws which uses socket.bufferSize and this issue here is the result of that discussion/investigation.

ronag added a commit that referenced this issue Jun 30, 2020
bufferSize should only look at writableLength otherwise it will
always show more than what is actually pending.

PR-URL: #34088
Refs: #34078
Reviewed-By: Luigi Pinca <luigipinca@gmail.com>
Reviewed-By: Anna Henningsen <anna@addaleax.net>
ronag added a commit that referenced this issue Jun 30, 2020
PR-URL: #34088
Refs: #34078
Reviewed-By: Luigi Pinca <luigipinca@gmail.com>
Reviewed-By: Anna Henningsen <anna@addaleax.net>
@ronag
Copy link
Member

ronag commented Jun 30, 2020

Fixed in 312a4f3

@ronag ronag closed this as completed Jun 30, 2020
MylesBorins pushed a commit that referenced this issue Jul 14, 2020
bufferSize should only look at writableLength otherwise it will
always show more than what is actually pending.

PR-URL: #34088
Refs: #34078
Reviewed-By: Luigi Pinca <luigipinca@gmail.com>
Reviewed-By: Anna Henningsen <anna@addaleax.net>
MylesBorins pushed a commit that referenced this issue Jul 14, 2020
PR-URL: #34088
Refs: #34078
Reviewed-By: Luigi Pinca <luigipinca@gmail.com>
Reviewed-By: Anna Henningsen <anna@addaleax.net>
MylesBorins pushed a commit that referenced this issue Jul 16, 2020
bufferSize should only look at writableLength otherwise it will
always show more than what is actually pending.

PR-URL: #34088
Refs: #34078
Reviewed-By: Luigi Pinca <luigipinca@gmail.com>
Reviewed-By: Anna Henningsen <anna@addaleax.net>
MylesBorins pushed a commit that referenced this issue Jul 16, 2020
PR-URL: #34088
Refs: #34078
Reviewed-By: Luigi Pinca <luigipinca@gmail.com>
Reviewed-By: Anna Henningsen <anna@addaleax.net>
addaleax pushed a commit that referenced this issue Sep 22, 2020
bufferSize should only look at writableLength otherwise it will
always show more than what is actually pending.

PR-URL: #34088
Refs: #34078
Reviewed-By: Luigi Pinca <luigipinca@gmail.com>
Reviewed-By: Anna Henningsen <anna@addaleax.net>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
net Issues and PRs related to the net subsystem.
Projects
None yet
Development

No branches or pull requests

3 participants