checkbox virtualization test fails if image is not pre-downloaded

[Rod Smith]

When testing with full Internet connections, checkbox should be able to download virtualization images automatically, but this fails:

Executing KVM Test
WARNING:root:Invalid or Empty timeout in config file. Falling back to default
DEBUG:root:Starting KVM Test
DEBUG:root:No image specified, downloading one now.
DEBUG:root:Downloading trusty-server-cloudimg-i386-disk1.img, from http://cloud-images.ubuntu.com
Traceback (most recent call last):
  File "/usr/lib/python3.4/urllib/request.py", line 1235, in do_open
    h.request(req.get_method(), req.selector, req.data, headers)
  File "/usr/lib/python3.4/http/client.py", line 1066, in request
    self._send_request(method, url, body, headers)
  File "/usr/lib/python3.4/http/client.py", line 1104, in _send_request
    self.endheaders(body)
  File "/usr/lib/python3.4/http/client.py", line 1062, in endheaders
    self._send_output(message_body)
  File "/usr/lib/python3.4/http/client.py", line 907, in _send_output
    self.send(msg)
  File "/usr/lib/python3.4/http/client.py", line 842, in send
    self.connect()
  File "/usr/lib/python3.4/http/client.py", line 820, in connect
    self.timeout, self.source_address)
  File "/usr/lib/python3.4/socket.py", line 509, in create_connection
    raise err
  File "/usr/lib/python3.4/socket.py", line 500, in create_connection
    sock.connect(sa)
OSError: [Errno 101] Network is unreachable

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/share/checkbox/scripts/virtualization", line 334, in <module>
    main()
  File "/usr/share/checkbox/scripts/virtualization", line 331, in main
    args.func(args)
  File "/usr/share/checkbox/scripts/virtualization", line 292, in test_kvm
    result = kvm_test.start()
  File "/usr/share/checkbox/scripts/virtualization", line 209, in start
    self.image = self.download_image()
  File "/usr/share/checkbox/scripts/virtualization", line 84, in download_image
    resp = urllib.request.urlretrieve(image_url, cloud_iso)
  File "/usr/lib/python3.4/urllib/request.py", line 178, in urlretrieve
    with contextlib.closing(urlopen(url, data)) as fp:
  File "/usr/lib/python3.4/urllib/request.py", line 153, in urlopen
    return opener.open(url, data, timeout)
  File "/usr/lib/python3.4/urllib/request.py", line 455, in open
    response = self._open(req, data)
  File "/usr/lib/python3.4/urllib/request.py", line 473, in _open
    '_open', req)
  File "/usr/lib/python3.4/urllib/request.py", line 433, in _call_chain
    result = func(*args)
  File "/usr/lib/python3.4/urllib/request.py", line 1261, in http_open
    return self.do_open(http.client.HTTPConnection, req)
  File "/usr/lib/python3.4/urllib/request.py", line 1238, in do_open
    raise URLError(err)
urllib.error.URLError: <urlopen error [Errno 101] Network is unreachable>
Error in sys.excepthook:
Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/apport_python_hook.py", line 68, in apport_excepthook
    binary = os.path.realpath(os.path.join(os.getcwd(), sys.argv[0]))
FileNotFoundError: [Errno 2] No such file or directory

Original exception was:
Traceback (most recent call last):
  File "/usr/lib/python3.4/urllib/request.py", line 1235, in do_open
    h.request(req.get_method(), req.selector, req.data, headers)
  File "/usr/lib/python3.4/http/client.py", line 1066, in request
    self._send_request(method, url, body, headers)
  File "/usr/lib/python3.4/http/client.py", line 1104, in _send_request
    self.endheaders(body)
  File "/usr/lib/python3.4/http/client.py", line 1062, in endheaders
    self._send_output(message_body)
  File "/usr/lib/python3.4/http/client.py", line 907, in _send_output
    self.send(msg)
  File "/usr/lib/python3.4/http/client.py", line 842, in send
    self.connect()
  File "/usr/lib/python3.4/http/client.py", line 820, in connect
    self.timeout, self.source_address)
  File "/usr/lib/python3.4/socket.py", line 509, in create_connection
    raise err
  File "/usr/lib/python3.4/socket.py", line 500, in create_connection
    sock.connect(sa)
OSError: [Errno 101] Network is unreachable

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/share/checkbox/scripts/virtualization", line 334, in <module>
    main()
  File "/usr/share/checkbox/scripts/virtualization", line 331, in main
    args.func(args)
  File "/usr/share/checkbox/scripts/virtualization", line 292, in test_kvm
    result = kvm_test.start()
  File "/usr/share/checkbox/scripts/virtualization", line 209, in start
    self.image = self.download_image()
  File "/usr/share/checkbox/scripts/virtualization", line 84, in download_image
    resp = urllib.request.urlretrieve(image_url, cloud_iso)
  File "/usr/lib/python3.4/urllib/request.py", line 178, in urlretrieve
    with contextlib.closing(urlopen(url, data)) as fp:
  File "/usr/lib/python3.4/urllib/request.py", line 153, in urlopen
    return opener.open(url, data, timeout)
  File "/usr/lib/python3.4/urllib/request.py", line 455, in open
    response = self._open(req, data)
  File "/usr/lib/python3.4/urllib/request.py", line 473, in _open
    '_open', req)
  File "/usr/lib/python3.4/urllib/request.py", line 433, in _call_chain
    result = func(*args)
  File "/usr/lib/python3.4/urllib/request.py", line 1261, in http_open
    return self.do_open(http.client.HTTPConnection, req)
  File "/usr/lib/python3.4/urllib/request.py", line 1238, in do_open
    raise URLError(err)
urllib.error.URLError: <urlopen error [Errno 101] Network is unreachable>

That's from a test under 14.04 beta (run March 12, 2014), but I see something similar ("Network is unreachable" error) under 12.04.4. The network tests do succeed (with a fix for bug #1288412 in place), and the system has no other obvious network problems -- it successfully downloaded checkbox via APT, for instance. The virtualization test succeeds when it's re-run with a pre-downloaded image. Thus, I suspect the network tests may be leaving the network unconfigured (although the network is back up by the end of the overall checkbox run).

[Daniel Manrique (roadmr)]

We kept that behavior in the virtualization script because if it has no image and is unable to download one, it's reasonable for it to barf loudly, particularly if, as reported, the network is unreachable (which is not the virtualization script's fault, poor thing). Still, we could maybe update this so the way it tracebacks and explodes is not so violent. A simple "unable to download image, test failed" should suffice.

Could you please run the virt script standalone, to confirm your assessment that a prior test is leaving the network unconfigured?

ensure the network is up and running, and do:

/usr/share/checkbox/scripts/virtualization kvm --debug

If so, we'd have two things to fix: better handling of exceptions in virtualization, and determining which test kills the network and ensure we at least wait for it to be up before running the following tests.

[Rod Smith (rodsmith)]

Running the virtualization script directly as you suggest seems to hang when downloading, but with no error messages displayed:

$ /usr/share/checkbox/scripts/virtualization kvm --debug
Executing KVM Test
WARNING:root:Invalid or Empty timeout in config file. Falling back to default
DEBUG:root:Starting KVM Test
DEBUG:root:No image specified, downloading one now.
DEBUG:root:Downloading trusty-server-cloudimg-i386-disk1.img, from http://cloud-images.ubuntu.com

[Jeff Lane  (bladernr)]

It may need to barf loudly, but tracebacks are really unnecessary, as you pointed out, simply something like:

logging.error("No local cloud image found and download of %s from %s failed" % (filename,url))

and more verbose logging of what it's doing when using --debug would be nice.

I also think this bit is unnecessary:
WARNING:root:Invalid or Empty timeout in config file. Falling back to default

since there's a default, it's logical to assume that the config file is an override (e.g. when we don't specify an image in the config file, it does not generate a warning, it simply says "DEBUG:root:No image specified, downloading one now." which is a lot less threatening or ominous than WARNING!!!!.

but that's just my opinion.

[Zygmunt Krynicki (zyga)]

+1 from me

On Thu, Mar 13, 2014 at 11:07 PM, Jeff Lane <email address hidden>wrote:

> It may need to barf loudly, but tracebacks are really unnecessary, as
> you pointed out, simply something like:
>
> logging.error("No local cloud image found and download of %s from %s
> failed" % (filename,url))
>
> and more verbose logging of what it's doing when using --debug would be
> nice.
>
> I also think this bit is unnecessary:
> WARNING:root:Invalid or Empty timeout in config file. Falling back to
> default
>
> since there's a default, it's logical to assume that the config file is
> an override (e.g. when we don't specify an image in the config file, it
> does not generate a warning, it simply says "DEBUG:root:No image
> specified, downloading one now." which is a lot less threatening or
> ominous than WARNING!!!!.
>
> but that's just my opinion.
>
> --
> You received this bug notification because you are a member of Checkbox
> Bug Wranglers, which is subscribed to checkbox.
> https://bugs.launchpad.net/bugs/1292032
>
> Title:
> checkbox virtualization test fails if image is not pre-downloaded
>
> To manage notifications about this bug go to:
> https://bugs.launchpad.net/checkbox/+bug/1292032/+subscriptions
>