Closed Bug 909485 Opened 11 years ago Closed 9 years ago

Intermittent B2G test_emergency_label.js | ScriptTimeoutException: timed out | MarionetteException: Emulator callback still pending when finish() called

Categories

(Firefox OS Graveyard :: General, defect)

Product:
Firefox OS Graveyard
Component:
General
Platform:
ARM
Gonk (Firefox OS)
Type:
defect
Priority:
Not set
Severity:
normal

Tracking

(Not tracked)

Status:
RESOLVED WORKSFORME

People

(Reporter: RyanVM, Unassigned)

References

Details

(Keywords: intermittent-failure) 

https://tbpl.mozilla.org/php/getParsedLog.php?id=27015868&tree=Mozilla-Inbound

b2g_emulator mozilla-inbound opt test marionette-webapi on 2013-08-26 11:46:37 PDT for push 6ef19b1dedf4
slave: talos-r3-fed-086

12:17:19     INFO -  TEST-START test_emergency_label.js
12:18:20     INFO -  /home/cltbld/talos-slave/test/build/tests/marionette/tests/dom/telephony/test/marionette/test_emergency_label.js, runTest (marionette_test.MarionetteJSTestCase) ... ERROR
12:18:20     INFO -  ======================================================================
12:18:20     INFO -  ERROR: /home/cltbld/talos-slave/test/build/tests/marionette/tests/dom/telephony/test/marionette/test_emergency_label.js, runTest (marionette_test.MarionetteJSTestCase)
12:18:20     INFO -  ----------------------------------------------------------------------
12:18:20     INFO -  Traceback (most recent call last):
12:18:20     INFO -    File "/home/cltbld/talos-slave/test/build/tests/marionette/marionette/marionette_test.py", line 132, in run
12:18:20     INFO -      testMethod()
12:18:20     INFO -    File "/home/cltbld/talos-slave/test/build/tests/marionette/marionette/marionette_test.py", line 395, in runTest
12:18:20     INFO -      filename=os.path.basename(self.jsFile))
12:18:20     INFO -    File "/home/cltbld/talos-slave/test/build/tests/marionette/marionette/marionette.py", line 929, in execute_js_script
12:18:20     INFO -      line=None)
12:18:20     INFO -    File "/home/cltbld/talos-slave/test/build/tests/marionette/marionette/marionette.py", line 570, in _send_message
12:18:20     INFO -      self._handle_error(response)
12:18:20     INFO -    File "/home/cltbld/talos-slave/test/build/tests/marionette/marionette/marionette.py", line 619, in _handle_error
12:18:20    ERROR -      raise ScriptTimeoutException(message=message, status=status, stacktrace=stacktrace)
12:18:20    ERROR -  TEST-UNEXPECTED-FAIL | test_emergency_label.js | ScriptTimeoutException: timed out
12:18:20     INFO -  ----------------------------------------------------------------------
12:18:20     INFO -  Ran 1 test in 61.230s
12:18:20  WARNING -  FAILED (errors=1)
12:18:21     INFO -  TEST-START test_voicemail_statuschanged.py
12:18:22     INFO -  testStatusChanged (test_voicemail_statuschanged.TestVoicemailStatusChanged) ... ERROR
12:18:22     INFO -  ======================================================================
12:18:22     INFO -  ERROR: testStatusChanged (test_voicemail_statuschanged.TestVoicemailStatusChanged)
12:18:22     INFO -  ----------------------------------------------------------------------
12:18:22     INFO -  Traceback (most recent call last):
12:18:22     INFO -    File "/home/cltbld/talos-slave/test/build/tests/marionette/marionette/marionette_test.py", line 132, in run
12:18:22     INFO -      testMethod()
12:18:22     INFO -    File "/home/cltbld/talos-slave/test/build/tests/marionette/tests/dom/voicemail/test/marionette/test_voicemail_statuschanged.py", line 14, in testStatusChanged
12:18:22     INFO -      self.marionette.execute_async_script(test)
12:18:22     INFO -    File "/home/cltbld/talos-slave/test/build/tests/marionette/marionette/marionette.py", line 1055, in execute_async_script
12:18:22     INFO -      filename=os.path.basename(frame[0]))
12:18:22     INFO -    File "/home/cltbld/talos-slave/test/build/tests/marionette/marionette/marionette.py", line 570, in _send_message
12:18:22     INFO -      self._handle_error(response)
12:18:22     INFO -    File "/home/cltbld/talos-slave/test/build/tests/marionette/marionette/marionette.py", line 631, in _handle_error
12:18:22     INFO -      raise MarionetteException(message=message, status=status, stacktrace=stacktrace)
12:18:22     INFO -  TEST-UNEXPECTED-FAIL | test_voicemail_statuschanged.py TestVoicemailStatusChanged.testStatusChanged | MarionetteException: Emulator callback still pending when finish() called
12:18:22     INFO -  START LOG:
12:18:22     INFO -  INFO Call list is now: outbound to  112        : ringing,OK Mon Aug 26 2013 19:18:20 GMT+0000 (GMT)
12:18:22     INFO -  INFO Answering the call. Mon Aug 26 2013 19:18:20 GMT+0000 (GMT)
12:18:22     INFO -  INFO Received 'connected' call event. Mon Aug 26 2013 19:18:20 GMT+0000 (GMT)
12:18:22     INFO -  INFO TEST-START: /home/cltbld/talos-slave/test/build/tests/marionette/tests/dom/voicemail/test/marionette/test_voicemail_statuschanged.py:testStatusChanged Mon Aug 26 2013 19:18:21 GMT+0000 (GMT)
12:18:22     INFO -  INFO -> sms pdu 00000B915121551532F45FF0000000000000000F3190BB7C07D9DFE971B91D4EB301 Mon Aug 26 2013 19:18:22 GMT+0000 (GMT)
12:18:22     INFO -  INFO <- OK Mon Aug 26 2013 19:18:22 GMT+0000 (GMT)
12:18:22     INFO -  INFO -> sms pdu 00000B915121551532F500C8000000000000000F3190BB7C07D9DFE971B91D4EB301 Mon Aug 26 2013 19:18:22 GMT+0000 (GMT)
12:18:22     INFO -  INFO <- OK Mon Aug 26 2013 19:18:22 GMT+0000 (GMT)
12:18:22     INFO -  INFO -> sms pdu 00000B915121551532F500C0000000000000000F3190BB7C07D9DFE971B91D4EB301 Mon Aug 26 2013 19:18:22 GMT+0000 (GMT)
12:18:22     INFO -  INFO <- OK Mon Aug 26 2013 19:18:22 GMT+0000 (GMT)
12:18:22     INFO -  INFO -> sms pdu 00400B915121551532F600C800000000000000160401020003CC40EEF21D647FA7C7E57638CD9E03 Mon Aug 26 2013 19:18:22 GMT+0000 (GMT)
12:18:22     INFO -  INFO <- OK Mon Aug 26 2013 19:18:22 GMT+0000 (GMT)
12:18:22     INFO -  INFO -> sms pdu 00400B915121551532F600C8000000000000001A040102000038DFA0BA5B5E0E9341F6777A5C6E87D3EC39 Mon Aug 26 2013 19:18:22 GMT+0000 (GMT)
12:18:22     INFO -  INFO <- OK Mon Aug 26 2013 19:18:22 GMT+0000 (GMT)
12:18:22     INFO -  INFO TEST-END: /home/cltbld/talos-slave/test/build/tests/marionette/tests/dom/voicemail/test/marionette/test_voicemail_statuschanged.py:testStatusChanged Mon Aug 26 2013 19:18:22 GMT+0000 (GMT)
12:18:22     INFO -  END LOG:
12:18:22     INFO -  ----------------------------------------------------------------------
12:18:22     INFO -  Ran 1 test in 1.712s
12:18:22  WARNING -  FAILED (errors=1)
Szu-Yu, I see you wrote this test. Can you please take a look? It's a big contributor to the webapi tests being near perma-fail on TBPL.
Flags: needinfo?(szchen)
Assignee: nobody → szchen
Flags: needinfo?(szchen)
Depends on: 1012504
(In reply to TBPL Robot from comment #96)
> Tomcat
> https://tbpl.mozilla.org/php/getParsedLog.php?id=40379311&tree=Mozilla-
> Inbound
> b2g_emulator_vm mozilla-inbound opt test marionette-webapi on 2014-05-25
> 19:21:09
> revision: 564504fcbca5
> slave: tst-linux64-spot-689
> 
> TEST-UNEXPECTED-FAIL | test_outgoing_emergency_in_airplane_mode.js |
> ScriptTimeoutException: ScriptTimeoutException: timed out
> TEST-UNEXPECTED-FAIL | test_emergency_label.js | ScriptTimeoutException:
> ScriptTimeoutException: timed out
> TEST-UNEXPECTED-FAIL | test_call_mute.js | ScriptTimeoutException:
> ScriptTimeoutException: timed out
> TEST-UNEXPECTED-FAIL | test_audiomanager_phonestate.js |
> ScriptTimeoutException: ScriptTimeoutException: timed out
> TEST-UNEXPECTED-FAIL | test_outgoing_answer_radio_off.js |
> ScriptTimeoutException: ScriptTimeoutException: timed out
> TEST-UNEXPECTED-FAIL | test_conference_two_calls.js |
> ScriptTimeoutException: ScriptTimeoutException: timed out
> TEST-UNEXPECTED-FAIL | test_conference_add_error.js |
> ScriptTimeoutException: ScriptTimeoutException: timed out
> TEST-UNEXPECTED-FAIL | test_conference_remove_error.js |
> ScriptTimeoutException: ScriptTimeoutException: timed out
> TEST-UNEXPECTED-FAIL | test_conference_two_hangup_one.js |
> ScriptTimeoutException: ScriptTimeoutException: timed out
> TEST-UNEXPECTED-FAIL | test_conference_two_hold_resume.js |
> ScriptTimeoutException: ScriptTimeoutException: timed out
> TEST-UNEXPECTED-FAIL | test_conference_two_remove_one.js |
> ScriptTimeoutException: ScriptTimeoutException: timed out
> TEST-UNEXPECTED-FAIL | test_conference_three_hangup_one.js |
> ScriptTimeoutException: ScriptTimeoutException: timed out
> TEST-UNEXPECTED-FAIL | test_conference_three_remove_one.js |
> ScriptTimeoutException: ScriptTimeoutException: timed out
> TEST-UNEXPECTED-FAIL | test_outgoing_when_two_calls_on_line.js |
> ScriptTimeoutException: ScriptTimeoutException: timed out
> Return code: 10

I have inspected the failure. It is caused by the bad interaction between emulator and the test_outgoing_emergency_in_airplane_mode.js. After the failure, telephony couldn't recover from the bad state and thus causes all the remaining tests fail. 

I have filed a new bug (Bug 1015097) to rewrite the test case. Hope it could solve the issue.
Depends on: 1018051
Assignee: szchen → nobody
Inactive; closing (see bug 1180138).
Status: NEW → RESOLVED
Closed: 9 years ago
Resolution: --- → WORKSFORME
You need to log in before you can comment on or make changes to this bug.