Hello!

On Wed, Jan 30, 2013 at 03:50:39AM +0000, 彭谦(研六 福州) wrote:

> Hello all!
> Recently I came across a problem that CPU 100% when nginx upstream were trying to SSL handshake to the web sever.
> the pass_proxy url is https://www.salesforce.com/export/login-messages/common/css/images/login/bk_promo_overlay3.png;
> maybe the slow https web site has the same problem.
>
> The debug log:
> 2013/01/30 11:06:23 [debug] 19604#0: posted event 100232FC
> 2013/01/30 11:06:23 [debug] 19604#0: *1 delete posted event 100232FC
> 2013/01/30 11:06:23 [debug] 19604#0: *1 SSL handshake handler: 1
> 2013/01/30 11:06:23 [debug] 19604#0: *1 SSL_do_handshake: -1
> 2013/01/30 11:06:23 [debug] 19604#0: *1 SSL_get_error: 2
> 2013/01/30 11:06:23 [debug] 19604#0: posted event 00000000
> 2013/01/30 11:06:23 [debug] 19604#0: worker cycle
> 2013/01/30 11:06:23 [debug] 19604#0: select event: fd:6 wr:0
> 2013/01/30 11:06:23 [debug] 19604#0: select event: fd:3 wr:0
> 2013/01/30 11:06:23 [debug] 19604#0: select event: fd:7 wr:0
> 2013/01/30 11:06:23 [debug] 19604#0: select event: fd:7 wr:1
> 2013/01/30 11:06:23 [debug] 19604#0: max_fd: 7
> 2013/01/30 11:06:23 [debug] 19604#0: select timer: 46801
> 2013/01/30 11:06:23 [debug] 19604#0: select ready 1
> 2013/01/30 11:06:23 [debug] 19604#0: select write 7
> 2013/01/30 11:06:23 [debug] 19604#0: *1 post event 100232FC
> 2013/01/30 11:06:23 [debug] 19604#0: timer delta: 0
> 2013/01/30 11:06:23 [debug] 19604#0: posted events 100232FC
> 2013/01/30 11:06:23 [debug] 19604#0: posted event 100232FC
> 2013/01/30 11:06:23 [debug] 19604#0: *1 delete posted event 100232FC
> 2013/01/30 11:06:23 [debug] 19604#0: *1 SSL handshake handler: 1
> 2013/01/30 11:06:23 [debug] 19604#0: *1 SSL_do_handshake: -1
> 2013/01/30 11:06:23 [debug] 19604#0: *1 SSL_get_error: 2
> 2013/01/30 11:06:23 [debug] 19604#0: posted event 00000000
> 2013/01/30 11:06:23 [debug] 19604#0: worker cycle
> 2013/01/30 11:06:23 [debug] 19604#0: select event: fd:6 wr:0
> 2013/01/30 11:06:23 [debug] 19604#0: select event: fd:3 wr:0
> 2013/01/30 11:06:23 [debug] 19604#0: select event: fd:7 wr:0
> 2013/01/30 11:06:23 [debug] 19604#0: select event: fd:7 wr:1
> 2013/01/30 11:06:23 [debug] 19604#0: max_fd: 7
>
> we can see the write handler will repeat again and again until the SSL_do_handshake return 1.
> i just repear the problem in select I/O multiplexing.
> Can you help me to fix this bug?

Thank you for your report, it looks like generic problem in ssl handshake
handling with level-triggered event methods.

The following patch should fix the problem:

diff --git a/src/event/ngx_event_openssl.c b/src/event/ngx_event_openssl.c
--- a/src/event/ngx_event_openssl.c
+++ b/src/event/ngx_event_openssl.c
@@ -808,6 +808,10 @@ ngx_ssl_handshake(ngx_connection_t *c)
return NGX_ERROR;
}

+ if (ngx_handle_write_event(c->write, 0) != NGX_OK) {
+ return NGX_ERROR;
+ }
+
return NGX_AGAIN;
}

@@ -816,6 +820,10 @@ ngx_ssl_handshake(ngx_connection_t *c)
c->read->handler = ngx_ssl_handshake_handler;
c->write->handler = ngx_ssl_handshake_handler;

+ if (ngx_handle_read_event(c->read, 0) != NGX_OK) {
+ return NGX_ERROR;
+ }
+
if (ngx_handle_write_event(c->write, 0) != NGX_OK) {
return NGX_ERROR;
}



--
Maxim Dounin
http://nginx.com/support.html

_______________________________________________
nginx-devel mailing list
nginx-devel@nginx.org
http://mailman.nginx.org/mailman/listinfo/nginx-devel