Running the memory usage test suite on the device crashes

[Christopher Lee]

Running on the latest flash (Build: 20130711.2 (Saucy-41)) I get the following error message:

Loading tests from: /usr/lib/python2.7/dist-packages

09:49:22.354 INFO globals:48 - ************************************************************
09:49:22.355 INFO globals:49 - Starting test ubuntu_test_cases.memory_usage_measurement.tests.test_memory_usage.MemoryUsageTests.test_scenario
09:49:22.355 WARNING testcase:113 - No tracing available - install the python-autopilot-trace package!
09:49:22.561 WARNING testcase:146 - Process manager backend unavailable, application snapshot support disabled.
09:49:22.622 ERROR importer:51 - Could not find any typelib for Gdk
09:49:22.918 DEBUG probes:42 - smem start: Browser started
09:49:22.938 INFO __init__:136 - Launching process: ['/usr/bin/webbrowser-app', '-testability']
09:49:22.955 INFO __init__:169 - Looking for autopilot interface for PID 2541 (and children)
09:49:23.000 WARNING __init__:186 - Caught exception while searching for autopilot interface: 'DBusException("Could not get PID of name 'org.freedesktop.DBus': no such name",)'
09:49:24.112 WARNING __init__:186 - Caught exception while searching for autopilot interface: 'DBusException("Could not get PID of name 'org.freedesktop.DBus': no such name",)'
09:49:24.243 DEBUG dbus:354 - Selecting objects of type QQuickWindow with attributes: {}
09:49:24.257 WARNING dbus:479 - Generating introspection instance for type 'QQuickWindow' based on generic class.
09:49:24.292 DEBUG probes:58 - smem stop: Browser started
09:49:24.292 DEBUG probes:59 - Running 'smem-tabs'...
09:49:24.973 INFO testcase:382 - waiting for process to exit.
09:49:26.018 ERROR testresult:35 - ERROR: ubuntu_test_cases.memory_usage_measurement.tests.test_memory_usage.MemoryUsageTests.test_scenario
09:49:26.020 ERROR testresult:35 - traceback: {{{
Traceback (most recent call last):
  File "/usr/lib/python2.7/dist-packages/ubuntu_test_cases/memory_usage_measurement/tests/test_memory_usage.py", line 38, in test_scenario
    self.smem.pids.append(browser.app.process)
  File "/usr/lib/python2.7/contextlib.py", line 24, in __exit__
    self.gen.next()
  File "/usr/lib/python2.7/dist-packages/ubuntu_test_cases/memory_usage_measurement/probes.py", line 29, in probe
    self.stop(event)
  File "/usr/lib/python2.7/dist-packages/ubuntu_test_cases/memory_usage_measurement/probes.py", line 66, in stop
    .format(**pids_info[pid]))
KeyError: <subprocess.Popen object at 0xc7ff50>
}}}
09:49:26.021 ERROR testresult:35 - process-stdout: {{{
}}}
09:49:26.021 ERROR testresult:35 - traceback-2: {{{
Traceback (most recent call last):
  File "/usr/lib/python2.7/dist-packages/autopilot/utilities.py", line 253, in action_on_test_end
    obj.on_test_end(test_instance)
TypeError: on_test_end() takes no arguments (2 given)
}}}
09:49:26.022 ERROR testresult:35 - traceback-1: {{{
Traceback (most recent call last):
  File "/usr/lib/python2.7/dist-packages/ubuntu_test_cases/memory_usage_measurement/tests/test_memory_usage.py", line 81, in _write_report
    indent=4, sort_keys=True)
  File "/usr/lib/python2.7/json/__init__.py", line 189, in dump
    for chunk in iterable:
  File "/usr/lib/python2.7/json/encoder.py", line 434, in _iterencode
    for chunk in _iterencode_dict(o, _current_indent_level):
  File "/usr/lib/python2.7/json/encoder.py", line 408, in _iterencode_dict
    for chunk in chunks:
  File "/usr/lib/python2.7/json/encoder.py", line 332, in _iterencode_list
    for chunk in chunks:
  File "/usr/lib/python2.7/json/encoder.py", line 442, in _iterencode
    o = _default(o)
  File "/usr/lib/python2.7/json/encoder.py", line 184, in default
    raise TypeError(repr(o) + " is not JSON serializable")
TypeError: <subprocess.Popen object at 0xc7ff50> is not JSON serializable
}}}
09:49:26.022 ERROR testresult:35 - process-stderr: {{{
unknown option -- t
unknown option -- e
unknown option -- s
unknown option -- t
unknown option -- a
unknown option -- b
unknown option -- i
unknown option -- l
unknown option -- i
unknown option -- t
unknown option -- y
loaded the dummy plugin
loaded the Linux plugin
Registered the AalSensorPlugin types

Loading testability driver.

WARNING: This project is using the experimental QML API extensions for QtWebKit and is therefore tied to a specific QtWebKit release.
WARNING: The experimental API will change from version to version, or even be removed. You have been warned!

callbacks 0x42af0499 0x42af049d
creating surface at (0, 58) with size (720, 1222)loaded the dummy plugin
loaded the Linux plugin
Registered the AalSensorPlugin types

}}}
Tests running...
__pthread_gettid -2
----------------------------Browser started-----------------------------
======================================================================
ERROR: ubuntu_test_cases.memory_usage_measurement.tests.test_memory_usage.MemoryUsageTests.test_scenario
----------------------------------------------------------------------
_StringException: Empty attachments:
  process-stdout

process-stderr: {{{
unknown option -- t
unknown option -- e
unknown option -- s
unknown option -- t
unknown option -- a
unknown option -- b
unknown option -- i
unknown option -- l
unknown option -- i
unknown option -- t
unknown option -- y
loaded the dummy plugin
loaded the Linux plugin
Registered the AalSensorPlugin types

Loading testability driver.

WARNING: This project is using the experimental QML API extensions for QtWebKit and is therefore tied to a specific QtWebKit release.
WARNING: The experimental API will change from version to version, or even be removed. You have been warned!

callbacks 0x42af0499 0x42af049d
creating surface at (0, 58) with size (720, 1222)loaded the dummy plugin
loaded the Linux plugin
Registered the AalSensorPlugin types
}}}

test-log: {{{
09:49:22.354 INFO globals:48 - ************************************************************
09:49:22.355 INFO globals:49 - Starting test ubuntu_test_cases.memory_usage_measurement.tests.test_memory_usage.MemoryUsageTests.test_scenario
09:49:22.355 WARNING testcase:113 - No tracing available - install the python-autopilot-trace package!
09:49:22.561 WARNING testcase:146 - Process manager backend unavailable, application snapshot support disabled.
09:49:22.622 ERROR importer:51 - Could not find any typelib for Gdk
09:49:22.918 DEBUG probes:42 - smem start: Browser started
09:49:22.938 INFO __init__:136 - Launching process: ['/usr/bin/webbrowser-app', '-testability']
09:49:22.955 INFO __init__:169 - Looking for autopilot interface for PID 2541 (and children)
09:49:23.000 WARNING __init__:186 - Caught exception while searching for autopilot interface: 'DBusException("Could not get PID of name 'org.freedesktop.DBus': no such name",)'
09:49:24.112 WARNING __init__:186 - Caught exception while searching for autopilot interface: 'DBusException("Could not get PID of name 'org.freedesktop.DBus': no such name",)'
09:49:24.243 DEBUG dbus:354 - Selecting objects of type QQuickWindow with attributes: {}
09:49:24.257 WARNING dbus:479 - Generating introspection instance for type 'QQuickWindow' based on generic class.
09:49:24.292 DEBUG probes:58 - smem stop: Browser started
09:49:24.292 DEBUG probes:59 - Running 'smem-tabs'...
09:49:24.973 INFO testcase:382 - waiting for process to exit.
}}}

traceback-1: {{{
Traceback (most recent call last):
  File "/usr/lib/python2.7/dist-packages/ubuntu_test_cases/memory_usage_measurement/tests/test_memory_usage.py", line 81, in _write_report
    indent=4, sort_keys=True)
  File "/usr/lib/python2.7/json/__init__.py", line 189, in dump
    for chunk in iterable:
  File "/usr/lib/python2.7/json/encoder.py", line 434, in _iterencode
    for chunk in _iterencode_dict(o, _current_indent_level):
  File "/usr/lib/python2.7/json/encoder.py", line 408, in _iterencode_dict
    for chunk in chunks:
  File "/usr/lib/python2.7/json/encoder.py", line 332, in _iterencode_list
    for chunk in chunks:
  File "/usr/lib/python2.7/json/encoder.py", line 442, in _iterencode
    o = _default(o)
  File "/usr/lib/python2.7/json/encoder.py", line 184, in default
    raise TypeError(repr(o) + " is not JSON serializable")
TypeError: <subprocess.Popen object at 0xc7ff50> is not JSON serializable
}}}

traceback-2: {{{
Traceback (most recent call last):
  File "/usr/lib/python2.7/dist-packages/autopilot/utilities.py", line 253, in action_on_test_end
    obj.on_test_end(test_instance)
TypeError: on_test_end() takes no arguments (2 given)
}}}

Traceback (most recent call last):
  File "/usr/lib/python2.7/dist-packages/ubuntu_test_cases/memory_usage_measurement/tests/test_memory_usage.py", line 38, in test_scenario
    self.smem.pids.append(browser.app.process)
  File "/usr/lib/python2.7/contextlib.py", line 24, in __exit__
    self.gen.next()
  File "/usr/lib/python2.7/dist-packages/ubuntu_test_cases/memory_usage_measurement/probes.py", line 29, in probe
    self.stop(event)
  File "/usr/lib/python2.7/dist-packages/ubuntu_test_cases/memory_usage_measurement/probes.py", line 66, in stop
    .format(**pids_info[pid]))
KeyError: <subprocess.Popen object at 0xc7ff50>

Ran 1 test in 3.669s
FAILED (failures=1)

[Javier Collado (javier.collado)]

The problem according to the traceback is as follows:
- test case fails
- cleanup runs
- an attempt to write report is made
- json module fails because data is not serializable

Anyway, there is another issue here that I'd like to bring up. According to the
tests I've run there's something that doesn't behave the same way in autopilot
depending on where the test is executed.

If the test case is executed in the desktop, then `proxy.app.process` seems to
be a `subprocess.Popen` object and `proxy.app.pid` is an integer that indeed
matches the process id for the application that was launched.

However, when the test case is executed in a device, `proxy.app.process` is an
integer that matches the process id for the application that was launched and
`proxy.app.pid` doesn't seem to exist.

What I think that happened in this case is that the test case was executed in a
desktop and, when it failed, the json module failed to serialize the data
because instead of an integer (as it happens in the touch image), what it found
was a `subprocess.Popen` object that cannot be serialized.

Consequently, what I'm going to do is move this bug to the `autopilot` project
since the root cause is that autopilot isn't providing a consistent way to
access the PID of an application that has been launched through the proxy
object.

[Javier Collado (javier.collado)]

As an example, the execution of a test case that launches the browser
application and prints the `process` and `pid` attributes if available, returns
the following results:

****************** Desktop ******************
$ PYTHONPATH=. autopilot run ubuntu_test_cases.memory_usage_measurement
Loading tests from: /home/javi/code/bzr/ubuntu-test-cases/memory-usage-measurement/autopilot

Tests running...
process: <subprocess.Popen object at 0x221c3d0>
pid: 16646
----------------------------Browser started-----------------------------

Ran 1 test in 3.316s
OK
********************************************

Note that both `process` and `pid` are available and their types.

****************** Device ******************
$ phablet-test-run -n -c /tmp/ubuntu-test-cases-memory-usage-measurement_0.1~rev73~saucy_all.deb ubuntu_test_cases.memory_usage_measurement
adbd is already running as root
Pushing ubuntu-test-cases-memory-usage-measurement_0.1~rev73~saucy_all.deb...
176 KB/s (7506 bytes in 0.041s)
(Reading database ... 34019 files and directories currently installed.)
Preparing to replace ubuntu-test-cases-memory-usage-measurement 0.1~rev73~saucy (using .../ubuntu-test-cases-memory-usage-measurement_0.1~rev73~saucy_all.deb) ...
Unpacking replacement ubuntu-test-cases-memory-usage-measurement ...
Setting up ubuntu-test-cases-memory-usage-measurement (0.1~rev73~saucy) ...
Disabling shell
Stopping Shell...
Loading tests from: /usr/lib/python2.7/dist-packages

Tests running...
__pthread_gettid -2
process: 4571
----------------------------Browser started-----------------------------

Ran 1 test in 4.458s
OK
Connection to 127.0.0.1 closed.
Restoring shell
********************************************

Note that only `pid` exists and its type isn't the same one as in the desktop case.

[Christopher Lee (veebers)]

Hi Javier,

Would you be able to check and post the autopilot versions on both your desktop and device please to assist in debugging.

Thanks.

[Javier Collado (javier.collado)]

I'm not sure what has changed, but I can no longer reproduce what I reported in
#2, that is, I get that `proxy.app.process` returns an integer for both the
desktop and the device with the touch image.

I remember that at some point there was a change from `pid` to `process` that
was needed to make the test work as it can be seen here:
http://bazaar.launchpad.net/~javier.collado/ubuntu-test-cases/memory-usage-measurement/revision/59

I might have mixed different versions, but that change in the autopilot
behavior seems to have happened around a couple of weeks ago which seems quite
a while given that I'm running saucy. Anyway, I can't think of any other way in
which a `subprocess.Popen` object could be in place of an integer with the
current test case code.

Can you think of any way for autopilot to behave diffently with regard to
process/pid in proxy objects? If not, then I think we should just close this
bug.

[PS Jenkins bot (ps-jenkins)]

Fix committed into lp:autopilot at revision 273, scheduled for release in autopilot, milestone 1.3.2

[Launchpad Janitor (janitor)]

This bug was fixed in the package autopilot - 1.3.1+13.10.20130717-0ubuntu1

---------------
autopilot (1.3.1+13.10.20130717-0ubuntu1) saucy; urgency=low

  [ Christopher Lee ]
  * Fixes bug where the proxy process object wasn't being set properly.
    (LP: #1200560)

  [ Ubuntu daily release ]
  * Automatic snapshot from revision 273
 -- Ubuntu daily release <email address hidden> Wed, 17 Jul 2013 00:02:12 +0000