Activity log for bug #1946520

Date Who What changed Old value New value Message
2021-10-08 18:42:20 Pat Viafore bug added bug
2021-10-11 09:26:52 Launchpad Janitor livecd-rootfs (Ubuntu): status New Confirmed
2021-10-21 09:03:22 Thomas Bechtold merge proposal linked https://code.launchpad.net/~toabctl/livecd-rootfs/+git/livecd-rootfs-1/+merge/410585
2021-10-21 09:03:29 Thomas Bechtold livecd-rootfs (Ubuntu): assignee Thomas Bechtold (toabctl)
2021-10-21 09:03:33 Thomas Bechtold livecd-rootfs (Ubuntu): status Confirmed In Progress
2021-10-25 10:45:10 Thomas Bechtold attachment added debdiff to fix this bug https://bugs.launchpad.net/ubuntu/+source/livecd-rootfs/+bug/1946520/+attachment/5535828/+files/debdiff-lp1946520.diff
2021-10-25 10:52:32 Thomas Bechtold bug added subscriber Ubuntu Sponsors Team
2021-10-25 10:52:37 Thomas Bechtold livecd-rootfs (Ubuntu): assignee Thomas Bechtold (toabctl)
2021-10-25 13:18:35 Utkarsh Gupta livecd-rootfs (Ubuntu): assignee Thomas Bechtold (toabctl)
2021-10-26 09:46:33 Utkarsh Gupta nominated for series Ubuntu Hirsute
2021-10-26 09:46:33 Utkarsh Gupta bug task added livecd-rootfs (Ubuntu Hirsute)
2021-10-26 09:46:33 Utkarsh Gupta nominated for series Ubuntu Focal
2021-10-26 09:46:33 Utkarsh Gupta bug task added livecd-rootfs (Ubuntu Focal)
2021-10-26 09:46:33 Utkarsh Gupta nominated for series Ubuntu Impish
2021-10-26 09:46:33 Utkarsh Gupta bug task added livecd-rootfs (Ubuntu Impish)
2021-10-26 10:34:28 Thomas Bechtold description During an impish build of ubuntu-cpc images with magic-proxy enabled, the installation of certain packages tried to reach an internet endpoint (specifically http://169.254.169.254/latest/meta-data/instance-id - which appears to be used for EC2 metadata) The magic-proxy log indicated : 10.10.10.2 - - [01/Oct/2021 13:21:26] urlopen() failed for http://169.254.169.254/2009-04-04/meta-data/instance-id with [Errno 110] Connection timed out 10.10.10.2 - - [01/Oct/2021 13:21:26] code 501, message [Errno 110] Connection timed out 10.10.10.2 - - [01/Oct/2021 13:21:26] "GET /2009-04-04/meta-data/instance-id HTTP/1.1" 501 - ---------------------------------------- Exception occurred during processing of request from ('10.10.10.2', 49672) Traceback (most recent call last): File "/usr/lib/python3.9/urllib/request.py", line 1346, in do_open h.request(req.get_method(), req.selector, req.data, headers, File "/usr/lib/python3.9/http/client.py", line 1279, in request self._send_request(method, url, body, headers, encode_chunked) File "/usr/lib/python3.9/http/client.py", line 1325, in _send_request self.endheaders(body, encode_chunked=encode_chunked) File "/usr/lib/python3.9/http/client.py", line 1274, in endheaders self._send_output(message_body, encode_chunked=encode_chunked) File "/usr/lib/python3.9/http/client.py", line 1034, in _send_output self.send(msg) File "/usr/lib/python3.9/http/client.py", line 974, in send self.connect() File "/usr/lib/python3.9/http/client.py", line 945, in connect self.sock = self._create_connection( File "/usr/lib/python3.9/socket.py", line 844, in create_connection raise err File "/usr/lib/python3.9/socket.py", line 832, in create_connection sock.connect(sa) TimeoutError: [Errno 110] Connection timed out During handling of the above exception, another exception occurred: Traceback (most recent call last): File "/usr/share/livecd-rootfs/magic-proxy", line 873, in __get_request with urllib.request.urlopen( File "/usr/lib/python3.9/urllib/request.py", line 214, in urlopen return opener.open(url, data, timeout) File "/usr/lib/python3.9/urllib/request.py", line 517, in open response = self._open(req, data) File "/usr/lib/python3.9/urllib/request.py", line 534, in _open result = self._call_chain(self.handle_open, protocol, protocol + File "/usr/lib/python3.9/urllib/request.py", line 494, in _call_chain result = func(*args) File "/usr/lib/python3.9/urllib/request.py", line 1375, in http_open return self.do_open(http.client.HTTPConnection, req) File "/usr/lib/python3.9/urllib/request.py", line 1349, in do_open raise URLError(err) urllib.error.URLError: <urlopen error [Errno 110] Connection timed out> During handling of the above exception, another exception occurred: Traceback (most recent call last): File "/usr/lib/python3.9/socketserver.py", line 683, in process_request_thread self.finish_request(request, client_address) File "/usr/lib/python3.9/socketserver.py", line 360, in finish_request self.RequestHandlerClass(request, client_address, self) File "/usr/lib/python3.9/socketserver.py", line 747, in __init__ self.handle() File "/usr/lib/python3.9/http/server.py", line 427, in handle self.handle_one_request() File "/usr/lib/python3.9/http/server.py", line 415, in handle_one_request method() File "/usr/share/livecd-rootfs/magic-proxy", line 787, in do_GET self.__get_request() File "/usr/share/livecd-rootfs/magic-proxy", line 887, in __get_request self.send_error(501, e.reason) File "/usr/lib/python3.9/http/server.py", line 473, in send_error 'message': html.escape(message, quote=False), File "/usr/lib/python3.9/html/__init__.py", line 19, in escape s = s.replace("&", "&amp;") # Must be done first! AttributeError: 'TimeoutError' object has no attribute 'replace' Because magic-proxy is proxying all traffic to port 80, it will intercept these sort of messages. The TimeoutError ends up bubbling up to the serversocket handling code, which will then cause a broken pipe for all future communications, effectively breaking future apt calls from within the build environment. The concrete problem here is that inside magic-proxy, self.send_error is called with the argument of e.reason, which can be a string (no error) or an exception (in case of a nested exception). If the nested exception is passed into self.send_error, html.replace will try to be called on the exception, hence the above exception. In addition to fixing this specific problem, magic-proxy's request handling should catch all exceptions to not interfere with higher up socketserver handling. [Impact] The fixes for this bug (including the fixes for LP:#1944906) need to be backported to hirsute, focal and bionic) to be able to re-enable the "repo-snapshot-stamp" feature for image builds. That feature is important to get consistent image builds (means the same set of packages included in the different images) when doing multiple builds (eg. for AWS, Azure and GCE). [Test plan] 1) sudo iptables -v -t nat -A OUTPUT -p tcp --dport 80 -m owner ! --uid-owner daemon -j REDIRECT --to 8080 2) sudo ./magic-proxy --address="127.0.0.1" --port=8080 --run-as=daemon --cutoff-time=1632467595 --setsid --log-file mp.log 3) curl http://169.254.169.254/latest/meta-data/instance-id (there should be no route to that host to trigger the error case, so don't do that in an EC2 instance) 4) sudo killall magic-proxy 5) cat mp.log 6) The problem "AttributeError: 'TimeoutError' object has no attribute 'replace'" should not be in the logfile [Where problems could occur] The codepath that will be changed is only executed in livecd-rootfs if the repo-snapshot-stamp feature is enabled. AFAIK this is only enabled for CPC builds so if there are problems, it will only affect CPC team builds. And there, builds (at least for AWS) are currently broken anyway due to this bug. [Original description] During an impish build of ubuntu-cpc images with magic-proxy enabled, the installation of certain packages tried to reach an internet endpoint (specifically http://169.254.169.254/latest/meta-data/instance-id - which appears to be used for EC2 metadata) The magic-proxy log indicated : 10.10.10.2 - - [01/Oct/2021 13:21:26] urlopen() failed for http://169.254.169.254/2009-04-04/meta-data/instance-id with [Errno 110] Connection timed out 10.10.10.2 - - [01/Oct/2021 13:21:26] code 501, message [Errno 110] Connection timed out 10.10.10.2 - - [01/Oct/2021 13:21:26] "GET /2009-04-04/meta-data/instance-id HTTP/1.1" 501 - ---------------------------------------- Exception occurred during processing of request from ('10.10.10.2', 49672) Traceback (most recent call last):   File "/usr/lib/python3.9/urllib/request.py", line 1346, in do_open     h.request(req.get_method(), req.selector, req.data, headers,   File "/usr/lib/python3.9/http/client.py", line 1279, in request     self._send_request(method, url, body, headers, encode_chunked)   File "/usr/lib/python3.9/http/client.py", line 1325, in _send_request     self.endheaders(body, encode_chunked=encode_chunked)   File "/usr/lib/python3.9/http/client.py", line 1274, in endheaders     self._send_output(message_body, encode_chunked=encode_chunked)   File "/usr/lib/python3.9/http/client.py", line 1034, in _send_output     self.send(msg)   File "/usr/lib/python3.9/http/client.py", line 974, in send     self.connect()   File "/usr/lib/python3.9/http/client.py", line 945, in connect     self.sock = self._create_connection(   File "/usr/lib/python3.9/socket.py", line 844, in create_connection     raise err   File "/usr/lib/python3.9/socket.py", line 832, in create_connection     sock.connect(sa) TimeoutError: [Errno 110] Connection timed out During handling of the above exception, another exception occurred: Traceback (most recent call last):   File "/usr/share/livecd-rootfs/magic-proxy", line 873, in __get_request     with urllib.request.urlopen(   File "/usr/lib/python3.9/urllib/request.py", line 214, in urlopen     return opener.open(url, data, timeout)   File "/usr/lib/python3.9/urllib/request.py", line 517, in open     response = self._open(req, data)   File "/usr/lib/python3.9/urllib/request.py", line 534, in _open     result = self._call_chain(self.handle_open, protocol, protocol +   File "/usr/lib/python3.9/urllib/request.py", line 494, in _call_chain     result = func(*args)   File "/usr/lib/python3.9/urllib/request.py", line 1375, in http_open     return self.do_open(http.client.HTTPConnection, req)   File "/usr/lib/python3.9/urllib/request.py", line 1349, in do_open     raise URLError(err) urllib.error.URLError: <urlopen error [Errno 110] Connection timed out> During handling of the above exception, another exception occurred: Traceback (most recent call last):   File "/usr/lib/python3.9/socketserver.py", line 683, in process_request_thread     self.finish_request(request, client_address)   File "/usr/lib/python3.9/socketserver.py", line 360, in finish_request     self.RequestHandlerClass(request, client_address, self)   File "/usr/lib/python3.9/socketserver.py", line 747, in __init__     self.handle()   File "/usr/lib/python3.9/http/server.py", line 427, in handle     self.handle_one_request()   File "/usr/lib/python3.9/http/server.py", line 415, in handle_one_request     method()   File "/usr/share/livecd-rootfs/magic-proxy", line 787, in do_GET     self.__get_request()   File "/usr/share/livecd-rootfs/magic-proxy", line 887, in __get_request     self.send_error(501, e.reason)   File "/usr/lib/python3.9/http/server.py", line 473, in send_error     'message': html.escape(message, quote=False),   File "/usr/lib/python3.9/html/__init__.py", line 19, in escape     s = s.replace("&", "&amp;") # Must be done first! AttributeError: 'TimeoutError' object has no attribute 'replace' Because magic-proxy is proxying all traffic to port 80, it will intercept these sort of messages. The TimeoutError ends up bubbling up to the serversocket handling code, which will then cause a broken pipe for all future communications, effectively breaking future apt calls from within the build environment. The concrete problem here is that inside magic-proxy, self.send_error is called with the argument of e.reason, which can be a string (no error) or an exception (in case of a nested exception). If the nested exception is passed into self.send_error, html.replace will try to be called on the exception, hence the above exception. In addition to fixing this specific problem, magic-proxy's request handling should catch all exceptions to not interfere with higher up socketserver handling.
2021-10-26 11:06:03 Utkarsh Gupta removed subscriber Ubuntu Sponsors Team
2021-10-26 14:23:02 Thomas Bechtold livecd-rootfs (Ubuntu Impish): assignee Thomas Bechtold (toabctl)
2021-10-26 14:23:06 Thomas Bechtold livecd-rootfs (Ubuntu Impish): status New In Progress
2021-10-26 14:45:21 Thomas Bechtold merge proposal linked https://code.launchpad.net/~toabctl/livecd-rootfs/+git/livecd-rootfs-1/+merge/410820
2021-10-26 14:54:35 Thomas Bechtold merge proposal linked https://code.launchpad.net/~toabctl/livecd-rootfs/+git/livecd-rootfs-1/+merge/410822
2021-10-26 14:54:49 Thomas Bechtold livecd-rootfs (Ubuntu Hirsute): assignee Thomas Bechtold (toabctl)
2021-10-26 14:54:52 Thomas Bechtold livecd-rootfs (Ubuntu Hirsute): status New In Progress
2021-10-26 15:00:46 Thomas Bechtold merge proposal linked https://code.launchpad.net/~toabctl/livecd-rootfs/+git/livecd-rootfs-1/+merge/410823
2021-11-05 14:17:24 Launchpad Janitor livecd-rootfs (Ubuntu): status In Progress Fix Released
2021-11-18 23:49:56 Brian Murray livecd-rootfs (Ubuntu Focal): status New In Progress
2021-11-23 16:30:23 Łukasz Zemczak livecd-rootfs (Ubuntu Impish): status In Progress Fix Committed
2021-11-23 16:30:25 Łukasz Zemczak bug added subscriber Ubuntu Stable Release Updates Team
2021-11-23 16:30:27 Łukasz Zemczak bug added subscriber SRU Verification
2021-11-23 16:30:30 Łukasz Zemczak tags verification-needed verification-needed-impish
2021-11-23 16:31:24 Łukasz Zemczak livecd-rootfs (Ubuntu Hirsute): status In Progress Fix Committed
2021-11-23 16:35:47 Łukasz Zemczak tags verification-needed verification-needed-impish verification-needed verification-needed-hirsute verification-needed-impish
2021-11-23 16:43:44 Łukasz Zemczak livecd-rootfs (Ubuntu Focal): status In Progress Fix Committed
2021-11-23 16:43:49 Łukasz Zemczak tags verification-needed verification-needed-hirsute verification-needed-impish verification-needed verification-needed-focal verification-needed-hirsute verification-needed-impish
2021-11-24 09:58:37 Launchpad Janitor merge proposal linked https://code.launchpad.net/~ubuntu-core-dev/livecd-rootfs/+git/livecd-rootfs/+merge/412331
2021-11-30 12:53:27 Thomas Bechtold tags verification-needed verification-needed-focal verification-needed-hirsute verification-needed-impish verification-done-impish verification-needed verification-needed-focal verification-needed-hirsute
2021-11-30 14:31:57 Thomas Bechtold tags verification-done-impish verification-needed verification-needed-focal verification-needed-hirsute verification-done-hirsute verification-done-impish verification-needed verification-needed-focal
2021-11-30 15:08:33 Thomas Bechtold tags verification-done-hirsute verification-done-impish verification-needed verification-needed-focal verification-done verification-done-focal verification-done-hirsute verification-done-impish
2021-11-30 17:59:02 Brian Murray bug added subscriber Brian Murray
2021-12-01 22:04:07 Launchpad Janitor livecd-rootfs (Ubuntu Impish): status Fix Committed Fix Released
2021-12-01 22:04:14 Brian Murray removed subscriber Ubuntu Stable Release Updates Team
2021-12-01 22:04:33 Launchpad Janitor livecd-rootfs (Ubuntu Hirsute): status Fix Committed Fix Released
2021-12-01 22:07:32 Launchpad Janitor livecd-rootfs (Ubuntu Focal): status Fix Committed Fix Released