SSL negotiation failures causing 408 error to be returned

[Maxim Dounin]

Hello!

On Sun, Apr 15, 2012 at 11:34:48PM -0400, bpiraeus wrote:

> 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.

This is because Chrome opens many connections to a server from 
very start, trying to reduce latence in case of these connections 
will be useful.  If they aren't - they are just kept idle and 
either closed by Chrome (in this case you'll likely see 400 in 
logs) or timed out (in this case you'll see 408).

[...]

> 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:

The "while SSL handshaking" part of the message is a bit 
misleading.  Probably something like this will make things a bit 
better:

--- a/src/http/ngx_http_request.c
+++ b/src/http/ngx_http_request.c
@@ -612,6 +612,8 @@ ngx_http_ssl_handshake_handler(ngx_conne
 
         c->ssl->no_wait_shutdown = 1;
 
+        c->log->action = "reading client request line";
+
         c->read->handler = ngx_http_process_request_line;
         /* STUB: epoll edge */ c->write->handler = ngx_http_empty_handler;
 


Maxim Dounin