control: merge 954904 986356 thanks
Hi,
I have been playing not just with KVM (virbr0) but also chroot (lo:
127.0.0.1). I experience pretty much the same situation.
Let me go over your comment and also present a few observations.
On Mon, 2021-04-12 at 19:49 +0200, Eduard Bloch wrote:
> Hallo,
> * Osamu Aoki [Mon, Apr 05 2021, 08:32:30PM]:
> > Hi,
> > I created a script to check all broken repo contents across all debian
> > and security downloads.
> >
> > After fiddling with this problem, I realized few things on this apt-
> > cacher-ng problem.
> >
> > Broken downloads is not just deb file but I also saw truncated
> > InRelease file. But such problem is much fewer than simple missed
> > downloads. I see them in log.
>
> Hm, thank you for the verbose report. All the things you reported make
> me worry a lot. Yes, it sounds very much like 954904 all over again.
>
> For a while it did happen to me too, but it's a Heisenbug, I never
> managed to reliably catch it and after some refactoring it disappeared.
> I never trusted that outcome, thus 954904 is still open.
>
> If you don't mind, I would like to merge them
I did with this reply.
I am not sure if this is intentional but this odd cached InRelease file
is reproduceble.
Please take a look at attached script (use this after making your cache
data. This will erase them. Please execute this after reading all.)
Cached data takes about 9 downloads to get it finished. (Sometimes,
size shrinks a bit) This is very odd.
$ sudo ./test-acng01
stop and clean acng cache
total 0
drwxr-xr-x 1 apt-cacher-ng apt-cacher-ng 12 Apr 19 17:16 .
drwxr-xr-x 1 root root 414 Apr 19 11:22 ..
drwxr-xr-x 1 apt-cacher-ng apt-cacher-ng 64 Apr 14 09:17 .bss.d
new acng cache
total 0
drwxr-xr-x 1 apt-cacher-ng apt-cacher-ng 26 Apr 19 17:16 .
drwxr-xr-x 1 root root 414 Apr 19 11:22 ..
drwxr-xr-x 1 apt-cacher-ng apt-cacher-ng 64 Apr 14 09:17 .bss.d
drwxr-xr-x 1 apt-cacher-ng apt-cacher-ng 22 Apr 19 17:16 _xstore
● apt-cacher-ng.service - Apt-Cacher NG software download proxy
Loaded: loaded (/lib/systemd/system/apt-cacher-ng.service; enabled; vendor
preset: enabled)
Active: active (running) since Mon 2021-04-19 17:16:08 JST; 8ms ago
Main PID: 1716585 (apt-cacher-ng)
Tasks: 1 (limit: 37504)
Memory: 2.2M
CPU: 19ms
CGroup: /system.slice/apt-cacher-ng.service
└─1716585 /usr/sbin/apt-cacher-ng -c /etc/apt-cacher-ng
ForeGround=1
Apr 19 17:16:08 goofy systemd[1]: Starting Apt-Cacher NG software download
proxy...
Apr 19 17:16:08 goofy systemd[1]: Started Apt-Cacher NG software download proxy.
Hit:1 http://deb.debian.org/debian bullseye InRelease
Reading package lists... Done
========== After apt update: 1
Content-Length: 145864
-rw-r--r-T 1 apt-cacher-ng apt-cacher-ng 21120 Apr 19 17:16
/var/cache/apt-cacher-ng/debrep/dists/bullseye/InRelease
Hit:1 http://deb.debian.org/debian bullseye InRelease
Reading package lists... Done
========== After apt update: 2
Content-Length: 145864
-rw-r--r-T 1 apt-cacher-ng apt-cacher-ng 40044 Apr 19 17:16
/var/cache/apt-cacher-ng/debrep/dists/bullseye/InRelease
Hit:1 http://deb.debian.org/debian bullseye InRelease
Reading package lists... Done
========== After apt update: 3
Content-Length: 145864
-rw-r--r-T 1 apt-cacher-ng apt-cacher-ng 68312 Apr 19 17:16
/var/cache/apt-cacher-ng/debrep/dists/bullseye/InRelease
Hit:1 http://deb.debian.org/debian bullseye InRelease
Reading package lists... Done
========== After apt update: 4
Content-Length: 145864
-rw-r--r-T 1 apt-cacher-ng apt-cacher-ng 68311 Apr 19 17:16
/var/cache/apt-cacher-ng/debrep/dists/bullseye/InRelease
Hit:1 http://deb.debian.org/debian bullseye InRelease
Reading package lists... Done
========== After apt update: 5
Content-Length: 145864
-rw-r--r-T 1 apt-cacher-ng apt-cacher-ng 95062 Apr 19 17:16
/var/cache/apt-cacher-ng/debrep/dists/bullseye/InRelease
Hit:1 http://deb.debian.org/debian bullseye InRelease
Reading package lists... Done
========== After apt update: 6
Content-Length: 145864
-rw-r--r-T 1 apt-cacher-ng apt-cacher-ng 115395 Apr 19 17:16
/var/cache/apt-cacher-ng/debrep/dists/bullseye/InRelease
Hit:1 http://deb.debian.org/debian bullseye InRelease
Reading package lists... Done
========== After apt update: 7
Content-Length: 145864
-rw-r--r-T 1 apt-cacher-ng apt-cacher-ng 115394 Apr 19 17:16
/var/cache/apt-cacher-ng/debrep/dists/bullseye/InRelease
Hit:1 http://deb.debian.org/debian bullseye InRelease
Reading package lists... Done
========== After apt update: 8
Content-Length: 145864
-rw-r--r-T 1 apt-cacher-ng apt-cacher-ng 134318 Apr 19 17:16
/var/cache/apt-cacher-ng/debrep/dists/bullseye/InRelease
Hit:1 http://deb.debian.org/debian bullseye InRelease
Reading package lists... Done
========== After apt update: 9
Content-Length: 145864
-rw-r--r-T 1 apt-cacher-ng apt-cacher-ng 145864 Apr 19 17:16
/var/cache/apt-cacher-ng/debrep/dists/bullseye/InRelease
Hit:1 http://deb.debian.org/debian bullseye InRelease
Reading package lists... Done
========== After apt update: 10
Content-Length: 145864
-rw-r--r-T 1 apt-cacher-ng apt-cacher-ng 145864 Apr 19 17:16
/var/cache/apt-cacher-ng/debrep/dists/bullseye/InRelease
...
Also, I see rare use of file permission:
-rw-r--r-T 1 apt-cacher-ng apt-cacher-ng 145864 Apr 19 16:11 InRelease
-rw-r--r-- 1 apt-cacher-ng apt-cacher-ng 219 Apr 19 16:11 InRelease.head
What is this "T"???
> > So after fixing apt-cacher-ng data with attached script, running apt
> > again goes smoothly.
>
> Yes, but the question is for how long. I am preparing a bigger upstream
> release right now, where the logics of file storage are overhauled to a
> large extent. This might solve your issue along the way. Especially,
> there won't be truncation of payload anymore, therefore no risk of
> getting into such trouble by design.
I understand. It is very complicated for me. Is this partial
mirroring a intentional feature? If so, I will not worry.
Most annoying this is failed download of deb files.
502 errors are most typical issue. I counted errors in the log I
previously posted.
2 apt-cacher.error.500.log
0 apt-cacher.error.501.log
2683 apt-cacher.error.502.log
43 apt-cacher.error.503.log
2728 apt-cacher.error.log
5456 total
In those cases, deb file are not cached yet. This is the annoying one.
I am not sure but have a feeling that this may be caused by many high
rate request to fetch file by apt-cacher-ng and my ISP start choking IP
connection. This fetch failure seems to happen when download exceepd
something like 5-10 GB size in less than a minutes. That's 1 hour
video data.
Any internal connection have bit rate around 30 Gbps. But outgoing is
about 0.5 Gbps as max speed. Does this apparent access speed differece
cause problem? I don't know. Maybe I should use "tc" to test.
> If you have a good environment to reproduce that issue, would you
> volunteer to test it in a couple of weeks? (or maybe even sooner, cannot
> tell yet)
>
> > As I read over BTS, I saw interesting one on approx BTS. Debian Bug
> > report logs - #884713
> > https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=884713 Under
> > systemd, socket activation is rate limited.
> >
> > This socket activation limit may be the root cause. What do you think?
>
> See /lib/systemd/system/apt-cacher-ng.service , socket activation is not
> used by default. Also it wouldn't explain sudden trancation in the
> cache.
Yes. You are right.
test-acng01.xz
Description: application/xz
