r27446 - Ping request, manager, and command by @Veracity0 in [

This adds a "ping" command which calls on PingManager to do a ping test and optionally save the results in properties.

A ping is a request we make of the server strictly to measure elapsed request/response time.
We support pinging to several KoL pages:

api.php - fast and small. Here in Boston, I've seen this as low as 22 msec, although normal is closer to 30. The response is ~1920 bytes.
main.php - about 3 times slower and 4 times bigger. About 90 msec and 8342 byte response.

Code: 
> ping

10 pings to api.php at 29-40 msec apiece (total = 325, average = 32) = 60369 bytes/second
I've seen this as high as 2326 msec. I logged out of that server and back into this one. Phew! :)
Code: 
> ping 100

100 pings to api.php at 30-157 msec apiece (total = 3556, average = 35) = 55174 bytes/second

> ping 100

100 pings to api.php at 29-42 msec apiece (total = 3350, average = 33) = 58567 bytes/second
Even on the same session & server, there is variance.
Code: 
> ping 100 main

100 pings to main.php at 89-199 msec apiece (total = 12247, average = 122) = 51433 bytes/second
I don't see much value in going to main.php, but, whatever.
Code: 
> ping 10 api true

Ping #1 of 10...
-> 30 msec (1962 bytes)
Ping #2 of 10...
-> 40 msec (1962 bytes)
Ping #3 of 10...
-> 31 msec (1962 bytes)
Ping #4 of 10...
-> 29 msec (1962 bytes)
Ping #5 of 10...
-> 31 msec (1962 bytes)
Ping #6 of 10...
-> 30 msec (1962 bytes)
Ping #7 of 10...
-> 27 msec (1962 bytes)
Ping #8 of 10...
-> 28 msec (1962 bytes)
Ping #9 of 10...
-> 34 msec (1962 bytes)
Ping #10 of 10...
-> 36 msec (1962 bytes)
10 pings to api.php at 27-40 msec apiece (total = 316, average = 31) = 62088 bytes/second

> ping 10 main true

Ping #1 of 10...
-> 135 msec (6299 bytes)
Ping #2 of 10...
-> 110 msec (6299 bytes)
Ping #3 of 10...
-> 120 msec (6299 bytes)
Ping #4 of 10...
-> 100 msec (6299 bytes)
Ping #5 of 10...
-> 136 msec (6299 bytes)
Ping #6 of 10...
-> 119 msec (6299 bytes)
Ping #7 of 10...
-> 119 msec (6299 bytes)
Ping #8 of 10...
-> 394 msec (6299 bytes)
Ping #9 of 10...
-> 113 msec (6299 bytes)
Ping #10 of 10...
-> 111 msec (6299 bytes)
10 pings to main.php at 100-394 msec apiece (total = 1457, average = 145) = 43232 bytes/second
If you are really curious...

We save results in 3 properties:

pingLatest - the last ping test you ran, any page, any count
pingLongest - the longest observed ping we saw with api.php & at least 10 pings
pingShortest - the shortest observed ping we saw with api.php & at least 10 pings

Code: 
> get pingLatest

main.php:10:100:394:1457:62990:145

> get pingLongest

api.php:10:178:364:2326:19620:232

> get pingShortest

api.php:10:19:28:221:19620:22
Seven fields:

PAGE:COUNT:LOW:HIGH:TOTAL:BYTES:AVERAGE

(AVERAGE is for convenience; it is simply TOTAL / COUNT)

This is the infrastructure I will use for my current project: optionally doing a ping test when you log in. Immediately after login.php is done but before we do any of the "refresh session" stuff. Optionally, if the average ping time is too much slower (configurable), pop up a dialog to give you the option to accept it, log out and back in and hope for better, or give up.

That ping test with 232 msec per api.php call, as opposed to something closer to 30, would be a good candidate for punting on. As I did. :)
 
Veracity said:
I've seen this as high as 2326 msec. I logged out of that server and back into this one. Phew!
Click to expand...
I do wonder what this is actually measuring. Were there timeouts, or was the server just slow to respond to all requests? (plausibly overload in conjunction with handling requests via fifo...)

Some timing observations from curl:
- My (ICMP) ping RTT (~20ms) to AWS's us-east-1 (where the servers should be based on the configured load balancer) is about half of my actual TCP handshake latency (40ms).
- TLS is being downgraded from 1.3 to 1.2 by the server, thereby injecting an additional RTT to connection setup latency.
- The server cert uses 2048-bit RSA encryption. Yay, burning cpu (several milliseconds on both ends...), but at least the exchanged symmetric key is AES128-GCM.
- Once the connection is set up, my roundtrip to the server is closer to 3x my expected RTT (60ms). Which is roughly what api.php requests yield, anyways.
- If I'm being redirected (e.g. from / -> /login.php?loginid=xxx), then this doesn't seem like it's actually being forwarded to the backend, so 40ms again.

In total, my curl latency looks like ~10 rtt even though in practice I only see... 6 network round trips (it should only be 3-4)?! Indeed, the TLS downgrade actually happens in roughly 1 RTT, which suggests AWS's LB is terminating the TLS connection (although I'm not sure why the initial TCP handshake is so much slower). And then by the time the connection is actually set up, this should be forwarded to the appropriate backend (which ought to be in the same or nearby datacenters). There's no reason why the server-side latency should vary based on user location (which should only affect network latency), assuming the servers are the same...

Note that in general, we're going to be reusing existing connections, so connection setup overhead shouldn't be relevant. And indeed, it's not. (I just have a habit of poking at networking details.)

I wonder why I'm seeing an extra 40ms latency over the physical network overhead purely within AWS, when that's longer than your entire request timing. The "obvious" explanation to me is that you're, say, landing at a load balancer in Ohio (due to Amazon having more diverse peering with your ISP) where the VMs actually are, while I'm dealing with internal round trips between IAD and CMH.
 
You must log in or register to reply here.
Back
Top