Fwd: nginx-devel Digest, Vol 55, Issue 15
idina sabari
idinasabari at gmail.com
Fri May 16 18:26:34 UTC 2014
---------- Forwarded message ----------
From: <nginx-devel-request at nginx.org>
Date: 2014-05-16 5:00 GMT-07:00
Subject: nginx-devel Digest, Vol 55, Issue 15
To: nginx-devel at nginx.org
Send nginx-devel mailing list submissions to
nginx-devel at nginx.org
To subscribe or unsubscribe via the World Wide Web, visit
http://mailman.nginx.org/mailman/listinfo/nginx-devel
or, via email, send a message with subject or body 'help' to
nginx-devel-request at nginx.org
You can reach the person managing the list at
nginx-devel-owner at nginx.org
When replying, please edit your Subject line so it is more specific
than "Re: Contents of nginx-devel digest..."
Today's Topics:
1. [nginx] SPDY: set log action for PROXY protocol only while
parsi... (Valentin Bartenev)
2. [nginx] SPDY: improved logging. (Valentin Bartenev)
3. [nginx] SPDY: refactored ngx_http_spdy_state_headers().
(Valentin Bartenev)
4. [nginx] SPDY: added a debug point to the state buffer
overflow p... (Valentin Bartenev)
5. [nginx] SPDY: added protection from overrun of the receive
buffer. (Valentin Bartenev)
----------------------------------------------------------------------
Message: 1
Date: Thu, 15 May 2014 15:25:50 +0000
From: Valentin Bartenev <vbart at nginx.com>
To: nginx-devel at nginx.org
Subject: [nginx] SPDY: set log action for PROXY protocol only while
parsi...
Message-ID:
<hg.ed5fb7d22d46.1400167550.6369085454036692193 at ns.nginx.org>
Content-Type: text/plain; charset="us-ascii"
details: http://hg.nginx.org/nginx/rev/ed5fb7d22d46
branches:
changeset: 5692:ed5fb7d22d46
user: Valentin Bartenev <vbart at nginx.com>
date: Thu May 15 19:22:06 2014 +0400
description:
SPDY: set log action for PROXY protocol only while parsing it.
Handling of PROXY protocol for SPDY connection is currently implemented as
a SPDY state. And while nginx waiting for PROXY protocol data it continues
to process SPDY connection: initializes zlib context, sends control frames.
diffstat:
src/http/ngx_http_spdy.c | 17 +++++++++--------
1 files changed, 9 insertions(+), 8 deletions(-)
diffs (40 lines):
diff -r 31349361558e -r ed5fb7d22d46 src/http/ngx_http_spdy.c
--- a/src/http/ngx_http_spdy.c Wed Apr 30 20:34:20 2014 +0400
+++ b/src/http/ngx_http_spdy.c Thu May 15 19:22:06 2014 +0400
@@ -424,12 +424,8 @@ ngx_http_spdy_init(ngx_event_t *rev)
sc->init_window = NGX_SPDY_INIT_STREAM_WINDOW;
- sc->handler = ngx_http_spdy_state_head;
-
- if (hc->proxy_protocol) {
- c->log->action = "reading PROXY protocol";
- sc->handler = ngx_http_spdy_proxy_protocol;
- }
+ sc->handler = hc->proxy_protocol ? ngx_http_spdy_proxy_protocol
+ : ngx_http_spdy_state_head;
sc->zstream_in.zalloc = ngx_http_spdy_zalloc;
sc->zstream_in.zfree = ngx_http_spdy_zfree;
@@ -823,14 +819,19 @@ static u_char *
ngx_http_spdy_proxy_protocol(ngx_http_spdy_connection_t *sc, u_char *pos,
u_char *end)
{
+ ngx_log_t *log;
+
+ log = sc->connection->log;
+ log->action = "reading PROXY protocol";
+
pos = ngx_proxy_protocol_parse(sc->connection, pos, end);
+ log->action = "processing SPDY";
+
if (pos == NULL) {
return ngx_http_spdy_state_protocol_error(sc);
}
- sc->connection->log->action = "processing SPDY";
-
return ngx_http_spdy_state_complete(sc, pos, end);
}
------------------------------
Message: 2
Date: Thu, 15 May 2014 15:25:52 +0000
From: Valentin Bartenev <vbart at nginx.com>
To: nginx-devel at nginx.org
Subject: [nginx] SPDY: improved logging.
Message-ID:
<hg.701d6e17e42c.1400167552.6369085454036692193 at ns.nginx.org>
Content-Type: text/plain; charset="us-ascii"
details: http://hg.nginx.org/nginx/rev/701d6e17e42c
branches:
changeset: 5693:701d6e17e42c
user: Valentin Bartenev <vbart at nginx.com>
date: Wed Apr 30 20:34:20 2014 +0400
description:
SPDY: improved logging.
diffstat:
src/http/ngx_http_spdy.c | 210
+++++++++++++++++++++++---------
src/http/ngx_http_spdy_filter_module.c | 3 +-
2 files changed, 151 insertions(+), 62 deletions(-)
diffs (truncated from 656 to 300 lines):
diff -r ed5fb7d22d46 -r 701d6e17e42c src/http/ngx_http_spdy.c
--- a/src/http/ngx_http_spdy.c Thu May 15 19:22:06 2014 +0400
+++ b/src/http/ngx_http_spdy.c Wed Apr 30 20:34:20 2014 +0400
@@ -395,8 +395,7 @@ ngx_http_spdy_init(ngx_event_t *rev)
c = rev->data;
hc = c->data;
- ngx_log_debug0(NGX_LOG_DEBUG_HTTP, c->log, 0,
- "init spdy request");
+ ngx_log_debug0(NGX_LOG_DEBUG_HTTP, c->log, 0, "init spdy request");
c->log->action = "processing SPDY";
@@ -556,7 +555,7 @@ ngx_http_spdy_read_handler(ngx_event_t *
if (n == 0 && (sc->incomplete || sc->processing)) {
ngx_log_error(NGX_LOG_INFO, c->log, 0,
- "client closed prematurely connection");
+ "client prematurely closed connection");
}
if (n == 0 || n == NGX_ERROR) {
@@ -644,7 +643,7 @@ ngx_http_spdy_write_handler(ngx_event_t
stream->handled = 0;
ngx_log_debug1(NGX_LOG_DEBUG_HTTP, c->log, 0,
- "spdy run stream %ui", stream->id);
+ "run spdy stream %ui", stream->id);
wev = stream->request->connection->write;
wev->handler(wev);
@@ -860,7 +859,7 @@ ngx_http_spdy_state_head(ngx_http_spdy_c
pos += sizeof(uint32_t);
ngx_log_debug3(NGX_LOG_DEBUG_HTTP, sc->connection->log, 0,
- "spdy process frame head:%08XD f:%Xd l:%uz",
+ "process spdy frame head:%08XD f:%Xd l:%uz",
head, sc->flags, sc->length);
if (ngx_spdy_ctl_frame_check(head)) {
@@ -872,6 +871,8 @@ ngx_http_spdy_state_head(ngx_http_spdy_c
return ngx_http_spdy_state_syn_stream(sc, pos, end);
case NGX_SPDY_SYN_REPLY:
+ ngx_log_error(NGX_LOG_INFO, sc->connection->log, 0,
+ "client sent unexpected SYN_REPLY frame");
return ngx_http_spdy_state_protocol_error(sc);
case NGX_SPDY_RST_STREAM:
@@ -887,6 +888,8 @@ ngx_http_spdy_state_head(ngx_http_spdy_c
return ngx_http_spdy_state_skip(sc, pos, end); /* TODO */
case NGX_SPDY_HEADERS:
+ ngx_log_error(NGX_LOG_INFO, sc->connection->log, 0,
+ "client sent unexpected HEADERS frame");
return ngx_http_spdy_state_protocol_error(sc);
case NGX_SPDY_WINDOW_UPDATE:
@@ -904,10 +907,8 @@ ngx_http_spdy_state_head(ngx_http_spdy_c
return ngx_http_spdy_state_data(sc, pos, end);
}
-
- /* TODO version & type check */
- ngx_log_debug0(NGX_LOG_DEBUG_HTTP, sc->connection->log, 0,
- "spdy unknown frame");
+ ngx_log_error(NGX_LOG_INFO, sc->connection->log, 0,
+ "client sent invalid frame");
return ngx_http_spdy_state_protocol_error(sc);
}
@@ -927,7 +928,10 @@ ngx_http_spdy_state_syn_stream(ngx_http_
}
if (sc->length <= NGX_SPDY_SYN_STREAM_SIZE) {
- /* TODO logging */
+ ngx_log_error(NGX_LOG_INFO, sc->connection->log, 0,
+ "client sent SYN_STREAM frame with incorrect length
%uz",
+ sc->length);
+
return ngx_http_spdy_state_protocol_error(sc);
}
@@ -968,7 +972,7 @@ ngx_http_spdy_state_syn_stream(ngx_http_
if (sc->processing >= sscf->concurrent_streams) {
ngx_log_error(NGX_LOG_INFO, sc->connection->log, 0,
- "spdy concurrent streams exceeded %ui",
sc->processing);
+ "concurrent streams exceeded %ui", sc->processing);
if (ngx_http_spdy_send_rst_stream(sc, sid, NGX_SPDY_REFUSED_STREAM,
prio)
@@ -1026,7 +1030,7 @@ ngx_http_spdy_state_headers(ngx_http_spd
r = sc->stream->request;
ngx_log_debug2(NGX_LOG_DEBUG_HTTP, r->connection->log, 0,
- "spdy process HEADERS %uz of %uz", size, sc->length);
+ "process spdy header block %uz of %uz", size,
sc->length);
buf = r->header_in;
@@ -1101,7 +1105,7 @@ ngx_http_spdy_state_headers(ngx_http_spd
buf->pos += NGX_SPDY_NV_NUM_SIZE;
ngx_log_debug1(NGX_LOG_DEBUG_HTTP, r->connection->log, 0,
- "spdy HEADERS block consists of %ui entries",
+ "spdy header block has %ui entries",
sc->entries);
if (ngx_list_init(&r->headers_in.headers, r->pool, 20,
@@ -1142,7 +1146,6 @@ ngx_http_spdy_state_headers(ngx_http_spd
rc = ngx_http_spdy_alloc_large_header_buffer(r);
if (rc == NGX_DECLINED) {
- /* TODO logging */
ngx_http_finalize_request(r,
NGX_HTTP_REQUEST_HEADER_TOO_LARGE);
return ngx_http_spdy_state_headers_skip(sc, pos, end);
@@ -1179,9 +1182,8 @@ ngx_http_spdy_state_headers(ngx_http_spd
}
if (complete) {
- /* TODO: improve error message */
ngx_log_debug0(NGX_LOG_DEBUG_HTTP, r->connection->log, 0,
- "spdy again while last chunk");
+ "premature end of spdy header block");
return ngx_http_spdy_state_headers_error(sc, pos, end);
}
@@ -1190,13 +1192,7 @@ ngx_http_spdy_state_headers(ngx_http_spd
ngx_http_spdy_state_headers);
case NGX_HTTP_PARSE_INVALID_HEADER:
-
- /* TODO: improve error message */
- ngx_log_error(NGX_LOG_INFO, r->connection->log, 0,
- "client sent invalid header line");
-
ngx_http_finalize_request(r, NGX_HTTP_BAD_REQUEST);
-
return ngx_http_spdy_state_headers_skip(sc, pos, end);
default: /* NGX_ERROR */
@@ -1262,6 +1258,9 @@ ngx_http_spdy_state_headers_skip(ngx_htt
ngx_http_spdy_state_headers_skip);
}
+ ngx_log_debug2(NGX_LOG_DEBUG_HTTP, sc->connection->log, 0,
+ "spdy header block skip %uz of %uz", size, sc->length);
+
sc->zstream_in.next_in = pos;
sc->zstream_in.avail_in = (size < sc->length) ? size : sc->length;
@@ -1364,7 +1363,7 @@ ngx_http_spdy_state_window_update(ngx_ht
ngx_log_error(NGX_LOG_INFO, sc->connection->log, 0,
"client violated flow control for stream %ui: "
"received WINDOW_UPDATE frame with delta %uz "
- "that is not allowed for window %z",
+ "not allowed for window %z",
sid, delta, stream->send_window);
if (ngx_http_spdy_terminate_stream(sc, stream,
@@ -1397,7 +1396,7 @@ ngx_http_spdy_state_window_update(ngx_ht
ngx_log_error(NGX_LOG_INFO, sc->connection->log, 0,
"client violated connection flow control: "
"received WINDOW_UPDATE frame with delta %uz "
- "that is not allowed for window %uz",
+ "not allowed for window %uz",
delta, sc->send_window);
return ngx_http_spdy_state_protocol_error(sc);
@@ -1440,8 +1439,8 @@ ngx_http_spdy_state_data(ngx_http_spdy_c
if (sc->length > sc->recv_window) {
ngx_log_error(NGX_LOG_INFO, sc->connection->log, 0,
- "client violated connection flow control: length of "
- "received DATA frame %uz, while available window
%uz",
+ "client violated connection flow control: "
+ "received DATA frame length %uz, available window
%uz",
sc->length, sc->recv_window);
return ngx_http_spdy_state_protocol_error(sc);
@@ -1465,13 +1464,16 @@ ngx_http_spdy_state_data(ngx_http_spdy_c
stream = sc->stream;
if (stream == NULL) {
+ ngx_log_debug0(NGX_LOG_DEBUG_HTTP, sc->connection->log, 0,
+ "unknown spdy stream");
+
return ngx_http_spdy_state_skip(sc, pos, end);
}
if (sc->length > stream->recv_window) {
ngx_log_error(NGX_LOG_INFO, sc->connection->log, 0,
- "client violated flow control for stream %ui: length
of "
- "received DATA frame %uz, while available window
%uz",
+ "client violated flow control for stream %ui: "
+ "received DATA frame length %uz, available window
%uz",
stream->id, sc->length, stream->recv_window);
if (ngx_http_spdy_terminate_stream(sc, stream,
@@ -1501,7 +1503,7 @@ ngx_http_spdy_state_data(ngx_http_spdy_c
if (stream->in_closed) {
ngx_log_error(NGX_LOG_INFO, sc->connection->log, 0,
- "client sent DATA frame for half closed stream %ui",
+ "client sent DATA frame for half-closed stream %ui",
stream->id);
if (ngx_http_spdy_terminate_stream(sc, stream,
@@ -1544,7 +1546,10 @@ ngx_http_spdy_state_read_data(ngx_http_s
stream->in_closed = 1;
}
- /* TODO log and accounting */
+ ngx_log_debug1(NGX_LOG_DEBUG_HTTP, sc->connection->log, 0,
+ "skipping spdy DATA frame, reason: %d",
+ stream->skip_data);
+
return ngx_http_spdy_state_skip(sc, pos, end);
}
@@ -1573,7 +1578,10 @@ ngx_http_spdy_state_read_data(ngx_http_s
if (r->headers_in.content_length_n != -1
&& r->headers_in.content_length_n < rb->rest)
{
- /* TODO logging */
+ ngx_log_error(NGX_LOG_INFO, r->connection->log, 0,
+ "client intended to send body data "
+ "larger than declared");
+
stream->skip_data = NGX_SPDY_DATA_ERROR;
goto error;
@@ -1584,9 +1592,8 @@ ngx_http_spdy_state_read_data(ngx_http_s
&& clcf->client_max_body_size < rb->rest)
{
ngx_log_error(NGX_LOG_ERR, r->connection->log, 0,
- "client intended to send too large chunked "
- "body: %O bytes",
- rb->rest);
+ "client intended to send "
+ "too large chunked body: %O bytes",
rb->rest);
stream->skip_data = NGX_SPDY_DATA_ERROR;
goto error;
@@ -1638,7 +1645,7 @@ ngx_http_spdy_state_read_data(ngx_http_s
} else if (r->headers_in.content_length_n != rb->rest) {
ngx_log_error(NGX_LOG_INFO, r->connection->log, 0,
"client prematurely closed stream: "
- "%O of %O bytes of request body received",
+ "only %O out of %O bytes of request body
received",
rb->rest, r->headers_in.content_length_n);
stream->skip_data = NGX_SPDY_DATA_ERROR;
@@ -1717,9 +1724,11 @@ ngx_http_spdy_state_rst_stream(ngx_http_
"spdy RST_STREAM sid:%ui st:%ui", sid, status);
stream = ngx_http_spdy_get_stream_by_id(sc, sid);
+
if (stream == NULL) {
ngx_log_debug0(NGX_LOG_DEBUG_HTTP, sc->connection->log, 0,
- "unknown stream, probably it has been closed
already");
+ "unknown spdy stream");
+
return ngx_http_spdy_state_complete(sc, pos, end);
}
@@ -1738,7 +1747,7 @@ ngx_http_spdy_state_rst_stream(ngx_http_
case NGX_SPDY_INTERNAL_ERROR:
ngx_log_error(NGX_LOG_INFO, fc->log, 0,
- "client terminated stream %ui because of internal
error",
+ "client terminated stream %ui due to internal error",
sid);
break;
@@ -1770,7 +1779,10 @@ ngx_http_spdy_state_ping(ngx_http_spdy_c
}
if (sc->length != NGX_SPDY_PING_SIZE) {
- /* TODO logging */
+ ngx_log_error(NGX_LOG_INFO, sc->connection->log, 0,
+ "client sent PING frame with incorrect length %uz",
+ sc->length);
+
return ngx_http_spdy_state_protocol_error(sc);
}
@@ -1810,6 +1822,9 @@ ngx_http_spdy_state_skip(ngx_http_spdy_c
size = end - pos;
+ ngx_log_debug2(NGX_LOG_DEBUG_HTTP, sc->connection->log, 0,
+ "spdy frame skip %uz of %uz", size, sc->length);
+
if (size < sc->length) {
sc->length -= size;
return ngx_http_spdy_state_save(sc, end, end,
@@ -1839,13 +1854,16 @@ ngx_http_spdy_state_settings(ngx_http_sp
------------------------------
Message: 3
Date: Thu, 15 May 2014 15:25:53 +0000
From: Valentin Bartenev <vbart at nginx.com>
To: nginx-devel at nginx.org
Subject: [nginx] SPDY: refactored ngx_http_spdy_state_headers().
Message-ID:
<hg.9a95eb9f448b.1400167553.6369085454036692193 at ns.nginx.org>
Content-Type: text/plain; charset="us-ascii"
details: http://hg.nginx.org/nginx/rev/9a95eb9f448b
branches:
changeset: 5694:9a95eb9f448b
user: Valentin Bartenev <vbart at nginx.com>
date: Wed Apr 30 20:34:20 2014 +0400
description:
SPDY: refactored ngx_http_spdy_state_headers().
This change is similar to d2ac5cf4056d. Special flag of completeness looks
surplus when there is also a counter of frame bytes left.
diffstat:
src/http/ngx_http_spdy.c | 13 ++++---------
1 files changed, 4 insertions(+), 9 deletions(-)
diffs (52 lines):
diff -r 701d6e17e42c -r 9a95eb9f448b src/http/ngx_http_spdy.c
--- a/src/http/ngx_http_spdy.c Wed Apr 30 20:34:20 2014 +0400
+++ b/src/http/ngx_http_spdy.c Wed Apr 30 20:34:20 2014 +0400
@@ -1009,7 +1009,6 @@ ngx_http_spdy_state_headers(ngx_http_spd
size_t size;
ngx_buf_t *buf;
ngx_int_t rc;
- ngx_uint_t complete;
ngx_http_request_t *r;
size = end - pos;
@@ -1019,12 +1018,8 @@ ngx_http_spdy_state_headers(ngx_http_spd
ngx_http_spdy_state_headers);
}
- if (size >= sc->length) {
+ if (size > sc->length) {
size = sc->length;
- complete = 1;
-
- } else {
- complete = 0;
}
r = sc->stream->request;
@@ -1089,7 +1084,7 @@ ngx_http_spdy_state_headers(ngx_http_spd
if (buf->last - buf->pos < NGX_SPDY_NV_NUM_SIZE) {
- if (complete) {
+ if (sc->length == 0) {
ngx_log_debug0(NGX_LOG_DEBUG_HTTP, r->connection->log, 0,
"premature end of spdy header block");
@@ -1181,7 +1176,7 @@ ngx_http_spdy_state_headers(ngx_http_spd
continue;
}
- if (complete) {
+ if (sc->length == 0) {
ngx_log_debug0(NGX_LOG_DEBUG_HTTP, r->connection->log, 0,
"premature end of spdy header block");
@@ -1225,7 +1220,7 @@ ngx_http_spdy_state_headers(ngx_http_spd
return ngx_http_spdy_state_headers_error(sc, pos, end);
}
- if (!complete) {
+ if (sc->length) {
return ngx_http_spdy_state_save(sc, pos, end,
ngx_http_spdy_state_headers);
}
------------------------------
Message: 4
Date: Thu, 15 May 2014 15:25:55 +0000
From: Valentin Bartenev <vbart at nginx.com>
To: nginx-devel at nginx.org
Subject: [nginx] SPDY: added a debug point to the state buffer
overflow p...
Message-ID:
<hg.231588611230.1400167555.6369085454036692193 at ns.nginx.org>
Content-Type: text/plain; charset="us-ascii"
details: http://hg.nginx.org/nginx/rev/231588611230
branches:
changeset: 5695:231588611230
user: Valentin Bartenev <vbart at nginx.com>
date: Wed Apr 30 20:34:20 2014 +0400
description:
SPDY: added a debug point to the state buffer overflow protection.
diffstat:
src/http/ngx_http_spdy.c | 1 +
1 files changed, 1 insertions(+), 0 deletions(-)
diffs (11 lines):
diff -r 9a95eb9f448b -r 231588611230 src/http/ngx_http_spdy.c
--- a/src/http/ngx_http_spdy.c Wed Apr 30 20:34:20 2014 +0400
+++ b/src/http/ngx_http_spdy.c Wed Apr 30 20:34:20 2014 +0400
@@ -1944,6 +1944,7 @@ ngx_http_spdy_state_save(ngx_http_spdy_c
ngx_log_error(NGX_LOG_ALERT, sc->connection->log, 0,
"state buffer overflow: %uz bytes required", size);
+ ngx_debug_point();
return ngx_http_spdy_state_internal_error(sc);
}
------------------------------
Message: 5
Date: Thu, 15 May 2014 15:25:57 +0000
From: Valentin Bartenev <vbart at nginx.com>
To: nginx-devel at nginx.org
Subject: [nginx] SPDY: added protection from overrun of the receive
buffer.
Message-ID:
<hg.19a14a484707.1400167557.6369085454036692193 at ns.nginx.org>
Content-Type: text/plain; charset="us-ascii"
details: http://hg.nginx.org/nginx/rev/19a14a484707
branches:
changeset: 5696:19a14a484707
user: Valentin Bartenev <vbart at nginx.com>
date: Wed Apr 30 20:34:20 2014 +0400
description:
SPDY: added protection from overrun of the receive buffer.
diffstat:
src/http/ngx_http_spdy.c | 8 ++++++++
1 files changed, 8 insertions(+), 0 deletions(-)
diffs (18 lines):
diff -r 231588611230 -r 19a14a484707 src/http/ngx_http_spdy.c
--- a/src/http/ngx_http_spdy.c Wed Apr 30 20:34:20 2014 +0400
+++ b/src/http/ngx_http_spdy.c Wed Apr 30 20:34:20 2014 +0400
@@ -1921,6 +1921,14 @@ ngx_http_spdy_state_complete(ngx_http_sp
ngx_log_debug2(NGX_LOG_DEBUG_HTTP, sc->connection->log, 0,
"spdy frame complete pos:%p end:%p", pos, end);
+ if (pos > end) {
+ ngx_log_error(NGX_LOG_ALERT, sc->connection->log, 0,
+ "receive buffer overrun");
+
+ ngx_debug_point();
+ return ngx_http_spdy_state_internal_error(sc);
+ }
+
sc->handler = ngx_http_spdy_state_head;
sc->stream = NULL;
------------------------------
_______________________________________________
nginx-devel mailing list
nginx-devel at nginx.org
http://mailman.nginx.org/mailman/listinfo/nginx-devel
End of nginx-devel Digest, Vol 55, Issue 15
*******************************************
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://mailman.nginx.org/pipermail/nginx-devel/attachments/20140516/2ddd3e9f/attachment-0001.html>
More information about the nginx-devel
mailing list