m6w6 / ext-http

Extended HTTP Support
BSD 2-Clause "Simplified" License
79 stars 22 forks source link

Windows TCP may cause issues when working with VMware Linux Guest on LAN, for specific payload length #132

Open slawomir-pryczek opened 1 year ago

slawomir-pryczek commented 1 year ago

Hello, i'm trying

$client = new http\Client('curl', 'fc'); $options = ['tcp_nodelay'=>true] $client->setOptions($opts)

This doesn't seem to have any effect. I need to add around 1000b of additional, empty payload so the request won't incur additional 50ms penalty. How to add nodelay flag?

Thanks

m6w6 commented 1 year ago

Jeez, so here's a copy of my reply in the email:

Yes, this is how it should work.

How did you actually verify that that it doesn’t work for you?

See line 4 of an strace I just made here:


$ strace -e network php -r '$c=new http\Client; $c->setOptions(["tcp_nodelay"=>true]); $c->enqueue(new http\Client\Request("GET", "http://localhost/")); $c->send();' 
socketpair(AF_UNIX, SOCK_STREAM, 0, [3, 4]) = 0
socket(AF_INET, SOCK_STREAM, IPPROTO_TCP) = 5
setsockopt(5, SOL_TCP, TCP_NODELAY, [1], 4) = 0
connect(5, {sa_family=AF_INET, sin_port=htons(80), sin_addr=inet_addr("127.0.0.1")}, 16) = -1 EINPROGRESS (Operation now in progress)
getsockopt(5, SOL_SOCKET, SO_ERROR, [0], [4]) = 0
getsockname(5, {sa_family=AF_INET, sin_port=htons(50528), sin_addr=inet_addr("127.0.0.1")}, [128 => 16]) = 0
getpeername(5, {sa_family=AF_INET, sin_port=htons(80), sin_addr=inet_addr("127.0.0.1")}, [128 => 16]) = 0
getsockname(5, {sa_family=AF_INET, sin_port=htons(50528), sin_addr=inet_addr("127.0.0.1")}, [128 => 16]) = 0
getpeername(5, {sa_family=AF_INET, sin_port=htons(80), sin_addr=inet_addr("127.0.0.1")}, [128 => 16]) = 0
getsockname(5, {sa_family=AF_INET, sin_port=htons(50528), sin_addr=inet_addr("127.0.0.1")}, [128 => 16]) = 0
sendto(5, "GET / HTTP/1.1\r\nHost: localhost\r"..., 112, MSG_NOSIGNAL, NULL, 0) = 112
recvfrom(5, "HTTP/1.1 200 OK\r\nServer: openres"..., 16384, 0, NULL, NULL) = 1269
+++ exited with 0 +++
slawomir-pryczek commented 1 year ago

Sorry you're right TCP_NODELAY is set properly and thanks for confirming. I was able to move with testing, so greatly appreciated. Will rename the bug to what i think it is, and we can close it later, maybe someone will have some idea or maybe it helps someone. Spent last 2 days on debugging and checking pecl_http sources.

So this issue seems to be related to some very specific issue with different TCP imlpementations. Reproduced that on 4 instances (VMware 16 and 17) on LAN. Workaround is to just add 3-4KB of "garbage" to each HTTP request when working with VMware and windows machines if communication is slow. Maybe someone who knows more about TCP can suggest some better solution.

So basically it seems that the issue is there for specific lengths of TCP payload (payload length which results in creation of exactly 2 TCP packets during send). It was working correctly using CURL/POST extension but my PECL_HTTP code was sending POST request in 2 system calls so it produced 2 packets (that's consistent with tests attached), so when I switched - HTTP requests with short payload (almost all) start to take significantly longer time to run. That was +50ms so exactly like it is on this system when Nagle's algo is ON. That's why I incorrectly assumed it's issue with NODELAY.

Setup for client: Vmware 17 (Win 10/11), newest Debian GUEST Host MTU: 1500 We connect to HTTP server on LAN (same switch). If message is >1460B then it's starting to take +50ms at best. For messages > 2919B - back to normal. So it seems that if the message contains 1 TCP packet it's good, for 2 packets it's bad and for 3 (and more) packets it is good again (TCP+IP headers are 40B minimum...)

And php_http was sending 2 packets minimum for every POST request, so that's a coincidence and that's why it was giving high latency for me, but the extension works perfectly fine.

Curl Request: root@debian:/mnt/hgfs/htdocs/adserver2/testing# strace -tt -e network php -f test-http-curl.php 1 06:55:17.054662 socket(AF_INET6, SOCK_DGRAM, IPPROTO_IP) = 3 06:55:17.054919 socketpair(AF_UNIX, SOCK_STREAM, 0, [3, 4]) = 0 06:55:17.055539 socket(AF_INET, SOCK_STREAM, IPPROTO_IP) = 5 06:55:17.055656 setsockopt(5, SOL_TCP, TCP_NODELAY, [1], 4) = 0 06:55:17.055762 setsockopt(5, SOL_SOCKET, SO_KEEPALIVE, [1], 4) = 0 06:55:17.055857 setsockopt(5, SOL_TCP, TCP_KEEPIDLE, [60], 4) = 0 06:55:17.056213 setsockopt(5, SOL_TCP, TCP_KEEPINTVL, [60], 4) = 0 06:55:17.056779 connect(5, {sa_family=AF_INET, sin_port=htons(80), sin_addr=inet_addr("192.168.88.119")}, 16) = -1 EINPROGRESS (Operation now in progress) 06:55:17.057464 getsockopt(5, SOL_SOCKET, SO_ERROR, [0], [4]) = 0 06:55:17.057646 getpeername(5, {sa_family=AF_INET, sin_port=htons(80), sin_addr=inet_addr("192.168.88.119")}, [128->16]) = 0 06:55:17.057768 getsockname(5, {sa_family=AF_INET, sin_port=htons(48808), sin_addr=inet_addr("192.168.10.150")}, [128->16]) = 0 06:55:17.057994 sendto(5, "POST /1.txt HTTP/1.1\r\nHost: 192."..., 128, MSG_NOSIGNAL, NULL, 0) = 128 06:55:17.059094 recvfrom(5, "HTTP/1.1 200 OK\r\nDate: Wed, 11 O"..., 16384, 0, NULL, NULL) = 426 TOOK:5.11

PHP_HTTP request: root@debian:/mnt/hgfs/htdocs/adserver2/testing# strace -tt -e network php -f test-http-pecl_http.php 1 06:54:38.823028 socket(AF_INET6, SOCK_DGRAM, IPPROTO_IP) = 3 06:54:38.823360 socketpair(AF_UNIX, SOCK_STREAM, 0, [3, 4]) = 0 06:54:38.824256 socket(AF_INET, SOCK_STREAM, IPPROTO_IP) = 5 06:54:38.824383 setsockopt(5, SOL_TCP, TCP_NODELAY, [1], 4) = 0 06:54:38.825059 connect(5, {sa_family=AF_INET, sin_port=htons(80), sin_addr=inet_addr("192.168.88.119")}, 16) = -1 EINPROGRESS (Operation now in progress) 06:54:38.825917 getsockopt(5, SOL_SOCKET, SO_ERROR, [0], [4]) = 0 06:54:38.826042 getpeername(5, {sa_family=AF_INET, sin_port=htons(80), sin_addr=inet_addr("192.168.88.119")}, [128->16]) = 0 06:54:38.826270 getsockname(5, {sa_family=AF_INET, sin_port=htons(48634), sin_addr=inet_addr("192.168.10.150")}, [128->16]) = 0 06:54:38.826463 sendto(5, "POST /1.txt HTTP/1.1\r\nHost: 192."..., 165, MSG_NOSIGNAL, NULL, 0) = 165 06:54:38.826867 sendto(5, " ", 1, MSG_NOSIGNAL, NULL, 0) = 1 06:54:38.879345 recvfrom(5, "HTTP/1.1 200 OK\r\nDate: Wed, 11 O"..., 16384, 0, NULL, NULL) = 426 TOOK:56.87 06:54:38.893966 +++ exited with 0 +++ `

Reproductible... ~4-6ms vs [~45-58ms]

Attaching tests Bytes sent, Bytes received, Time, Body Length

php_tests.zip timing_curl.txt timing_http-pecl.txt

Done more tests... attached laptop with win10 using just single cable (not switch / router) - same thing (so that's probably not hardware). Attached laptop with debian and it works OK. So it seems there's some issue with windows TCP when working with VMware...

CLIENT ||| SERVER Host: Windows Guest: VM Debian ||| Host: Windows Guest: VM Debian (APACHE) -> BAD Host: Windows Guest: VM Debian ||| Host: Windows (APACHE/Xampp) -> BAD Host: Windows Guest: VM Debian ||| Host: Debian (Apache) -> Good Host: Debian ||| Host: Windows Guest: VM Debian (Apache) -> Good Host: Debian ||| Host: Windows (APACHE/Xampp) -> Good

m6w6 commented 1 year ago

The second sendto for pecl_http probably happens, because we're using a callback to supply the body data to libcurl, since http\Message\Body represents a (temporary) stream.

Let me reformat your results table: CLIENT Host CLIENT Guest SERVER Host SERVER Guest GOOD
Windows VM Debian Windows VM Debian :x:
Windows VM Debian Windows - :x:
Windows VM Debian Debian - :heavy_check_mark:
Debian - Windows VM Debian :heavy_check_mark:
Debian - Windows - :heavy_check_mark:
Debian - Debian - :heavy_check_mark: (assumed)
Windows - Windows - :x: (Assumed)
Windows - Debian - :heavy_check_mark: (assumed)

It looks like it depends on Windows being the native Client/Server Host on both sides, even more so If the assumed rows are right.

Also, the strace shows, that it's actually the server side delaying 50ms.

m6w6 commented 1 year ago

Maybe any of the PHP Windows Gurus can shed some light on here, though, since that 50ms seem oddly specific? /CC @Jan-E @cmb69

slawomir-pryczek commented 1 year ago

Thanks for the table, looks much better. Figured it out actually and that's very good info if anyone is experiencing issues with latency on windows. Found some people complaining about high network latency in games on windows while linux was ok (in windows 7 this latency is 200ms, this was changed to 50ms in Win10/11 so it's huge issue for games). Also found these posts https://www.howtoguides.org/reduce-latency-in-Windows-7 https://www.speedguide.net/articles/gaming-tweaks-5812

So there's a value which you can set in the registry for each network interface TcpAckFrequency which defaults to 2. If there are less packets than TcpAckFrequency then the ACK gets delayed by 200ms on Win <10 and by 50ms in Win10 and above. This seems to be less or equal actually. Increased that to 5 and after restart all traffic which was <= 5 frames was delayed by additional 50ms.

When you set TcpAckFrequency on your LAN network card to 1 (on server side is enough) the problem is gone, because ACK gets send instantly. Not sure why packets which are fitting inside 1 frame are getting ACK'ed quickly, maybe there's some additional optimization for this case.

There's also interesting comment about NODELAY, so maybe VMware is not implementing NODELAY correctly as well...

Since Windows Vista, TCP_NODELAY option must be set prior to calling connect, or (on the server) prior to calling listen. If you set TCP_NODELAY after calling connect, it will not actually disable Nagle algorithm, yet GetSocketOption will state that Nagle has been disabled! This all appears to be undocumented, and contradicts what many tutorials/articles on the subject teach. With Nagle actually disabled, TCP delayed acknowledgements no longer cause latency. https://stackoverflow.com/questions/22583941/what-is-the-workaround-for-tcp-delayed-acknowledgment