Closed Bug 823084 Opened 11 years ago Closed 10 years ago

Intermittent test_incoming_already_connected.js | ScriptTimeoutException: timed out (followed by many more)

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 FIXED

People

(Reporter: emorley, Assigned: edgar)

References

Details

(Keywords: intermittent-failure) 

b2g_ics_armv7a_gecko_emulator mozilla-inbound opt test marionette-webapi on 2012-12-19 07:53:15 PST for push d7a482019f54

slave: talos-r3-fed-029

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

{
07:59:08     INFO -  TEST-START test_incoming_already_connected.js
07:59:58     INFO -  /home/cltbld/talos-slave/test/build/tests/marionette/tests/dom/telephony/test/marionette/test_incoming_already_connected.js, runTest (marionette_test.MarionetteJSTestCase) ... ERROR
07:59:59     INFO -  ======================================================================
07:59:59     INFO -  ERROR: /home/cltbld/talos-slave/test/build/tests/marionette/tests/dom/telephony/test/marionette/test_incoming_already_connected.js, runTest (marionette_test.MarionetteJSTestCase)
07:59:59     INFO -  ----------------------------------------------------------------------
07:59:59    ERROR -  Traceback (most recent call last):
07:59:59     INFO -    File "/home/cltbld/talos-slave/test/build/tests/marionette/marionette/marionette_test.py", line 213, in runTest
07:59:59     INFO -      results = self.marionette.execute_js_script(js, args, special_powers=True)
07:59:59     INFO -    File "/home/cltbld/talos-slave/test/build/tests/marionette/marionette/marionette.py", line 450, in execute_js_script
07:59:59     INFO -      specialPowers=special_powers)
07:59:59     INFO -    File "/home/cltbld/talos-slave/test/build/tests/marionette/marionette/marionette.py", line 227, in _send_message
07:59:59     INFO -      self._handle_error(response)
07:59:59     INFO -    File "/home/cltbld/talos-slave/test/build/tests/marionette/marionette/marionette.py", line 276, in _handle_error
07:59:59    ERROR -      raise ScriptTimeoutException(message=message, status=status, stacktrace=stacktrace)
07:59:59    ERROR -  TEST-UNEXPECTED-FAIL | test_incoming_already_connected.js | ScriptTimeoutException: timed out
07:59:59     INFO -  ----------------------------------------------------------------------
07:59:59     INFO -  Ran 1 test in 50.886s
07:59:59    ERROR -  FAILED (errors=1)
07:59:59     INFO -  TEST-START test_incoming_answer_remote_hangup.js
08:00:01     INFO -  /home/cltbld/talos-slave/test/build/tests/marionette/tests/dom/telephony/test/marionette/test_incoming_answer_remote_hangup.js, runTest (marionette_test.MarionetteJSTestCase) ... FAIL
08:00:01     INFO -  ======================================================================
08:00:01     INFO -  FAIL: /home/cltbld/talos-slave/test/build/tests/marionette/tests/dom/telephony/test/marionette/test_incoming_answer_remote_hangup.js, runTest (marionette_test.MarionetteJSTestCase)
08:00:01     INFO -  ----------------------------------------------------------------------
08:00:01    ERROR -  Traceback (most recent call last):
08:00:01     INFO -    File "/home/cltbld/talos-slave/test/build/tests/marionette/marionette/marionette_test.py", line 229, in runTest
08:00:01     INFO -      '%d tests failed:\n%s' % (results['failed'], '\n'.join(fails)))
08:00:01     INFO -  AssertionError: 1 tests failed:
08:00:01     INFO -  TEST-UNEXPECTED-FAIL | test_incoming_answer_remote_hangup.js | got outbound to  5555551111 : active, expected OK | got false, expected true
...
...
}
08:04:25     INFO -  I/Gecko   (  299): MARIONETTE TEST RESULT:TEST-UNEXPECTED-FAIL | test_incoming_already_connected.js | undefined - got outbound to  5555551111 : active, expected outbound to  5555551111 : ringing

According to the failed log, I believe this failed is related to a bug in emulator which will be fixed in bug 839368 (pull request part2 [1]).

In current emulator's design, the call state changes to active automatically when it is in ringing state [2]. Although there is 1 sec delay, but this behavior still has some potential racing problems. 
Like,
1). We expect the call state is in ringing, but it already changed to active. (log of comment 0, comment 1, comment 2)
2). We expect to receive onconnected event after sending 'gsm accept' in console, but call state changed to active before we send console command. So we lost the event. (log of comment 3)

The correct behavior is that call state should stay in ringing and not change to active until receiving 'gsm accept' from console.

[1] https://github.com/mozilla-b2g/platform_external_qemu/pull/21
[2] https://github.com/mozilla-b2g/platform_external_qemu/blob/master/telephony/android_modem.c#L2158
Assignee: nobody → echen
Cool, thank Edgar!
Also, in bug 842492, I am doing some improvement in emulator and test case to make sure a previous failure not affecting the followings.
Depends on: 839368, 843631
This issue was fixed in bug 839368. (Part-2 patch [1])
And the emulator was updated in bug 843631.

So change status to FIXED.

[1] https://github.com/EdgarChen/platform_external_qemu/commit/763b804698f19aca7a47a054b113a18b8b77dc85
Status: NEW → RESOLVED
Closed: 10 years ago
Resolution: --- → FIXED
You need to log in before you can comment on or make changes to this bug.