Debian Bug report logs - #960304
snapshot.debian.org: Snapshot repo repeatedly cutting off connection, returning partial content

Package: snapshot.debian.org; Maintainer for snapshot.debian.org is snapshot.debian.org Team <debian-snapshot@lists.debian.org>;

Reported by: Chanseok Oh <chanseok@google.com>

Date: Mon, 11 May 2020 16:51:02 UTC

Severity: important

Done: Julien Cristau <jcristau@debian.org>

Bug is archived. No further changes may be made.

Toggle useless messages

View this report as an mbox folder, status mbox, maintainer mbox


Report forwarded to debian-bugs-dist@lists.debian.org, snapshot.debian.org Team <debian-snapshot@lists.debian.org>:
Bug#960304; Package snapshot.debian.org. (Mon, 11 May 2020 16:51:04 GMT) (full text, mbox, link).


Acknowledgement sent to Chanseok Oh <chanseok@google.com>:
New Bug report received and forwarded. Copy sent to snapshot.debian.org Team <debian-snapshot@lists.debian.org>. (Mon, 11 May 2020 16:51:04 GMT) (full text, mbox, link).


Message #5 received at submit@bugs.debian.org (full text, mbox, reply):

From: Chanseok Oh <chanseok@google.com>
To: Debian Bug Tracking System <submit@bugs.debian.org>
Subject: snapshot.debian.org: Snapshot repo repeatedly cutting off connection, returning partial content
Date: Mon, 11 May 2020 12:47:33 -0400
[Message part 1 (text/plain, inline)]
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
[Message part 2 (text/html, inline)]

Information forwarded to debian-bugs-dist@lists.debian.org, snapshot.debian.org Team <debian-snapshot@lists.debian.org>:
Bug#960304; Package snapshot.debian.org. (Tue, 13 Oct 2020 10:48:02 GMT) (full text, mbox, link).


Acknowledgement sent to Zoran Dželajlija <debian-bts@jelly.kladdkaka.org>:
Extra info received and forwarded to list. Copy sent to snapshot.debian.org Team <debian-snapshot@lists.debian.org>. (Tue, 13 Oct 2020 10:48:02 GMT) (full text, mbox, link).


Message #10 received at 960304@bugs.debian.org (full text, mbox, reply):

From: Zoran Dželajlija <debian-bts@jelly.kladdkaka.org>
To: Debian Bug Tracking System <960304@bugs.debian.org>
Subject: Re: snapshot.debian.org: Snapshot repo repeatedly cutting off connection, returning partial content
Date: Tue, 13 Oct 2020 12:37:20 +0200
Package: snapshot.debian.org
Followup-For: Bug #960304

Hi, this issue persists/reappears and makes snapshot.d.o unusable via apt for
any large package.  Reproduced from IP addresses in , ipv4 and ipv6
connectivity.

From an .hr IP:

[11:09] /tmp => wget -nd https://snapshot.debian.org/archive/debian/20200917T084540Z/pool/main/libr/libreoffice/libreoffice-dbg_4.3.3-2%2Bdeb8u11_amd64.deb
--2020-10-13 11:09:24--  https://snapshot.debian.org/archive/debian/20200917T084540Z/pool/main/libr/libreoffice/libreoffice-dbg_4.3.3-2%2Bdeb8u11_amd64.deb
Resolving snapshot.debian.org (snapshot.debian.org)... 2001:630:206:4000:1a1a:0:c13e:ca1b, 2001:1af8:4020:b030:deb::185, 185.17.185.185, ...
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: 739029194 (705M)
Saving to: ‘libreoffice-dbg_4.3.3-2+deb8u11_amd64.deb’

libreoffice-dbg_4.3.3-2+deb8u11_amd64.deb         3%[==>                                                                                                   ]  27.06M  19.7MB/s    in 1.4s    

2020-10-13 11:09:26 (19.7 MB/s) - Connection closed at byte 28377088. Retrying.

--2020-10-13 11:09:27--  (try: 2)  https://snapshot.debian.org/archive/debian/20200917T084540Z/pool/main/libr/libreoffice/libreoffice-dbg_4.3.3-2%2Bdeb8u11_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: 739029194 (705M), 710652106 (678M) remaining
Saving to: ‘libreoffice-dbg_4.3.3-2+deb8u11_amd64.deb’

libreoffice-dbg_4.3.3-2+deb8u11_amd64.deb         7%[+++===>                                                                                               ]  50.31M  17.4MB/s    in 1.3s    

2020-10-13 11:09:28 (17.4 MB/s) - Connection closed at byte 52756480. Retrying.

--2020-10-13 11:09:30--  (try: 3)  https://snapshot.debian.org/archive/debian/20200917T084540Z/pool/main/libr/libreoffice/libreoffice-dbg_4.3.3-2%2Bdeb8u11_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: 739029194 (705M), 686272714 (654M) remaining
Saving to: ‘libreoffice-dbg_4.3.3-2+deb8u11_amd64.deb’

libreoffice-dbg_4.3.3-2+deb8u11_amd64.deb         9%[+++++++=>                                                                                             ]  66.34M  14.6MB/s    in 1.1s    

2020-10-13 11:09:31 (14.6 MB/s) - Connection closed at byte 69566464. Retrying.

^C

Another try from a .de IP:

y% wget -4 -nd https://snapshot.debian.org/archive/debian/20200917T084540Z/pool/main/libr/libreoffice/libreoffice-dbg_4.3.3-2%2Bdeb8u11_amd64.deb
--2020-10-13 10:34:28--  https://snapshot.debian.org/archive/debian/20200917T084540Z/pool/main/libr/libreoffice/libreoffice-dbg_4.3.3-2%2Bdeb8u11_amd64.deb
Resolving snapshot.debian.org (snapshot.debian.org)... 193.62.202.27, 185.17.185.185
Connecting to snapshot.debian.org (snapshot.debian.org)|193.62.202.27|:443... connected.
HTTP request sent, awaiting response... 200 OK
Length: 739029194 (705M)
Saving to: ‘libreoffice-dbg_4.3.3-2+deb8u11_amd64.deb’

libreoffice-dbg_4.3.3-2+deb8u11_amd64.deb         6%[=====>                                                                                                  ]  46,56M  50,4MB/s   in 0,9s   

2020-10-13 10:34:29 (50,4 MB/s) - Connection closed at byte 48824320. Retrying.

--2020-10-13 10:34:30--  (try: 2)  https://snapshot.debian.org/archive/debian/20200917T084540Z/pool/main/libr/libreoffice/libreoffice-dbg_4.3.3-2%2Bdeb8u11_amd64.deb
Connecting to snapshot.debian.org (snapshot.debian.org)|193.62.202.27|:443... connected.
HTTP request sent, awaiting response... 206 Partial Content
Length: 739029194 (705M), 690204874 (658M) remaining
Saving to: ‘libreoffice-dbg_4.3.3-2+deb8u11_amd64.deb’

libreoffice-dbg_4.3.3-2+deb8u11_amd64.deb        18%[++++++============>                                                                                     ] 131,44M  46,5MB/s   in 1,8s   

2020-10-13 10:34:32 (46,5 MB/s) - Connection closed at byte 137822208. Retrying.

--2020-10-13 10:34:34--  (try: 3)  https://snapshot.debian.org/archive/debian/20200917T084540Z/pool/main/libr/libreoffice/libreoffice-dbg_4.3.3-2%2Bdeb8u11_amd64.deb
Connecting to snapshot.debian.org (snapshot.debian.org)|193.62.202.27|:443... connected.
HTTP request sent, awaiting response... 206 Partial Content
Length: 739029194 (705M), 601206986 (573M) remaining
Saving to: ‘libreoffice-dbg_4.3.3-2+deb8u11_amd64.deb’

libreoffice-dbg_4.3.3-2+deb8u11_amd64.deb        23%[+++++++++++++++++++====>                                                                                ] 163,00M  35,9MB/s   in 0,9s   

2020-10-13 10:34:35 (35,9 MB/s) - Connection closed at byte 170917888. Retrying.

^C

Regards,
Zoran

*** Reporter, please consider answering these questions, where appropriate ***

   * What led up to the situation?
   * What exactly did you do (or not do) that was effective (or
     ineffective)?
   * What was the outcome of this action?
   * What outcome did you expect instead?

*** End of the template - remove these template lines ***


-- System Information:
Debian Release: 10.4
  APT prefers stable
  APT policy: (990, 'stable'), (500, 'stable-updates'), (500, 'proposed-updates'), (1, 'experimental')
Architecture: i386 (x86_64)
Foreign Architectures: amd64

Kernel: Linux 5.4.0-0.bpo.4-amd64 (SMP w/4 CPU cores)
Kernel taint flags: TAINT_UNSIGNED_MODULE
Locale: LANG=C.UTF-8, LC_CTYPE=hr_HR.UTF-8 (charmap=UTF-8), LANGUAGE=C.UTF-8 (charmap=UTF-8)
Shell: /bin/sh linked to /bin/dash
Init: systemd (via /run/systemd/system)
LSM: AppArmor: enabled

Information forwarded to debian-bugs-dist@lists.debian.org, snapshot.debian.org Team <debian-snapshot@lists.debian.org>:
Bug#960304; Package snapshot.debian.org. (Tue, 13 Oct 2020 11:24:04 GMT) (full text, mbox, link).


Acknowledgement sent to Björn Stenberg <bjorn@haxx.se>:
Extra info received and forwarded to list. Copy sent to snapshot.debian.org Team <debian-snapshot@lists.debian.org>. (Tue, 13 Oct 2020 11:24:04 GMT) (full text, mbox, link).


Message #15 received at 960304@bugs.debian.org (full text, mbox, reply):

From: Björn Stenberg <bjorn@haxx.se>
To: 960304@bugs.debian.org
Subject: Re: snapshot.debian.org: Snapshot repo repeatedly cutting off connection, returning partial content
Date: Tue, 13 Oct 2020 13:21:33 +0200
[Message part 1 (text/plain, inline)]
Severity: serious

This problem is still present, and is making the snapshot service unusable
for many people.

At the time of writing, this is the status:

$ wget
https://snapshot.debian.org/archive/debian/20200917T084540Z/pool/main/libr/libreoffice/libreoffice-dbg_4.3.3-2%2Bdeb8u11_amd64.deb
--2020-10-13 12:50:28--
https://snapshot.debian.org/archive/debian/20200917T084540Z/pool/main/libr/libreoffice/libreoffice-dbg_4.3.3-2%2Bdeb8u11_amd64.deb
Resolving snapshot.debian.org (snapshot.debian.org)... 193.62.202.27,
185.17.185.185, 2001:630:206:4000:1a1a:0:c13e:ca1b, ...
Connecting to snapshot.debian.org (snapshot.debian.org)|193.62.202.27|:443...
connected.
HTTP request sent, awaiting response... 200 OK
Length: 739029194 (705M)
Saving to: ‘libreoffice-dbg_4.3.3-2+deb8u11_amd64.deb.4’

libreoffice-dbg_4.3.3-2+deb8   3%[>
   ]  25,03M  11,1MB/s    in 2,3s

2020-10-13 12:50:31 (11,1 MB/s) - Connection closed at byte 26247168.
Retrying.

--2020-10-13 12:50:32--  (try: 2)
https://snapshot.debian.org/archive/debian/20200917T084540Z/pool/main/libr/libreoffice/libreoffice-dbg_4.3.3-2%2Bdeb8u11_amd64.deb
Connecting to snapshot.debian.org (snapshot.debian.org)|193.62.202.27|:443...
connected.
HTTP request sent, awaiting response... 206 Partial Content
Length: 739029194 (705M), 712782026 (680M) remaining
Saving to: ‘libreoffice-dbg_4.3.3-2+deb8u11_amd64.deb.4’

libreoffice-dbg_4.3.3-2+deb8   7%[+=>
   ]  52,22M  10,9MB/s    in 2,5s

2020-10-13 12:50:34 (10,9 MB/s) - Connection closed at byte 54755328.
Retrying.

--2020-10-13 12:50:36--  (try: 3)
https://snapshot.debian.org/archive/debian/20200917T084540Z/pool/main/libr/libreoffice/libreoffice-dbg_4.3.3-2%2Bdeb8u11_amd64.deb
Connecting to snapshot.debian.org (snapshot.debian.org)|193.62.202.27|:443...
connected.
HTTP request sent, awaiting response... 206 Partial Content
Length: 739029194 (705M), 684273866 (653M) remaining
Saving to: ‘libreoffice-dbg_4.3.3-2+deb8u11_amd64.deb.4’

libreoffice-dbg_4.3.3-2+deb8   9%[+++>
    ]  66,02M  9,89MB/s    in 1,4s

2020-10-13 12:50:38 (9,89 MB/s) - Connection closed at byte 69222400.
Retrying.

--2020-10-13 12:50:41--  (try: 4)
https://snapshot.debian.org/archive/debian/20200917T084540Z/pool/main/libr/libreoffice/libreoffice-dbg_4.3.3-2%2Bdeb8u11_amd64.deb
Connecting to snapshot.debian.org (snapshot.debian.org)|193.62.202.27|:443...
connected.
HTTP request sent, awaiting response... 206 Partial Content
Length: 739029194 (705M), 669806794 (639M) remaining
Saving to: ‘libreoffice-dbg_4.3.3-2+deb8u11_amd64.deb.4’

libreoffice-dbg_4.3.3-2+deb8  12%[++++>
   ]  88,97M  10,5MB/s    in 2,2s

2020-10-13 12:50:44 (10,5 MB/s) - Connection closed at byte 93290496.
Retrying.

^C
$

As you can see, the connection is forcibly closed by the server and wget
has to retry repeatedly. Apt does not retry connections by default, instead
it fails completely. You have to rerun the apt command again and again
until all packages are successfully downloaded, which can require a large
number of retries and a very long time.

It is not always trivial to trigger this bug. It comes and goes with time,
perhaps due to general network load. One rather reliable way of triggering
it seems to be to install buster on a machine and then dist-upgrade to a
recent snapshot. This results in a large number of downloads, which
snapshot eventually starts to abort. Once it has started
aborting downloads, the bug can be triggered by plain wget or curl calls.

The source of the problem is unidentified, but one guess is that Varnish
somehow erroneously interprets the rapid file accesses as a
denial-of-service attack and applies restrictions.

/Björn
[Message part 2 (text/html, inline)]

Information forwarded to debian-bugs-dist@lists.debian.org, snapshot.debian.org Team <debian-snapshot@lists.debian.org>:
Bug#960304; Package snapshot.debian.org. (Sat, 02 Jan 2021 22:48:02 GMT) (full text, mbox, link).


Message #18 received at 960304@bugs.debian.org (full text, mbox, reply):

From: Johannes Schauer Marin Rodrigues <josch@debian.org>
To: 960304@bugs.debian.org, 969906@bugs.debian.org, 977653@bugs.debian.org
Cc: stefanoshaliassos@gmail.com, chanseok@google.com
Subject: avoiding and recovering from snapshot.d.o rate-limiting
Date: Sat, 02 Jan 2021 23:46:23 +0100
[Message part 1 (text/plain, inline)]
Hi,

as the author of metasnap, debrebuild and debbisect (all using snapshot.d.o) I
thought that maybe it makes sense to post to these bugs what I learned about
how to reliably pull data from snapshot.d.o.

For the most reliable and stable solution (has been able to download stuff for
over three months without unrecoverable errors) I recommend to look at the
function download() in the metasnap source code:

https://salsa.debian.org/josch/metasnap/-/blob/master/run.py#L129

To run stable the code:

 - throttles the number of requests such that each request takes a minimum of
   1.5 seconds which allows about 2200 connections per hour
 - is able to recover from infinite timeouts
 - is able to handle HTTP errors 500
 - recovers after E_COULDNT_CONNECT errors
 - backs off for four seconds (less do not work) to the power of number of retries

The second-best solution is implemented by debbisect. Since the same packages
are required multiple times, it builds a local cache of the packages and then
apt only sees that cache. The caching code borrows some of the things I learned
from writing metasnap and seems to run reasonably well. See the _download_new()
function in the Proxy class:

https://salsa.debian.org/debian/devscripts/-/blob/master/scripts/debbisect#L159

Thirdly, debrebuild only needs packages once, so a cache doesn't make sense.
Instead we try to do the best we can just using apt options. The following
options seem to work okay. If it still fails, retrying works most of the time.

   Acquire::Check-Valid-Until "false";
   Acquire::http::Dl-Limit "1000";
   Acquire::https::Dl-Limit "1000";
   Acquire::Retries "5";

https://salsa.debian.org/debian/devscripts/-/blob/master/scripts/debrebuild

Maybe my next project will be an overlay for snapshot.d.o which provides a sane
rate limiting and throttles the bandwidth instead of cutting connections,
refusing new connections or throwing HTTP 500 errors...

Thanks!

cheers, josch
[signature.asc (application/pgp-signature, inline)]

Information forwarded to debian-bugs-dist@lists.debian.org, snapshot.debian.org Team <debian-snapshot@lists.debian.org>:
Bug#960304; Package snapshot.debian.org. (Wed, 04 Aug 2021 08:57:03 GMT) (full text, mbox, link).


Acknowledgement sent to Julien Cristau <jcristau@debian.org>:
Extra info received and forwarded to list. Copy sent to snapshot.debian.org Team <debian-snapshot@lists.debian.org>. (Wed, 04 Aug 2021 08:57:03 GMT) (full text, mbox, link).


Message #23 received at 960304@bugs.debian.org (full text, mbox, reply):

From: Julien Cristau <jcristau@debian.org>
To: Chanseok Oh <chanseok@google.com>, 960304@bugs.debian.org, dsa@debian.org
Subject: Re: Bug#960304: snapshot.debian.org: Snapshot repo repeatedly cutting off connection, returning partial content
Date: Wed, 4 Aug 2021 10:55:09 +0200
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            




Reply sent to Julien Cristau <jcristau@debian.org>:
You have taken responsibility. (Wed, 04 Aug 2021 12:36:02 GMT) (full text, mbox, link).


Notification sent to Chanseok Oh <chanseok@google.com>:
Bug acknowledged by developer. (Wed, 04 Aug 2021 12:36:02 GMT) (full text, mbox, link).


Message #28 received at 960304-done@bugs.debian.org (full text, mbox, reply):

From: Julien Cristau <jcristau@debian.org>
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
Date: Wed, 4 Aug 2021 14:32:01 +0200
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            
> 



Information forwarded to debian-bugs-dist@lists.debian.org, snapshot.debian.org Team <debian-snapshot@lists.debian.org>:
Bug#960304; Package snapshot.debian.org. (Thu, 05 Aug 2021 10:48:03 GMT) (full text, mbox, link).


Message #31 received at 960304@bugs.debian.org (full text, mbox, reply):

From: Johannes Schauer Marin Rodrigues <josch@debian.org>
To: jcristau@debian.org
Cc: 960304@bugs.debian.org, chanseok@google.com, dsa@debian.org
Subject: Re: Bug#960304: snapshot.debian.org: Snapshot repo repeatedly cutting off connection, returning partial content
Date: Thu, 05 Aug 2021 12:36:02 +0200
[Message part 1 (text/plain, inline)]
References:

Hi Julien,

On Wed, 4 Aug 2021 10:55:09 +0200 Julien Cristau <jcristau@debian.org> wrote:
> 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.

thanks a lot for looking into this!

Maybe some problems are gone now, but when I drop the measures in my code that
implemented the heavy throttling that was necessary in the past, I now run into
the same problems like before. So as far as my use of snapshot.d.o goes, it
doesn't seem as if anything has changed.

Can you confirm that I still need to limit my download speed to a certain
number of bytes per second or limit the number of files I download per hour
below a certain threshold?

Thanks!

cheers, josch
[signature.asc (application/pgp-signature, inline)]

Information forwarded to debian-bugs-dist@lists.debian.org, snapshot.debian.org Team <debian-snapshot@lists.debian.org>:
Bug#960304; Package snapshot.debian.org. (Thu, 05 Aug 2021 11:48:02 GMT) (full text, mbox, link).


Acknowledgement sent to Julien Cristau <jcristau@debian.org>:
Extra info received and forwarded to list. Copy sent to snapshot.debian.org Team <debian-snapshot@lists.debian.org>. (Thu, 05 Aug 2021 11:48:02 GMT) (full text, mbox, link).


Message #36 received at 960304@bugs.debian.org (full text, mbox, reply):

From: Julien Cristau <jcristau@debian.org>
To: Johannes Schauer Marin Rodrigues <josch@debian.org>
Cc: 960304@bugs.debian.org, dsa@debian.org
Subject: Re: Bug#960304: snapshot.debian.org: Snapshot repo repeatedly cutting off connection, returning partial content
Date: Thu, 5 Aug 2021 13:45:15 +0200
On Thu, Aug 05, 2021 at 12:36:02PM +0200, Johannes Schauer Marin Rodrigues wrote:
> On Wed, 4 Aug 2021 10:55:09 +0200 Julien Cristau <jcristau@debian.org> wrote:
> > 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.
> 
> thanks a lot for looking into this!
> 
> Maybe some problems are gone now, but when I drop the measures in my code that
> implemented the heavy throttling that was necessary in the past, I now run into
> the same problems like before. So as far as my use of snapshot.d.o goes, it
> doesn't seem as if anything has changed.
> 
> Can you confirm that I still need to limit my download speed to a certain
> number of bytes per second or limit the number of files I download per hour
> below a certain threshold?
> 
We cap new connections, but there's no limit on download speed as far as
I know.

Cheers,
Julien



Information forwarded to debian-bugs-dist@lists.debian.org, snapshot.debian.org Team <debian-snapshot@lists.debian.org>:
Bug#960304; Package snapshot.debian.org. (Thu, 05 Aug 2021 17:18:02 GMT) (full text, mbox, link).


Message #39 received at 960304@bugs.debian.org (full text, mbox, reply):

From: Johannes Schauer Marin Rodrigues <josch@debian.org>
To: Julien Cristau <jcristau@debian.org>
Cc: 960304@bugs.debian.org, dsa@debian.org
Subject: Re: Bug#960304: snapshot.debian.org: Snapshot repo repeatedly cutting off connection, returning partial content
Date: Thu, 05 Aug 2021 19:15:29 +0200
[Message part 1 (text/plain, inline)]
Hi Julien,

Quoting Julien Cristau (2021-08-05 13:45:15)
> > Can you confirm that I still need to limit my download speed to a certain
> > number of bytes per second or limit the number of files I download per hour
> > below a certain threshold?
> > 
> We cap new connections, but there's no limit on download speed as far as I
> know.

could the download limits, be it rate-limit or connection limit be documented
somewhere?

I'm maintaining a number of tools and services in Debian (debrebuild,
debbisect, metasnap, debootsnap) that interface with snapshot.d.o and while I
managed to figure out some settings that seem to work by trial and error, it
would be great if the tools we ship in Debian could properly respect the
download limits of snapshot.d.o.

Thanks!

cheers, josch
[signature.asc (application/pgp-signature, inline)]

Information forwarded to debian-bugs-dist@lists.debian.org, snapshot.debian.org Team <debian-snapshot@lists.debian.org>:
Bug#960304; Package snapshot.debian.org. (Fri, 06 Aug 2021 08:12:03 GMT) (full text, mbox, link).


Acknowledgement sent to Mike Hommey <mh+reportbug@glandium.org>:
Extra info received and forwarded to list. Copy sent to snapshot.debian.org Team <debian-snapshot@lists.debian.org>. (Fri, 06 Aug 2021 08:12:03 GMT) (full text, mbox, link).


Message #44 received at 960304@bugs.debian.org (full text, mbox, reply):

From: Mike Hommey <mh+reportbug@glandium.org>
To: Debian Bug Tracking System <960304@bugs.debian.org>
Subject: Re: snapshot.debian.org: Snapshot repo repeatedly cutting off connection, returning partial content
Date: Fri, 06 Aug 2021 17:08:40 +0900
Package: snapshot.debian.org
Followup-For: Bug #960304

Dear Maintainer,

We're hitting this problem regularly on Mozilla CI (from using dget),
and what is probably a variant of this bug with apt, which fails with,
for example:

[task 2021-08-05T21:27:09.094Z] Err:187 http://snapshot.debian.org/archive/debian/20210208T213147Z jessie/main amd64 adwaita-icon-theme all 3.14.0-2
[task 2021-08-05T21:27:09.094Z]   Undetermined Error [IP: 193.62.202.27 80]
(...)
[task 2021-08-05T21:27:23.590Z] Err:202 http://snapshot.debian.org/archive/debian/20210208T213147Z jessie/main amd64 libicu52 amd64 52.1-8+deb8u7
[task 2021-08-05T21:27:23.591Z]   Undetermined Error [IP: 193.62.202.27 80]
(...)
[task 2021-08-05T21:28:41.210Z] E: Failed to fetch http://snapshot.debian.org/archive/debian/20210208T213147Z/pool/main/a/adwaita-icon-theme/adwaita-icon-theme_3.14.0-2_all.deb  Undetermined Error [IP: 193.62.202.27 80]
[task 2021-08-05T21:28:41.210Z] E: Failed to fetch http://snapshot.debian.org/archive/debian/20210208T213147Z/pool/main/i/icu/libicu52_52.1-8+deb8u7_amd64.deb  Undetermined Error [IP: 193.62.202.27 80]

Corresponding server-side log for the same url:
54.162.202.139 - - [05/Aug/2021:21:27:08 +0000] "GET http://snapshot.debian.org/archive/debian/20210208T213147Z/pool/main/a/adwaita-icon-theme/adwaita-icon-theme_3.14.0-2_all.deb HTTP/1.1" 200 3518464 "-" "Debian APT-HTTP/1.3 (1.8.2.2)"
54.202.218.195 - - [05/Aug/2021:21:39:12 +0000] "GET http://snapshot.debian.org/archive/debian/20210208T213147Z/pool/main/a/adwaita-icon-theme/adwaita-icon-theme_3.14.0-2_all.deb HTTP/1.1" 200 9978092 "-" "Debian APT-HTTP/1.3 (1.8.2.2)"

Mike



Information forwarded to debian-bugs-dist@lists.debian.org, snapshot.debian.org Team <debian-snapshot@lists.debian.org>:
Bug#960304; Package snapshot.debian.org. (Fri, 06 Aug 2021 10:09:02 GMT) (full text, mbox, link).


Acknowledgement sent to Julien Cristau <jcristau@debian.org>:
Extra info received and forwarded to list. Copy sent to snapshot.debian.org Team <debian-snapshot@lists.debian.org>. (Fri, 06 Aug 2021 10:09:02 GMT) (full text, mbox, link).


Message #49 received at 960304@bugs.debian.org (full text, mbox, reply):

From: Julien Cristau <jcristau@debian.org>
To: Mike Hommey <mh+reportbug@glandium.org>, 960304@bugs.debian.org
Subject: Re: Bug#960304: snapshot.debian.org: Snapshot repo repeatedly cutting off connection, returning partial content
Date: Fri, 6 Aug 2021 12:07:52 +0200
On Fri, Aug 06, 2021 at 05:08:40PM +0900, Mike Hommey wrote:
> Package: snapshot.debian.org
> Followup-For: Bug #960304
> 
> Dear Maintainer,
> 
> We're hitting this problem regularly on Mozilla CI (from using dget),
> and what is probably a variant of this bug with apt, which fails with,
> for example:
> 
> [task 2021-08-05T21:27:09.094Z] Err:187 http://snapshot.debian.org/archive/debian/20210208T213147Z jessie/main amd64 adwaita-icon-theme all 3.14.0-2
> [task 2021-08-05T21:27:09.094Z]   Undetermined Error [IP: 193.62.202.27 80]
> (...)
> [task 2021-08-05T21:27:23.590Z] Err:202 http://snapshot.debian.org/archive/debian/20210208T213147Z jessie/main amd64 libicu52 amd64 52.1-8+deb8u7
> [task 2021-08-05T21:27:23.591Z]   Undetermined Error [IP: 193.62.202.27 80]
> (...)
> [task 2021-08-05T21:28:41.210Z] E: Failed to fetch http://snapshot.debian.org/archive/debian/20210208T213147Z/pool/main/a/adwaita-icon-theme/adwaita-icon-theme_3.14.0-2_all.deb  Undetermined Error [IP: 193.62.202.27 80]
> [task 2021-08-05T21:28:41.210Z] E: Failed to fetch http://snapshot.debian.org/archive/debian/20210208T213147Z/pool/main/i/icu/libicu52_52.1-8+deb8u7_amd64.deb  Undetermined Error [IP: 193.62.202.27 80]
> 
> Corresponding server-side log for the same url:
> 54.162.202.139 - - [05/Aug/2021:21:27:08 +0000] "GET http://snapshot.debian.org/archive/debian/20210208T213147Z/pool/main/a/adwaita-icon-theme/adwaita-icon-theme_3.14.0-2_all.deb HTTP/1.1" 200 3518464 "-" "Debian APT-HTTP/1.3 (1.8.2.2)"
> 54.202.218.195 - - [05/Aug/2021:21:39:12 +0000] "GET http://snapshot.debian.org/archive/debian/20210208T213147Z/pool/main/a/adwaita-icon-theme/adwaita-icon-theme_3.14.0-2_all.deb HTTP/1.1" 200 9978092 "-" "Debian APT-HTTP/1.3 (1.8.2.2)"
> 
Hi,

it looks like yesterday's config change wasn't enough, and we still hit
"LRU reached nuke_limit" / "Could not get storage" errors in varnish
(except now only with files that are smaller than 10MB, since we no
longer cache larger ones).  Will need to figure out the right tradeoffs.

Thanks,
Julien



Bug archived. Request was from Debbugs Internal Request <owner@bugs.debian.org> to internal_control@bugs.debian.org. (Sat, 04 Sep 2021 07:24:35 GMT) (full text, mbox, link).


Send a report that this bug log contains spam.


Debian bug tracking system administrator <owner@bugs.debian.org>. Last modified: Wed May 17 12:28:22 2023; Machine Name: buxtehude

Debian Bug tracking system

Debbugs is free software and licensed under the terms of the GNU Public License version 2. The current version can be obtained from https://bugs.debian.org/debbugs-source/.

Copyright © 1999 Darren O. Benham, 1997,2003 nCipher Corporation Ltd, 1994-97 Ian Jackson, 2005-2017 Don Armstrong, and many other contributors.