Logging $ssl_session_id can crash Nginx 1.5.9 worker

I run the nginx.org mainline packages on Ubuntu 12.04, 32- and 64-bit. I
use
a wacky custom log format, and after 1.5.9 was released today, I enabled
logging the $ssl_session_id variable. I later ran an SSL Labs SSL Server
Test, [0] which makes numerous HTTPS requests of various sorts, and lo
and
behold, one of my worker processes core dumped. I fooled around with my
configuration and determined that the problem was logging
$ssl_session_id.
If I don’t log it, it’s fine. If I enable a log that contains
$ssl_session_id – even only $ssl_session_id – it crashes.

Normal HTTPS requests – well, I just tried curl and Firefox – work
fine. I
notice that curl does log a session ID, but for Firefox that field is
just a
“-”. I have no idea if that’s an(other) Nginx bug or just a difference
between the two clients, but it smells funny to me. I briefly enabled
$ssl_session_id logging on 2013-12-17 with 1.5.7 or 1.5.8 and whatever
Firefox version was current at the time and it did log he session data.
(I
never tried curl or SSL Labs then.)

nginx.conf: https://mn9.us/tmp/nginx.conf (my logging nonsense is at
the
end)

Good and bad log snippets at https://mn9.us/tmp/nginx.log and pasted
below.

Bad:

==> /var/log/nginx/access13.log <==
173.203.79.216 36823 “www.mn9.us” 192.155.93.101 443 “mn9.us” 586 1 on
TLSv1.2 - “-” [2014-01-22T18:05:54+00:00] “GET / HTTP/1.0” 200 975 612 -
“-”
“SSL Labs (https://www.ssllabs.com/about/assessment.html)” “-”
“ECDHE-RSA-AES128-SHA” “-”
173.203.79.216 36876 “-” 192.155.93.101 443 “mn9.us” 594 1 on TLSv1 -
“-”
[2014-01-22T18:06:06+00:00] “HEAD
/?SSL_Labs_Renegotiation_Test=User_Agent_May_Not_Show HTTP/1.0” 400 0 0

“-” “SSL Labs (https://www.ssllabs.com/about/assessment.html)” “-”
“DHE-RSA-AES128-SHA” “-”

==> /var/log/nginx/error.log <==
2014/01/22 18:06:06 [notice] 24848#0: *595 SSL renegotiation disabled
while
reading client request headers, client: 173.203.79.216, server: mn9.us,
request: “HEAD /?SSL_Labs_Renegotiation_Test=User_Agent_May_Not_Show
HTTP/1.0”
2014/01/22 18:06:07 [notice] 24681#0: signal 17 (SIGCHLD) received
2014/01/22 18:06:07 [alert] 24681#0: worker process 24848 exited on
signal
11 (core dumped)
2014/01/22 18:06:07 [notice] 24681#0: start worker process 26865
2014/01/22 18:06:07 [notice] 24681#0: signal 29 (SIGIO) received

Good:

==> /var/log/nginx/access11.log <==
173.203.79.216 60618 “www.mn9.us” 192.155.93.101 443 “mn9.us” 1003 1 on
TLSv1.2 - “-” [2014-01-22T18:27:09+00:00] “GET / HTTP/1.0” 200 975 612 -
“-”
“SSL Labs (https://www.ssllabs.com/about/assessment.html)” “-”
“ECDHE-RSA-AES128-SHA”
173.203.79.216 60701 “-” 192.155.93.101 443 “mn9.us” 1008 1 on TLSv1 -
“-”
[2014-01-22T18:27:22+00:00] “HEAD
/?SSL_Labs_Renegotiation_Test=User_Agent_May_Not_Show HTTP/1.0” 400 0 0

“-” “SSL Labs (https://www.ssllabs.com/about/assessment.html)” “-”
“DHE-RSA-AES128-SHA”

==> /var/log/nginx/error.log <==
2014/01/22 18:27:22 [notice] 27156#0: *1009 SSL renegotiation disabled
while
reading client request headers, client: 173.203.79.216, server: mn9.us,
request: “HEAD /?SSL_Labs_Renegotiation_Test=User_Agent_May_Not_Show
HTTP/1.0”

==> /var/log/nginx/access11.log <==
173.203.79.216 60948 “-” 192.155.93.101 443 “mn9.us” 1009 1 on TLSv1.2 -
“-”
[2014-01-22T18:27:22+00:00] “HEAD
/?SSL_Labs_Renegotiation_Test=User_Agent_May_Not_Show HTTP/1.0” 400 0 0

“-” “SSL Labs (https://www.ssllabs.com/about/assessment.html)” “-”
“(NONE)”

[0] https://www.ssllabs.com/ssltest/index.html

Cheers

Posted at Nginx Forum:

On Wed, Jan 22, 2014 at 02:02:51PM -0500, mnordhoff wrote:

I run the nginx.org mainline packages on Ubuntu 12.04, 32- and 64-bit. I use
a wacky custom log format, and after 1.5.9 was released today, I enabled
logging the $ssl_session_id variable. I later ran an SSL Labs SSL Server
Test, [0] which makes numerous HTTPS requests of various sorts, and lo and
behold, one of my worker processes core dumped. I fooled around with my
configuration and determined that the problem was logging $ssl_session_id.
If I don’t log it, it’s fine. If I enable a log that contains
$ssl_session_id – even only $ssl_session_id – it crashes.

The following patch fixes this:

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
@@ -2509,6 +2509,10 @@ ngx_ssl_get_session_id(ngx_connection_t

 sess = SSL_get0_session(c->ssl->connection);
  • if (sess == NULL) {
  •    return NGX_ERROR;
    
  • }
  • buf = sess->session_id;
    len = sess->session_id_length;

Hello!

On Wed, Jan 22, 2014 at 02:02:51PM -0500, mnordhoff wrote:

I run the nginx.org mainline packages on Ubuntu 12.04, 32- and 64-bit. I use
a wacky custom log format, and after 1.5.9 was released today, I enabled
logging the $ssl_session_id variable. I later ran an SSL Labs SSL Server
Test, [0] which makes numerous HTTPS requests of various sorts, and lo and
behold, one of my worker processes core dumped. I fooled around with my
configuration and determined that the problem was logging $ssl_session_id.
If I don’t log it, it’s fine. If I enable a log that contains
$ssl_session_id – even only $ssl_session_id – it crashes.

Thanks for the report, the following patch should fix it:

— a/src/event/ngx_event_openssl.c
+++ b/src/event/ngx_event_openssl.c
@@ -2508,6 +2508,10 @@ ngx_ssl_get_session_id(ngx_connection_t
SSL_SESSION *sess;

 sess = SSL_get0_session(c->ssl->connection);
  • if (sess == NULL) {

  •    s->len = 0;
    
  •    return NGX_OK;
    
  • }

    buf = sess->session_id;
    len = sess->session_id_length;

Normal HTTPS requests – well, I just tried curl and Firefox – work fine. I
notice that curl does log a session ID, but for Firefox that field is just a
“-”. I have no idea if that’s an(other) Nginx bug or just a difference
between the two clients, but it smells funny to me. I briefly enabled

That’s normal, session id is expected to be empty, e.g., if session
tickets are
used.


Maxim D.
http://nginx.org/

On Thu, Jan 23, 2014 at 01:48:58AM +0400, Maxim D. wrote:

$ssl_session_id – even only $ssl_session_id – it crashes.

  • if (sess == NULL) {
  •    return NGX_ERROR;
    
  • }
  • buf = sess->session_id;
    len = sess->session_id_length;

You were faster. :slight_smile:
I think that len = 0 + NGX_OK is better than NGX_ERROR here
though, and also in line with other similar functions like
ngx_ssl_get_[raw_]certificate().

It’s also consistent with the previous behavior, so I agree.

Hello!

On Thu, Jan 23, 2014 at 12:06:55AM +0400, Ruslan E. wrote:

The following patch fixes this:

  • }
  • buf = sess->session_id;
    len = sess->session_id_length;

You were faster. :slight_smile:
I think that len = 0 + NGX_OK is better than NGX_ERROR here
though, and also in line with other similar functions like
ngx_ssl_get_[raw_]certificate().


Maxim D.
http://nginx.org/