Your message dated Wed, 4 Aug 2021 14:32:01 +0200 with message-id <YQqIwTItI2LWJnSv@chou.cristau.org> and subject line Re: Bug#960304: snapshot.debian.org: Snapshot repo repeatedly cutting off connection, returning partial content has caused the Debian Bug report #960304, regarding snapshot.debian.org: Snapshot repo repeatedly cutting off connection, returning partial content to be marked as done. This means that you claim that the problem has been dealt with. If this is not the case it is now your responsibility to reopen the Bug report if necessary, and/or fix the problem forthwith. (NB: If you are a system administrator and have no idea what this message is talking about, this may indicate a serious mail system misconfiguration somewhere. Please contact owner@bugs.debian.org immediately.) -- 960304: https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=960304 Debian Bug Tracking System Contact owner@bugs.debian.org with problems
--- Begin Message ---
- To: Debian Bug Tracking System <submit@bugs.debian.org>
- Subject: snapshot.debian.org: Snapshot repo repeatedly cutting off connection, returning partial content
- From: Chanseok Oh <chanseok@google.com>
- Date: Mon, 11 May 2020 12:47:33 -0400
- Message-id: <CAP5K-1aYF2T5qWpWoC14CwWdDs7xrfoR-WDND5tZtpQ4WG6XKQ@mail.gmail.com>
Package: snapshot.debian.org
Severity: important
Dear Maintainer,
We've got multiple error reports when downloading a large .deb package (e.g., https://snapshot.debian.org/archive/debian-security/20200424T130133Z/pool/updates/main/o/openjdk-11/openjdk-11-jdk-headless_11.0.7%2B10-3~deb10u1_amd64.deb). The server repeatedly cuts the connection after returning an arbitrary amount of bytes. (More detailed information is in https://github.com/GoogleContainerTools/distroless/issues/509)$ curl -o a.deb https://snapshot.debian.org/archive/debian-security/20200424T130133Z/pool/updates/main/o/openjdk-11/openjdk-11-jdk-headless_11.0.7%2B10-3~deb10u1_amd64.deb
% Total % Received % Xferd Average Speed Time Time Time Current
Dload Upload Total Spent Left Speed
37 205M 37 77.8M 0 0 6964k 0 0:00:30 0:00:11 0:00:19 6313k
curl: (18) transfer closed with 133739032 bytes remaining to read
The workaround is for an HTTP client to repeatedly make Range requests, as "wget" does below. This seems unreasonably demanding.
$ wget https://snapshot.debian.org/archive/debian-security/20200424T130133Z/pool/updates/main/o/openjdk-11/openjdk-11-jdk-headless_11.0.7%2B10-3~deb10u1_amd64.deb
--2020-05-11 11:19:11-- https://snapshot.debian.org/archive/debian-security/20200424T130133Z/pool/updates/main/o/openjdk-11/openjdk-11-jdk-headless_11.0.7%2B10-3~deb10u1_amd64.deb
Resolving snapshot.debian.org (snapshot.debian.org)... 2001:630:206:4000:1a1a:0:c13e:ca1b, 2001:1af8:4020:b030:deb::185, 193.62.202.27, ...
Connecting to snapshot.debian.org (snapshot.debian.org)|2001:630:206:4000:1a1a:0:c13e:ca1b|:443... connected.
HTTP request sent, awaiting response... 200 OK
Length: 215331352 (205M)
Saving to: ‘openjdk-11-jdk-headless_11.0.7+10-3~deb10u1_amd64.deb’
openjdk-11-jdk-headless_11.0.7+10-3~deb10u1_amd6 33%[=================================> ] 68.45M 29.6MB/s in 2.3s
2020-05-11 11:19:14 (29.6 MB/s) - Connection closed at byte 71770112. Retrying.
--2020-05-11 11:19:15-- (try: 2) https://snapshot.debian.org/archive/debian-security/20200424T130133Z/pool/updates/main/o/openjdk-11/openjdk-11-jdk-headless_11.0.7%2B10-3~deb10u1_amd64.deb
Connecting to snapshot.debian.org (snapshot.debian.org)|2001:630:206:4000:1a1a:0:c13e:ca1b|:443... connected.
HTTP request sent, awaiting response... 206 Partial Content
Length: 215331352 (205M), 143561240 (137M) remaining
Saving to: ‘openjdk-11-jdk-headless_11.0.7+10-3~deb10u1_amd64.deb’
openjdk-11-jdk-headless_11.0.7+10-3~deb10u1_amd6 53%[++++++++++++++++++++++++++++++++++====================> ] 109.32M 26.6MB/s in 1.5s
2020-05-11 11:19:17 (26.6 MB/s) - Connection closed at byte 114630656. Retrying.
--2020-05-11 11:19:19-- (try: 3) https://snapshot.debian.org/archive/debian-security/20200424T130133Z/pool/updates/main/o/openjdk-11/openjdk-11-jdk-headless_11.0.7%2B10-3~deb10u1_amd64.deb
Connecting to snapshot.debian.org (snapshot.debian.org)|2001:630:206:4000:1a1a:0:c13e:ca1b|:443... connected.
HTTP request sent, awaiting response... 206 Partial Content
Length: 215331352 (205M), 100700696 (96M) remaining
Saving to: ‘openjdk-11-jdk-headless_11.0.7+10-3~deb10u1_amd64.deb’
openjdk-11-jdk-headless_11.0.7+10-3~deb10u1_amd6 69%[+++++++++++++++++++++++++++++++++++++++++++++++++++++++================> ] 142.20M 23.8MB/s in 1.4s
2020-05-11 11:19:20 (23.8 MB/s) - Connection closed at byte 149106688. Retrying.
--2020-05-11 11:19:23-- (try: 4) https://snapshot.debian.org/archive/debian-security/20200424T130133Z/pool/updates/main/o/openjdk-11/openjdk-11-jdk-headless_11.0.7%2B10-3~deb10u1_amd64.deb
Connecting to snapshot.debian.org (snapshot.debian.org)|2001:630:206:4000:1a1a:0:c13e:ca1b|:443... connected.
HTTP request sent, awaiting response... 206 Partial Content
Length: 215331352 (205M), 66224664 (63M) remaining
Saving to: ‘openjdk-11-jdk-headless_11.0.7+10-3~deb10u1_amd64.deb’
openjdk-11-jdk-headless_11.0.7+10-3~deb10u1_amd6 100%[++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++===============================>] 205.36M 29.5MB/s in 2.1s
2020-05-11 11:19:26 (29.5 MB/s) - ‘openjdk-11-jdk-headless_11.0.7+10-3~deb10u1_amd64.deb’ saved [215331352/215331352]-- System Information:
Debian Release: 10.3
APT prefers stable-updates
APT policy: (500, 'stable-updates'), (500, 'stable')
Architecture: amd64 (x86_64)
Kernel: Linux 5.2.17-1rodete3-amd64 (SMP w/6 CPU cores)
Kernel taint flags: TAINT_PROPRIETARY_MODULE, TAINT_USER, TAINT_OOT_MODULE
Locale: LANG=C, LC_CTYPE=C.UTF-8 (charmap=UTF-8), LANGUAGE=C (charmap=UTF-8)
Shell: /bin/sh linked to /bin/dash
Init: unable to detect
--- End Message ---
--- Begin Message ---
- To: Chanseok Oh <chanseok@google.com>, 960304-done@bugs.debian.org, dsa@debian.org
- Subject: Re: Bug#960304: snapshot.debian.org: Snapshot repo repeatedly cutting off connection, returning partial content
- From: Julien Cristau <jcristau@debian.org>
- Date: Wed, 4 Aug 2021 14:32:01 +0200
- Message-id: <YQqIwTItI2LWJnSv@chou.cristau.org>
- In-reply-to: <[🔎] YQpV7aZBcM671En8@chou.cristau.org>
- References: <CAP5K-1aYF2T5qWpWoC14CwWdDs7xrfoR-WDND5tZtpQ4WG6XKQ@mail.gmail.com> <[🔎] YQpV7aZBcM671En8@chou.cristau.org>
I've made some changes to the varnish config on snapshot.d.o to address this: we no longer cache large files so they won't be evicting many smaller ones from the storage. We now also limit ttl to a week (instead of the 1 year max-age). Closing; please feel free to file new bugs if issues persist. Thanks for the report, and for your patience. Cheers, Julien On Wed, Aug 04, 2021 at 10:55:09AM +0200, Julien Cristau wrote: > Hi, > > I just had a look at this again. It seems the issue comes from our > varnish setup, as things are fine when hitting apache directly. But the > combination of streaming and a mix of small and large files in varnish's > cache leads to things like the below, where varnish gives up after > hitting nuke_limit (50) files to make space in the cache. > > Cheers, > Julien > > > jcristau@sallinen:~$ sudo varnishlog -g session -q 'ReqUrl eq "/file/51288439bde385157c889f23483b467608586aad"' > > * << Session >> 3937381 > > - Begin sess 0 HTTP/1 > > - SessOpen 2a01:cb08:88c7:5b00:6798:1a76:ef57:4714 58440 a1 2001:630:206:4000:1a1a:0:c13e:ca1b 80 1628066418.824244 26 > > - Link req 3937382 rxreq > > - SessClose REM_CLOSE 2.846 > > - End > > ** << Request >> 3937382 > > -- Begin req 3937381 rxreq > > -- Timestamp Start: 1628066418.824321 0.000000 0.000000 > > -- Timestamp Req: 1628066418.824321 0.000000 0.000000 > > -- ReqStart 2a01:cb08:88c7:5b00:6798:1a76:ef57:4714 58440 a1 > > -- ReqMethod GET > > -- ReqURL /file/51288439bde385157c889f23483b467608586aad > > -- ReqProtocol HTTP/1.1 > > -- ReqHeader Host: snapshot.debian.org > > -- ReqHeader User-Agent: curl/7.74.0 > > -- ReqHeader Accept: */* > > -- ReqHeader X-Forwarded-For: 2a01:cb08:88c7:5b00:6798:1a76:ef57:4714 > > -- VCL_call RECV > > -- VCL_return hash > > -- VCL_call HASH > > -- VCL_return lookup > > -- VCL_call MISS > > -- VCL_return fetch > > -- Link bereq 3937383 fetch > > -- Timestamp Fetch: 1628066418.826448 0.002127 0.002127 > > -- RespProtocol HTTP/1.1 > > -- RespStatus 200 > > -- RespReason OK > > -- RespHeader Date: Wed, 04 Aug 2021 08:40:18 GMT > > -- RespHeader Server: Apache > > -- RespHeader X-Content-Type-Options: nosniff > > -- RespHeader X-Frame-Options: sameorigin > > -- RespHeader Referrer-Policy: no-referrer > > -- RespHeader X-Xss-Protection: 1 > > -- RespHeader Permissions-Policy: interest-cohort=() > > -- RespHeader Last-Modified: Fri, 20 Apr 2018 20:58:57 GMT > > -- RespHeader ETag: "2c0cb0ca-56a4df4e5684a" > > -- RespHeader Content-Length: 739029194 > > -- RespHeader X-Clacks-Overhead: GNU Terry Pratchett > > -- RespHeader Cache-Control: max-age=31536000, public > > -- RespHeader X-Varnish: 3937382 > > -- RespHeader Age: 0 > > -- RespHeader Via: 1.1 varnish (Varnish/6.1) > > -- VCL_call DELIVER > > -- RespHeader connection: close > > -- VCL_return deliver > > -- Timestamp Process: 1628066418.826480 0.002160 0.000032 > > -- RespHeader Accept-Ranges: bytes > > -- Timestamp Resp: 1628066421.667356 2.843036 2.840876 > > -- ReqAcct 128 0 128 512 19857408 19857920 > > -- End > > *** << BeReq >> 3937383 > > --- Begin bereq 3937382 fetch > > --- Timestamp Start: 1628066418.824419 0.000000 0.000000 > > --- BereqMethod GET > > --- BereqURL /file/51288439bde385157c889f23483b467608586aad > > --- BereqProtocol HTTP/1.1 > > --- BereqHeader Host: snapshot.debian.org > > --- BereqHeader User-Agent: curl/7.74.0 > > --- BereqHeader Accept: */* > > --- BereqHeader X-Forwarded-For: 2a01:cb08:88c7:5b00:6798:1a76:ef57:4714 > > --- BereqHeader Accept-Encoding: gzip > > --- BereqHeader X-Varnish: 3937383 > > --- VCL_call BACKEND_FETCH > > --- VCL_return fetch > > --- BackendOpen 32 default 127.0.0.1 80 127.0.0.1 56612 > > --- BackendStart 127.0.0.1 80 > > --- Timestamp Bereq: 1628066418.824718 0.000299 0.000299 > > --- Timestamp Beresp: 1628066418.826314 0.001895 0.001596 > > --- BerespProtocol HTTP/1.1 > > --- BerespStatus 200 > > --- BerespReason OK > > --- BerespHeader Date: Wed, 04 Aug 2021 08:40:18 GMT > > --- BerespHeader Server: Apache > > --- BerespHeader X-Content-Type-Options: nosniff > > --- BerespHeader X-Frame-Options: sameorigin > > --- BerespHeader Referrer-Policy: no-referrer > > --- BerespHeader X-Xss-Protection: 1 > > --- BerespHeader Permissions-Policy: interest-cohort=() > > --- BerespHeader Upgrade: h2,h2c > > --- BerespHeader Connection: Upgrade > > --- BerespHeader Last-Modified: Fri, 20 Apr 2018 20:58:57 GMT > > --- BerespHeader ETag: "2c0cb0ca-56a4df4e5684a" > > --- BerespHeader Accept-Ranges: bytes > > --- BerespHeader Content-Length: 739029194 > > --- BerespHeader X-Clacks-Overhead: GNU Terry Pratchett > > --- BerespHeader Cache-Control: max-age=31536000, public > > --- TTL RFC 31536000 10 0 1628066419 1628066419 1628066418 0 31536000 cacheable > > --- VCL_call BACKEND_RESPONSE > > --- VCL_return deliver > > --- Filters > > --- Storage file s0 > > --- Fetch_Body 3 length stream > > --- ExpKill LRU_Cand p=0x7fa236c79b00 f=0x0 r=1 > > --- ExpKill LRU x=3873725 > > --- ExpKill LRU_Cand p=0x7fa236c6f700 f=0x0 r=1 > > --- ExpKill LRU x=3696172 > > --- ExpKill LRU_Cand p=0x7fa238320d40 f=0x0 r=1 > > --- ExpKill LRU x=3873726 > > --- ExpKill LRU_Cand p=0x7fa23e73c640 f=0x0 r=1 > > --- ExpKill LRU x=3627041 > > --- ExpKill LRU_Cand p=0x7fa2388080c0 f=0x0 r=1 > > --- ExpKill LRU x=3696176 > > --- ExpKill LRU_Cand p=0x7fa236864680 f=0x0 r=1 > > --- ExpKill LRU x=3902662 > > --- ExpKill LRU_Cand p=0x7fa2402ca500 f=0x0 r=1 > > --- ExpKill LRU x=3696177 > > --- ExpKill LRU_Cand p=0x7fa238807dc0 f=0x0 r=1 > > --- ExpKill LRU x=3696178 > > --- ExpKill LRU_Cand p=0x7fa23eee1080 f=0x0 r=1 > > --- ExpKill LRU x=3902663 > > --- ExpKill LRU_Cand p=0x7fa23e73c580 f=0x0 r=1 > > --- ExpKill LRU x=3627042 > > --- ExpKill LRU_Cand p=0x7fa236c7a280 f=0x0 r=1 > > --- ExpKill LRU x=3627043 > > --- ExpKill LRU_Cand p=0x7fa23fa9a440 f=0x0 r=1 > > --- ExpKill LRU x=3696185 > > --- ExpKill LRU_Cand p=0x7fa236463200 f=0x0 r=1 > > --- ExpKill LRU x=3873739 > > --- ExpKill LRU_Cand p=0x7fa23faf6840 f=0x0 r=1 > > --- ExpKill LRU x=3627044 > > --- ExpKill LRU_Cand p=0x7fa23ca36780 f=0x0 r=1 > > --- ExpKill LRU x=3873740 > > --- ExpKill LRU_Cand p=0x7fa23ceb0f80 f=0x0 r=1 > > --- ExpKill LRU x=3784856 > > --- ExpKill LRU_Cand p=0x7fa2361702c0 f=0x0 r=1 > > --- ExpKill LRU x=3457616 > > --- ExpKill LRU_Cand p=0x7fa237402700 f=0x0 r=1 > > --- ExpKill LRU x=3784857 > > --- ExpKill LRU_Cand p=0x7fa23fe35a40 f=0x0 r=1 > > --- ExpKill LRU x=3901352 > > --- ExpKill LRU_Cand p=0x7fa236d032c0 f=0x0 r=1 > > --- ExpKill LRU x=3624875 > > --- ExpKill LRU_Cand p=0x7fa23689e2c0 f=0x0 r=1 > > --- ExpKill LRU x=3696197 > > --- ExpKill LRU_Cand p=0x7fa238808300 f=0x0 r=1 > > --- ExpKill LRU x=3873741 > > --- ExpKill LRU_Cand p=0x7fa23e746c00 f=0x0 r=1 > > --- ExpKill LRU x=3696198 > > --- ExpKill LRU_Cand p=0x7fa2364d7900 f=0x0 r=1 > > --- ExpKill LRU x=3696199 > > --- ExpKill LRU_Cand p=0x7fa236c777c0 f=0x0 r=1 > > --- ExpKill LRU x=3873742 > > --- ExpKill LRU_Cand p=0x7fa23fa99b40 f=0x0 r=1 > > --- ExpKill LRU x=3696200 > > --- ExpKill LRU_Cand p=0x7fa236c86880 f=0x0 r=1 > > --- ExpKill LRU x=3873743 > > --- ExpKill LRU_Cand p=0x7fa2368a30c0 f=0x0 r=1 > > --- ExpKill LRU x=3696201 > > --- ExpKill LRU_Cand p=0x7fa23fa9aa40 f=0x0 r=1 > > --- ExpKill LRU x=3460107 > > --- ExpKill LRU_Cand p=0x7fa23610b040 f=0x0 r=1 > > --- ExpKill LRU x=3460108 > > --- ExpKill LRU_Cand p=0x7fa23cea5f40 f=0x0 r=1 > > --- ExpKill LRU x=3724090 > > --- ExpKill LRU_Cand p=0x7fa23da433c0 f=0x0 r=1 > > --- ExpKill LRU x=3724091 > > --- ExpKill LRU_Cand p=0x7fa23611f140 f=0x0 r=1 > > --- ExpKill LRU x=3627063 > > --- ExpKill LRU_Cand p=0x7fa23ceac000 f=0x0 r=1 > > --- ExpKill LRU x=3724092 > > --- ExpKill LRU_Cand p=0x7fa23616f900 f=0x0 r=1 > > --- ExpKill LRU x=3720845 > > --- ExpKill LRU_Cand p=0x7fa236c6ef80 f=0x0 r=1 > > --- ExpKill LRU x=2487312 > > --- ExpKill LRU_Cand p=0x7fa238809bc0 f=0x0 r=1 > > --- ExpKill LRU x=3627066 > > --- ExpKill LRU_Cand p=0x7fa238320e00 f=0x0 r=1 > > --- ExpKill LRU x=3724093 > > --- ExpKill LRU_Cand p=0x7fa2364d8800 f=0x0 r=1 > > --- ExpKill LRU x=3902697 > > --- ExpKill LRU_Cand p=0x7fa24022cc00 f=0x0 r=1 > > --- ExpKill LRU x=3460117 > > --- ExpKill LRU_Cand p=0x7fa23fa999c0 f=0x0 r=1 > > --- ExpKill LRU x=3460118 > > --- ExpKill LRU_Cand p=0x7fa238320140 f=0x0 r=1 > > --- ExpKill LRU x=3724098 > > --- ExpKill LRU_Cand p=0x7fa236cd6340 f=0x0 r=1 > > --- ExpKill LRU x=3627069 > > --- ExpKill LRU_Cand p=0x7fa236109180 f=0x0 r=1 > > --- ExpKill LRU x=3724099 > > --- ExpKill LRU_Cand p=0x7fa23ceac0c0 f=0x0 r=1 > > --- ExpKill LRU x=3724100 > > --- ExpKill LRU_Cand p=0x7fa23ce69c80 f=0x0 r=1 > > --- ExpKill LRU x=3460122 > > --- ExpKill LRU_Cand p=0x7fa238320200 f=0x0 r=1 > > --- ExpKill LRU x=3724101 > > --- ExpKill LRU_Cand p=0x7fa23f205540 f=0x0 r=1 > > --- ExpKill LRU x=3724102 > > --- ExpKill LRU_Cand p=0x7fa23611f080 f=0x0 r=1 > > --- ExpKill LRU x=3627070 > > --- ExpKill LRU_Cand p=0x7fa236128880 f=0x0 r=1 > > --- ExpKill LRU x=3724103 > > --- ExpKill LRU reached nuke_limit > > --- FetchError Could not get storage > > --- BackendClose 32 default > > --- BereqAcct 229 0 229 471 106479616 106480087 > > --- End >
--- End Message ---