Open aloababa opened 5 years ago
@aloababa the example you gave doesn't seem to work. It is throwing an error: "./prog.go:37:38: undefined: syscall.SIGTERM".
Is undefined only in playground, try to download code and run it on local unix machine.
Gotcha, thanks. /cc @rsc @FiloSottile as an fyi until I can reproduce this on my linux machine tomorrow.
Debugs on both sides show proper shutdown.
Server side
2019/07/29 20:58:10 Shutting down http server...
2019/07/29 20:58:10 http2: Framer 0xc00032e1c0: wrote GOAWAY len=8 LastStreamID=13 ErrCode=NO_ERROR Debug=""
2019/07/29 20:58:11 done
Client side (nghttp)
[ 5.369] recv GOAWAY frame <length=8, flags=0x00, stream_id=0>
(last_stream_id=13, error_code=NO_ERROR(0x00), opaque_data(0)=[])
Some requests were not processed. total=1, processed=0
I made a new test on a different machine.
And i still got a different behavior between h2 and http/1.1.
When using h2 I got EOF. And when using http/1.1 I got the PID.
I sent a SIGTERM before the request was complete.
cURL output with http:
root@bentest:~# curl -k https://127.0.0.1:8080 -v
* Rebuilt URL to: https://127.0.0.1:8080/
* Trying 127.0.0.1...
* TCP_NODELAY set
* Connected to 127.0.0.1 (127.0.0.1) port 8080 (#0)
* ALPN, offering h2
* ALPN, offering http/1.1
* successfully set certificate verify locations:
* CAfile: /etc/ssl/certs/ca-certificates.crt
CApath: /etc/ssl/certs
* (304) (OUT), TLS handshake, Client hello (1):
* (304) (IN), TLS handshake, Server hello (2):
* TLSv1.2 (IN), TLS handshake, Certificate (11):
* TLSv1.2 (IN), TLS handshake, Server key exchange (12):
* TLSv1.2 (IN), TLS handshake, Server finished (14):
* TLSv1.2 (OUT), TLS handshake, Client key exchange (16):
* TLSv1.2 (OUT), TLS change cipher, Client hello (1):
* TLSv1.2 (OUT), TLS handshake, Finished (20):
* TLSv1.2 (IN), TLS handshake, Finished (20):
* SSL connection using TLSv1.2 / ECDHE-RSA-AES128-GCM-SHA256
* ALPN, server accepted to use http/1.1
* Server certificate:
* subject: C=FR; L=PAR; O=ORG; CN=bentest
* start date: Jul 30 08:23:47 2019 GMT
* expire date: Jul 29 08:23:47 2020 GMT
* issuer: C=FR; L=PAR; O=ORG; CN=bentest
* SSL certificate verify result: unable to get local issuer certificate (20), continuing anyway.
> GET / HTTP/1.1
> Host: 127.0.0.1:8080
> User-Agent: curl/7.58.0
> Accept: */*
>
< HTTP/1.1 200 OK
< Date: Tue, 30 Jul 2019 08:24:03 GMT
< Content-Length: 11
< Content-Type: text/plain; charset=utf-8
< Connection: close
<
PID: 69120
* Closing connection 0
* TLSv1.2 (OUT), TLS alert, Client hello (1):
cURL output with http2:
root@bentest:~# curl -k https://127.0.0.1:8080 -v
* Rebuilt URL to: https://127.0.0.1:8080/
* Trying 127.0.0.1...
* TCP_NODELAY set
* Connected to 127.0.0.1 (127.0.0.1) port 8080 (#0)
* ALPN, offering h2
* ALPN, offering http/1.1
* successfully set certificate verify locations:
* CAfile: /etc/ssl/certs/ca-certificates.crt
CApath: /etc/ssl/certs
* (304) (OUT), TLS handshake, Client hello (1):
* (304) (IN), TLS handshake, Server hello (2):
* TLSv1.2 (IN), TLS handshake, Certificate (11):
* TLSv1.2 (IN), TLS handshake, Server key exchange (12):
* TLSv1.2 (IN), TLS handshake, Server finished (14):
* TLSv1.2 (OUT), TLS handshake, Client key exchange (16):
* TLSv1.2 (OUT), TLS change cipher, Client hello (1):
* TLSv1.2 (OUT), TLS handshake, Finished (20):
* TLSv1.2 (IN), TLS handshake, Finished (20):
* SSL connection using TLSv1.2 / ECDHE-RSA-AES128-GCM-SHA256
* ALPN, server accepted to use h2
* Server certificate:
* subject: C=FR; L=PAR; O=ORG; CN=bentest
* start date: Jul 30 08:24:43 2019 GMT
* expire date: Jul 29 08:24:43 2020 GMT
* issuer: C=FR; L=PAR; O=ORG; CN=bentest
* SSL certificate verify result: unable to get local issuer certificate (20), continuing anyway.
* Using HTTP2, server supports multi-use
* Connection state changed (HTTP/2 confirmed)
* Copying HTTP/2 data in stream buffer to connection buffer after upgrade: len=0
* Using Stream ID: 1 (easy handle 0x56330e0294b0)
> GET / HTTP/2
> Host: 127.0.0.1:8080
> User-Agent: curl/7.58.0
> Accept: */*
>
* Connection state changed (MAX_CONCURRENT_STREAMS updated)!
* TLSv1.2 (IN), TLS alert, Client hello (1):
* Unexpected EOF
* Connection #0 to host 127.0.0.1 left intact
curl: (56) Unexpected EOF
@fraenkel this is exactly a bug described by OP, server send GOAWAY without waiting for handlers to finish.
EDIT: (after reading spec) Actually GOAWAY is right thing to do is such situation, but still server close connection without waiting for handlers to finish.
Actually, I am not convinced any client is sending a GOAWAY. From the traces and from additional debug, the server receives an EOF rather than any more messages to finish the request.
If you do a trace of a clean GET, you will notice that the client does not wait for the GOAWAY from the server.
Server send GOAWAY. It happens here: https://github.com/golang/go/blob/fbb819ebc443518e9caea3c1b0d0f9e0efec2262/src/net/http/h2_bundle.go#L3779
Ok, I found some problems:
http2 connection never become active (I mean we never call c.setState(c.rwc, StateActive)
on http2 connections), so Shutdown() is not waiting for such connection to finish processing.
If I add c.setState(c.rwc, StateActive)
here: https://github.com/golang/go/blob/fbb819ebc443518e9caea3c1b0d0f9e0efec2262/src/net/http/server.go#L1800
The graceful shutdown works as expected but curl will complain about malformed HTTP2 frames, and maybe this is bug in curl, because I don't see any wrong HTTP2 packets in Wireshark.
UPD: Definitely curl bug.
with
curl 7.54.0 (x86_64-apple-darwin18.0) libcurl/7.54.0 LibreSSL/2.6.5 zlib/1.2.11 nghttp2/1.24.1
Protocols: dict file ftp ftps gopher http https imap imaps ldap ldaps pop3 pop3s rtsp smb smbs smtp smtps telnet tftp
Features: AsynchDNS IPv6 Largefile GSS-API Kerberos SPNEGO NTLM NTLM_WB SSL libz HTTP2 UnixSockets HTTPS-proxy
I got curl: (16) Error in the HTTP2 framing layer
But with
curl 7.65.3 (x86_64-apple-darwin18.6.0) libcurl/7.65.3 OpenSSL/1.0.2s zlib/1.2.11 brotli/1.0.7 c-ares/1.15.0 libssh2/1.9.0 nghttp2/1.39.1 librtmp/2.3
Release-Date: 2019-07-19
Protocols: dict file ftp ftps gopher http https imap imaps ldap ldaps pop3 pop3s rtmp rtsp scp sftp smb smbs smtp smtps telnet tftp
Features: AsynchDNS brotli GSS-API HTTP2 HTTPS-proxy IPv6 Kerberos Largefile libz Metalink NTLM NTLM_WB SPNEGO SSL TLS-SRP UnixSockets
I don't get any error messages, also found this: https://bugzilla.redhat.com/show_bug.cgi?id=1690971
HTTP2 is hard :(
Bug was introduced here: In this commit https://github.com/golang/go/commit/a79fe5354fad08086c0a2018661f06a5f2e6eaa3, on this line: https://github.com/golang/go/blob/fbb819ebc443518e9caea3c1b0d0f9e0efec2262/src/net/http/server.go#L2710
Also if you change Sleep here for more than 5 seconds https://github.com/golang/go/blob/fbb819ebc443518e9caea3c1b0d0f9e0efec2262/src/net/http/serve_test.go#L5556
Test will fail.
/cc @bradfitz
Looks like duplicate of #39776 fixed by https://go-review.googlesource.com/c/go/+/240278
What version of Go are you using (
go version
)?Does this issue reproduce with the latest release?
Yes
What operating system and processor architecture are you using (
go env
)?go env
OutputWhat did you do?
Well when using h2 proto in tls config, calling server.Shutdown will not wait for active connections.
Here is the example:
https://play.golang.org/p/kjFfgwHIvIj
Just use tlsConfig() and tlsConfigWithHTTP2() and send SIGINT while doing a curl.
With http/1.1 proto Shutdown works properly but not with h2 proto.