Apps failing to start in some autopilot tests

[Omer Akram]

Many of the tests are performing fine but in multiple autopilot tests it seems the app is failing to start. I didn't see any crash logs.

test-log: {{{
08:57:22.568 WARNING testcase:115 - No tracing available - install the python-autopilot-trace package!
08:57:22.582 WARNING testcase:162 - Process manager backend unavailable, application snapshot support disabled.
08:57:22.638 INFO logging:45 - str: Set the value of an initctl environment variable. Arguments ('/home/phablet/autopilot/fakeenv/tmpnbcc1e62',).
Keyword arguments: {}.
08:57:22.658 DEBUG __init__:174 - Patched home to fake home directory /home/phablet/autopilot/fakeenv/tmpnbcc1e62
08:57:22.660 DEBUG __init__:178 - Creating music library for click test
08:57:22.661 DEBUG __init__:179 - Home set to /home/phablet/autopilot/fakeenv/tmpnbcc1e62
08:57:22.661 DEBUG __init__:181 - Music path set to /home/phablet/autopilot/fakeenv/tmpnbcc1e62/Music
08:57:22.662 DEBUG __init__:186 - Mediascanner path set to /home/phablet/autopilot/fakeenv/tmpnbcc1e62/.cache/mediascanner-2.0
08:57:22.663 DEBUG __init__:192 - Content dir set to /home/phablet/autopilot/music_app/content
08:57:22.726 DEBUG __init__:201 - Music copied, files ['1.ogg', '2.ogg', '3.mp3']
08:57:22.726 DEBUG __init__:214 - Patching fake mediascanner database in /home/phablet/autopilot/fakeenv/tmpnbcc1e62/.cache/mediascanner-2.0
08:57:22.727 DEBUG __init__:217 - Mediascanner database files ['mediastore.sql', 'mediastore.db']
08:57:22.826 DEBUG __init__:207 - Mediascanner database copied, files ['mediastore.sql', 'mediastore.db']
08:57:22.828 INFO logging:45 - TestMainWindow: launch_test_click. Arguments (). Keyword arguments: {}.
08:57:22.829 INFO _launcher:280 - Attempting to launch click application '(default)' from click package 'com.ubuntu.music' and URIs ''
08:57:23.736 INFO _launcher:120 - Attempting to launch application 'com.ubuntu.music_music_1.3.625' with URIs '' via upstart-app-launch
08:57:51.371 ERROR proxies:410 - Introspect error on :1.229:/com/canonical/Autopilot/Introspection: dbus.exceptions.DBusException:
org.freedesktop.DBus.Error.NoReply: Did not receive a reply. Possible causes include: the remote application did not send a reply, the message bus
security policy blocked the reply, the reply timeout expired, or the network connection was broken.
08:57:51.393 DEBUG proxies:413 - Executing introspect queue due to error
08:58:42.649 ERROR proxies:410 - Introspect error on :1.231:/com/canonical/Autopilot/Introspection: dbus.exceptions.DBusException:
org.freedesktop.DBus.Error.NoReply: Did not receive a reply. Possible causes include: the remote application did not send a reply, the message bus
security policy blocked the reply, the reply timeout expired, or the network connection was broken.
08:58:42.654 DEBUG proxies:413 - Executing introspect queue due to error
08:59:17.074 INFO logging:45 - str: Set the value of an initctl environment variable. Arguments ('/home/phablet',). Keyword arguments: {}.
}}}

Traceback (most recent call last):
  File "/home/phablet/autopilot/music_app/tests/test_music.py", line 26, in setUp
    super(TestMainWindow, self).setUp()
  File "/home/phablet/autopilot/music_app/tests/__init__.py", line 255, in setUp
    self.app = MusicApp(launcher_method())
  File "/usr/lib/python3/dist-packages/autopilot/logging.py", line 46, in inner
    return f(instance, *args, **kwargs)
  File "/home/phablet/autopilot/music_app/tests/__init__.py", line 92, in launch_test_click
    emulator_base=ubuntuuitoolkit.UbuntuUIToolkitCustomProxyObjectBase)
  File "/usr/lib/python3/dist-packages/autopilot/testcase.py", line 310, in launch_click_package
    return launcher.launch(package_id, app_name, app_uris)
  File "/usr/lib/python3/dist-packages/autopilot/application/_launcher.py", line 283, in launch
    return super().launch(app_id, app_uris)
  File "/usr/lib/python3/dist-packages/autopilot/application/_launcher.py", line 146, in launch
    pid=pid
  File "/usr/lib/python3/dist-packages/autopilot/introspection/_search.py", line 176, in get_proxy_object_for_existing_process
    _get_search_criteria_string_representation(**kwargs)
  File "/usr/lib/python3/dist-packages/autopilot/introspection/_search.py", line 375, in _raise_if_not_single_result
    (criteria_string)
autopilot.exceptions.ProcessSearchError: Search criteria (object path = '/com/canonical/Autopilot/Introspection', pid = 10421) returned no results

[Omer Akram (om26er)]

http://ci.ubuntu.com/smokeng/utopic/touch/mako/243:20140916:20140903.1/10486/music_app/1683611/

[Victor Thompson (vthompson)]

I can't think of anything that was introduced that would be causing this. Some of the tests were refactored, but the setup is much the same. Also, I don't think the setup is taking significant time--maybe 300 milliseconds.

I wonder if there might be some issue with the updating of the mediascanner2 models as the app is being opened?

[Nicholas Skaggs (nskaggs)]

The screenshots show that indeed the app is still loading. It's hard to say if the app failed to start, or simply took a long time to start. I've been noticing this in other jenkins runs as well. Sadly, the environment does not provide a signal for when the application has loaded, thus we are stuck with resorting to things like this in the mainview instead:

class MainView(MainView):
        super(MainView, self).__init__(*args)
        self.visible.wait_for(True)

As you can see in the log, this doesn't help in this case because the application itself has not started (it's not delayed in drawing the UI).

[Nicholas Skaggs (nskaggs)]

Adding autopilot as affected and proposing MP for autopilot devs to have a look at to attempt to mitigate this.

[Nicholas Skaggs (nskaggs)]

Should we decide to increase the timeout of test runs, chris informs us we can use --timeout-profile=long to make the timeout 30 seconds for that run. I'm removing my branch and unmarking AP for now.

[Nicholas Skaggs (nskaggs)]

I would propose to raise the default timeout to 30 seconds for jenkins CI dashboard runs as well as jenkins jobs used during merges.

[Andrew Hayzen (ahayzen)]

Is this still occurring? I haven't seen any failures for music for a while [0] [1]

0 - http://ci.ubuntu.com/smokeng/utopic/touch_stable/mako/153:20141217.2:20141119/11690/
1 - http://91.189.93.70:8080/job/music-app-autolanding/