python exceptions bleeding into stdout
Affects | Status | Importance | Assigned to | Milestone | |
---|---|---|---|---|---|
squid-deb-proxy (Ubuntu) |
Fix Released
|
Low
|
Miriam España Acebal | ||
Trusty |
Won't Fix
|
Low
|
Unassigned | ||
Xenial |
Won't Fix
|
Low
|
Unassigned | ||
Bionic |
Fix Released
|
Low
|
Miriam España Acebal | ||
Focal |
Fix Released
|
Low
|
Miriam España Acebal | ||
Hirsute |
Fix Released
|
Low
|
Miriam España Acebal | ||
Impish |
Fix Released
|
Low
|
Miriam España Acebal |
Bug Description
[Impact]
As @cell explains, the problem here is that the errors are going to stdout, not to stderr. This means apt's Acquire:
[Test Plan]
The idea is to create a VM with several interfaces, to cache them plus to check configuration and do the discovery. Here you can see the test for Focal, but it has been the same behaviour for Hirsute, Bionic and Impish.
Note: In comment #22 there's a very straightforward test (Impish) without the need for extra ifaces.
Steps to reproduce (thanks to @cpaelzer and @sergiodj):
#0
# On the test Host install apt-cacher-ng
# you need to do so before creating the guest VM to propagate
# and configure correctly when spawned
$ sudo apt install apt-cacher-ng
# 1
# On the Host, create the IPv4 addresses and the VM. Stop the VM to
# attach the ifaces and start again the VM to log in.
$ for i in 1 2 3 4; do lxc network create testnet${i}; done
$ lxc network list
$ lxc launch ubuntu-daily:focal test-bug1505670-focal --vm
$ lxc stop test-bug1505670-focal
$ for i in 1 2 3 4; do lxc network attach testnet${i} test-bug1505670-focal; done
$ lxc start test-bug1505670-focal
$ lxc shell test-bug1505670-focal
# Now at the VM, install prereq packages
$ sudo apt update
$ sudo apt install avahi-utils squid-deb-
#3
# check if all are interfaces are configured
$ ip a
# (you might need to edit netplan or E/N/I to e.g. dhcp on all of them) to have the following content (check the names of your interfaces from the 'ip a' command above and change them if needed):
$ vim /etc/netplan/
network:
version: 2
renderer: networked
ethernet:
enp5s0:
dhcp4: true
enp6s0:
dhcp4: true
enp7s0:
dhcp4: true
enp8s0:
dhcp4: true
enp09s0:
dhcp4: true
#apply the changes to the ifaces:
$ sudo netplan apply
# 4
# avahi probes all ifaces
$ avahi-browse -kprtf _apt_proxy._tcp
+;enp8s0;
+;enp8s0;
+;enp7s0;
+;enp7s0;
+;enp6s0;
+;enp6s0;
+;enp5s0;
+;enp5s0;
+;lo;IPv4;
=;enp8s0;
=;enp8s0;
=;enp7s0;
=;enp7s0;
=;enp6s0;
=;enp6s0;
=;enp5s0;
=;enp5s0;
=;lo;IPv4;
+;enp8s0;
+;enp8s0;
+;enp6s0;
+;enp7s0;
+;enp6s0;
+;enp7s0;
=;enp8s0;
=;enp8s0;
=;enp6s0;
=;enp7s0;
=;enp6s0;
=;enp7s0;
# 5
# After being announced stop the cacher on the host
$ sudo systemctl stop apt-cacher-
#6
# Check it is now dead from the guests POV with curl <addr>:3142, i.e.:
$ curl 10.8.60.155:3142
curl: (7) Failed to connect to 10.8.60.155 port 3142: Connection refused
$ curl 10.232.244.137:3142
curl: (7) Failed to connect to 10.232.244.137 port 3142: Connection refused
$ curl 10.115.171.242:3142
curl: (7) Failed to connect to 10.115.171.242 port 3142: Connection refused
$ curl 10.47.127.209:3142
curl: (7) Failed to connect to 10.47.127.209 port 3142: Connection refused
#7
# Ensure that it is still announced in avahi in the guest
$ avahi-browse -kprtf _apt_proxy._tcp | grep '^=' | cut -d";" -f 4,8-9 | grep -v '::'
...
root@test-bug1505670-focal:~# avahi-browse -kprtf _apt_proxy._tcp | grep '^=' | cut -d";" -f 4,8-9 | grep -v '::'
[...]
apt-cacher-
apt-cacher-
apt-cacher-
apt-cacher-
apt-cacher-
apt-cacher-
apt-cacher-
apt-cacher-
apt-cacher-
### Bad response:
#8
# Now run apt-avahi-discover which shows the python errors
# bleeding into the output even with stderr redirected
$ /usr/share/
root@test-bug1505670-focal:~# /usr/share/
error: uncaptured python exception, closing channel <AptAvahiClient> ('fd42:
error: uncaptured python exception, closing channel <AptAvahiClient> ('fd42:
error: uncaptured python exception, closing channel <AptAvahiClient> ('fd42:
error: uncaptured python exception, closing channel <AptAvahiClient> ('fd42:
error: uncaptured python exception, closing channel <AptAvahiClient> ('10.8.60.155', 3142): 9223372036854775807 (<class 'ConnectionRefu
error: uncaptured python exception, closing channel <AptAvahiClient> ('10.232.244.137', 3142): 9223372036854775807 (<class 'ConnectionRefu
error: uncaptured python exception, closing channel <AptAvahiClient> ('10.115.171.242', 3142): 9223372036854775807 (<class 'ConnectionRefu
error: uncaptured python exception, closing channel <AptAvahiClient> ('10.47.127.209', 3142): 9223372036854775807 (<class 'ConnectionRefu
error: uncaptured python exception, closing channel <AptAvahiClient> ('127.0.0.1', 3142): 9223372036854775807 (<class 'ConnectionRefu
http://
### Good response, after applying the fix from proposed package
# now no output bleeding through
$ /usr/share/
# actually since there is no proxy left there is juts nothing now in this setup
$ /usr/share/
# But as soon as the cacher is back up it works:
$ /usr/share/
http://
[Where problems could occur]
As the change itself redirects the errors to the proper logs using the proper output flow (stderr), the risk of losing any kind of information is avoided as well as the risk to produce any kind of interference with the rest of the system. It uses standard python calls to do it, so it doesn't have to rely on anything in particular.
[Other Info]
The change is cherry-picked from upstream for fixing this bug precisely: https:/
[Original Report]
-------
Steps to reproduce (for later SRU work)
#0
# On the test Host install apt-cacher-ng
# you need to do so before creating the guest to propagate
# and configure correctly when spawned
$ sudo apt install apt-cacher-ng
#1
# create a VM guest or container with at least three IPv4 adresses
# In the example below I used 4 virtio net in KVM all with DHCP configured
#2
# install prereq packages
$ sudo apt install avahi-utils squid-deb-
#3
# check if all are interfaces are configured and avahi probes them all
# (you might need to edit netplan or E/N/I to e.g. dhcp on all of them)
$ avahi-browse -kprtf _apt_proxy._tcp
+;enp9s0;
+;enp9s0;
+;enp9s0;
+;enp8s0;
+;enp8s0;
+;enp8s0;
+;enp7s0;
+;enp7s0;
+;enp7s0;
+;enp1s0;
+;enp1s0;
+;enp1s0;
+;lo;IPv4;
=;enp8s0;
=;enp9s0;
=;enp7s0;
=;enp1s0;
=;enp9s0;
=;enp8s0;
=;enp7s0;
=;enp1s0;
=;enp9s0;
=;enp8s0;
=;enp7s0;
=;enp1s0;
=;lo;IPv4;
#5
# After being announced stop the cacher on the host
$ sudo systemctl stop apt-cacher-
#6
Check it is now dead from the guests POV
$ curl 192.168.122.1:3142
curl: (7) Failed to connect to 192.168.122.1 port 3142: Connection refused
#7
# Ensure that it is still announced in avahi in the guest
$ avahi-browse -kprtf _apt_proxy._tcp | grep '^=' | cut -d";" -f 4,8-9 | grep -v '::'
...
apt-cacher-
#8
# Now run apt-avahi-discover which shows the python errors
# bleeding into the output even with stderr redirected
$ /usr/share/
error: uncaptured python exception, closing channel <AptAvahiClient> ('192.168.122.1', 3142): 9223372036854775807 (<class 'ConnectionRefu
error: uncaptured python exception, closing channel <AptAvahiClient> ('192.168.122.1', 3142): 9223372036854775807 (<class 'ConnectionRefu
error: uncaptured python exception, closing channel <AptAvahiClient> ('192.168.122.1', 3142): 9223372036854775807 (<class 'ConnectionRefu
error: uncaptured python exception, closing channel <AptAvahiClient> ('192.168.122.1', 3142): 9223372036854775807 (<class 'ConnectionRefu
http://
P.S. I'm (paelzer) not entirely sure we need "multiple" IPs an announced but down entry might be enough, but we want to stick close to what was reported.
---
I get the following error when running the discovery script on the command line.
$ /usr/share/
error: uncaptured python exception, closing channel <AptAvahiClient> ('10.1.2.3', 3142): 2147483647 (<class 'socket.
error: uncaptured python exception, closing channel <AptAvahiClient> ('10.0.3.1', 3142): 2147483647 (<class 'socket.
error: uncaptured python exception, closing channel <AptAvahiClient> ('172.24.74.129', 3142): 2147483647 (<class 'socket.
http://
The last line still returns the proper proxy URI so as far as I can tell things are still working. The IP 10.1.2.3 is for an n2n VPN. This is on trusty with version 0.8.6ubuntu1.
To trigger the bug the environment setup needs to be in a specific way.
It seems for the problem to occur it need more than one host/IP discovered via avahi. This can be probed via $ avahi-browse -kprtf _apt_proxy._tcp
and e.g. the common LXD setup of IPv4 + ipv6 is NOT enough to trigger it.
TODO: a sample output of the above command in an affected environment could be helpful.
TODO: if possible outlining how the environment can be configured to have this multi host/IP reply in avahi would be helpful as well.
Related branches
- Sergio Durigan Junior (community): Approve
- Canonical Server MOTU reviewers: Pending requested
-
Diff: 48 lines (+17/-1)3 files modifiedapt-avahi-discover (+5/-0)
debian/changelog (+10/-0)
debian/control (+2/-1)
- Sergio Durigan Junior (community): Approve
- Canonical Server MOTU reviewers: Pending requested
-
Diff: 48 lines (+17/-1)3 files modifiedapt-avahi-discover (+5/-0)
debian/changelog (+10/-0)
debian/control (+2/-1)
- Sergio Durigan Junior (community): Approve
- Canonical Server MOTU reviewers: Pending requested
-
Diff: 48 lines (+17/-1)3 files modifiedapt-avahi-discover (+5/-0)
debian/changelog (+10/-0)
debian/control (+2/-1)
- Christian Ehrhardt (community): Approve
- Utkarsh Gupta (community): Needs Fixing
-
Diff: 56 lines (+18/-1)3 files modifiedapt-avahi-discover (+6/-0)
debian/changelog (+10/-0)
debian/control (+2/-1)
Changed in squid-deb-proxy (Ubuntu): | |
status: | In Progress → Confirmed |
tags: | added: bionic |
tags: | added: focal |
description: | updated |
description: | updated |
summary: |
- "uncaptured python exception" + python exceptions bleeding into stdout |
Changed in squid-deb-proxy (Ubuntu Impish): | |
status: | Confirmed → In Progress |
Changed in squid-deb-proxy (Ubuntu Bionic): | |
status: | New → In Progress |
Changed in squid-deb-proxy (Ubuntu Focal): | |
status: | New → In Progress |
Changed in squid-deb-proxy (Ubuntu Hirsute): | |
status: | New → In Progress |
description: | updated |
description: | updated |
description: | updated |
description: | updated |
Changed in squid-deb-proxy (Ubuntu Bionic): | |
importance: | Undecided → Low |
Changed in squid-deb-proxy (Ubuntu Focal): | |
importance: | Undecided → Low |
Changed in squid-deb-proxy (Ubuntu Hirsute): | |
importance: | Undecided → Low |
Changed in squid-deb-proxy (Ubuntu Trusty): | |
status: | New → Won't Fix |
importance: | Undecided → Low |
Changed in squid-deb-proxy (Ubuntu Xenial): | |
status: | New → Won't Fix |
importance: | Undecided → Low |
I just ran into this bug, and I think I've figured it out.
/usr/share/ squid-deb- proxy-client/ apt-avahi- discover is outputting the URL of my squid-deb-proxy server, but it is also spitting out some errors:
root@debian:~# /usr/share/ squid-deb- proxy-client/ apt-avahi- discover error'> :[Errno 111] Connection refused [/usr/lib/ python2. 7/asyncore. py|read| 83] [/usr/lib/ python2. 7/asyncore. py|handle_ read_event| 446] [/usr/lib/ python2. 7/asyncore. py|handle_ connect_ event|454] ) error'> :[Errno 111] Connection refused [/usr/lib/ python2. 7/asyncore. py|read| 83] [/usr/lib/ python2. 7/asyncore. py|handle_ read_event| 446] [/usr/lib/ python2. 7/asyncore. py|handle_ connect_ event|454] ) 192.168. 2.232:8000/]
error: uncaptured python exception, closing channel <AptAvahiClient> ('192.168.2.232', 3142): 9223372036854775807 (<class 'socket.
error: uncaptured python exception, closing channel <AptAvahiClient> ('192.168.2.80', 3142): 9223372036854775807 (<class 'socket.
http://
The problem here is that the errors are going to stdout, not to stderr. This means apt's Acquire: :http:: ProxyAutoDetect is not able to figure out what the proxy URL is.
I have locally modified apt-avahi-discover so that the errors are sent to stderr, and I have verified that this allows apt's Acquire: :http:: ProxyAutoDetect to work correctly. I have attached this as a patch.
This patch is enough to fix this bug, but I'm not sure it's ultimately the best fix for the overall issue. I think ideally, in the case were apt-avahi-discover encounters non-fatal errors (and is still able to produce a working URL), these error should probably just get logged to syslog, rather than being sent to stderr, because it does make apt's console output look rather ugly, and the user doesn't need to see any of that, because if there's a working URL, ultimately they don't care any other errors.
(This is what apt's output looks like with the patch applied to apt-avahi- discover: )
0 upgraded, 826 newly installed, 0 to remove and 1 not upgraded. error'> :[Errno 111] Connection refused [/usr/lib/ python2. 7/asyncore. py|read| 83] [/usr/lib/ python2. 7/asyncore. py|handle_ read_event| 446] [/usr/lib/ python2. 7/asyncore. py|handle_ connect_ event|454] ) error'> :[Errno 111] Connection refused [/usr/lib/ python2. 7/asyncore. py|read| 83] [/usr/lib/ python2. 7/asyncore. py|handle_ read_event| 446] [/usr/lib/ python2. 7/asyncore. py|handle_ connect_ event|454] ) error'> :[Errno 111] Connection refused [/usr/lib/ python2. 7/asyncore. py|read| 83] [/usr/lib/ python2. 7/asyncore. py|handle_ read_event| 446] [/usr/lib/ python2. 7/asyncore. py|handle_ connect_ event|454] )
Need to get 500 MB of archives.
After this operation, 1,554 MB of additional disk space will be used.
Do you want to continue? [Y/n]
0% [Working]log: error: uncaptured python exception, closing channel <AptAvahiClient> ('192.168.2.80', 3142): 9223372036854775807 (<class 'socket.
log: error: uncaptured python exception, closing channel <AptAvahiClient> ('192.168.2.232', 3142): 9223372036854775807 (<class 'socket.
log: error: uncaptured python exception, closing channel <AptAvahiClient> ('192.168.2.80', 3142): 9223372036854775807 (<class 'socket.
log: error: uncaptured python exception, closing channel <AptAvahiClient> (...