使用 Nginx proxy_pass 时如何防止 SSL 重新协商

使用 Nginx proxy_pass 时如何防止 SSL 重新协商

我有一个非常简单的反向代理,它应该只是将请求代理到另一个域。它失败了,因为它尝试 SSL 重新协商,这是不允许的(正如预期的那样)。

此 SSL 重新协商的原因可能是什么?我该如何防止它?

基本服务器信息

Debian release: 9.8 / stretch
nginx version: nginx/1.10.3
built with OpenSSL 1.1.0f  25 May 2017 (running with OpenSSL 1.1.1b  26 Feb 2019)
TLS SNI support enabled

配置

upstream example {
        server test.example.com:443;
}

server {
        listen 443 http2;
        listen [::]:443 http2;

        ssl_certificate  /etc/letsencrypt/live/website/fullchain.pem;
        ssl_certificate_key /etc/letsencrypt/live/website/privkey.pem;
        ssl_trusted_certificate /etc/letsencrypt/live/website/fullchain.pem;

        #include snippets/global-ssl.conf;

        server_name example.com www.example.com;

        location / {
                proxy_pass https://example;
                proxy_set_header Host test.example.com;
                proxy_ssl_server_name on;
                proxy_ssl_name test.example.com;
        }
}

客户端日志(已修剪)

2019/03/24 16:56:22 [debug] 8496#8496: accept on 0.0.0.0:443, ready: 0
2019/03/24 16:56:22 [debug] 8496#8496: posix_memalign: 00005563F4DEDF70:512 @16
2019/03/24 16:56:22 [debug] 8496#8496: *8434 accept: 213.126.45.75:54725 fd:40
2019/03/24 16:56:22 [debug] 8496#8496: *8434 event timer add: 40: 60000:1553443042390
2019/03/24 16:56:22 [debug] 8496#8496: *8434 reusable connection: 1
2019/03/24 16:56:22 [debug] 8496#8496: *8434 epoll add event: fd:40 op:1 ev:80002001
2019/03/24 16:56:22 [debug] 8496#8496: *8434 http check ssl handshake
2019/03/24 16:56:22 [debug] 8496#8496: *8434 http recv(): 1
2019/03/24 16:56:22 [debug] 8496#8496: *8434 https ssl handshake: 0x16
2019/03/24 16:56:22 [debug] 8496#8496: *8434 ssl get session: BAE39B42:32
2019/03/24 16:56:22 [debug] 8496#8496: *8434 SSL server name: "www.example.com"

==> /var/log/nginx/example_website_error.log <==
2019/03/24 16:56:22 [debug] 8496#8496: *8434 SSL ALPN supported by client: h2
2019/03/24 16:56:22 [debug] 8496#8496: *8434 SSL ALPN supported by client: http/1.1
2019/03/24 16:56:22 [debug] 8496#8496: *8434 SSL ALPN selected: h2
2019/03/24 16:56:22 [debug] 8496#8496: *8434 SSL_do_handshake: -1
2019/03/24 16:56:22 [debug] 8496#8496: *8434 SSL_get_error: 2
2019/03/24 16:56:22 [debug] 8496#8496: *8434 reusable connection: 0
2019/03/24 16:56:22 [debug] 8496#8496: *8434 SSL handshake handler: 0
2019/03/24 16:56:22 [debug] 8496#8496: *8434 ssl new session: 00AE8065:32:174
2019/03/24 16:56:22 [debug] 8496#8496: *8434 SSL_do_handshake: 1
2019/03/24 16:56:22 [debug] 8496#8496: *8434 SSL: TLSv1.3, cipher: "TLS_AES_256_GCM_SHA384 TLSv1.3 Kx=any Au=any Enc=AESGCM(256) Mac=AEAD"
2019/03/24 16:56:22 [debug] 8496#8496: *8434 SSL reused session
2019/03/24 16:56:22 [debug] 8496#8496: *8434 init http2 connection
2019/03/24 16:56:22 [debug] 8496#8496: *8434 http2 send SETTINGS frame ack:0
2019/03/24 16:56:22 [debug] 8496#8496: *8434 http2 send WINDOW_UPDATE frame sid:0, window:2147418112
2019/03/24 16:56:22 [debug] 8496#8496: *8434 http2 read handler
2019/03/24 16:56:22 [debug] 8496#8496: *8434 SSL_read: 64
2019/03/24 16:56:22 [debug] 8496#8496: *8434 SSL_read: -1
2019/03/24 16:56:22 [debug] 8496#8496: *8434 SSL_get_error: 2
2019/03/24 16:56:22 [debug] 8496#8496: *8434 http2 preface verified
2019/03/24 16:56:22 [debug] 8496#8496: *8434 SSL buf copy: 27
2019/03/24 16:56:22 [debug] 8496#8496: *8434 SSL buf copy: 13
2019/03/24 16:56:22 [debug] 8496#8496: *8434 SSL buf copy: 9
2019/03/24 16:56:22 [debug] 8496#8496: *8434 SSL to write: 49
2019/03/24 16:56:22 [debug] 8496#8496: *8434 SSL_write: 49
2019/03/24 16:56:22 [debug] 8496#8496: *8434 free: 00005563F4C95410, unused: 3495
2019/03/24 16:56:22 [debug] 8496#8496: *8434 free: 00005563F4E4F0A0
2019/03/24 16:56:22 [debug] 8496#8496: *8434 reusable connection: 1
2019/03/24 16:56:22 [debug] 8496#8496: *8434 event timer del: 40: 1553443042390
2019/03/24 16:56:22 [debug] 8496#8496: *8434 event timer add: 40: 180000:1553443162406
2019/03/24 16:56:22 [debug] 8496#8496: *8434 http2 idle handler
2019/03/24 16:56:22 [debug] 8496#8496: *8434 reusable connection: 0
2019/03/24 16:56:22 [debug] 8496#8496: *8434 posix_memalign: 00005563F4C95410:4096 @16
2019/03/24 16:56:22 [debug] 8496#8496: *8434 http2 read handler
2019/03/24 16:56:22 [debug] 8496#8496: *8434 SSL_read: 267
2019/03/24 16:56:22 [debug] 8496#8496: *8434 SSL_read: -1
2019/03/24 16:56:22 [debug] 8496#8496: *8434 SSL_get_error: 2
2019/03/24 16:56:22 [debug] 8496#8496: *8434 process http2 frame type:1 f:25 l:258 sid:1
2019/03/24 16:56:22 [debug] 8496#8496: *8434 http2 HEADERS frame sid:1 on 0 excl:1 weight:256
2019/03/24 16:56:22 [debug] 8496#8496: *8434 http2 get indexed header name: 2
2019/03/24 16:56:22 [debug] 8496#8496: *8434 http2 get indexed header: 1
2019/03/24 16:56:22 [debug] 8496#8496: *8434 http2 hpack encoded string length: 14
2019/03/24 16:56:22 [debug] 8496#8496: *8434 http2 add header to hpack table: ":authority: www.example.com"
2019/03/24 16:56:22 [debug] 8496#8496: *8434 http script copy: "Host: test.example.online
"
2019/03/24 16:56:22 [debug] 8496#8496: *8434 http script copy: "Connection: close
"
2019/03/24 16:56:22 [debug] 8496#8496: *8434 http script copy: ""
2019/03/24 16:56:22 [debug] 8496#8496: *8434 http script copy: ""
2019/03/24 16:56:22 [debug] 8496#8496: *8434 http script copy: ""
2019/03/24 16:56:22 [debug] 8496#8496: *8434 http script copy: ""
2019/03/24 16:56:22 [debug] 8496#8496: *8434 http proxy header: "cache-control: max-age=0"
2019/03/24 16:56:22 [debug] 8496#8496: *8434 http proxy header: "upgrade-insecure-requests: 1"
2019/03/24 16:56:22 [debug] 8496#8496: *8434 http proxy header: "user-agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_14_3) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/72.0.3626.121 Safari/537.36"
2019/03/24 16:56:22 [debug] 8496#8496: *8434 http proxy header: "dnt: 1"
2019/03/24 16:56:22 [debug] 8496#8496: *8434 http proxy header: "accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,image/apng,*/*;q=0.8"
2019/03/24 16:56:22 [debug] 8496#8496: *8434 http proxy header: "accept-encoding: gzip, deflate, br"
2019/03/24 16:56:22 [debug] 8496#8496: *8434 http proxy header: "accept-language: en-US,en;q=0.9,nl;q=0.8"
2019/03/24 16:56:22 [debug] 8496#8496: *8434 http proxy header:
"GET / HTTP/1.0
Host: test.example.online
Connection: close
cache-control: max-age=0
upgrade-insecure-requests: 1
user-agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_14_3) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/72.0.3626.121 Safari/537.36
dnt: 1
accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,image/apng,*/*;q=0.8
accept-encoding: gzip, deflate, br
accept-language: en-US,en;q=0.9,nl;q=0.8

"
2019/03/24 16:56:22 [debug] 8496#8496: *8434 posix_memalign: 00005563F4CCC5A0:4096 @16
2019/03/24 16:56:22 [debug] 8496#8496: *8434 http cleanup add: 00005563F4CCC5C0
2019/03/24 16:56:22 [debug] 8496#8496: *8434 get rr peer, try: 2
2019/03/24 16:56:22 [debug] 8496#8496: *8434 get rr peer, current: 00005563F4DCC798 1
2019/03/24 16:56:22 [debug] 8496#8496: *8434 stream socket 42
2019/03/24 16:56:22 [debug] 8496#8496: *8434 epoll add connection: fd:42 ev:80002005
2019/03/24 16:56:22 [debug] 8496#8496: *8434 connect to [2001:1690:100:800::4]:443, fd:42 #8435
2019/03/24 16:56:22 [debug] 8496#8496: *8434 http upstream connect: -2
2019/03/24 16:56:22 [debug] 8496#8496: *8434 posix_memalign: 00005563F4D66C30:128 @16
2019/03/24 16:56:22 [debug] 8496#8496: *8434 event timer add: 42: 60000:1553443042411
2019/03/24 16:56:22 [debug] 8496#8496: *8434 http finalize request: -4, "/?" a:1, c:2
2019/03/24 16:56:22 [debug] 8496#8496: *8434 http request count:2 blk:0
2019/03/24 16:56:22 [debug] 8496#8496: *8434 http2 frame complete pos:00005563F4F1000B end:00005563F4F1000B
2019/03/24 16:56:22 [debug] 8496#8496: *8434 event timer del: 40: 1553443162406
2019/03/24 16:56:22 [debug] 8496#8496: *8434 http upstream request: "/?"
2019/03/24 16:56:22 [debug] 8496#8496: *8434 http upstream send request handler
2019/03/24 16:56:22 [debug] 8496#8496: *8434 malloc: 00005563F4E65870:72
2019/03/24 16:56:22 [debug] 8496#8496: *8434 upstream SSL server name: "test.example.online"
2019/03/24 16:56:22 [debug] 8496#8496: *8434 set session: 00005563F4E3EB60
2019/03/24 16:56:22 [debug] 8496#8496: *8434 tcp_nodelay
2019/03/24 16:56:22 [debug] 8496#8496: *8434 SSL_do_handshake: -1
2019/03/24 16:56:22 [debug] 8496#8496: *8434 SSL_get_error: 2
2019/03/24 16:56:22 [debug] 8496#8496: *8434 SSL handshake handler: 0
2019/03/24 16:56:22 [debug] 8496#8496: *8434 SSL_do_handshake: 1
2019/03/24 16:56:22 [debug] 8496#8496: *8434 SSL: TLSv1.3, cipher: "TLS_AES_256_GCM_SHA384 TLSv1.3 Kx=any Au=any Enc=AESGCM(256) Mac=AEAD"
2019/03/24 16:56:22 [debug] 8496#8496: *8434 save session: 00005563F4D0A470
2019/03/24 16:56:22 [debug] 8496#8496: *8434 old session: 00005563F4E3EB60
2019/03/24 16:56:22 [debug] 8496#8496: *8434 SSL buf copy: 435
2019/03/24 16:56:22 [debug] 8496#8496: *8434 SSL to write: 435
2019/03/24 16:56:22 [debug] 8496#8496: *8434 SSL_write: 435
2019/03/24 16:56:22 [debug] 8496#8496: *8434 chain writer out: 0000000000000000
2019/03/24 16:56:22 [debug] 8496#8496: *8434 event timer del: 42: 1553443042411
2019/03/24 16:56:22 [debug] 8496#8496: *8434 event timer add: 42: 60000:1553443042414

==> /var/log/nginx/error.log <==
2019/03/24 16:56:22 [debug] 8496#8496: accept on [::]:443, ready: 0
2019/03/24 16:56:22 [debug] 8496#8496: posix_memalign: 00005563F4D0A770:512 @16
2019/03/24 16:56:22 [debug] 8496#8496: *8436 accept: [2001:1690:100:800::4]:54472 fd:43
2019/03/24 16:56:22 [debug] 8496#8496: *8436 event timer add: 43: 60000:1553443042412
2019/03/24 16:56:22 [debug] 8496#8496: *8436 reusable connection: 1
2019/03/24 16:56:22 [debug] 8496#8496: *8436 epoll add event: fd:43 op:1 ev:80002001
2019/03/24 16:56:22 [debug] 8496#8496: *8436 http check ssl handshake
2019/03/24 16:56:22 [debug] 8496#8496: *8436 http recv(): 1
2019/03/24 16:56:22 [debug] 8496#8496: *8436 https ssl handshake: 0x16
2019/03/24 16:56:22 [debug] 8496#8496: *8436 SSL server name: "test.example.online"

==> /var/log/nginx/example_website_error.log <==
2019/03/24 16:56:22 [debug] 8496#8496: *8434 http upstream process header
2019/03/24 16:56:22 [debug] 8496#8496: *8434 malloc: 00005563F4DB8F90:4096
2019/03/24 16:56:22 [debug] 8496#8496: *8434 SSL_read: -1
2019/03/24 16:56:22 [debug] 8496#8496: *8434 SSL_get_error: 2
2019/03/24 16:56:22 [debug] 8496#8496: *8434 http upstream request: "/?"
2019/03/24 16:56:22 [debug] 8496#8496: *8434 http upstream dummy handler
2019/03/24 16:56:22 [debug] 8496#8496: *8434 http upstream request: "/?"
2019/03/24 16:56:22 [debug] 8496#8496: *8434 http upstream process header
2019/03/24 16:56:22 [debug] 8496#8496: *8434 SSL renegotiation
2019/03/24 16:56:22 [debug] 8496#8496: *8434 SSL_read: -1
2019/03/24 16:56:22 [notice] 8496#8496: *8434 SSL renegotiation disabled while reading response header from upstream, client: 213.126.45.75, server: example.com, request: "GET / HTTP/2.0", upstream: "https://[2001:1690:100:800::4]:443/", host: "www.example.com"
2019/03/24 16:56:22 [debug] 8496#8496: *8434 http next upstream, 2
2019/03/24 16:56:22 [debug] 8496#8496: *8434 free rr peer 2 4
2019/03/24 16:56:22 [warn] 8496#8496: *8434 upstream server temporarily disabled while reading response header from upstream, client: 213.126.45.75, server: example.com, request: "GET / HTTP/2.0", upstream: "https://[2001:1690:100:800::4]:443/", host: "www.example.com"
2019/03/24 16:56:22 [debug] 8496#8496: *8434 free rr peer failed: 00005563F4DCC798 0
2019/03/24 16:56:22 [debug] 8496#8496: *8434 close http upstream connection: 42
2019/03/24 16:56:22 [debug] 8496#8496: *8434 SSL_shutdown: 1
2019/03/24 16:56:22 [debug] 8496#8496: *8434 event timer del: 42: 1553443042414
2019/03/24 16:56:22 [debug] 8496#8496: *8434 reusable connection: 0
2019/03/24 16:56:22 [debug] 8496#8496: *8434 get rr peer, try: 1
2019/03/24 16:56:22 [debug] 8496#8496: *8434 get rr peer, current: 00005563F4DCC6F8 -1
2019/03/24 16:56:22 [debug] 8496#8496: *8434 stream socket 42
2019/03/24 16:56:22 [debug] 8496#8496: *8434 epoll add connection: fd:42 ev:80002005
2019/03/24 16:56:22 [debug] 8496#8496: *8434 connect to 84.241.175.19:443, fd:42 #8438
2019/03/24 16:56:22 [debug] 8496#8496: *8434 http upstream connect: -2
2019/03/24 16:56:22 [debug] 8496#8496: *8434 posix_memalign: 00005563F4E8CB30:128 @16
2019/03/24 16:56:22 [debug] 8496#8496: *8434 event timer add: 42: 60000:1553443042427
2019/03/24 16:56:22 [debug] 8496#8496: *8434 http2 read handler
2019/03/24 16:56:22 [debug] 8496#8496: *8434 SSL_read: 9
2019/03/24 16:56:22 [debug] 8496#8496: *8434 SSL_read: -1
2019/03/24 16:56:22 [debug] 8496#8496: *8434 SSL_get_error: 2
2019/03/24 16:56:22 [debug] 8496#8496: *8434 process http2 frame type:4 f:1 l:0 sid:0
2019/03/24 16:56:22 [debug] 8496#8496: *8434 http2 frame complete pos:00005563F4F0FF09 end:00005563F4F0FF09
2019/03/24 16:56:22 [debug] 8496#8496: *8434 http upstream request: "/?"
2019/03/24 16:56:22 [debug] 8496#8496: *8434 http upstream send request handler
2019/03/24 16:56:22 [debug] 8496#8496: *8434 malloc: 00005563F4E4A700:72
2019/03/24 16:56:22 [debug] 8496#8496: *8434 upstream SSL server name: "test.example.online"
2019/03/24 16:56:22 [debug] 8496#8496: *8434 set session: 00005563F4E491C0
2019/03/24 16:56:22 [debug] 8496#8496: *8434 tcp_nodelay
2019/03/24 16:56:22 [debug] 8496#8496: *8434 SSL_do_handshake: -1
2019/03/24 16:56:22 [debug] 8496#8496: *8434 SSL_get_error: 2

==> /var/log/nginx/error.log <==
2019/03/24 16:56:22 [debug] 8496#8496: accept on 0.0.0.0:443, ready: 0
2019/03/24 16:56:22 [debug] 8496#8496: posix_memalign: 00005563F4E02160:512 @16
2019/03/24 16:56:22 [debug] 8496#8496: *8439 accept: 84.241.175.19:58052 fd:43
2019/03/24 16:56:22 [debug] 8496#8496: *8439 event timer add: 43: 60000:1553443042429
2019/03/24 16:56:22 [debug] 8496#8496: *8439 reusable connection: 1
2019/03/24 16:56:22 [debug] 8496#8496: *8439 epoll add event: fd:43 op:1 ev:80002001
2019/03/24 16:56:22 [debug] 8496#8496: *8439 http check ssl handshake
2019/03/24 16:56:22 [debug] 8496#8496: *8439 http recv(): 1
2019/03/24 16:56:22 [debug] 8496#8496: *8439 https ssl handshake: 0x16
2019/03/24 16:56:22 [debug] 8496#8496: *8439 SSL server name: "test.example.online"

==> /var/log/nginx/example_website_error.log <==
2019/03/24 16:56:22 [debug] 8496#8496: *8434 SSL handshake handler: 0
2019/03/24 16:56:22 [debug] 8496#8496: *8434 SSL_do_handshake: 1
2019/03/24 16:56:22 [debug] 8496#8496: *8434 SSL: TLSv1.3, cipher: "TLS_AES_256_GCM_SHA384 TLSv1.3 Kx=any Au=any Enc=AESGCM(256) Mac=AEAD"
2019/03/24 16:56:22 [debug] 8496#8496: *8434 save session: 00005563F4E3EB60
2019/03/24 16:56:22 [debug] 8496#8496: *8434 old session: 00005563F4E491C0
2019/03/24 16:56:22 [debug] 8496#8496: *8434 http upstream send request
2019/03/24 16:56:22 [debug] 8496#8496: *8434 http upstream send request body
2019/03/24 16:56:22 [debug] 8496#8496: *8434 chain writer buf fl:0 s:435
2019/03/24 16:56:22 [debug] 8496#8496: *8434 chain writer buf fl:1 s:0
2019/03/24 16:56:22 [debug] 8496#8496: *8434 chain writer in: 00005563F4CCC640
2019/03/24 16:56:22 [debug] 8496#8496: *8434 malloc: 00005563F4D6E3B0:80
2019/03/24 16:56:22 [debug] 8496#8496: *8434 malloc: 00005563F4E70BA0:16384
2019/03/24 16:56:22 [debug] 8496#8496: *8434 SSL buf copy: 435
2019/03/24 16:56:22 [debug] 8496#8496: *8434 SSL to write: 435
2019/03/24 16:56:22 [debug] 8496#8496: *8434 SSL_write: 435
2019/03/24 16:56:22 [debug] 8496#8496: *8434 chain writer out: 0000000000000000
2019/03/24 16:56:22 [debug] 8496#8496: *8434 event timer del: 42: 1553443042427
2019/03/24 16:56:22 [debug] 8496#8496: *8434 event timer add: 42: 60000:1553443042443
2019/03/24 16:56:22 [debug] 8496#8496: *8434 http upstream process header
2019/03/24 16:56:22 [debug] 8496#8496: *8434 SSL_read: -1
2019/03/24 16:56:22 [debug] 8496#8496: *8434 SSL_get_error: 2
2019/03/24 16:56:22 [debug] 8496#8496: *8434 http upstream request: "/?"
2019/03/24 16:56:22 [debug] 8496#8496: *8434 http upstream dummy handler
2019/03/24 16:56:22 [debug] 8496#8496: *8434 http upstream request: "/?"
2019/03/24 16:56:22 [debug] 8496#8496: *8434 http upstream process header
2019/03/24 16:56:22 [debug] 8496#8496: *8434 SSL renegotiation
2019/03/24 16:56:22 [debug] 8496#8496: *8434 SSL_read: -1
2019/03/24 16:56:22 [notice] 8496#8496: *8434 SSL renegotiation disabled while reading response header from upstream, client: 213.126.45.75, server: example.com, request: "GET / HTTP/2.0", upstream: "https://84.241.175.19:443/", host: "www.example.com"
2019/03/24 16:56:22 [debug] 8496#8496: *8434 http next upstream, 2
2019/03/24 16:56:22 [debug] 8496#8496: *8434 free rr peer 1 4
2019/03/24 16:56:22 [warn] 8496#8496: *8434 upstream server temporarily disabled while reading response header from upstream, client: 213.126.45.75, server: example.com, request: "GET / HTTP/2.0", upstream: "https://84.241.175.19:443/", host: "www.example.com"
2019/03/24 16:56:22 [debug] 8496#8496: *8434 free rr peer failed: 00005563F4DCC6F8 0
2019/03/24 16:56:22 [debug] 8496#8496: *8434 finalize http upstream request: 502
2019/03/24 16:56:22 [debug] 8496#8496: *8434 finalize http proxy request
2019/03/24 16:56:22 [debug] 8496#8496: *8434 SSL_shutdown: 1
2019/03/24 16:56:22 [debug] 8496#8496: *8434 close http upstream connection: 42
2019/03/24 16:56:22 [debug] 8496#8496: *8434 free: 00005563F4E70BA0
2019/03/24 16:56:22 [debug] 8496#8496: *8434 free: 00005563F4D6E3B0
2019/03/24 16:56:22 [debug] 8496#8496: *8434 free: 00005563F4E4A700
2019/03/24 16:56:22 [debug] 8496#8496: *8434 free: 00005563F4E8CB30, unused: 0
2019/03/24 16:56:22 [debug] 8496#8496: *8434 event timer del: 42: 1553443042443
2019/03/24 16:56:22 [debug] 8496#8496: *8434 reusable connection: 0
2019/03/24 16:56:22 [debug] 8496#8496: *8434 http finalize request: 502, "/?" a:1, c:1
2019/03/24 16:56:22 [debug] 8496#8496: *8434 http special response: 502, "/?"
2019/03/24 16:56:22 [debug] 8496#8496: *8434 xslt filter header
2019/03/24 16:56:22 [debug] 8496#8496: *8434 http2 header filter
2019/03/24 16:56:22 [debug] 8496#8496: *8434 http2 output header: ":status: 502"
2019/03/24 16:56:22 [debug] 8496#8496: *8434 http2 output header: "server: nginx"
2019/03/24 16:56:22 [debug] 8496#8496: *8434 http2 output header: "date: Sun, 24 Mar 2019 15:56:22 GMT"
2019/03/24 16:56:22 [debug] 8496#8496: *8434 http2 output header: "content-type: text/html"
2019/03/24 16:56:22 [debug] 8496#8496: *8434 http2 output header: "content-length: 568"

上游日志

2019/03/24 17:13:22 [debug] 8496#8496: *8731 SSL_do_handshake: -1
2019/03/24 17:13:22 [debug] 8496#8496: *8731 SSL_get_error: 2
2019/03/24 17:13:22 [debug] 8496#8496: *8731 reusable connection: 0
2019/03/24 17:13:22 [debug] 8496#8496: *8731 SSL handshake handler: 0
2019/03/24 17:13:22 [debug] 8496#8496: *8731 ssl new session: 487D1A42:32:168
2019/03/24 17:13:22 [debug] 8496#8496: *8731 ssl new session: EDD4C86C:32:168
2019/03/24 17:13:22 [debug] 8496#8496: *8731 SSL_do_handshake: 1
2019/03/24 17:13:22 [debug] 8496#8496: *8731 SSL: TLSv1.3, cipher: "TLS_AES_256_GCM_SHA384 TLSv1.3 Kx=any Au=any Enc=AESGCM(256) Mac=AEAD"
2019/03/24 17:13:22 [debug] 8496#8496: *8731 reusable connection: 1
2019/03/24 17:13:22 [debug] 8496#8496: *8731 http wait request handler
2019/03/24 17:13:22 [debug] 8496#8496: *8731 posix_memalign: 00005563F4E52060:512 @16
2019/03/24 17:13:22 [debug] 8496#8496: *8731 malloc: 00005563F4E03870:1024
2019/03/24 17:13:22 [debug] 8496#8496: *8731 SSL_read: 435
2019/03/24 17:13:22 [debug] 8496#8496: *8731 SSL_read: -1
2019/03/24 17:13:22 [debug] 8496#8496: *8731 SSL_get_error: 2
2019/03/24 17:13:22 [debug] 8496#8496: *8731 reusable connection: 0
2019/03/24 17:13:22 [debug] 8496#8496: *8731 posix_memalign: 00005563F4D94030:4096 @16
2019/03/24 17:13:22 [debug] 8496#8496: *8731 http process request line
2019/03/24 17:13:22 [debug] 8496#8496: *8731 http request line: "GET / HTTP/1.0"
2019/03/24 17:13:22 [debug] 8496#8496: *8731 http uri: "/"
2019/03/24 17:13:22 [debug] 8496#8496: *8731 http args: ""
2019/03/24 17:13:22 [debug] 8496#8496: *8731 http exten: ""
2019/03/24 17:13:22 [debug] 8496#8496: *8731 posix_memalign: 00005563F4D611F0:4096 @16
2019/03/24 17:13:22 [debug] 8496#8496: *8731 http process request header line
2019/03/24 17:13:22 [debug] 8496#8496: *8731 http header: "Host: test.example.com"
2019/03/24 17:13:22 [debug] 8496#8496: *8731 http header: "Connection: close"
2019/03/24 17:13:22 [debug] 8496#8496: *8731 http header: "cache-control: max-age=0"
2019/03/24 17:13:22 [debug] 8496#8496: *8731 http header: "upgrade-insecure-requests: 1"
2019/03/24 17:13:22 [debug] 8496#8496: *8731 http header: "user-agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_14_3) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/72.0.3626.121 Safari/537.36"
2019/03/24 17:13:22 [debug] 8496#8496: *8731 http header: "dnt: 1"
2019/03/24 17:13:22 [debug] 8496#8496: *8731 http header: "accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,image/apng,*/*;q=0.8"
2019/03/24 17:13:22 [debug] 8496#8496: *8731 http header: "accept-encoding: gzip, deflate, br"
2019/03/24 17:13:22 [debug] 8496#8496: *8731 http header: "accept-language: en-US,en;q=0.9,nl;q=0.8"
2019/03/24 17:13:22 [debug] 8496#8496: *8731 http header done
2019/03/24 17:13:22 [debug] 8496#8496: *8731 epoll add connection: fd:47 ev:80002005
2019/03/24 17:13:22 [debug] 8496#8496: *8731 connect to unix:/var/run/php/php7.1-fpm.sock, fd:47 #8732
2019/03/24 17:13:22 [debug] 8496#8496: *8731 http finalize request: -4, "/index.php?" a:1, c:3
2019/03/24 17:13:22 [debug] 8496#8496: *8731 http request count:3 blk:0
2019/03/24 17:13:22 [debug] 8496#8496: *8731 http finalize request: -4, "/index.php?" a:1, c:2
2019/03/24 17:13:22 [debug] 8496#8496: *8731 http request count:2 blk:0
2019/03/24 17:13:22 [debug] 8496#8496: *8731 http run request: "/index.php?"
2019/03/24 17:13:22 [debug] 8496#8496: *8731 http upstream check client, write event:1, "/index.php"
2019/03/24 17:13:22 [debug] 8496#8496: *8731 http upstream recv(): 0 (11: Resource temporarily unavailable)
2019/03/24 17:13:22 [debug] 8496#8496: *8731 http upstream request: "/index.php?"
2019/03/24 17:13:22 [debug] 8496#8496: *8731 http upstream dummy handler
2019/03/24 17:13:22 [debug] 8496#8496: *8731 http run request: "/index.php?"
2019/03/24 17:13:22 [debug] 8496#8496: *8731 http upstream check client, write event:0, "/index.php"
2019/03/24 17:13:22 [info] 8496#8496: *8731 epoll_wait() reported that client prematurely closed connection, so upstream connection is closed too (32: Broken pipe) while sending request to upstream, client: 2001:1690:100:800::4, server: test.example.com, request: "GET / HTTP/1.0", upstream: "fastcgi://unix:/var/run/php/php7.1-fpm.sock:", host: "test.example.com"
2019/03/24 17:13:22 [debug] 8496#8496: *8731 finalize http upstream request: 499
2019/03/24 17:13:22 [debug] 8496#8496: *8731 finalize http fastcgi request
2019/03/24 17:13:22 [debug] 8496#8496: *8731 free rr peer 1 0
2019/03/24 17:13:22 [debug] 8496#8496: *8731 close http upstream connection: 47
2019/03/24 17:13:22 [debug] 8496#8496: *8731 free: 00005563F4EB1430, unused: 48
2019/03/24 17:13:22 [debug] 8496#8496: *8731 event timer del: 47: 1553444602755
2019/03/24 17:13:22 [debug] 8496#8496: *8731 reusable connection: 0
2019/03/24 17:13:22 [debug] 8496#8496: *8731 http finalize request: 499, "/index.php?" a:1, c:1
2019/03/24 17:13:22 [debug] 8496#8496: *8731 http close request
2019/03/24 17:13:22 [debug] 8496#8496: *8731 http log handler

==> /var/log/nginx/example_test_access.log <==
2001:1690:100:800::4 - - [24/Mar/2019:17:13:22 +0100] "GET / HTTP/1.0" 499 0 "-" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_14_3) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/72.0.3626.121 Safari/537.36"

==> /var/log/nginx/example_test_error.log <==
2019/03/24 17:13:22 [debug] 8496#8496: *8731 close http connection: 46
2019/03/24 17:13:22 [debug] 8496#8496: *8731 SSL_shutdown: -1
2019/03/24 17:13:22 [debug] 8496#8496: *8731 reusable connection: 0
2019/03/24 17:13:22 [debug] 8496#8496: *8734 SSL_do_handshake: -1
2019/03/24 17:13:22 [debug] 8496#8496: *8734 SSL_get_error: 2
2019/03/24 17:13:22 [debug] 8496#8496: *8734 reusable connection: 0
2019/03/24 17:13:22 [debug] 8496#8496: *8734 SSL handshake handler: 0
2019/03/24 17:13:22 [debug] 8496#8496: *8734 ssl new session: 470148A8:32:167
2019/03/24 17:13:22 [debug] 8496#8496: *8734 ssl new session: 6BA2403E:32:168
2019/03/24 17:13:22 [debug] 8496#8496: *8734 SSL_do_handshake: 1
2019/03/24 17:13:22 [debug] 8496#8496: *8734 SSL: TLSv1.3, cipher: "TLS_AES_256_GCM_SHA384 TLSv1.3 Kx=any Au=any Enc=AESGCM(256) Mac=AEAD"
2019/03/24 17:13:22 [debug] 8496#8496: *8734 reusable connection: 1
2019/03/24 17:13:22 [debug] 8496#8496: *8734 http wait request handler
2019/03/24 17:13:22 [debug] 8496#8496: *8734 malloc: 00005563F4D33400:1024
2019/03/24 17:13:22 [debug] 8496#8496: *8734 SSL_read: 435
2019/03/24 17:13:22 [debug] 8496#8496: *8734 SSL_read: -1
2019/03/24 17:13:22 [debug] 8496#8496: *8734 SSL_get_error: 2
2019/03/24 17:13:22 [debug] 8496#8496: *8734 reusable connection: 0
2019/03/24 17:13:22 [debug] 8496#8496: *8734 http process request line
2019/03/24 17:13:22 [debug] 8496#8496: *8734 http request line: "GET / HTTP/1.0"
2019/03/24 17:13:22 [debug] 8496#8496: *8734 http process request header line
2019/03/24 17:13:22 [debug] 8496#8496: *8734 http header: "Host: test.example.com"
2019/03/24 17:13:22 [debug] 8496#8496: *8734 http header: "Connection: close"
2019/03/24 17:13:22 [debug] 8496#8496: *8734 http header: "cache-control: max-age=0"
2019/03/24 17:13:22 [debug] 8496#8496: *8734 http header: "upgrade-insecure-requests: 1"
2019/03/24 17:13:22 [debug] 8496#8496: *8734 http header: "user-agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_14_3) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/72.0.3626.121 Safari/537.36"
2019/03/24 17:13:22 [debug] 8496#8496: *8734 http header: "dnt: 1"
2019/03/24 17:13:22 [debug] 8496#8496: *8734 http header: "accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,image/apng,*/*;q=0.8"
2019/03/24 17:13:22 [debug] 8496#8496: *8734 http header: "accept-encoding: gzip, deflate, br"
2019/03/24 17:13:22 [debug] 8496#8496: *8734 http header: "accept-language: en-US,en;q=0.9,nl;q=0.8"
2019/03/24 17:13:22 [debug] 8496#8496: *8734 http header done
2019/03/24 17:13:22 [debug] 8496#8496: *8734 event timer del: 42: 1553444062788
2019/03/24 17:13:22 [debug] 8496#8496: *8734 test location: "/"
2019/03/24 17:13:22 [debug] 8496#8496: *8734 test location: ~ "^/index\.php(/|$)"
2019/03/24 17:13:22 [debug] 8496#8496: *8734 test location: ~ "\.php$"
2019/03/24 17:13:22 [debug] 8496#8496: *8734 http run request: "/index.php?"
2019/03/24 17:13:22 [debug] 8496#8496: *8734 http upstream check client, write event:0, "/index.php"
2019/03/24 17:13:22 [info] 8496#8496: *8734 epoll_wait() reported that client prematurely closed connection, so upstream connection is closed too (32: Broken pipe) while sending request to upstream, client: 84.241.175.19, server: test.example.com, request: "GET / HTTP/1.0", upstream: "fastcgi://unix:/var/run/php/php7.1-fpm.sock:", host: "test.example.com"
2019/03/24 17:13:22 [debug] 8496#8496: *8734 finalize http upstream request: 499
2019/03/24 17:13:22 [debug] 8496#8496: *8734 http finalize request: 499, "/index.php?" a:1, c:1

相关内容