Opened 12 months ago

Closed 4 months ago

#428 closed defect (fixed)

SPDY and Proxy Cache prematurely closes connections

Reported by: Phil Sweeney Owned by: Valentin V. Bartenev
Priority: major Milestone:
Component: nginx-core Version:
Keywords: spdy proxy cache Cc:
Sensitive: no
uname -a: Linux myserver 3.8.0-31-generic #46~precise1-Ubuntu SMP Wed Sep 11 18:21:16 UTC 2013 x86_64 x86_64 x86_64 GNU/Linux
nginx -V: nginx version: nginx/1.5.6 TLS SNI support enabled configure arguments: --prefix=/etc/nginx --sbin-path=/usr/sbin/nginx --conf-path=/etc/nginx/nginx.conf --error-log-path=/var/log/nginx/error.log --http-log-path=/var/log/nginx/access.log --pid-path=/var/run/nginx.pid --lock-path=/var/run/nginx.lock --http-client-body-temp-path=/var/cache/nginx/client_temp --http-proxy-temp-path=/var/cache/nginx/proxy_temp --http-fastcgi-temp-path=/var/cache/nginx/fastcgi_temp --http-uwsgi-temp-path=/var/cache/nginx/uwsgi_temp --http-scgi-temp-path=/var/cache/nginx/scgi_temp --user=nginx --group=nginx --with-http_ssl_module --with-http_realip_module --with-http_addition_module --with-http_sub_module --with-http_dav_module --with-http_flv_module --with-http_mp4_module --with-http_gunzip_module --with-http_gzip_static_module --with-http_random_index_module --with-http_secure_link_module --with-http_stub_status_module --with-http_auth_request_module --with-mail --with-mail_ssl_module --with-file-aio --with-http_spdy_module --with-cc-opt='-g -O2 -fstack-protector --param=ssp-buffer-size=4 -Wformat -Wformat-security -Werror=format-security -Wp,-D_FORTIFY_SOURCE=2' --with-ld-opt='-Wl,-Bsymbolic-functions -Wl,-z,relro' --with-ipv6

Description

As originally reported via mailing list/forum (a while ago):
http://forum.nginx.org/read.php?2,233497,241193#msg-241193

When SPDY and proxy cache are both being used, nginx will prematurely close the connection to avoid sending the body to the client. However with SPDY, there could be other items still to send, so this causes empty responses. In my case, css/js/images come back empty to the browser occasionally.

Debug logs have been provided to Valentin V. Bartenev, who stated in April:

"Well, from what I've examined from your debug logs, it looks like a known feature of caching mechanism, that closes connection to prevent sending body to a client, while the whole response is receiving from upstream. It's not a big deal in http, but turns into serious issue with spdy."

"The problem appears when the whole page is requested from upstream for caching purposes, but the client should not get its body (i.e. 304 response, or HEAD request)."

Didn't originally file a ticket here because Valentin hoped that rewrites going on at the time for the upstream code might fix this, but looks like it did not.

Change History (11)

comment:1 Changed 12 months ago by Valentin V. Bartenev

  • Owner set to vbart
  • Status changed from new to assigned

comment:2 Changed 9 months ago by Valentin V. Bartenev

This patch should fix the problem:

diff -r 01e2a5bcdd8f src/http/ngx_http_upstream.c
--- a/src/http/ngx_http_upstream.c      Tue Jan 28 15:33:49 2014 -0800
+++ b/src/http/ngx_http_upstream.c      Thu Jan 30 18:18:22 2014 +0400
@@ -66,6 +66,8 @@ static void
 static void
     ngx_http_upstream_process_non_buffered_request(ngx_http_request_t *r,
     ngx_uint_t do_write);
+static ngx_int_t ngx_http_upstream_output_filter(ngx_http_request_t *r,
+    ngx_chain_t *in);
 static ngx_int_t ngx_http_upstream_non_buffered_filter_init(void *data);
 static ngx_int_t ngx_http_upstream_non_buffered_filter(void *data,
     ssize_t bytes);
@@ -2216,23 +2218,9 @@ ngx_http_upstream_send_response(ngx_http
 
     c = r->connection;
 
-    if (r->header_only) {
-
-        if (u->cacheable || u->store) {
-
-            if (ngx_shutdown_socket(c->fd, NGX_WRITE_SHUTDOWN) == -1) {
-                ngx_connection_error(c, ngx_socket_errno,
-                                     ngx_shutdown_socket_n " failed");
-            }
-
-            r->read_event_handler = ngx_http_request_empty_handler;
-            r->write_event_handler = ngx_http_request_empty_handler;
-            c->error = 1;
-
-        } else {
-            ngx_http_upstream_finalize_request(r, u, rc);
-            return;
-        }
+    if (r->header_only && !(u->cacheable || u->store)) {
+        ngx_http_upstream_finalize_request(r, u, rc);
+        return;
     }
 
     if (r->request_body && r->request_body->temp_file) {
@@ -2384,7 +2372,9 @@ ngx_http_upstream_send_response(ngx_http
 
     p = u->pipe;
 
-    p->output_filter = (ngx_event_pipe_output_filter_pt) ngx_http_output_filter;
+    p->output_filter =
+        (ngx_event_pipe_output_filter_pt) ngx_http_upstream_output_filter;
+
     p->output_ctx = r;
     p->tag = u->output.tag;
     p->bufs = u->conf->bufs;
@@ -2843,7 +2833,7 @@ ngx_http_upstream_process_non_buffered_r
         if (do_write) {
 
             if (u->out_bufs || u->busy_bufs) {
-                rc = ngx_http_output_filter(r, u->out_bufs);
+                rc = ngx_http_upstream_output_filter(r, u->out_bufs);
 
                 if (rc == NGX_ERROR) {
                     ngx_http_upstream_finalize_request(r, u, NGX_ERROR);
@@ -2943,6 +2933,23 @@ ngx_http_upstream_process_non_buffered_r
 
 
 static ngx_int_t
+ngx_http_upstream_output_filter(ngx_http_request_t *r, ngx_chain_t *in)
+{
+
+    if (!r->header_only) {
+        return ngx_http_output_filter(r, in);
+    }
+
+    while (in) {
+        in->buf->pos = in->buf->last;
+        in = in->next;
+    }
+
+    return NGX_OK;
+}
+
+
+static ngx_int_t
 ngx_http_upstream_non_buffered_filter_init(void *data)
 {
     return NGX_OK;

Feel free to use it.

comment:3 follow-up: Changed 9 months ago by Phil Sweeney

Thanks for that. I have tried it against 1.5.10 and it does appear to solve the issue!

Do you expect to apply this to mainline or does it require further work before that?

comment:4 in reply to: ↑ 3 Changed 9 months ago by Valentin V. Bartenev

Replying to Phil Sweeney <philcollect@gmail.com>:

Do you expect to apply this to mainline or does it require further work before that?

Yes, it needs more work. But not because it does something wrong, the patch is correct and shouldn't introduce any bugs. Just the way it solves the problem hasn't been liked by colleagues.

comment:5 Changed 8 months ago by Ba Duong

This bug makes me 3 days to investigate and search for solution to use SPDY with proxy cache.
The issue occurs if use

proxy_cache_bypass $no_cache;

or cached items deleted on server while use F5 in browsers. Only the first request is response (GET 304 status) and error with subsequent requests.
No problem if I remove SPDY.

I tested the patch of Valentin V. Bartenev on 1.5.10 and it work for me.
Thanks.

Update: Sorry, but today I got an error in Chrome 33 Dev tool when I post several wordpress comments:
net::ERR_SPDY_PROTOCOL_ERROR.

Last edited 8 months ago by Ba Duong (previous) (diff)

comment:6 follow-up: Changed 7 months ago by www.google.com/accounts/o8/id?id=AItOawlDriEnv-y6Xg9DA3Xg0k8r-h-p-wHri4w

Hello,

it this problem fixed in 1.5.13?

comment:7 in reply to: ↑ 6 Changed 7 months ago by Valentin V. Bartenev

Replying to www.google.com/accounts/o8/id?id=AItOawlDriEnv-y6Xg9DA3Xg0k8r-h-p-wHri4w:

it this problem fixed in 1.5.13?

No. The patch above is still relevant.

comment:8 follow-up: Changed 7 months ago by Harry Tuttle

hi,

is the vuln and the patch valid for the stable 1.4.7 too?

brad

comment:9 in reply to: ↑ 8 Changed 7 months ago by Valentin V. Bartenev

The issue and the patch valid for 1.4.x branch too.

comment:10 Changed 5 months ago by pavel stano

Patch work also for 1.6.
If it is not yet fixed information should be in documentation or somewhere.

I encountered also second problem with this issue. With limit_conn it looks like connections are not decreased when they are prematurely closed. So you can see in log that connections are limited on spdy but they are not over limit.

comment:11 Changed 4 months ago by Maxim Dounin

  • Resolution set to fixed
  • Status changed from assigned to closed

Fixed by 35990c69b3ac.

Note: See TracTickets for help on using tickets.