[Bug 1946520] Re: magic-proxy does not gracefully handle error conditions

Thu Nov 18 23:50:18 UTC 2021

I've sponsored this for all of the relevant releases of Ubuntu.

** Changed in: livecd-rootfs (Ubuntu Focal)
       Status: New => In Progress

-- 
You received this bug notification because you are a member of Ubuntu
Foundations Bugs, which is subscribed to livecd-rootfs in Ubuntu.
https://bugs.launchpad.net/bugs/1946520

Title:
  magic-proxy does not gracefully handle error conditions

Status in livecd-rootfs package in Ubuntu:
  Fix Released
Status in livecd-rootfs source package in Focal:
  In Progress
Status in livecd-rootfs source package in Hirsute:
  In Progress
Status in livecd-rootfs source package in Impish:
  In Progress

Bug description:
  [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("&", "&") # 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.

To manage notifications about this bug go to:
https://bugs.launchpad.net/ubuntu/+source/livecd-rootfs/+bug/1946520/+subscriptions