Ubuntu
apt package

  1. Bug #2003851
  2. Comment #4

Comment 4 for bug 2003851

Revision history for this message
Walter (wdoekes) wrote :

Okay. I got some pcaps now. And apparently our apt-cacher-ng proxy sometimes serves:

- an InRelease
- with a 200 OK
- and a non-zero Content-Length
- BUT, no content, but instead a TCP-FIN.

Under the right circumstances, this causes apt to stall forever.

The right circumstances seem to include:

- a valid download (or 304) from the same host
- a valid download from another host

---

I created a test server, and got this to reproduce with apt 2.4.9 (from jammy-proposed):

=====================================
sources.list
=====================================
deb http://junk.devs.nu:3851/ubuntu jammy main
deb http://junk.devs.nu:3851/ubuntu jammy-updates main
deb [arch=amd64 signed-by=/etc/apt/keyrings/zabbix.gpg] http://repo.zabbix.com/zabbix/6.2/ubuntu jammy main

=====================================
server.py logs
=====================================
13:31:58 [2771009] client connected: ('217.21.199.56', 42838)
13:31:58 [2771009] client said: b'GET /ubuntu/dists/jammy/InRelease HTTP/1.1\r\nHost: junk.devs.nu:3851\r\nCache-Control: max-age=0\r\nAccept: text/*\r\nUser-Agent: Debian APT-HTTP/1.3 (2.4.9) non-interactive\r\n\r\n'
13:31:58 [2771009] we say: 200 and serve local InRelease
13:31:58 [2771009] client said: b'GET /ubuntu/dists/jammy-updates/InRelease HTTP/1.1\r\nHost: junk.devs.nu:3851\r\nCache-Control: max-age=0\r\nAccept: text/*\r\nUser-Agent: Debian APT-HTTP/1.3 (2.4.9) non-interactive\r\n\r\n'
13:31:58 [2771009] we say: 200 but serve a FIN
13:31:58 [2771009] client said: b''
13:31:58 [2771009] client disconnected: ('217.21.199.56', 42838)

=====================================
apt-get update -o Debug::Acquire::http=1
=====================================
0% [Connecting to junk.devs.nu] [Connecting to repo.zabbix.com (2604:a880:2:d0::2062:d001)]GET /zabbix/6.2/ubuntu/dists/jammy/InRelease HTTP/1.1
Host: repo.zabbix.com
Cache-Control: max-age=0
Accept: text/*
If-Modified-Since: Wed, 01 Feb 2023 15:02:57 GMT
User-Agent: Debian APT-HTTP/1.3 (2.4.9) non-interactive

Answer for: http://repo.zabbix.com/zabbix/6.2/ubuntu/dists/jammy/InRelease
HTTP/1.1 304 Not Modified
Server: nginx/1.14.2
Date: Tue, 21 Feb 2023 12:31:54 GMT
Last-Modified: Wed, 01 Feb 2023 15:02:57 GMT
Connection: keep-alive
ETag: "63da7f21-135e"

Hit:1 http://repo.zabbix.com/zabbix/6.2/ubuntu jammy InRelease
0% [Connecting to junk.devs.nu]GET /ubuntu/dists/jammy/InRelease HTTP/1.1
Host: junk.devs.nu:3851
Cache-Control: max-age=0
Accept: text/*
User-Agent: Debian APT-HTTP/1.3 (2.4.9) non-interactive

Answer for: http://junk.devs.nu:3851/ubuntu/dists/jammy/InRelease
HTTP/1.1 200 OK
date: Fri, 17 Feb 2023 15:11:49 GMT
content-type: octet/stream
content-length: 270087
last-modified: Fri, 17 Feb 2023 13:29:00 GMT
x-original-source: http://de.archive.ubuntu.com/ubuntu/dists/jammy/InRelease

Get:2 http://junk.devs.nu:3851/ubuntu jammy InRelease [270 kB]
0% [2 InRelease 0 B/270 kB 0%]GET /ubuntu/dists/jammy-updates/InRelease HTTP/1.1
Host: junk.devs.nu:3851
Cache-Control: max-age=0
Accept: text/*
User-Agent: Debian APT-HTTP/1.3 (2.4.9) non-interactive

Answer for: http://junk.devs.nu:3851/ubuntu/dists/jammy-updates/InRelease
HTTP/1.1 200 OK
date: Fri, 17 Feb 2023 15:11:49 GMT
content-type: octet/stream
content-length: 118747
last-modified: Fri, 17 Feb 2023 13:29:00 GMT
x-original-source: http://de.archive.ubuntu.com/ubuntu/dists/jammy-updates/InRelease

Get:3 http://junk.devs.nu:3851/ubuntu jammy-updates InRelease [119 kB]
Ign:3 http://junk.devs.nu:3851/ubuntu jammy-updates InRelease
0% [Working]

=====================================
ps faxu
=====================================
root 3549798 0.0 0.0 16652 6556 pts/3 S+ 12:31 0:00 \_ apt-get update -o Debug::Acquire::http=1
_apt 3549801 0.0 0.0 22068 6540 pts/3 S+ 12:31 0:00 \_ /usr/lib/apt/methods/http
_apt 3549802 0.0 0.0 22068 6552 pts/3 S+ 12:31 0:00 \_ /usr/lib/apt/methods/http
_apt 3549804 0.0 0.0 15440 5016 pts/3 S+ 12:31 0:00 \_ /usr/lib/apt/methods/gpgv

=====================================
netstat
=====================================
tcp 1 0 217.21.199.56:44494 178.128.6.101:80 CLOSE_WAIT 3549801/http

(this IP belongs to the zabbix repo. the connection to the junk.devs.nu broken server is already gone.)

=====================================
preliminary info
=====================================
The connection to the zabbix repo is unclosed. The connection to the broken server is closed. The sequence was:

12:31:58.082726 eth0 In IP 217.21.198.165.3851 > 217.21.199.56.42838: Flags [F.], seq 270320:270560, ack 349, win 507, options [nop,nop,TS val 4041174334 ecr 558653630], length 240
12:31:58.083017 eth0 Out IP 217.21.199.56.42838 > 217.21.198.165.3851: Flags [F.], seq 349, ack 270561, win 1022, options [nop,nop,TS val 558653631 ecr 4041174334], length 0
12:31:58.083199 eth0 In IP 217.21.198.165.3851 > 217.21.199.56.42838: Flags [.], ack 350, win 507, options [nop,nop,TS val 4041174335 ecr 558653631], length 0

Where that last request was:

GET /ubuntu/dists/jammy-updates/InRelease HTTP/1.1
Host: junk.devs.nu:3851
Cache-Control: max-age=0
Accept: text/*
User-Agent: Debian APT-HTTP/1.3 (2.4.9) non-interactive

And the last response was:

HTTP/1.1 200 OK
date: Fri, 17 Feb 2023 15:11:49 GMT
content-type: octet/stream
content-length: 118747
last-modified: Fri, 17 Feb 2023 13:29:00 GMT
x-original-source: http://de.archive.ubuntu.com/ubuntu/dists/jammy-updates/InRelease

This response was sent in the FIN packet. So no actual content would be delivered.

The apt-get process which got the broken server has this backtrace:

(gdb) bt
#0 0x00007efc90d3774d in __GI___select (nfds=1, readfds=0x7ffe64790920, writefds=0x0, exceptfds=0x0, timeout=0x0) at ../sysdeps/unix/sysv/linux/select.c:69
#1 0x00007efc91418b43 in WaitFd(int, bool, unsigned long) () from /lib/x86_64-linux-gnu/libapt-pkg.so.6.0
#2 0x0000555a612d47b3 in BaseHttpMethod::Loop (this=0x7ffe64790bf0) at ./methods/basehttp.cc:611
#3 main (argv=<optimized out>) at ./methods/http.cc:1052

The process which got the good server (zabbix) has a similar backtrace:

(gdb) bt
#0 0x00007f8e345e674d in __GI___select (nfds=1, readfds=0x7ffc6f6b9990, writefds=0x0, exceptfds=0x0, timeout=0x0) at ../sysdeps/unix/sysv/linux/select.c:69
#1 0x00007f8e34cc7b43 in WaitFd(int, bool, unsigned long) () from /lib/x86_64-linux-gnu/libapt-pkg.so.6.0
#2 0x00005614260967b3 in BaseHttpMethod::Loop (this=0x7ffc6f6b9c60) at ./methods/basehttp.cc:611
#3 main (argv=<optimized out>) at ./methods/http.cc:1052

=====================================
server.py
=====================================
http://junk.devs.nu/2023/lp2003851/server.py
http://junk.devs.nu/2023/lp2003851/2023-02-21-13-31.pcap

=====================================

I'll go take a look at why apt-cacher-ng misbehaves.

[~juliank]: Maybe this is sufficient info for you to work with? Even though our server is at fault, we still don't want an infinitely hanging apt.

NOTE: Maybe this isn't an apt 2.4.x thing, but something that started happening for Jammy-served apt-cacher-ng responses and therefore only visible on Jammy? In that case this isn't a newly introduced problem in apt.

Cheers,
Walter Doekes
OSSO B.V.