Connection performance

[John Arbash Meinel]

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

...

> 5) So if we found a way to pipeline requests, and get rid of gaps, 
> instead of taking 10 RTT, we could potentially get down to 5 RTT.
> (2 gaps, calling Upgrade + Login + SetEnvironmentConstraints
> immediately rather than waiting for responses, not waiting for
> Close).
> 
> Is it worth pushing further on this? I certainly think the first
> thing to do is start caching the API, as we know we want to do
> that, but we potentially can speed it up *another* 2x by doing
> better pipelining.

I was curious, so I threw together a Python script that just uses
socket.connect and ssl.wrap_socket, and then replays the bites on the
wire that I captured with wireshark. Some interesting results:

1) s = socket.connect((address, port)); sslSock = ssl.wrap_socket(s)
is the same speed as
  s = socket.socket(); sslSock = ssl.wrap_socket(s); sslSock.connect()

Consistently >800ms for me (w/ 222ms average ping). (I've seen spikes
of 2s to ssl connect.)
Anyway, it just means that it really does require TCP to round trip
the connection before SSL starts talking.


2) It *is* possible to pipeline the HTTP GET/Upgrade request and the
Login request. Such that I can do:

    sslSock.sendall((HTTPUPGRADE % (opts.address, opts.port)) + LOGIN)

And everything works fine.

However, you cannot send the LOGIN request and a PING/SETCONSTRAINTS
request without a pause in the middle.

I ran into some really strange behavior here. If I did:
   sslSock.sendall(HTTPUPGRADE)
   sslSock.sendall(LOGIN)
   sslSock.sendall(PING)
   sslSock.sendall(SETCONSTRAINTS)

Then it fails unless I wait a really long time after login (200+ms).
My best guess is the LOGIN bytes don't actually go out the pipe very
quickly when it is 2 sendall. Which ends up putting the PING into the
same approximate time as the LOGIN. (And if you send LOGIN+PING it
fails because go hasn't changed the srvRoot for the connection when it
tries to serve the PING request.)

However, I *can* do:
   sslSock.sendall(HTTPUPGRADE + LOGIN)
   sslSock.sendall(PING + SETCONSTRAINTS + CLOSE)

I tried a small sleep() between the two requests but it isn't actually
required. Since whatever is going on does cause the second set of
packets to get sent at a later time.

Maybe this is an SSL thing? It has to finish encrypting whatever bytes
to give it so that partially frames the requests?

3) ssl.recv has a strange behavior in python. Whereby the first call
always seems to return 1 byte of the content, and the next call
returns the rest of the body for a given request. recv() does seem to
partition the response based on the actual response frame from the
server, even when you pipeline everything.


4) Pipelining does help, quite measurably:

$ time juju set-constraints -e amz-jam mem=2G
real	0m2.164s


# Issue each one-by-one and wait for a response
$ time py test_set_constraints.py
connecting to 184.73.69.243:17070
0.222s 0.222s connected
0.934s 0.713s ssl connected to ('184.73.69.243', 17070) ...
1.157s 0.222s HTTP upgraded to WebSocket: HTTP/1.1 101 Switch...
1.512s 0.356s WebSocket Login: \x81\x1d{"RequestId":1,"Response":{}}
1.734s 0.222s WebSocket Ping: \x81\x1d{"RequestId":2,"Response":{}}
1.960s 0.226s WebSocket SetConstraints: \x81\x1d{"RequestId":3,"Res...
2.182s 0.222s WebSocket Close: \x88\x02\x03\xe8


# sendall(HTTPUPGRADE + LOGIN); sendall(PING+SETCONSTRAINTS+CLOSE)
$ time py test_set_constraints.py --pipelined
0.843s 0.843s ssl connected
1.067s 0.224s response: H
1.067s 0.000s response: TTP/1.1 101 Switching ...
1.192s 0.125s response: \x81
1.192s 0.000s response: \x1d{"RequestId":1,"Response":{}}
1.289s 0.096s response: \x81
1.289s 0.000s response: \x1d{"RequestId":2,"Response":{}}
1.292s 0.003s response: \x81
1.292s 0.000s response: \x1d{"RequestId":3,"Response":{}}
1.292s 0.000s response: \x88
1.292s 0.000s response: \x02\x03\xe8

So that is 1.3s to do everything, rather than closer to 2s. If you
subtract out the 0.8s for SSL handshake that we can't get rid of, it
is 0.5s vs 1.2s :).

5) Ping seems to have a negligible real-world effect. Taking it out of
the Pipelined version might take us from 129ms to 128ms.
Certainly it isn't something I can measure given the variability in
real-world RTT.

6) Is this worth doing? I'm not really sure. It would be nice for
commands that only have 1 thing to do (SetConstraints) to make them
take half the time.
I think we already have api.Open() that connects and logs in, so if it
could collapse the HTTP GET with the Login bytes that could shave at
least one Round trip off.

Something to think about, at least.

John
=:->
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.13 (Cygwin)
Comment: Using GnuPG with Thunderbird - http://www.enigmail.net/

iEYEARECAAYFAlKR3bgACgkQJdeBCYSNAAMj7wCfYQj0XRvO2fWagr3MQFY17zv+
0A0AoK7UBXgwmZiP13JoNW0QPZ5Twu5M
=lA8M
-----END PGP SIGNATURE-----