News for hackers. Stuff that matters.
Re:The Case of the 50ms request by gizmo on Thursday May 06, 2021 @04:38AM (#27060546)
Pretty fun puzzle, but this kind of debugging is alien to me. Without going into too much detail, it's pretty easy to see something suspect is going on, and this hunch can be easily tested. This debugging tour takes you to strace, wireshark, all sorts of other low level debugging techniques, when really all you had to do was simulate the client with curl -d and the problem would have been pretty obvious.

And in this case the more complicated debugging tools didn't even explain anything. As the last page says, the answer is kind of a leap. If you already knew about this problem curl would have solved it immediately, and if you didn't you'd still be baffled even after knowing exactly why the stack traces are the way they are.

Re:The Case of the 50ms request by inopinatus on Thursday May 06, 2021 @09:04AM (#27062586)
I had to read this remark a couple of times before I realised it's suggesting a curl debugging trace is somehow more definitive and less complicated than tcpdump, despite it being a TCP issue.

For those of us who grew up reading W.R.Stevens, that might seem absolutely back-to-front. Not only that, curl ain't gonna help you diagnose the next one, which is a Path MTU Discovery issue, or the one after that, which is an undervoltage on the DRAM refresh controller. It might, however, be helpful in nailing that HTTP/2 prefetch request connection upgrade bug.

Mechanical sympathy means feeling every part of the machine, right down in your bones.

Re:The Case of the 50ms request by jcims on Thursday May 06, 2021 @09:26AM (#27062861)
To be fair, it was much simpler to develop and retain fluency in tcpdump when your interfaces were physical and your protocols weren't encrypted.
Re:The Case of the 50ms request by toast0 on Thursday May 06, 2021 @12:35PM (#27065772)
It is a lot nicer to tcpdump/wireshark when you can see everything, but most of the patterns of bad behavior are visible with encrypted data too.

Of course it's not as easy as it used to be / there's a lot more hurdles.

Encryption as you mentioned; although if you control the client or the server, you can often log keys and decrypt with wireshark, but it's a lot of steps, and you don't get helpful feedback to find mistakes.

NIC offloading means the OS doesn't necessarily see packets as they are on the wire. Segmentation offload means you may see larger packets than are on the wire, and checksum offload often makes sent packets show as errors but they're fine on the wire. If the NIC mutilates the packet, that's hard to debug.

It's not easy to run packet captures on mobile devices. If you can't get tcpdump on the device, you can't get captures from the client side of your cellular data. A lot of people don't have a network router they can run tcpdump on either, and if not, they can't get the client side of wifi data either.

Re:The Case of the 50ms request by barrkel on Thursday May 06, 2021 @04:59AM (#27060696)
That's the first thing I wanted to do after seeing the JS; since it was a simple request / response, check to see if it's a problem with the client vs the server by replacing the client with a known good piece of code. This effectively bisects the search space without first diving into low-level details.
Re:The Case of the 50ms request by joshspankit on Thursday May 06, 2021 @07:28AM (#27061648)
Exactly. If anyone has ever seen The Price Is Right, this is the optimal strategy for the “higher / lower” game: cut the options in half each time.
Re:The Case of the 50ms request by nevada_scout on Thursday May 06, 2021 @07:35AM (#27061716)
Also known as: Binary Search
Re:The Case of the 50ms request by joshspankit on Friday May 07, 2021 @07:45AM (#27074828)
True, but not as catchy
Re:The Case of the 50ms request by spuz on Thursday May 06, 2021 @04:54AM (#27060662)
How would using curl -d make the problem obvious?
Re:The Case of the 50ms request by barrkel on Thursday May 06, 2021 @05:01AM (#27060712)
It wouldn't have split the request over separate sends.

That's what flushHeaders() is doing; it does a separate send for headers vs the body of the request.

https://nodejs.org/api/http.html#http_request_flushheaders

Re:The Case of the 50ms request by adenhoed on Thursday May 06, 2021 @08:37AM (#27062270)
flushHeaders() is there to have a simple bug to find. In real world cases, tools like tcpdump and strace are essential, and I think this is a nice way to teach about how these tools can be used.
Re:The Case of the 50ms request by spuz on Thursday May 06, 2021 @05:16AM (#27060807)
Ok, I think that would have helped me learn that the client can some how trigger the bug but I don't think it would have allowed me to narrow it down to flushHeaders.
Re:The Case of the 50ms request by gizmo on Thursday May 06, 2021 @06:56AM (#27061408)
There is no such thing as flushing a TCP socket which is why that function jumped out at me. curl would have confirmed the server isn't misbehaving. Googling flushHeaders shows it's a node implementation specific thing and the docs explain that it has to do with the way node buffers http headers. Which makes sense because you don't want to call socket.send() for every http header you add to your request. But you also don't want to send() in between your headers and the body, because then you violate TCP package size expectations.