If you enable http2, our proxy setup develops 5s hangs, under load. This happens from at least Chrome/linux, Firefox/linux and Edge/win10.
Any suggestions on how to further diagnose this problem, or work out
where this "5 second" number is coming from? Full reproduction config
and debug logs are attached, but I don't understand the debug logs.
This isn't always reproducible, but happens frequently. Changing
browser, restarting nginx, ... doesn't cause it to be immediately
reproducible.
The proxying is based on a variable:
resolver 8.8.4.4;
location ~/proxy/([a-z-]+\.example\.com)$ {
proxy_pass https://$1/foo;
...
This is easiest to see when a number of these urls are hit from a
single page, e.g.
<iframe src="/proxy/a.example.com"></iframe>
<iframe src="/proxy/b.example.com"></iframe>
... etc.
The observed effect is that exactly eight requests will be serviced,
then there will be a 5s wait, then another eight will be serviced,
then hang, etc. until all requests have been serviced.
Reproduced on Ubuntu 16.04's nginx packages (1.10 based), with default
config, and this sites-enabled/default full config:
server {
listen 443 default_server ssl http2;
ssl on;
ssl_certificate /etc/letsencrypt/live/.../fullchain.pem;
ssl_certificate_key /etc/letsencrypt/live/.../privkey.pem;
root /var/www/html;
index index.html index.htm;
server_name _;
location / {
try_files $uri $uri/ =404;
}
resolver 8.8.4.4;
location ~/proxy/([a-z-]+\....)$ {
proxy_pass https://$1/index.txt;
proxy_http_version 1.1;
proxy_connect_timeout 13s;
proxy_read_timeout 28s;
}
}
The 5s pause is evident in the debug log. However, the debug log
*also* shows that the upstream requests have been generated, which
means that all the requests have been received.
Pause:
2016/10/10 11:17:31 [debug] 4058#4058: *238 process http2 frame type:3
f:0 l:4 sid:17
2016/10/10 11:17:31 [debug] 4058#4058: *238 http2 RST_STREAM frame,
sid:17 status:8
2016/10/10 11:17:31 [debug] 4058#4058: *238 unknown http2 stream
2016/10/10 11:17:31 [debug] 4058#4058: *238 http2 frame complete
pos:00007F536315501D end:00007F536315501D
2016/10/10 11:17:31 [debug] 4058#4058: *238 http2 read handler
2016/10/10 11:17:31 [debug] 4058#4058: *238 SSL_read: 13
2016/10/10 11:17:31 [debug] 4058#4058: *238 SSL_read: -1
2016/10/10 11:17:31 [debug] 4058#4058: *238 SSL_get_error: 2
2016/10/10 11:17:31 [debug] 4058#4058: *238 process http2 frame type:3
f:0 l:4 sid:13
2016/10/10 11:17:31 [debug] 4058#4058: *238 http2 RST_STREAM frame,
sid:13 status:8
2016/10/10 11:17:31 [debug] 4058#4058: *238 unknown http2 stream
2016/10/10 11:17:31 [debug] 4058#4058: *238 http2 frame complete
pos:00007F536315501D end:00007F536315501D
2016/10/10 11:17:31 [debug] 4058#4058: *238 http2 read handler
2016/10/10 11:17:31 [debug] 4058#4058: *238 SSL_read: 13
2016/10/10 11:17:31 [debug] 4058#4058: *238 SSL_read: -1
2016/10/10 11:17:31 [debug] 4058#4058: *238 SSL_get_error: 2
2016/10/10 11:17:31 [debug] 4058#4058: *238 process http2 frame type:3
f:0 l:4 sid:5
2016/10/10 11:17:31 [debug] 4058#4058: *238 http2 RST_STREAM frame,
sid:5 status:8
2016/10/10 11:17:31 [debug] 4058#4058: *238 unknown http2 stream
2016/10/10 11:17:31 [debug] 4058#4058: *238 http2 frame complete
pos:00007F536315501D end:00007F536315501D
2016/10/10 11:17:36 [debug] 4058#4058: *238 http upstream resolve:
"/proxy/nettesto....?"
2016/10/10 11:17:36 [debug] 4058#4058: *238 name was resolved to 94.23.43.98
2016/10/10 11:17:36 [debug] 4058#4058: *238 name was resolved to
2001:41d0:2:2c62::
2016/10/10 11:17:36 [debug] 4058#4058: *238 posix_memalign:
000055B45897FDB0:4096 @16
2016/10/10 11:17:36 [debug] 4058#4058: *238 get rr peer, try: 2
2016/10/10 11:17:36 [debug] 4058#4058: *238 get rr peer, current:
000055B45897FE18 -1
2016/10/10 11:17:36 [debug] 4058#4058: *238 stream socket 12
Upstream requsets:
2016/10/10 11:17:31 [debug] 4058#4058: *238 http proxy header:
"GET /index.txt HTTP/1.1^M
Host: nettestz.fau...^M
But they're not served by the backend until much later, at
[10/Oct/2016:11:17:46 +0000] in this case (according to the backend's
nginx access logs).
The host names mentioned in the debug log are public and are valid
until I pull them down, but I don't know if this is reproducible with
multiple people accessing it (and you can probably guess why I
stripped them from the email body).
debug.log.gz
Description: GNU Zip compressed data
_______________________________________________ nginx mailing list nginx@nginx.org http://mailman.nginx.org/mailman/listinfo/nginx
