diff --git a/changelog/unreleased/issue-2742 b/changelog/unreleased/issue-2742 new file mode 100644 index 000000000..72dac6de8 --- /dev/null +++ b/changelog/unreleased/issue-2742 @@ -0,0 +1,15 @@ +Bugfix: Improve error handling for rclone and rest backend over HTTP2 + +When retrieving data from the rclone / rest backend while also using HTTP2 +restic did not detect when no data was returned at all. This could cause +for example the `check` command to report the following error: +``` +Pack ID does not match, want xxxxxxxx, got e3b0c442 +``` + +This has been fixed by correctly detecting the incomplete download and +retrying the download. + +https://github.com/restic/restic/issues/2742 +https://github.com/restic/restic/pull/3453 +https://forum.restic.net/t/http2-stream-closed-connection-reset-context-canceled/3743/10 diff --git a/internal/backend/rest/rest.go b/internal/backend/rest/rest.go index 44fcaead6..55732e871 100644 --- a/internal/backend/rest/rest.go +++ b/internal/backend/rest/rest.go @@ -7,8 +7,10 @@ import ( "io" "io/ioutil" "net/http" + "net/textproto" "net/url" "path" + "strconv" "strings" "golang.org/x/net/context/ctxhttp" @@ -197,6 +199,44 @@ func (b *Backend) Load(ctx context.Context, h restic.Handle, length int, offset return err } +// checkContentLength returns an error if the server returned a value in the +// Content-Length header in an HTTP2 connection, but closed the connection +// before any data was sent. +// +// This is a workaround for https://github.com/golang/go/issues/46071 +// +// See also https://forum.restic.net/t/http2-stream-closed-connection-reset-context-canceled/3743/10 +func checkContentLength(resp *http.Response) error { + // the following code is based on + // https://github.com/golang/go/blob/b7a85e0003cedb1b48a1fd3ae5b746ec6330102e/src/net/http/h2_bundle.go#L8646 + + if resp.ContentLength != 0 { + return nil + } + + if resp.ProtoMajor != 2 && resp.ProtoMinor != 0 { + return nil + } + + if len(resp.Header[textproto.CanonicalMIMEHeaderKey("Content-Length")]) != 1 { + return nil + } + + // make sure that if the server returned a content length and we can + // parse it, it is really zero, otherwise return an error + contentLength := resp.Header.Get("Content-Length") + cl, err := strconv.ParseUint(contentLength, 10, 63) + if err != nil { + return fmt.Errorf("unable to parse Content-Length %q: %w", contentLength, err) + } + + if cl != 0 { + return errors.Errorf("unexpected EOF: got 0 instead of %v bytes", cl) + } + + return nil +} + func (b *Backend) openReader(ctx context.Context, h restic.Handle, length int, offset int64) (io.ReadCloser, error) { debug.Log("Load %v, length %v, offset %v", h, length, offset) if err := h.Valid(); err != nil { @@ -246,6 +286,14 @@ func (b *Backend) openReader(ctx context.Context, h restic.Handle, length int, o return nil, errors.Errorf("unexpected HTTP response (%v): %v", resp.StatusCode, resp.Status) } + // workaround https://github.com/golang/go/issues/46071 + // see also https://forum.restic.net/t/http2-stream-closed-connection-reset-context-canceled/3743/10 + err = checkContentLength(resp) + if err != nil { + _ = resp.Body.Close() + return nil, err + } + return resp.Body, nil } diff --git a/internal/backend/rest/rest_int_go114_test.go b/internal/backend/rest/rest_int_go114_test.go new file mode 100644 index 000000000..036a136e1 --- /dev/null +++ b/internal/backend/rest/rest_int_go114_test.go @@ -0,0 +1,94 @@ +// +build go1.14 + +package rest_test + +import ( + "context" + "io" + "io/ioutil" + "net/http" + "net/http/httptest" + "net/url" + "testing" + + "github.com/restic/restic/internal/backend/rest" + "github.com/restic/restic/internal/restic" +) + +func TestZeroLengthRead(t *testing.T) { + // Test workaround for https://github.com/golang/go/issues/46071. Can be removed once this is fixed in Go + // and the minimum golang version supported by restic includes the fix. + numRequests := 0 + srv := httptest.NewUnstartedServer(http.HandlerFunc(func(res http.ResponseWriter, req *http.Request) { + numRequests++ + t.Logf("req %v %v", req.Method, req.URL.Path) + if req.Method == "GET" { + res.Header().Set("Content-Length", "42") + // Now the handler fails for some reason and is unable to send data + return + } + + t.Errorf("unhandled request %v %v", req.Method, req.URL.Path) + })) + srv.EnableHTTP2 = true + srv.StartTLS() + defer srv.Close() + + srvURL, err := url.Parse(srv.URL) + if err != nil { + t.Fatal(err) + } + + cfg := rest.Config{ + Connections: 5, + URL: srvURL, + } + be, err := rest.Open(cfg, srv.Client().Transport) + if err != nil { + t.Fatal(err) + } + defer func() { + err = be.Close() + if err != nil { + t.Fatal(err) + } + }() + + err = be.Load(context.TODO(), restic.Handle{Type: restic.ConfigFile}, 0, 0, func(rd io.Reader) error { + _, err := ioutil.ReadAll(rd) + if err == nil { + t.Fatal("ReadAll should have returned an 'Unexpected EOF' error") + } + return nil + }) + if err == nil { + t.Fatal("Got no unexpected EOF error") + } +} + +func TestGolangZeroLengthRead(t *testing.T) { + // This test is intended to fail once the underlying issue has been fixed in Go + ts := httptest.NewUnstartedServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + w.Header().Set("Content-Length", "42") + // Now the handler fails for some reason and is unable to send data + })) + ts.EnableHTTP2 = true + ts.StartTLS() + defer ts.Close() + + res, err := ts.Client().Get(ts.URL) + if err != nil { + t.Fatal(err) + } + _, err = ioutil.ReadAll(res.Body) + defer func() { + err = res.Body.Close() + if err != nil { + t.Fatal(err) + } + }() + if err != nil { + // This should fail with an 'Unexpected EOF' error + t.Fatal(err) + } +}