932385 - Errors in logcat E/GeckoConsole( 5720): [JavaScript Warning: "Empty string passed to getElementById()." {file: "chrome://marionette/content/marionette-elements.js" line: 164}]

Status: RESOLVED FIXED

(Remote Protocol :: Marionette, defect)

Description

[Zac C (:zac)]

Attachment: crash_hamachi.log

Hundreds of these are causing the device to freeze and test to fail.

Replicated by running:
https://github.com/mozilla-b2g/gaia/blob/master/tests/python/gaia-ui-tests/gaiatest/tests/functional/dialer/test_call_log_all_calls.py

Device Hamachi
Gecko  http://hg.mozilla.org/mozilla-central/rev/518f5bff0ae4
Gaia  92c097fd7ac9886f937d9decb0e03ab673deaa1b
BuildID 20131029040205
Version 28.0a1

Comment 1

[Jonathan Griffin (:jgriffin)]

This is a weird error.  There are lots of errors in logcat before this occurs, like:

E/GeckoConsole(  772): [JavaScript Error: "Error: Unknown rilSuppSvcNotification: null" {file: "jar:file:///system/b2g/omni.ja!/components/TelephonyProvider.js" line: 273}]
E/GeckoConsole(  772): [JavaScript Error: "NS_ERROR_XPC_JS_THREW_JS_OBJECT: 'Error: Unknown rilSuppSvcNotification: null' when calling method: [nsIGonkTelephonyProvider::notifySupplementaryService]" {file: "jar:file:///system/b2g/omni.ja!/components/RadioInterfaceLayer.js" line: 1020}]

The particular Marionette command that's causing the getElementById errors is:

  execute_script("return window.navigator.mozTelephony.active;")

...which is pretty confusing.  This is very likely a bug in Marionette, but it's secondary to whatever is causing the ril errors.

Comment 2

[Zac C (:zac)]

jgriffin, if it helps at all we also use the mozTelephony.active method in test_dialer.py but that does not cause the hang.

Comment 3

[Jonathan Griffin (:jgriffin)]

I suspect that the telephony WebAPI is breaking, and the Marionette errors are a side-effect, but I don't have a hamachi, so can't tell for certain.

Comment 4

[Zac C (:zac)]

I do; how can I help debug this further?

Comment 5

[Zac C (:zac)]

Yoshi, are you familiar with the exceptions in the logcat and comment #1 ?

Comment 6

[Jonathan Griffin (:jgriffin)]

It would help to know what "window.navigator.mozTelephony.active" is in the failing case; you could add the following call preceding the existing one:

execute_script("""
var active = window.navigator.mozTelephony.active;
log('active = ' + active + ', ' + typeof(active));
""")

Then, there should be something interesting showing up in the log which might help us figure out the Marionette side of things.

Comment 7

[Yoshi Cheng-Hao Huang [:allstars.chh][:allstarschh][:yoshi]]

CC Hsinyi here for she's the expert here.

Comment 8

[Zac C (:zac)]

Hsinyi, I'll re-run with the above debug later today and ni? you.

I'll also compare with Moz RIL and Com RIL. Comment #0 was with Mozilla RIL.

Comment 9

[Hsin-Yi Tsai (she/her) [:hsinyi]]

(In reply to Jonathan Griffin (:jgriffin) from comment #1)
> This is a weird error.  There are lots of errors in logcat before this
> occurs, like:
> 
> E/GeckoConsole(  772): [JavaScript Error: "Error: Unknown
> rilSuppSvcNotification: null" {file:
> "jar:file:///system/b2g/omni.ja!/components/TelephonyProvider.js" line: 273}]
> E/GeckoConsole(  772): [JavaScript Error: "NS_ERROR_XPC_JS_THREW_JS_OBJECT:
> 'Error: Unknown rilSuppSvcNotification: null' when calling method:
> [nsIGonkTelephonyProvider::notifySupplementaryService]" {file:
> "jar:file:///system/b2g/omni.ja!/components/RadioInterfaceLayer.js" line:
> 1020}]
> 

I know the messages look scaring, but these are not real errors. These are some types of notification not supported yet. Maybe we should have a softer way to handling this in RIL.

> The particular Marionette command that's causing the getElementById errors
> is:
> 
>   execute_script("return window.navigator.mozTelephony.active;")
> 
> ...which is pretty confusing.  This is very likely a bug in Marionette, but
> it's secondary to whatever is causing the ril errors.

What is the expected value of |mozTelephony.active| here? |mozTelephony.active| could be null, a telephonyCall object, or a telephonyCallGroup object.

Comment 10

[Zac C (:zac)]

> self.wait_for_condition(lambda m: not self.marionette.execute_script('return  window.navigator.mozTelephony.active;'), timeout=30)

is the exact syntax.

I've rewritten the code to skip this part and take a UI cue (wait for call screen co disappear).

However I'm still curious about why this regressed. Prior to this this code has worked fine for months.

Comment 11

[Zac C (:zac)]

Attachment: github pr

Bob, this needs Hamachi test. thanks

Comment 12

[Bob Silverberg [:bsilverberg]]

Attachment: Pointer to Github pull request: https://github.com/mozilla-b2g/gaia/pull/13330

Pointer to Github pull-request

Comment 13

[Bob Silverberg [:bsilverberg]]

Comment on attachment 826451 [details]
Pointer to Github pull request: https://github.com/mozilla-b2g/gaia/pull/13330

I'm not sure if we want to uplift this to v1.2, but I created a PR and have reopened this bug for investigation. The test seems to pass fine currently on v1.2 without this change, but perhaps it's safest to bring it over anyway?

Comment 14

[Zac C (:zac)]

Yes let's zap it over to keep the test cases inline.

Comment 15

[Bob Silverberg [:bsilverberg]]

Landed in v1.2 as https://github.com/mozilla-b2g/gaia/commit/3735da893b52418bf25fa32a9f961217c0707a85