821927 - Frequent test_redundant_operations.js | ScriptTimeoutException: timed out

Status: RESOLVED WORKSFORME

(Core :: DOM: Device Interfaces, defect)

Description

[Jonathan Griffin (:jgriffin)]

The test dom/telephony/test/marionette/test_redundant_operations.js is frequently failing with this error:

14:56:57    ERROR -  Traceback (most recent call last):
14:56:57     INFO -    File "/home/cltbld/talos-slave/test/build/tests/marionette/marionette/marionette_test.py", line 213, in runTest
14:56:57     INFO -      results = self.marionette.execute_js_script(js, args, special_powers=True)
14:56:57     INFO -    File "/home/cltbld/talos-slave/test/build/tests/marionette/marionette/marionette.py", line 450, in execute_js_script
14:56:57     INFO -      specialPowers=special_powers)
14:56:57     INFO -    File "/home/cltbld/talos-slave/test/build/tests/marionette/marionette/marionette.py", line 227, in _send_message
14:56:57     INFO -      self._handle_error(response)
14:56:57     INFO -    File "/home/cltbld/talos-slave/test/build/tests/marionette/marionette/marionette.py", line 276, in _handle_error
14:56:57    ERROR -      raise ScriptTimeoutException(message=message, status=status, stacktrace=stacktrace)
14:56:57    ERROR -  TEST-UNEXPECTED-FAIL | test_redundant_operations.js | ScriptTimeoutException: timed out

Sometimes, this causes mass carnage afterwards, othertimes it's just this one test that fails.

This appeared at roughly the same time on mozilla-inbound and mozilla-central, at about the same time the emulator used by buildbot was updated (bug 821563), so I'm thinking that is the cause, even though I can't reproduce it locally.

I'm going to disable this test for now, since it's failing most of the time.

Comment 1

[Jonathan Griffin (:jgriffin)]

Failing logs:

https://tbpl.mozilla.org/php/getParsedLog.php?id=17957399&tree=Mozilla-Inbound&full=1
https://tbpl.mozilla.org/php/getParsedLog.php?id=17959053&tree=Mozilla-Inbound&full=1
https://tbpl.mozilla.org/php/getParsedLog.php?id=17955036&tree=Mozilla-Inbound&full=1
https://tbpl.mozilla.org/php/getParsedLog.php?id=17953705&tree=Mozilla-Inbound&full=1
https://tbpl.mozilla.org/php/getParsedLog.php?id=17955241&tree=Firefox&full=1
https://tbpl.mozilla.org/php/getParsedLog.php?id=17959135&tree=Firefox&full=1

Comment 2

[Jonathan Griffin (:jgriffin)]

test disabled:

https://hg.mozilla.org/integration/mozilla-inbound/rev/75e1f24b9af7
https://hg.mozilla.org/releases/mozilla-b2g18/rev/47823629795e
https://hg.mozilla.org/releases/mozilla-aurora/rev/baa0d68059af
https://hg.mozilla.org/mozilla-central/rev/5706b21f8c95

Comment 3

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/mozilla-central/rev/75e1f24b9af7

Comment 4

[Legacy TBPL/Treeherder Robot]

edmorley
https://tbpl.mozilla.org/php/getParsedLog.php?id=17963164&tree=Mozilla-Inbound
b2g_ics_armv7a_gecko_emulator mozilla-inbound opt test marionette-webapi on 2012-12-14 20:07:12
slave: talos-r3-fed-027

20:14:54    ERROR -  Traceback (most recent call last):
20:14:54    ERROR -      raise ScriptTimeoutException(message=message, status=status, stacktrace=stacktrace)
20:14:54    ERROR -  TEST-UNEXPECTED-FAIL | test_redundant_operations.js | ScriptTimeoutException: timed out
20:14:54    ERROR -  FAILED (errors=1)
20:14:58    ERROR -  Traceback (most recent call last):
20:14:58     INFO -  TEST-UNEXPECTED-FAIL | test_multiple_hold.js | MarionetteException: Emulator callback still pending when finish() called
20:14:58    ERROR -  FAILED (errors=1)
20:18:47    ERROR - Return code: 10

Comment 5

[Legacy TBPL/Treeherder Robot]

edmorley
https://tbpl.mozilla.org/php/getParsedLog.php?id=17963098&tree=Mozilla-Inbound
b2g_ics_armv7a_gecko_emulator mozilla-inbound opt test marionette-webapi on 2012-12-14 20:04:05
slave: talos-r3-fed-014

20:10:42    ERROR -  Traceback (most recent call last):
20:10:42    ERROR -      raise ScriptTimeoutException(message=message, status=status, stacktrace=stacktrace)
20:10:42    ERROR -  TEST-UNEXPECTED-FAIL | test_redundant_operations.js | ScriptTimeoutException: timed out
20:10:42    ERROR -  FAILED (errors=1)
20:10:42    ERROR -  Traceback (most recent call last):
20:10:42     INFO -  TEST-UNEXPECTED-FAIL | test_multiple_hold.js | MarionetteException: {u'from': u'root', u'id': u'conn29.marionette1'}
20:10:42    ERROR -  FAILED (errors=1)
20:10:42    ERROR -  Traceback (most recent call last):
20:10:42     INFO -  TEST-UNEXPECTED-FAIL | test_battery_status_charging.js | MarionetteException: {u'from': 158, u'error': u'noSuchActor'}
20:10:42    ERROR -  FAILED (errors=1)
20:10:42    ERROR -  Traceback (most recent call last):
20:10:42     INFO -  TEST-UNEXPECTED-FAIL | test_battery_status_discharging.js | MarionetteException: {u'from': 158, u'error': u'noSuchActor'}
20:10:42    ERROR -  FAILED (errors=1)
20:10:42    ERROR -  Traceback (most recent call last):
20:10:42     INFO -  TEST-UNEXPECTED-FAIL | test_battery_status_full.js | MarionetteException: {u'from': 158, u'error': u'noSuchActor'}
20:10:42    ERROR -  FAILED (errors=1)
20:10:42    ERROR -  Traceback (most recent call last):
20:10:42     INFO -  TEST-UNEXPECTED-FAIL | test_battery_status_not_charging.js | MarionetteException: {u'from': 158, u'error': u'noSuchActor'}
20:10:42    ERROR -  FAILED (errors=1)
20:10:42    ERROR -  Traceback (most recent call last):
Only displaying first 20 of 100+ failures -
.

Comment 6

[Legacy TBPL/Treeherder Robot]

edmorley
https://tbpl.mozilla.org/php/getParsedLog.php?id=17963109&tree=Mozilla-Inbound
b2g_ics_armv7a_gecko_emulator mozilla-inbound opt test marionette-webapi on 2012-12-14 20:05:35
slave: talos-r3-fed-066

20:12:01    ERROR -  Traceback (most recent call last):
20:12:01    ERROR -      raise ScriptTimeoutException(message=message, status=status, stacktrace=stacktrace)
20:12:01    ERROR -  TEST-UNEXPECTED-FAIL | test_redundant_operations.js | ScriptTimeoutException: timed out
20:12:01    ERROR -  FAILED (errors=1)
20:12:01    ERROR -  Traceback (most recent call last):
20:12:01     INFO -  TEST-UNEXPECTED-FAIL | test_multiple_hold.js | MarionetteException: {u'from': u'root', u'id': u'conn29.marionette1'}
20:12:01    ERROR -  FAILED (errors=1)
20:12:01    ERROR -  Traceback (most recent call last):
20:12:01     INFO -  TEST-UNEXPECTED-FAIL | test_battery_status_charging.js | MarionetteException: {u'from': 156, u'error': u'noSuchActor'}
20:12:01    ERROR -  FAILED (errors=1)
20:12:01    ERROR -  Traceback (most recent call last):
20:12:01     INFO -  TEST-UNEXPECTED-FAIL | test_battery_status_discharging.js | MarionetteException: {u'from': 156, u'error': u'noSuchActor'}
20:12:01    ERROR -  FAILED (errors=1)
20:12:01    ERROR -  Traceback (most recent call last):
20:12:01     INFO -  TEST-UNEXPECTED-FAIL | test_battery_status_full.js | MarionetteException: {u'from': 156, u'error': u'noSuchActor'}
20:12:01    ERROR -  FAILED (errors=1)
20:12:01    ERROR -  Traceback (most recent call last):
20:12:01     INFO -  TEST-UNEXPECTED-FAIL | test_battery_status_not_charging.js | MarionetteException: {u'from': 156, u'error': u'noSuchActor'}
20:12:01    ERROR -  FAILED (errors=1)
20:12:01    ERROR -  Traceback (most recent call last):
Only displaying first 20 of 100+ failures -
.

Comment 7

[Legacy TBPL/Treeherder Robot]

edmorley
https://tbpl.mozilla.org/php/getParsedLog.php?id=17963148&tree=Mozilla-Inbound
b2g_ics_armv7a_gecko_emulator mozilla-inbound opt test marionette-webapi on 2012-12-14 20:05:57
slave: talos-r3-fed-073

20:12:22    ERROR -  Traceback (most recent call last):
20:12:22    ERROR -      raise ScriptTimeoutException(message=message, status=status, stacktrace=stacktrace)
20:12:22    ERROR -  TEST-UNEXPECTED-FAIL | test_redundant_operations.js | ScriptTimeoutException: timed out
20:12:22    ERROR -  FAILED (errors=1)
20:12:26    ERROR -  Traceback (most recent call last):
20:12:26     INFO -  TEST-UNEXPECTED-FAIL | test_multiple_hold.js | MarionetteException: Emulator callback still pending when finish() called
20:12:26    ERROR -  FAILED (errors=1)
20:16:15    ERROR - Return code: 10
20:16:16     INFO -  I/Gecko   (  304): MARIONETTE TEST RESULT:TEST-UNEXPECTED-FAIL | test_multiple_hold.js | undefined - got inbound from 5555551111 : active, expected OK
20:16:16     INFO -  I/Gecko   (  304): MARIONETTE TEST RESULT:TEST-UNEXPECTED-FAIL | test_multiple_hold.js | undefined - got 2, expected 1
20:16:16     INFO -  I/Gecko   (  304): MARIONETTE TEST RESULT:TEST-UNEXPECTED-FAIL | test_multiple_hold.js | undefined - got [object TelephonyCall], expected [object TelephonyCall]
20:16:16     INFO -  I/Gecko   (  304): MARIONETTE TEST RESULT:TEST-UNEXPECTED-FAIL | test_multiple_hold.js | undefined - got inbound from 5555551111 : active, expected inbound from 5555551111 : incoming
20:16:16     INFO -  I/Gecko   (  304): MARIONETTE TEST RESULT:TEST-UNEXPECTED-FAIL | test_multiple_hold.js | undefined - got inbound from 5555551111 : incoming, expected OK
20:16:16     INFO -  I/Gecko   (  304): MARIONETTE TEST RESULT:TEST-UNEXPECTED-FAIL | test_multiple_hold.js | undefined - got inbound from 5555551111 : held, expected inbound from 5555551111 : active
20:16:16     INFO -  I/Gecko   (  304): MARIONETTE TEST RESULT:TEST-UNEXPECTED-FAIL | test_multiple_hold.js | undefined - got inbound from 5555551111 : active, expected OK
20:16:16     INFO -  I/Gecko   (  304): MARIONETTE TEST RESULT:TEST-UNEXPECTED-FAIL | test_multiple_hold.js | undefined - got [object TelephonyCall], expected null
20:16:16     INFO -  I/Gecko   (  304): MARIONETTE TEST RESULT:TEST-UNEXPECTED-FAIL | test_multiple_hold.js | undefined - got 2, expected 1
20:16:16     INFO -  I/Gecko   (  304): MARIONETTE TEST RESULT:TEST-UNEXPECTED-FAIL | test_multiple_hold.js | undefined - got [object TelephonyCall], expected [object TelephonyCall]
20:16:16     INFO -  I/Gecko   (  304): MARIONETTE TEST RESULT:TEST-UNEXPECTED-FAIL | test_multiple_hold.js | undefined - got inbound from 5555551111 : active, expected inbound from 5555551111 : held
20:16:16     INFO -  I/Gecko   (  304): MARIONETTE TEST RESULT:TEST-UNEXPECTED-FAIL | test_multiple_hold.js | undefined - got inbound from 5555551111 : held, expected OK
Only displaying first 20 of 39 failures -
.

Comment 8

[Ed Morley [:emorley]]

Resolving WFM keyword:intermittent-failure bugs last modified >3 months ago, whose whiteboard contains none of:
{random,disabled,marked,fuzzy,todo,fails,failing,annotated,time-bomb,leave open}

There will inevitably be some false positives; for that (and the bugspam) I apologise. Filter on orangewfm.