Sergey Kandaurov Wrote:
-------------------------------------------------------
> > On 6 Oct 2017, at 18:40, joseph-pg <nginx-forum@forum.nginx.org>
> wrote:
> >
> > Hi,
> > I'm currently testing nginx 1.13.6 x64 on my development machine,
> which is
> > Windows 10 1703 x64, and sometimes I got a "Secure connection
> failed" error
> > on Firefox (55.x and 56). If I hit the reload button (F5)
> repeatedly, the
> > page will eventually load.
> >
> > Dev tools shows: 200 OK, size 0, and transferred -. nginx debug log
> doesn't
> > show anything weird.
> >
> > Things that I observed:
> > 1. 1.13.5 works fine
> > 2. Chrome on Android works fine
> >
> > I've tested 5a3ab1b5804b, 46ddff109e72, and 924b6ef942bf and they
> have the
> > same problem.
> >
> > Configuration is pretty much default with HTTPS and HTTP/2 server
> blocks.
>
> Please check if reverting 12cadc4669a7 helps.
>
> --
> Sergey Kandaurov
>
> _______________________________________________
> nginx mailing list
> nginx@nginx.org
> http://mailman.nginx.org/mailman/listinfo/nginx
Looks like it's the culprit. It happens at random times for a few seconds, so it's rather difficult to reproduce.
Here's the output of the debug log when the error occured (I was wrong, weird things do happen here, eg. an entry with alert flag below):
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 http2 idle handler
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 reusable connection: 0
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 malloc: 00000287AAEDD260:4096
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 http2 read handler
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 SSL_read: 60
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 SSL_read: -1
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 SSL_get_error: 2
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 process http2 frame type:1 f:25 l:38 sid:29
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 http2 HEADERS frame sid:29 on 13 excl:0 weight:42
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 malloc: 00000287AAE35390:1024
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 malloc: 00000287AAED8210:4096
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 malloc: 00000287AAEE22B0:4096
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 http2 get indexed header name: 2
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 http2 pseudo-header: ":method: GET"
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 http2 get indexed header: 5
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 http2 hpack encoded string length: 20
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 http uri: "/"
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 http args: "somequerystring"
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 http exten: ""
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 http2 pseudo-header: ":path: /?somequerystring"
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 http2 get indexed header name: 78
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 http2 pseudo-header: ":authority: my-internaldomain"
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 http2 get indexed header name: 7
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 http2 pseudo-header: ":scheme: https"
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 http2 get indexed header name: 77
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 http2 http header: "user-agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:56.0) Gecko/20100101 Firefox/56.0"
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 http2 get indexed header name: 76
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 http2 http header: "accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8"
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 http2 get indexed header name: 75
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 http2 http header: "accept-language: en-US,en;q=0.5"
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 http2 get indexed header name: 74
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 http2 http header: "accept-encoding: gzip, deflate, br"
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 http2 get indexed header name: 73
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 http2 http header: "dnt: 1"
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 http2 get indexed header name: 72
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 http2 http header: "upgrade-insecure-requests: 1"
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 http2 get indexed header name: 63
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 http2 http header: "if-modified-since: Sat, 07 Oct 2017 04:26:43 GMT"
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 http2 get indexed header name: 62
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 http2 http header: "if-none-match: W/"59d85783-3f5""
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 http2 http request line: "GET /?somequerystring HTTP/2.0"
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 generic phase: 0
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 rewrite phase: 1
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 test location: "/"
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 using configuration "/"
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 http cl:-1 max:1048576
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 rewrite phase: 3
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 post rewrite phase: 4
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 generic phase: 5
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 generic phase: 6
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 generic phase: 7
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 access phase: 8
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 access phase: 9
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 access phase: 10
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 post access phase: 11
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 generic phase: 12
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 generic phase: 13
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 content phase: 14
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 open index "path/to/website/index.html"
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 add cleanup: 00000287AAED91F8
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 cached open file: path/to/website/index.html, fd:560, c:1, e:0, u:15
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 internal redirect: "/index.html?somequerystring"
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 rewrite phase: 1
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 test location: "/"
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 using configuration "/"
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 http cl:-1 max:1048576
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 rewrite phase: 3
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 post rewrite phase: 4
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 generic phase: 5
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 generic phase: 6
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 generic phase: 7
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 access phase: 8
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 access phase: 9
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 access phase: 10
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 post access phase: 11
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 generic phase: 12
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 generic phase: 13
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 content phase: 14
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 content phase: 15
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 content phase: 16
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 content phase: 17
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 http filename: "path/to/website/index.html"
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 add cleanup: 00000287AAEE2B18
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 cached open file: path/to/website/index.html, fd:560, c:2, e:0, u:16
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 http static fd: 560
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 http ims:1507350403 lm:1507350443
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 filter http_cookie_flag is disabled
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 charset: "" > "utf-8"
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 http2 header filter
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 http2 output header: ":status: 200"
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 http2 output header: "server: nginx"
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 http2 output header: "date: Sat, 07 Oct 2017 04:28:05 GMT"
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 http2 output header: "content-type: text/html; charset=utf-8"
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 http2 output header: "last-modified: Sat, 07 Oct 2017 04:27:23 GMT"
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 http2 output header: "etag: W/"59d857ab-3f5""
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 http2 output header: "expires: Sat, 07 Oct 2017 04:28:04 GMT"
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 http2 output header: "cache-control: no-cache"
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 http2 output header: "strict-transport-security: max-age=63072000; includeSubDomains"
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 http2 output header: "referrer-policy: no-referrer"
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 http2 output header: "x-content-type-options: nosniff"
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 http2 output header: "x-frame-options: DENY"
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 http2 output header: "x-xss-protection: 1; mode=block"
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 http2 output header: "content-encoding: gzip"
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 http2:29 create HEADERS frame 00000287AAEE2FA0: len:293
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 http cleanup add: 00000287AAEE30A4
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 http2 frame out: 00000287AAEE2FA0 sid:29 bl:1 len:293
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 malloc: 00000287ACA000D0:16384
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 SSL buf copy: 9
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 SSL buf copy: 293
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 http2:29 HEADERS frame 00000287AAEE2FA0 was sent
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 http2 frame sent: 00000287AAEE2FA0 sid:29 bl:1 len:293
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 http output filter "/index.html?somequerystring"
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 http copy filter: "/index.html?somequerystring"
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 malloc: 00000287AAEE0290:4096
> 2017/10/07 11:28:05 [alert] 18764#15836: *15 ReadFile() read only 993 of 1013 from "path/to/website/index.html" while sending response to client, client: 127.0.0.1, server: my-internaldomain, request: "GET /?somequerystring HTTP/2.0", host: "my-internaldomain"
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 http copy filter: -1 "/index.html?somequerystring"
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 http finalize request: -1, "/index.html?somequerystring" a:1, c:2
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 http terminate request count:2
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 http terminate cleanup count:2 blk:0
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 http finalize request: -4, "/index.html?somequerystring" a:1, c:2
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 http request count:2 blk:0
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 http posted request: "/index.html?somequerystring"
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 http terminate handler count:1
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 http request count:1 blk:0
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 http2 close stream 29, queued 0, processing 1
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 http2 send RST_STREAM frame sid:29, status:2
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 http close request
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 http log handler
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 run cleanup: 00000287AAEE2B18
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 close cached open file: path/to/website/index.html, fd:560, c:1, u:16, 0
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 run cleanup: 00000287AAED91F8
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 close cached open file: path/to/website/index.html, fd:560, c:0, u:16, 0
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 free: 00000287AAED8210, unused: 0
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 free: 00000287AAEE22B0, unused: 300
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 free: 00000287AAEE0290, unused: 3051
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 free: 00000287AAE35390, unused: 546
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 http2 frame complete pos:00000287AD2800AF end:00000287AD2800BC
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 process http2 frame type:8 f:0 l:4 sid:29
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 http2 WINDOW_UPDATE frame sid:29 window:12451840
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 unknown http2 stream
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 http2 frame complete pos:00000287AD2800BC end:00000287AD2800BC
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 http2 frame out: 00000287AAEDD520 sid:0 bl:0 len:4
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 SSL buf copy: 13
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 SSL to write: 315
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 SSL_write: 315
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 http2 frame sent: 00000287AAEDD520 sid:0 bl:0 len:4
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 free: 00000287AAEDD260, unused: 3216
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 free: 00000287ACA000D0
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 reusable connection: 1
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 event timer del: 588: 1507350661972
> 2017/10/07 11:28:05 [debug] 18764#15836: *15 event timer add: 588: 180000:1507350665357
------------------------------------------------------------------------------------------------------------------------------------------------------------
Compile options:
nginx version: nginx/1.13.6 (12cadc4669a7)
built by cl <-- Built with VS 2017, but somehow the compiler version doesn't appear here.
built with OpenSSL 1.1.0f 25 May 2017
TLS SNI support enabled
configure arguments: --with-cc=cl --with-cc-opt=-DFD_SETSIZE=8192 --builddir=nginx --build=12cadc4669a7 --prefix= --conf-path=conf/nginx.conf --http-log-path=logs/access.log --error-log-path=logs/error.log --pid-path=pid/nginx.pid --sbin-path=nginx.exe --http-client-body-temp-path=temp/client_body_temp --http-proxy-temp-path=temp/proxy_temp --http-fastcgi-temp-path=temp/fastcgi_temp --http-scgi-temp-path=temp/scgi_temp --http-uwsgi-temp-path=temp/uwsgi_temp --with-openssl=lib/openssl-1.1.0f --with-openssl-opt='no-asm no-dgram no-heartbeats no-nextprotoneg no-ssl3-method no-weak-ssl-ciphers no-deprecated no-blake2 no-camellia no-des no-dsa no-gost no-idea no-psk no-seed no-scrypt no-sctp no-srp no-cms no-comp no-whirlpool' --with-pcre=lib/pcre-8.41 --with-pcre-jit --with-zlib=lib/zlib-1.2.11 --with-debug --with-select_module --with-http_addition_module --with-http_auth_request_module --with-http_gzip_static_module --with-http_realip_module --with-http_secure_link_module --with-http_slice_module --with-http_ssl_module --with-http_stub_status_module --with-http_sub_module --with-http_v2_module --with-stream --with-stream_ssl_module
