SSL negotiation failures causing 408 error to be returned

[bpiraeus]

While debugging for a client, we found that we're seeing significant
numbers of 408s being generated for SSL connections. It seems to be
MOSTLY Chrome on a Windows 7 base with some MSIE 9.0 (also on Win 7) as
user agents go, and at this point I'm completely stumped. We've tried
disabling session cache, upping timeout values, enabling/disabling
keepalives, nothing seems to stem the steady flow of these. Below is a
sample debug log (I've redacted specific pieces for business reasons).
What I see a lot of is 6 simultaneous connections being setup, 2 being
used, and then 4 timing out 60s later. Invariably, if I enable full
debug, I see 'client timed out (60: Operation timed out) while SSL
handshaking' which makes no sense. If I turn on logging for session IDs,
I can clearly see the clients being sent 408s are being assigned session
IDs which says to me they're completing the SSL negotiation and then
just.. sitting idle.

2012/04/14 14:51:41 [debug] 99433#0: *3313 accept: <CLIENT IP> fd:100
2012/04/14 14:51:41 [debug] 99433#0: *3313 post event 0000000801A026F0
2012/04/14 14:51:41 [debug] 99433#0: *3313 delete posted event
0000000801A026F0
2012/04/14 14:51:41 [debug] 99433#0: *3313 malloc:
0000000801EEF000:1256
2012/04/14 14:51:41 [debug] 99433#0: *3313 posix_memalign:
0000000801EE8300:256 @16
2012/04/14 14:51:41 [debug] 99433#0: *3313 malloc:
0000000800DE5000:4096
2012/04/14 14:51:41 [debug] 99433#0: *3313 posix_memalign:
0000000800DFE000:4096 @16
2012/04/14 14:51:41 [debug] 99433#0: *3313 http check ssl handshake
2012/04/14 14:51:41 [debug] 99433#0: *3313 https ssl handshake: 0x16
2012/04/14 14:51:41 [debug] 99433#0: *3313 SSL server name: "<SERVER
NAME>"
2012/04/14 14:51:41 [debug] 99433#0: *3313 SSL_do_handshake: -1
2012/04/14 14:51:41 [debug] 99433#0: *3313 SSL_get_error: 2
2012/04/14 14:51:41 [debug] 99433#0: *3313 kevent set event: 100: ft:-1
fl:0025
2012/04/14 14:51:41 [debug] 99433#0: *3313 event timer add: 100:
60000:1334440361120
2012/04/14 14:51:41 [debug] 99433#0: *3313 post event 0000000801A026F0
2012/04/14 14:51:41 [debug] 99433#0: *3313 delete posted event
0000000801A026F0
2012/04/14 14:51:41 [debug] 99433#0: *3313 SSL handshake handler: 0
2012/04/14 14:51:41 [debug] 99433#0: *3313 SSL_do_handshake: 1
2012/04/14 14:51:41 [debug] 99433#0: *3313 SSL: TLSv1, cipher: "RC4-SHA
SSLv3 Kx=RSA Au=RSA Enc=RC4(128) Mac=SHA1"
2012/04/14 14:51:41 [debug] 99433#0: *3313 SSL reused session
2012/04/14 14:51:41 [debug] 99433#0: *3313 http process request line
2012/04/14 14:51:41 [debug] 99433#0: *3313 SSL_read: -1
2012/04/14 14:51:41 [debug] 99433#0: *3313 SSL_get_error: 2
2012/04/14 14:52:41 [debug] 99433#0: *3313 event timer del: 100:
1334440361120
2012/04/14 14:52:41 [debug] 99433#0: *3313 http process request line
2012/04/14 14:52:41 [info] 99433#0: *3313 client timed out (60:
Operation timed out) while SSL handshaking, client: <CLIENT IP>,
server:
2012/04/14 14:52:41 [debug] 99433#0: *3313 http request count:1 blk:0
2012/04/14 14:52:41 [debug] 99433#0: *3313 http close request
2012/04/14 14:52:41 [debug] 99433#0: *3313 http log handler
2012/04/14 14:52:41 [debug] 99433#0: *3313 free: 0000000800DFE000,
unused: 2426
2012/04/14 14:52:41 [debug] 99433#0: *3313 close http connection: 100
2012/04/14 14:52:41 [debug] 99433#0: *3313 SSL_shutdown: 1
2012/04/14 14:52:41 [debug] 99433#0: *3313 reusable connection: 0
2012/04/14 14:52:41 [debug] 99433#0: *3313 free: 0000000800DE5000
2012/04/14 14:52:41 [debug] 99433#0: *3313 free: 0000000801EEF000
2012/04/14 14:52:41 [debug] 99433#0: *3313 free: 0000000801EE8200,
unused: 8
2012/04/14 14:52:41 [debug] 99433#0: *3313 free: 0000000801EE8300,
unused: 72

The following 5 UAs are by far the most common

Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/535.19 (KHTML, like
Gecko) Chrome/18.0.1025.152 Safari/535.19
Mozilla/5.0 (Windows NT 6.1) AppleWebKit/535.19 (KHTML, like Gecko)
Chrome/18.0.1025.162 Safari/535.19
Mozilla/5.0 (Windows NT 5.1) AppleWebKit/535.19 (KHTML, like Gecko)
Chrome/18.0.1025.162 Safari/535.19
Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/535.19 (KHTML, like
Gecko) Chrome/18.0.1025.162 Safari/535.19
Mozilla/5.0 (compatible; MSIE 9.0; Windows NT 6.1; WOW64; Trident/5.0)

This appears to implicate Windows in some way, but I've yet to figure it
out and am, quite frankly, stumped.

Posted at Nginx Forum: http://forum.nginx.org/read.php?2,225349,225349#msg-225349