search

golang / go

The Go programming language
https://go.dev
BSD 3-Clause "New" or "Revised" License
124.12k stars 17.68k forks source link

x/net/http2: Transport interop issue against Apache mod_h2? #16519

Closed songgao closed 8 years ago

songgao commented 8 years ago

Please answer these questions before submitting your issue. Thanks!

  1. What version of Go are you using (go version)?
go version go1.6.3 linux/amd64
  1. What operating system and processor architecture are you using (go env)?
GOARCH="amd64"
GOBIN="/home/songgao/gopath/bin"
GOEXE=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GOOS="linux"
GOPATH="/home/songgao/gopath"
GORACE=""
GOROOT="/usr/lib/go"
GOTOOLDIR="/usr/lib/go/pkg/tool/linux_amd64"
GO15VENDOREXPERIMENT="1"
CC="gcc"
GOGCCFLAGS="-fPIC -m64 -pthread -fmessage-length=0"
CXX="g++"
CGO_ENABLED="1"
  1. What did you do?
// main.go
package main

import (
    "io"
    "log"
    "net/http"
    "os"
    "time"
)

func main() {
    c := &http.Client{
        Timeout: 4 * time.Second,
    }
    log.Println("about to get ...")
    resp, err := c.Get("https://wohlford.co")
    if err != nil {
        log.Fatal(err)
    }
    io.Copy(os.Stdout, resp.Body)
}
songgao at Song-ThinkPad in /tmp 
$ GODEBUG=http2debug=2 go run main.go
2016/07/27 16:09:12 about to get ...
2016/07/27 16:09:12 http2: Transport failed to get client conn for wohlford.co:443: http2: no cached connection was available
2016/07/27 16:09:13 http2: Transport creating client conn to 184.106.215.246:443
2016/07/27 16:09:13 http2: Framer 0xc8203762c0: wrote SETTINGS len=18, settings: ENABLE_PUSH=0, INITIAL_WINDOW_SIZE=4194304, MAX_HEADER_LIST_SIZE=10485760
2016/07/27 16:09:13 http2: Framer 0xc8203762c0: wrote WINDOW_UPDATE len=4 (conn) incr=1073741824
2016/07/27 16:09:16 Get https://wohlford.co: net/http: request canceled while waiting for connection (Client.Timeout exceeded while awaiting headers)
exit status 1

songgao at Song-ThinkPad in /tmp 
$ GODEBUG=http2client=0 go run main.go
2016/07/27 16:09:23 about to get ...
<!DOCTYPE html>
<html lang=en>
<head>
  <meta charset=utf-8 />
  <title>Wohlford &amp; Co.</title>
  <style title="text/css">body{background-color:#f2f1e6;margin:25% 0 0 0}div{text-align:center}a{color:#4c3c2f;text-decoration:none}</style>
</head>
<body>
  <div>
    <img src=xwohlford-co.png.pagespeed.ic.QfSuzO-s_o.png alt="Wohlford &amp; Co. Logo" width=555 height=69 />
  </div>
<script>if(window.parent==window){(function(i,s,o,g,r,a,m){i['GoogleAnalyticsObject']=r;i[r]=i[r]||function(){(i[r].q=i[r].q||[]).push(arguments)},i[r].l=1*new Date();a=s.createElement(o),m=s.getElementsByTagName(o)[0];a.async=1;a.src=g;m.parentNode.insertBefore(a,m)})(window,document,'script','//www.google-analytics.com/analytics.js','ga');ga('create','UA-1898639-5','auto',{'siteSpeedSampleRate':100});ga('send','pageview');}</script></body>
</html>
  1. What did you expect to see? Falls back to HTTP/1.1 or errors
  2. What did you see instead? Hangs until timeout
songgao commented 8 years ago

Just tried above code with go1.6 and HTTP/2 works fine. So it seems to be something introduced in (go1.6, go1.6.3].

wohlford commented 8 years ago

Ubuntu 14.04.4 LTS (amd64) Apache 2.4.23 OpenSSL 1.0.2h Nghttp2 1.13.0

/etc/apache2/sites-enabled/wohlford.co.conf:

<VirtualHost 184.106.215.246:80 [2001:470:c50c::1]:80>
  SuexecUserGroup "#2566" "#2129"
  ServerName wohlford.co
  ServerAlias www.wohlford.co
  DocumentRoot /home/wohlford.co/web

  ErrorLog /var/log/virtualmin/wohlford.co_error_log
  CustomLog /var/log/virtualmin/wohlford.co_access_log combined

  # HTTP/2
  <IfModule mod_http2.c>
    Protocols h2 h2c http/1.1
  </IfModule>

  # Cache
  <IfModule mod_cache_disk.c>
    CacheEnable disk /
    <IfModule mod_headers.c>
      Header setifempty Cache-Control "max-age=1" env=GATEWAY_INTERFACE
    </IfModule>
  </IfModule>

  # Enable Page Optimizations
  <IfModule pagespeed_module>
    ModPagespeed On
    ModPagespeedRewriteLevel CoreFilters
    #ModPagespeedEnableFilters add_instrumentation
    ModPagespeedEnableFilters insert_ga
    ModPagespeedAnalyticsID UA-1898639-5
    ModPagespeedEnableFilters inline_images
    <ModPagespeedIf spdy>
      ModPagespeedDisableFilters inline_images
    </ModPagespeedIf>
  </IfModule>

  <IfModule mod_rewrite.c>
    # Enable Rewrite Engine
    RewriteEngine on
    RewriteOptions InheritDown

    # Disable TRACE and TRACK
    RewriteCond %{REQUEST_METHOD} ^(TRACE|TRACK)
    RewriteRule .* - [F,NS]

    # Redirect all queries to wohlford.co
    RewriteCond %{HTTPS} !=on
    RewriteCond %{HTTP_HOST} !=wohlford.co [NC]
    RewriteRule ^/(.*) http://wohlford.co/$1 [R=301,L]

    # Redirect all encrypted queries to https://wohlford.co
    RewriteCond %{HTTPS} ==on
    RewriteCond %{HTTP_HOST} !=wohlford.co [NC]
    RewriteRule ^/(.*) https://wohlford.co/$1 [R=301,L]

    # Prevent Hotlinking
    RewriteCond %{HTTP_REFERER} !://wohlford.co/ [NC]
    RewriteCond %{HTTP_REFERER} !^$
    RewriteRule .\.(?:gif|jpe?g|png|bmp|ico|mov|mp4|wmv|mpe?g|mp3|ogg|swf|flv|pdf|docx?|xslx?|pptx?|zip|rar|gz|tgz|bz2|tbz|sitx?)$ - [F,L]
  </IfModule>

  <IfModule mod_ssl.c>
    <If "-T %{SSL_CIPHER}">
      <IfModule mod_headers.c>
        # Enable HSTS
        Header always set Strict-Transport-Security "max-age=15552000"

        # Public Key Pinning (HPKP)
        Header always set Public-Key-Pins "pin-sha256=\"V+sq7PzGY76Xm5KCr1c4UbSfQXAfRZjSbKIKhZEUI1s=\"; pin-sha256=\"AWBnEHm13/KDq7NWvRdWy+ESYII86+7Z20WO/G32ROs=\"; pin-sha256=\"ImP7Nf6Xq6zC1loswY5OMcem5s2M2p1i+qxV12bspG8=\"; max-age=15552000"
      </IfModule>
    </If>
    <ElseIf "-f '/home/wohlford.co/ssl.ca'">
      <IfModule mod_rewrite.c>
        # Switch to HTTPS if UA asks
        RewriteCond %{HTTP:Upgrade-Insecure-Requests} 1
        RewriteRule ^ https://wohlford.co%{REQUEST_URI} [R,L]

        RewriteCond %{THE_REQUEST} ^[A-Z]{3,9}\ /(.*)\ HTTP/ [NC]
        RewriteRule ^/?(wp-admin/|wp-login\.php) https://wohlford.co%{REQUEST_URI}%{QUERY_STRING} [R=301,QSA,L]
      </IfModule>
    </ElseIf>
  </IfModule>

  ScriptAlias /cgi-bin/ /home/wohlford.co/cgi-bin/
  <Directory /home/wohlford.co/cgi-bin>
    Require all granted
    Options None
    AllowOverride None Options=ExecCGI,Includes,IncludesNOEXEC,Indexes,MultiViews,SymLinksIfOwnerMatch
  </Directory>

  <Directory /home/wohlford.co/web/stats>
    AuthName "wohlford.co statistics"
    AuthType Basic
    AuthUserFile /home/wohlford.co/.stats-htpasswd
    Require valid-user
    <Files .stats-htpasswd>
      Deny from all
    </Files>
    Options None
    AllowOverride AuthConfig Limit Options=ExecCGI,Includes,IncludesNOEXEC,Indexes,MultiViews,SymLinksIfOwnerMatch
  </Directory>

  <Directory /home/wohlford.co/web>
    Require all granted
    Options +MultiViews +SymLinksIfOwnerMatch +ExecCGI
    AllowOverride AuthConfig Limit Nonfatal=Override Options=ExecCGI,Includes,IncludesNOEXEC,Indexes,MultiViews,SymLinksIfOwnerMatch
    AllowOverrideList Header RequestHeader SetEnvIf SetEnvIfNoCase \
      RewriteEngine RewriteOptions RewriteBase RewriteCond RewriteRule \
      Redirect RedirectTemp RedirectPermanent RedirectMatch \
      DefaultIcon AddDescription AddIcon AddIconByEncoding AddIconByType

    # WordPress Rewriting
#    RewriteBase /
#    RewriteCond %{REQUEST_FILENAME} !-f
#    RewriteCond %{REQUEST_FILENAME} !-d
#    RewriteRule . /index.php [L]

    <IfModule mod_fcgid.c>
      AddHandler fcgid-script .php
      AddHandler fcgid-script .php5.6
      AddHandler fcgid-script .php7.0
      AddType application/x-httpd-php .php
      FCGIWrapper /home/wohlford.co/fcgi-bin/php7.0.fcgi .php
      FCGIWrapper /home/wohlford.co/fcgi-bin/php5.6.fcgi .php5.6
      FCGIWrapper /home/wohlford.co/fcgi-bin/php7.0.fcgi .php7.0
    </IfModule>
  </Directory>

  <IfModule mod_fcgid.c>
    RemoveHandler .php
    RemoveHandler .php5.6
    RemoveHandler .php7.0
    IPCCommTimeout 20
    FcgidMaxRequestLen 1073741824
  </IfModule>
</VirtualHost>
<VirtualHost 184.106.215.246:443 [2001:470:c50c::1]:443>
  SuexecUserGroup "#2566" "#2129"
  ServerName wohlford.co
  ServerAlias www.wohlford.co
  DocumentRoot /home/wohlford.co/web

  ErrorLog /var/log/virtualmin/wohlford.co_error_log
  CustomLog /var/log/virtualmin/wohlford.co_access_log combined

  SSLEngine on
  SSLCertificateFile      /home/wohlford.co/ssl.cert
  SSLCertificateKeyFile   /home/wohlford.co/ssl.key
  SSLCertificateChainFile /home/wohlford.co/ssl.ca
  SSLCACertificateFile    /etc/ssl/certs/StartCom_Ltd.-ca.pem

  # HTTP/2
  <IfModule mod_http2.c>
    Protocols h2 h2c http/1.1
  </IfModule>

  # Cache
  <IfModule mod_cache_disk.c>
    CacheEnable disk /
    <IfModule mod_headers.c>
      Header setifempty Cache-Control "max-age=1" env=GATEWAY_INTERFACE
    </IfModule>
  </IfModule>

  # Enable Page Optimizations
  <IfModule pagespeed_module>
    ModPagespeed On
    ModPagespeedRewriteLevel CoreFilters
    #ModPagespeedEnableFilters add_instrumentation
    ModPagespeedEnableFilters insert_ga
    ModPagespeedAnalyticsID UA-1898639-5
    ModPagespeedEnableFilters inline_images
    <ModPagespeedIf spdy>
      ModPagespeedDisableFilters inline_images
    </ModPagespeedIf>
  </IfModule>

  <IfModule mod_rewrite.c>
    # Enable Rewrite Engine
    RewriteEngine on
    RewriteOptions InheritDown

    # Disable TRACE and TRACK
    RewriteCond %{REQUEST_METHOD} ^(TRACE|TRACK)
    RewriteRule .* - [F,NS]

    # Redirect all queries to wohlford.co
    RewriteCond %{HTTPS} !=on
    RewriteCond %{HTTP_HOST} !=wohlford.co [NC]
    RewriteRule ^/(.*) http://wohlford.co/$1 [R=301,L]

    # Redirect all encrypted queries to https://wohlford.co
    RewriteCond %{HTTPS} ==on
    RewriteCond %{HTTP_HOST} !=wohlford.co [NC]
    RewriteRule ^/(.*) https://wohlford.co/$1 [R=301,L]

    # Prevent Hotlinking
    RewriteCond %{HTTP_REFERER} !://wohlford.co/ [NC]
    RewriteCond %{HTTP_REFERER} !^$
    RewriteRule .\.(?:gif|jpe?g|png|bmp|ico|mov|mp4|wmv|mpe?g|mp3|ogg|swf|flv|pdf|docx?|xslx?|pptx?|zip|rar|gz|tgz|bz2|tbz|sitx?)$ - [F,L]
  </IfModule>

  <IfModule mod_ssl.c>
    <If "-T %{SSL_CIPHER}">
      <IfModule mod_headers.c>
        # Enable HSTS
        Header always set Strict-Transport-Security "max-age=15552000"

        # Public Key Pinning (HPKP)
        Header always set Public-Key-Pins "pin-sha256=\"V+sq7PzGY76Xm5KCr1c4UbSfQXAfRZjSbKIKhZEUI1s=\"; pin-sha256=\"AWBnEHm13/KDq7NWvRdWy+ESYII86+7Z20WO/G32ROs=\"; pin-sha256=\"ImP7Nf6Xq6zC1loswY5OMcem5s2M2p1i+qxV12bspG8=\"; max-age=15552000"
      </IfModule>
    </If>
    <ElseIf "-f '/home/wohlford.co/ssl.ca'">
      <IfModule mod_rewrite.c>
        # Switch to HTTPS if UA asks
        RewriteCond %{HTTP:Upgrade-Insecure-Requests} 1
        RewriteRule ^ https://wohlford.co%{REQUEST_URI} [R,L]

        RewriteCond %{THE_REQUEST} ^[A-Z]{3,9}\ /(.*)\ HTTP/ [NC]
        RewriteRule ^/?(wp-admin/|wp-login\.php) https://wohlford.co%{REQUEST_URI}%{QUERY_STRING} [R=301,QSA,L]
      </IfModule>
    </ElseIf>
  </IfModule>

  ScriptAlias /cgi-bin/ /home/wohlford.co/cgi-bin/
  <Directory /home/wohlford.co/cgi-bin>
    Require all granted
    Options None
    AllowOverride None Options=ExecCGI,Includes,IncludesNOEXEC,Indexes,MultiViews,SymLinksIfOwnerMatch
  </Directory>

  <Directory /home/wohlford.co/web/stats>
    AuthName "wohlford.co statistics"
    AuthType Basic
    AuthUserFile /home/wohlford.co/.stats-htpasswd
    Require valid-user
    <Files .stats-htpasswd>
      Deny from all
    </Files>
    Options None
    AllowOverride AuthConfig Limit Options=ExecCGI,Includes,IncludesNOEXEC,Indexes,MultiViews,SymLinksIfOwnerMatch
  </Directory>

  <Directory /home/wohlford.co/web>
    Require all granted
    Options +MultiViews +SymLinksIfOwnerMatch +ExecCGI
    AllowOverride AuthConfig Limit Nonfatal=Override Options=ExecCGI,Includes,IncludesNOEXEC,Indexes,MultiViews,SymLinksIfOwnerMatch
    AllowOverrideList Header RequestHeader SetEnvIf SetEnvIfNoCase \
      RewriteEngine RewriteOptions RewriteBase RewriteCond RewriteRule \
      Redirect RedirectTemp RedirectPermanent RedirectMatch \
      DefaultIcon AddDescription AddIcon AddIconByEncoding AddIconByType

    # WordPress Rewriting
#    RewriteBase /
#    RewriteCond %{REQUEST_FILENAME} !-f
#    RewriteCond %{REQUEST_FILENAME} !-d
#    RewriteRule . /index.php [L]

    <IfModule mod_fcgid.c>
      AddHandler fcgid-script .php
      AddHandler fcgid-script .php5.6
      AddHandler fcgid-script .php7.0
      AddType application/x-httpd-php .php
      FCGIWrapper /home/wohlford.co/fcgi-bin/php7.0.fcgi .php
      FCGIWrapper /home/wohlford.co/fcgi-bin/php5.6.fcgi .php5.6
      FCGIWrapper /home/wohlford.co/fcgi-bin/php7.0.fcgi .php7.0
    </IfModule>
  </Directory>

  <IfModule mod_fcgid.c>
    RemoveHandler .php
    RemoveHandler .php5.6
    RemoveHandler .php7.0
    IPCCommTimeout 20
    FcgidMaxRequestLen 1073741824
  </IfModule>
</VirtualHost>

Server Module List:

bradfitz commented 8 years ago

@icing, we might have an interop problem.

@songgao, there's no obvious place to fallback here. There's no great way to distinguish between an interop problem (if that's what it is... some bug on either side, or both), or an actual slow response hitting your timeout. Falling back h2 to h1 whenever an h2 response was legitimately slow doesn't work. Especially for general http retry reasons. (non-idempotent methods, etc)

I'll work on a preparing a Docker container with mod_h2 so I can reproduce this, unless somebody already has one.

@songgao, do you have a minimal repro?

icing commented 8 years ago

@bradfitz I see hanging request with my go 1.6.2. In order to check against my local test server, how do i disable the cert verification? :-D

bradfitz commented 8 years ago

@icing, you can write code like:

import (
   "crypto/tls"
   "log"
   "net/http"
   "os"

   "golang.org/x/net/http2"
)

func main() {
    c := &http.Client{
        Transport: &http2.Transport{
              TLSClientConfig: &tls.Config{InsecureSkipVerify: true},
        },
    }
    res, err := c.Get("https://localhost:1234/foo.txt")
    if err != nil { log.Fatal(err) }
    res.Write(os.Stdout)
}

And if you run it with GODEBUG=http2debug=2 set in your environment, it will dump out lots of information to stderr.

Thanks for looking!

I'll investigate more when I'm home.

icing commented 8 years ago

@bradfitz thanks!

I think you are running into the issue fixed in v1.5.12:

when the client waits on a SETTINGS ACK without anything else going on, it might get stuck in h2's output buffers.

As nghttp and curl always open stream 1 without waiting for the ack, this was not noticed. Have to add go tests some day...

bradfitz commented 8 years ago

Perhaps Go could send a dummy OPTIONS request if no settings response is heard after an RTT or so? That should force a flush on the mod_h2 side?

On Jul 29, 2016 11:12 AM, "Stefan Eissing" notifications@github.com wrote:

@bradfitz https://github.com/bradfitz thanks!

I think you are running into the issue fixed in v1.5.12 https://github.com/icing/mod_h2/releases/tag/v1.5.12:

when the client waits on a SETTINGS ACK without anything else going on, it might get stuck in h2's output buffers.

As nghttp and curl always open stream 1 without waiting for the ack, this was not noticed. Have to add go tests some day...

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/golang/go/issues/16519#issuecomment-236132685, or mute the thread https://github.com/notifications/unsubscribe-auth/AAAKPb3toD6l9yBNM8XkTrxk1s-MMv8fks5qacQLgaJpZM4JWt-- .

icing commented 8 years ago

Or send the first request right away? Save your client 1 RTT..

songgao commented 8 years ago

@bradfitz Thanks for the explanation. I don't have a minimal repro yet; sorry!

songgao commented 8 years ago

So, out of curiosity, I was wondering why go1.6 works with the same server. Does go1.6 always open stream 1 without waiting for the ack like nghttp/curl? If so, was the reason for changing that "compliance with standard"?

bradfitz commented 8 years ago

@songgao, Go 1.6 had a bug where HTTP/2 was enabled by default on all HTTP clients except the default one, embarrassingly. It was a bug introduced almost immediately before Go 1.6 was released, in the process of fixing a different bug, embarrassingly. It was fixed in Go 1.6.2 (Go 1.6.1 was a security-only release).

So you weren't using Go's http2 stack with Go 1.6 probably.

@icing, yeah, I suppose I could do that too. But would a PING frame force a flush of your buffers? That might be lower-risk at this stage of our release, which is just around the corner.

icing commented 8 years ago

If I understand my code, only a request will bring it out of that embarrassing state of not flushing its buffers then. It could be any request, really. Maybe insert a dummy one? Sorry about that.

icing commented 8 years ago

Started adding go tests into my test suite. Seeing other interop issues, e.g. where Apache sends response HEADER + DATA (eof set) and the go client hangs. No flow involved. And go on http1 works fine.

Does it makes sense to test with 1.6.2? Will have a closer look next week...

bradfitz commented 8 years ago

If I understand my code, only a request will bring it out of that embarrassing state of not flushing its buffers then. It could be any request, really. Maybe insert a dummy one? Sorry about that.

I thought about sending a dummy OPTIONS request, but then I found it was easier to just not wait for the peer's settings & settings ACK instead. I hacked that up on the plane ride home. It might be too late for Go 1.7.

Started adding go tests into my test suite. Seeing other interop issues, e.g. where Apache sends response HEADER + DATA (eof set) and the go client hangs. No flow involved. And go on http1 works fine.

File a new Go bug and post details? I need to setup mod_h2 interop tests on my side too, but do share any Go snippet you find that hangs.

Does it makes sense to test with 1.6.2? Will have a closer look next week...

Either use Go 1.6.2, or use Go 1.6 and just make sure you create your own *http.Client instead of relying on the http.DefaultClient ... 

     c:= &http.Client{Transport: &http.Transport{}}
     c.Get(....)
wohlford commented 8 years ago

I've been tracking this issue and I'm afraid some of the technical details are over me head. Pardon if I ask questions that don't really make all that much sense. ;-)

The original symptom came up with my use of keybase.io. It would validate my identity on my website over https, but not http. I mentioned it to @maxtaco. I believe he followed up with @songgao, and now there's this issue on GitHub. And frankly all that is so damn cool! I love open source! :-)

If I follow everything above, it breaks when using http2. I've disabled my http2 module in apache and restarted the daemon. So why can't I still validate?

Works: https://wohlford.co/.well-known/keybase.txt

Doesn't work: http://wohlford.co/.well-known/keybase.txt

I'm thinking there is something else going on here besides h2/h2c issues. Don't want us to miss that if true.

songgao commented 8 years ago

Thanks for looking into it @wohlford (Also thanks @bradfitz for the fantastic explanation!)

Jason, I think this thread is more for Go's net/http package. Let's move the Keybase related discussion to https://github.com/keybase/client/pull/3656 :D

gopherbot commented 8 years ago

CL https://golang.org/cl/25362 mentions this issue.

songgao commented 8 years ago

@bradfitz Thanks for the fix! Any chance the patch will make it into go1.7?

bradfitz commented 8 years ago

@songgao, it's pretty late in the cycle, but it's pretty crappy for users as-is so we probably should. I verified that this makes Go work with the latest Debian squeeze apache2, which doesn't yet have the upstream mod_h2 fix yet.

@adg, @broady, @quentinmit, @ianlancetaylor... thoughts?

quentinmit commented 8 years ago

My vote is to put it in 1.7. It's pretty annoying if we enable HTTP2 by default and we can't interoperate with Apache.

adg commented 8 years ago

Where do we draw the line for these changes?

bradfitz commented 8 years ago

There aren't many http2 implementations. I think it's pretty bad for users if they don't interop, even if it's temporary.

Plus I think the proposed change is how we want things anyway.

adg commented 8 years ago

OK

On 1 August 2016 at 11:04, Brad Fitzpatrick notifications@github.com wrote:

There aren't many http2 implementations. I think it's pretty bad for users if they don't interop, even if it's temporary.

Plus I think the proposed change is how we want things anyway.

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/golang/go/issues/16519#issuecomment-236468794, or mute the thread https://github.com/notifications/unsubscribe-auth/AIDilY_qLW_iKJhrySnVHIKOYone3RO2ks5qbUYJgaJpZM4JWt-- .

gopherbot commented 8 years ago

CL https://golang.org/cl/25388 mentions this issue.

songgao commented 8 years ago

Thanks for getting this in before 1.7 release!

icing commented 8 years ago

Thanks for the quick fix!

gopherbot commented 8 years ago

CL https://golang.org/cl/25508 mentions this issue.