archive/zip: Performance regression with reading ZIP files with many entries

[stanhu]

What version of Go are you using (go version)?

$ go version
go version go1.17.1 linux/amd64

Does this issue reproduce with the latest release?

Yes.

What operating system and processor architecture are you using (go env)?

go env Output

$ go env
GO111MODULE=""
GOARCH="amd64"
GOBIN=""
GOCACHE="/home/stanhu/.cache/go-build"
GOENV="/home/stanhu/.config/go/env"
GOEXE=""
GOEXPERIMENT=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GOINSECURE=""
GOMODCACHE="/home/stanhu/.gvm/pkgsets/go1.17.1/global/pkg/mod"
GONOPROXY=""
GONOSUMDB=""
GOOS="linux"
GOPATH="/home/stanhu/.gvm/pkgsets/go1.17.1/global"
GOPRIVATE=""
GOPROXY="https://proxy.golang.org,direct"
GOROOT="/home/stanhu/.gvm/gos/go1.17.1"
GOSUMDB="sum.golang.org"
GOTMPDIR=""
GOTOOLDIR="/home/stanhu/.gvm/gos/go1.17.1/pkg/tool/linux_amd64"
GOVCS=""
GOVERSION="go1.17.1"
GCCGO="gccgo"
AR="ar"
CC="gcc"
CXX="g++"
CGO_ENABLED="1"
GOMOD="/dev/null"
CGO_CFLAGS="-g -O2"
CGO_CPPFLAGS=""
CGO_CXXFLAGS="-g -O2"
CGO_FFLAGS="-g -O2"
CGO_LDFLAGS="-g -O2"
PKG_CONFIG="pkg-config"
GOGCCFLAGS="-fPIC -m64 -pthread -fmessage-length=0 -fdebug-prefix-map=/tmp/go-build4184767189=/tmp/go-build -gno-record-gcc-switches"

What did you do?

We use HTTP Range Requests to seek around an externally stored ZIP file to extract the directory listing. For example:

package main

import (
	"archive/zip"
	"fmt"
	"net/http"

	"github.com/jfbus/httprs"
)

func main() {
	url := "https://stanhu-s3-test-bucket.s3.us-west-1.amazonaws.com/test.zip"
	req, err := http.NewRequest(http.MethodGet, url, nil)
	if err != nil {
		panic(err)
	}

	httpClient := &http.Client{}

	resp, err := httpClient.Do(req)
	if err != nil || resp.StatusCode != http.StatusOK {
		panic(err)
	}

	rs := httprs.NewHttpReadSeeker(resp, httpClient)
	defer resp.Body.Close()
	defer rs.Close()

	archive, err := zip.NewReader(rs, resp.ContentLength)
	if err != nil {
		panic(err)
	}

	for _, entry := range archive.File {
		fmt.Println(entry.Name)
	}

	fmt.Printf("Range Requests: %d\n", rs.Requests)
}

What did you expect to see?

With Go v1.16.4:

# time ./main
<snip>
tmp/tests/frontend/fixtures-ee/projects_json/pipelines_empty.json
tmp/tests/frontend/fixtures-ee/pipeline_schedules/edit_with_variables.html
tmp/tests/frontend/fixtures-ee/projects_json/files.json
tmp/tests/frontend/fixtures-ee/projects/overview.html
tmp/tests/frontend/fixtures-ee/search/show.html
tmp/tests/frontend/fixtures-ee/search/blob_search_result.html
Range Requests: 2

real	0m0.277s
user	0m0.060s
sys	0m0.028s

What did you see instead?

# time ./main
<snip>
tmp/tests/frontend/fixtures-ee/pipeline_schedules/edit_with_variables.html
tmp/tests/frontend/fixtures-ee/projects_json/files.json
tmp/tests/frontend/fixtures-ee/projects/overview.html
tmp/tests/frontend/fixtures-ee/search/show.html
tmp/tests/frontend/fixtures-ee/search/blob_search_result.html
Range Requests: 78

real	0m9.547s
user	0m0.239s
sys	0m0.154s

It appears the call to f.readDataDescriptor is causing these extra 76 HTTP Range Requests:

go/src/archive/zip/reader.go

Line 120 in ddb648f

f.readDataDescriptor()

This was added in ddb648f for #34974.

Granted that not many people may be using the library with HTTP Range Requests, but this is compatible with the interface. This problem caused a production incident as our Google Cloud Storage request rate jumped from 2000/s to over 30,000/s (https://gitlab.com/gitlab-com/gl-infra/production/-/issues/5521).

The additional reads also slows down opening ZIP files, especially on a networked filesystem. The OpenRaw() interface doesn't really work as a substitute because the HTTP client uses io.Reader, so we'd need to buffer the output to a file, which we're trying to avoid.

@escholtz @ianlancetaylor I realize this parsing of the data descriptors might have been done to support the raw methods/ ZIP64, but is there a way we can skip this since we're primarily interested in extracting the central directory header?

[escholtz]

Yikes! I'm sorry this caused a production incident.

You're correct that the readDataDescriptor in Reader.init is causing many additional random access reads. And there is no way to bypass that with the current public methods. This placement was proposed by @rsc in #34974 (comment). We'll have to take a closer look if it can be conditionally skipped or moved elsewhere. If I remember correctly, we were trying to balance constraints of the existing package interface/behavior, the needs of the new methods, and edge cases with the zip format.

Would it be possible for your use case to read the file from GCS first and then open it from memory? Or does that violate your bandwidth and local storage requirements?

[WarheadsSE]

Would it be possible for your use case to read the file from GCS first and then open it from memory? Or does that violate your bandwidth and local storage requirements?

We really need to be operating from the HTTP range requests for the functionality impacted here, as it is directly related to our CI artifacts, as uploaded by GitLab Runner instances. There are many projects that generate rather large artifacts in public/private instances, and it would be best not to force the transit round trip when we really just need the metadata.

[gopherbot]

Change https://golang.org/cl/353715 mentions this issue: archive/zip: lazy load file data descriptor

[gopherbot]

Change https://golang.org/cl/353716 mentions this issue: archive/zip: load file data descriptor on demand

[guilhem]

@WarheadsSE @escholtz I created https://github.com/guilhem/chunkreaderat to solve this kind of performance issue with zip + HTTP range call.

In our case, using caching on read with a pipeline of Azure Blob -> zip -> csv -> zip -> Azure Blob improved performance by over x200.

[escholtz]

@guilhem I don't think caching reads will help here. (Unless the zip file is very small, in which case you'd probably be better off reading the entire file with a single read.) The problem is big zip files and reading small portions spaced throughout the file during init.

[guilhem]

@escholtz caching with my lib will help to keep all metadata in the same chunk in memory.
So any new read being in memory instead of doing a new http call.

[escholtz]

@guilhem Happy to change my mind if you share benchmarks for the scenario described. Otherwise, I think this is sidetracking the original issue. The problem reported is additional per-file reads spread throughout large zip files. The sections are only read once so caching won't help.

[guilhem]

@escholtz I did some tests and benchmarks: https://play.golang.org/p/6Da7Bq6vwLs

Results:
1.17

Details

goos: linux
goarch: amd64
pkg: benchzip
cpu: 11th Gen Intel(R) Core(TM) i7-1165G7 @ 2.80GHz
Range Requests: 78
BenchmarkTestNoCache-8         	       1	53492265878 ns/op
Range Requests: 61
BenchmarkTest1024_1-8          	       1	43789868429 ns/op
Range Requests: 61
BenchmarkTest1024_10-8         	       1	41351607605 ns/op
Range Requests: 61
BenchmarkTest1024_100-8        	       1	41900755470 ns/op
Range Requests: 11
BenchmarkTest1024_64_1-8       	       1	8513921216 ns/op
Range Requests: 3
BenchmarkTest1024_64_10-8      	       1	2708611041 ns/op
Range Requests: 3
BenchmarkTest1024_64_100-8     	       1	4615014652 ns/op
Range Requests: 9
BenchmarkTest1024_256_1-8      	       1	6609027592 ns/op
Range Requests: 2
BenchmarkTest1024_256_10-8     	       1	1771012854 ns/op
Range Requests: 2
BenchmarkTest1024_256_100-8    	       1	2278849474 ns/op
Range Requests: 6
BenchmarkTest1024_1024_1-8     	       1	4454133078 ns/op
Range Requests: 2
BenchmarkTest1024_1024_10-8    	       1	1837363328 ns/op
Range Requests: 2
BenchmarkTest1024_1024_100-8   	       1	2234271086 ns/op
PASS
ok  	benchzip	215.579s

1.16

Details

goos: linux
goarch: amd64
pkg: benchzip
cpu: 11th Gen Intel(R) Core(TM) i7-1165G7 @ 2.80GHz
Range Requests: 2
BenchmarkTestNoCache-8         	       1	1667792285 ns/op
Range Requests: 2
BenchmarkTest1024_1-8          	       1	1119663831 ns/op
Range Requests: 2
BenchmarkTest1024_10-8         	       1	1126226778 ns/op
Range Requests: 2
BenchmarkTest1024_100-8        	       1	1116728348 ns/op
Range Requests: 1
BenchmarkTest1024_64_1-8       	       1	1428527826 ns/op
Range Requests: 1
BenchmarkTest1024_64_10-8      	Range Requests: 1
Range Requests: 1
       2	 962857761 ns/op
Range Requests: 1
BenchmarkTest1024_64_100-8     	Range Requests: 1
Range Requests: 1
       2	 961547464 ns/op
Range Requests: 1
BenchmarkTest1024_256_1-8      	       1	1100716445 ns/op
Range Requests: 1
BenchmarkTest1024_256_10-8     	       1	1120852478 ns/op
Range Requests: 1
BenchmarkTest1024_256_100-8    	       1	1119547786 ns/op
Range Requests: 1
BenchmarkTest1024_1024_1-8     	       1	1148681635 ns/op
Range Requests: 1
BenchmarkTest1024_1024_10-8    	       1	1115886109 ns/op
Range Requests: 1
BenchmarkTest1024_1024_100-8   	       1	1247170472 ns/op
Range Requests: 0
BenchmarkTest1024_4096_100-8   	Range Requests: 0
Range Requests: 0
Range Requests: 0
Range Requests: 0
Range Requests: 0
       3	 380116127 ns/op
PASS
ok  	benchzip	21.856s

conclusions:

• 1.16 has vanilla better performance than 1.17
• even 1.16 performances can be improved by using a cache (x4 when cache is big enough)
• 1.17 performances match 1.16 vanilla when using some buffers
• 1.17 perfs stay lower than 1.16