"uncaptured python exception"

[Rolf Leggewie]

I get the following error when running the discovery script on the command line.

$ /usr/share/squid-deb-proxy-client/apt-avahi-discover
error: uncaptured python exception, closing channel <AptAvahiClient> ('10.1.2.3', 3142): 2147483647 (<class 'socket.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: uncaptured python exception, closing channel <AptAvahiClient> ('10.0.3.1', 3142): 2147483647 (<class 'socket.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: uncaptured python exception, closing channel <AptAvahiClient> ('172.24.74.129', 3142): 2147483647 (<class 'socket.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])
http://172.24.74.145:3142/

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.

[cell (jasonpepas)]

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: uncaptured python exception, closing channel <AptAvahiClient> ('192.168.2.232', 3142): 9223372036854775807 (<class 'socket.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: uncaptured python exception, closing channel <AptAvahiClient> ('192.168.2.80', 3142): 9223372036854775807 (<class 'socket.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])
http://192.168.2.232:8000/]

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.
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.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])
log: error: uncaptured python exception, closing channel <AptAvahiClient> ('192.168.2.232', 3142): 9223372036854775807 (<class 'socket.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])
log: error: uncaptured python exception, closing channel <AptAvahiClient> ('192.168.2.80', 3142): 9223372036854775807 (<class 'socket.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])
log: error: uncaptured python exception, closing channel <AptAvahiClient> (...

[Ubuntu Foundations Team Bug Bot (crichton)]

The attachment "Minimal patch to work-around this bug." seems to be a patch. If it isn't, please remove the "patch" flag from the attachment, remove the "patch" tag, and if you are a member of the ~ubuntu-reviewers, unsubscribe the team.

[This is an automated message performed by a Launchpad user owned by ~brian-murray, for any issues please contact him.]

[cell (jasonpepas)]

(oops, the previous patch had some garbage at the top. re-attaching the patch here).

[cell (jasonpepas)]

So, I went ahead and made a different version of the patch which sends asyncore's logging output to syslog, instead of stderr. This keep's apt-get's output clean.

I think this is the patch I'd prefer. However, I should probably also bark up the tree of asyncore.py and ask why they are calling 'print' on something labelled as an 'error' instead of just throwing an exception (which would allow apt-avahi-discover to deal with it appropriately).

(see attached patch).

[Rolf Leggewie (r0lf)]

Thanks, Jason! I applied the patch locally and indeed it works beautifully.

I hope it lands soon and gets backported to trusty.

[Rolf Leggewie (r0lf)]

@mvo, it would be nice if you took the time to consider inclusion of the patch from comment 4

[Rolf Leggewie (r0lf)]

Going by what's written here and in bug 1422162 it looks like this problem occurs whenever there is more than one host/IP discovered via avahi.

[Andreas Hasenack (ahasenack)]

I believe this is fixed in eoan at least:

root@eoan-squid-deb-proxy-clienbt:~# rm -f errors.txt
root@eoan-squid-deb-proxy-clienbt:~# /usr/share/squid-deb-proxy-client/apt-avahi-discover 2>errors.txt
http://10.0.100.99:8000/
root@eoan-squid-deb-proxy-clienbt:~# cat errors.txt
Failed to resolve service 'Squid deb proxy on eoan-squid-deb-proxy2' of type '_apt_proxy._tcp' in domain 'local': Timeout reached
root@eoan-squid-deb-proxy-clienbt:~#

apt update works just fine, but it spits out the error, as mentioned in comment #3:
root@eoan-squid-deb-proxy-clienbt:~# apt update
Failed to resolve service 'Squid deb proxy on eoan-squid-deb-proxy2' of type '_apt_proxy._tcp' in domain 'local': Timeout reached
Hit:1 http://archive.ubuntu.com/ubuntu eoan InRelease
Hit:2 http://archive.ubuntu.com/ubuntu eoan-updates InRelease
Hit:3 http://archive.ubuntu.com/ubuntu eoan-backports InRelease
Hit:4 http://archive.ubuntu.com/ubuntu eoan-security InRelease
Reading package lists... Done
Building dependency tree
Reading state information... Done
4 packages can be upgraded. Run 'apt list --upgradable' to see them.

Same in xenial, so I'll assume the versions in between are also ok:root@xenial-squid-deb-proxy-client:~# /usr/share/squid-deb-proxy-client/apt-avahi-discover
Failed to resolve service 'Squid deb proxy on eoan-squid-deb-proxy2' of type '_apt_proxy._tcp' in domain 'local': Timeout reached
http://10.0.100.99:8000/
root@xenial-squid-deb-proxy-client:~# /usr/share/squid-deb-proxy-client/apt-avahi-discover 2>/dev/null
http://10.0.100.99:8000/
root@xenial-squid-deb-proxy-client:~#

root@xenial-squid-deb-proxy-client:~# apt update
0% [Working]Failed to resolve service 'Squid deb proxy on eoan-squid-deb-proxy2' of type '_apt_proxy._tcp' in domain 'local': Timeout reached
Failed to resolve service 'Squid deb proxy on eoan-squid-deb-proxy2' of type '_apt_proxy._tcp' in domain 'local': Timeout reached
Hit:1 http://archive.canonical.com/ubuntu xenial InRelease
Hit:2 http://br.archive.ubuntu.com/ubuntu xenial InRelease
Hit:3 http://br.archive.ubuntu.com/ubuntu xenial-updates InRelease
Hit:4 http://br.archive.ubuntu.com/ubuntu xenial-backports InRelease
Hit:5 http://br.archive.ubuntu.com/ubuntu xenial-security InRelease
Reading package lists... Done
Building dependency tree
Reading state information... Done
All packages are up to date.
root@xenial-squid-deb-proxy-client:~# echo $?
0
root@xenial-squid-deb-proxy-client:~#

[Rolf Leggewie (r0lf)]

Andreas, I cannot confirm this for focal and I believe you should have asked for confirmation from others before closing.

Code inspection suggests nothing was done to fix this bug, but of course it was possible that a change in asyncore.py fixed this. That does not look to be the case. I tested the patch from #4 again, it works and I believe it should be applied in focal and bionic.

$ /usr/share/squid-deb-proxy-client/apt-avahi-discover
error: uncaptured python exception, closing channel <AptAvahiClient> ('2003:d3:b725:fb45:290:27ff:fe25:f52', 3142, 0, 0): 9223372036854775807 (<class 'ConnectionRefusedError'>:[Errno 111] Connection refused [/usr/lib/python3.8/asyncore.py|read|83] [/usr/lib/python3.8/asyncore.py|handle_read_event|417] [/usr/lib/python3.8/asyncore.py|handle_connect_event|425])
error: uncaptured python exception, closing channel <AptAvahiClient> ('2003:d3:b725:fb45:290:27ff:fe25:f52', 3142, 0, 0): 9223372036854775807 (<class 'ConnectionRefusedError'>:[Errno 111] Connection refused [/usr/lib/python3.8/asyncore.py|read|83] [/usr/lib/python3.8/asyncore.py|handle_read_event|417] [/usr/lib/python3.8/asyncore.py|handle_connect_event|425])
error: uncaptured python exception, closing channel <AptAvahiClient> ('2003:d3:b725:fb45:2e0:c5ff:fe34:f66c', 3142, 0, 0): 9223372036854775807 (<class 'ConnectionRefusedError'>:[Errno 111] Connection refused [/usr/lib/python3.8/asyncore.py|read|83] [/usr/lib/python3.8/asyncore.py|handle_read_event|417] [/usr/lib/python3.8/asyncore.py|handle_connect_event|425])
error: uncaptured python exception, closing channel <AptAvahiClient> ('2003:d3:b725:fb45:2e0:c5ff:fe34:f66c', 3142, 0, 0): 9223372036854775807 (<class 'ConnectionRefusedError'>:[Errno 111] Connection refused [/usr/lib/python3.8/asyncore.py|read|83] [/usr/lib/python3.8/asyncore.py|handle_read_event|417] [/usr/lib/python3.8/asyncore.py|handle_connect_event|425])
error: uncaptured python exception, closing channel <AptAvahiClient> ('192.168.34.22', 3142): 9223372036854775807 (<class 'ConnectionRefusedError'>:[Errno 111] Connection refused [/usr/lib/python3.8/asyncore.py|read|83] [/usr/lib/python3.8/asyncore.py|handle_read_event|417] [/usr/lib/python3.8/asyncore.py|handle_connect_event|425])
error: uncaptured python exception, closing channel <AptAvahiClient> ('192.168.34.22', 3142): 9223372036854775807 (<class 'ConnectionRefusedError'>:[Errno 111] Connection refused [/usr/lib/python3.8/asyncore.py|read|83] [/usr/lib/python3.8/asyncore.py|handle_read_event|417] [/usr/lib/python3.8/asyncore.py|handle_connect_event|425])
http://192.168.34.5:3142/

[Rolf Leggewie (r0lf)]

filing against python2.7 as well based on comment #4

[Rolf Leggewie (r0lf)]

I've long been using the patch from this ticket successfully and have now published a bionic package in my LTS ppa https://launchpad.net/~r0lf/+archive/ubuntu/stable Other release pockets to follow.