1026072 - xpconnect wrapped JSObject: DOMIdentity.jsm:354 - TypeError: this.getContextForMM(...).RP is undefined

Status: RESOLVED FIXED

(Core Graveyard :: Identity, defect)

Description

[Nicolas B. Pierron [:nbp]]

Device:
 - Flame (latest v1.4, with B2G-flash-tool)
 - fastboot oem mem 256

STR:
 - Connect to a wifi network.
 - Open the marketplace.
 - Install the first ~30 games & click on "More" to install moar games.

Seen:
 - The Marketplace application is crashing (this does not look like an OOM kill of the Marketplace)

Expected:
 - Install as much apps as humanly possible.

Logcat:
> ************************************************************
> * Call to xpconnect wrapped JSObject produced this error:  *
> [Exception... "Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIMessageSender.sendAsyncMessage]"  nsresult: "0x80004005 (NS_ERROR_FAILURE)"  location: "JS frame :: resource://gre/modules/Webapps.jsm :: broadcastMessage/< :: line 1143"  data: no]
> ************************************************************
> System JS : ERROR resource://gre/modules/DOMIdentity.jsm:354 - TypeError: this.getContextForMM(...).RP is undefined

Comment 1

[Borja Salguero [:borjasalguero]]

For me it's happening the same (FLAME, m-c & Gaia master). STR:
- Open an APP which uses FxA
- Open FxA flow with 'watch' + 'request'
- Close the flow
- Close the APP

EXPECTED:
- Nothing happens

CURRENTLY:
- We see in the console a log with "System JS : ERROR resource://gre/modules/DOMIdentity.jsm:354 - TypeError: this.getContextForMM(...).RP is undefined"

After this, sometimes 'onlogin' & 'onlogout' events are not working (just 'onready') within the 'watch' callbacks of mozId. When this happens, I need to reboot my device.

Comment 2

[Jed Parsons (use needinfo, please) [:jedp, :jparsons]]

Thank you both for the STR. I'll take a look.

Comment 3

[Preeti Raghunath(:Preeti)]

QA,

Can we please check if this is seen in 1.3?

Comment 4

[Joshua Mitchell (Inactive)]

QA-Wanted: We can't test this with 256 MB Flame due to Bug 1008050 blocking us; let's try to test this on 1.4 Buri and if we can repro move on the 1.3 Buri to do the 1.3 check

Comment 5

[Nicolas B. Pierron [:nbp]]

(In reply to Joshua Mitchell from comment #4)
> QA-Wanted: We can't test this with 256 MB Flame due to Bug 1008050 blocking
> us;

I do not have this issue on v1.4 flame.
But maybe this is a side effect bug 1008050.

Comment 6

[Jed Parsons (use needinfo, please) [:jedp, :jparsons]]

Borja or Nicolas, if you still have the logs, can you attach them?  I'm particularly interested in any surrounding context that might show messages like 'unwatch()' and 'child-process-shutdown'.  Thanks!

I have a patch in progress; building gecko for flame now to test it.

Comment 7

[Pi Wei Cheng [:piwei] (inactive)]

According to this comment https://bugzilla.mozilla.org/show_bug.cgi?id=1024692#c12 I can boot Flame into 288mb.

I'm unable to reproduce the original bug after installing 50 games on Flame 1.4 with 288mb mem. Marketplace didn't crash, and no said JS error occurred in logcat.

Also tried on 1.4 Buri and Marketplace didn't crash after installing 44 games.

Comment 1 mentions a feature that is only available on 2.0+ which for the qawanted request I can safely say it doesn't occur in 1.3 because the feature isn't available.

Tested on:
(no repro)
Device: Flame
Build ID: 20140619000201
Gaia: 233da2865de3a2c73329e04c6deb21766f0d09d4
Gecko: 7978e6b470f2
Version: 30.0 (1.4) 
Firmware Version: v121-2

(no repro)
Device: Buri
Build ID: 20140619000201
Gaia: 233da2865de3a2c73329e04c6deb21766f0d09d4
Gecko: 7978e6b470f2
Version: 30.0 (1.4) 
Firmware Version: v1.2device.cfg


(In reply to Nicolas B. Pierron [:nbp] from comment #5)
> (In reply to Joshua Mitchell from comment #4)
> > QA-Wanted: We can't test this with 256 MB Flame due to Bug 1008050 blocking
> > us;
> 
> I do not have this issue on v1.4 flame.
> But maybe this is a side effect bug 1008050.

I'm assuming you meant to say you do not see this issue on 1.4 Buri? Because the bug was filed for 1.4 Flame.

Comment 8

[Nicolas B. Pierron [:nbp]]

(In reply to Pi Wei Cheng from comment #7)
> (In reply to Nicolas B. Pierron [:nbp] from comment #5)
> > (In reply to Joshua Mitchell from comment #4)
> > > QA-Wanted: We can't test this with 256 MB Flame due to Bug 1008050 blocking
> > > us;
> > 
> > I do not have this issue on v1.4 flame.
> > But maybe this is a side effect bug 1008050.
> 
> I'm assuming you meant to say you do not see this issue on 1.4 Buri? Because
> the bug was filed for 1.4 Flame.

Sorry for not being clear, what I meant is the same as Bug 1008050 comment 7, that I did not see Bug 1008050 while testing.

Comment 9

[Nicolas B. Pierron [:nbp]]

Attachment: stderr

This is the stderr (~logcat) I had within a gdb session.  I did not follow the STR to reproduce this one.  Sadly my shell history does not have the original logcat anymore.

I do not remember what I was testing, but based on the number of opened applications, I was probably trying to open a large number of applications without waiting for these application to be loaded.

Comment 10

[Jed Parsons (use needinfo, please) [:jedp, :jparsons]]

(In reply to Nicolas B. Pierron [:nbp] from comment #9)
> Created attachment 8443387 [details]

Thanks, Nicholas.  Ah yes, it would have needed toolkit.identity.debug preffed on to see the debug messages that came before.

Your description is very helpful.  I think I see something that could have been the culprit, but it may be difficult to prove with testing.  But I'll try.

Comment 11

[Jed Parsons (use needinfo, please) [:jedp, :jparsons]]

I can cause the "this.getContextForMM(...).RP is undefined" message to manifest by killing the app during sign-in, but I still haven't been able to break the app from working when restarted (as Borja describes in Comment 1).

Comment 12

[Jed Parsons (use needinfo, please) [:jedp, :jparsons]]

Attachment: v1

This patch simply tests for the existence of the RP context before calling methods on it.  This appears to be necessary when a child-process-shutdown event occurs.

Before applying this patch, the killing of an app that had called watch({wantIssuer: "firefox-accounts"}) would result in a "this.getContextForMM(...).RP is undefined" error.  (I was not able to reproduce the results described in Comment 1 where the phone needed to be rebooted as well, so I don't claim that this patch addresses that problem.)

With the patch applied, the error no longer occurs.  In manual testing, I have tried killing the app both before and during the sign-in flow (i.e., with the FxA UI showing over it).  In each case, the app shut down normally and I was able to restart it with full sign-in functionality.

Note that, in the case where you kill the app while it's in the middle of the sign-in flow, cancelling the sign-in will try to send an error notification back to the RP ("DIALOG_CLOSED_BY_USER"), but the RP no longer exists and this results in DOMIdentity's attempt to send an asyncMessage to result in an error.  (Component returned failure code: 0xc1f30001 (NS_ERROR_NOT_INITIALIZED) [nsIMessageSender.sendAsyncMessage])

MattN, is the sendAsyncMessage failure code something I need somehow to guard against?  Does the rest of this patch seem reasonable?

Recall that the getContext business was added in https://hg.mozilla.org/mozilla-central/diff/9ed86b468f73/dom/identity/DOMIdentity.jsm.

Thanks!
j

Comment 13

[Matthew N. [:MattN]]

Comment on attachment 8443825 [details] [diff] [review]
v1

Review of attachment 8443825 [details] [diff] [review]:
-----------------------------------------------------------------

This seems reasonable to check that the services exists but tbh. I don't have enough context anymore to know whether this is the best solution. I think this is fine for now since you're adding logging in these cases.

(In reply to Jed Parsons (use needinfo, please) [:jedp, :jparsons] from comment #12)
> MattN, is the sendAsyncMessage failure code something I need somehow to
> guard against?

smaug, tells me that NS_ERROR_NOT_INITIALIZED is expected when a frame is closing. What is the stack of the call to sendAsyncMessage that gives the error as I don't see that coming from identity code directly (gaia or m-c) after a quick look. If it's expected we may want to log our own message to explain the circumstance so people looking through logs won't file bugs on it unless they encounter an actual problem.

::: dom/identity/DOMIdentity.jsm
@@ +341,5 @@
>      // not have the right callbacks, we don't want unwatch to throw, because it
>      // will break the process of releasing the page's resources and leak
>      // memory.
> +    let service = this.getService(message);
> +    if (service || service.RP) {

Don't you mean "&&"?

@@ +351,5 @@
>    },
>  
>    _request: function DOMIdentity__request(message) {
> +    let service = this.getService(message);
> +    if (service || service.RP) {

ditto

@@ +373,5 @@
>        return;
>      }
>  
> +    let service = this.getContextForMM(targetMM);
> +    if (service && service.RP) {

got it right this time :)

Comment 14

[Preeti Raghunath(:Preeti)]

Doesn't impact Dolphin do backlog on the same.

Comment 15

[Jed Parsons (use needinfo, please) [:jedp, :jparsons]]

Attachment: fix "RP is undefined"

Hi, Matthew,

Thanks for your feedback and notes in Comment 13.

I've fixed the errors you spotted, and updated the patch to catch the NS_ERROR_NOT_INITIALIZED error and print what is hopefully an informative message.

I am worried that I am doing something naughty by assigning __proto__ in the various context objects.  Is that ok in this case, or am I a bad person for doing that?

Thanks,
j

Comment 16

[Matthew N. [:MattN]]

Comment on attachment 8452676 [details] [diff] [review]
fix "RP is undefined"

Review of attachment 8452676 [details] [diff] [review]:
-----------------------------------------------------------------

The changes are fine other than the proto stuff (unless you consult with a JS engine dev.). I believe this code runs on every page load of sites using Persona on B2G.

::: dom/identity/DOMIdentity.jsm
@@ +78,5 @@
>    this._mm = aTargetMM;
>  }
>  
>  IDPProvisioningContext.prototype = {
> +  __proto__: Context.prototype,

See https://developer.mozilla.org/en-US/docs/Web/JavaScript/Reference/Global_Objects/Object/create and https://developer.mozilla.org/en-US/docs/Web/JavaScript/Reference/Global_Objects/Object/proto

IDPProvisioningContext.prototype = Object.create(Context.prototype);
is preferred but then you have to change all of the method to be assigned on IDPProvisioningContext.prototype.foo instead of part of the object assigned to IDPProvisioningContext.prototype. Otherwise you need to use property descriptors which gets messy IMO.

How about not using inheritance for now and just attaching the function to the three contexts manually? That's not ideal if we're going to add more stuff to the contexts but it reduces the churn for now.

IDPProvisioningContext.prototype.sendAsyncMessage = …sendAsyncMessage;

If you really want, switch the __proto__ to setPrototypeOf but I guess you should talk to someone on the JS team (maybe Waldo? or #jsapi in general) to use either of these "slow" functions.

Comment 17

[Jed Parsons (use needinfo, please) [:jedp, :jparsons]]

(In reply to Matthew N. [:MattN] (behind on bugmail) from comment #16)
> Comment on attachment 8452676 [details] [diff] [review]
> fix "RP is undefined"

Thanks for your review, Matthew.

> Review of attachment 8452676 [details] [diff] [review]:
> -----------------------------------------------------------------
> 
> The changes are fine other than the proto stuff (unless you consult with a
> JS engine dev.). I believe this code runs on every page load of sites using
> Persona on B2G.

Yes, it does.  Ok let's not do that.

> How about not using inheritance for now and just attaching the function to
> the three contexts manually? That's not ideal if we're going to add more
> stuff to the contexts but it reduces the churn for now.

Let's do that instead.

Thanks!
j

Comment 18

[Jed Parsons (use needinfo, please) [:jedp, :jparsons]]

Attachment: fix "RP is undefined"; r=MattN

Removing wretched __proto__ inheritance.  r=MattN.

Comment 19

[Jed Parsons (use needinfo, please) [:jedp, :jparsons]]

Try push:

https://tbpl.mozilla.org/?tree=Try&rev=7f0ee34e423b

Comment 20

[Matthew N. [:MattN]]

Comment on attachment 8454156 [details] [diff] [review]
fix "RP is undefined"; r=MattN

Review of attachment 8454156 [details] [diff] [review]:
-----------------------------------------------------------------

::: dom/identity/DOMIdentity.jsm
@@ +50,5 @@
>  function IDDOMMessage(aOptions) {
>    objectCopy(aOptions, this);
>  }
>  
> +function sendAsyncMessage(identifier, message, mm) {

Out of curiosity, why didn't you go with my IDPProvisioningContext.prototype.sendAsyncMessage = …sendAsyncMessage; approach? It seems cleaner than passing mm each time. Was it because of the 3 lines to add the sendAsyncMessage function?

Comment 21

[Maire Reavy [:mreavy]]

Needinfo'ing for Comment 20 from MattN

Comment 22

[Jed Parsons (use needinfo, please) [:jedp, :jparsons]]

Attachment: fix "RP is undefined"; r=MattN

Thanks for setting me straight in Comment 20, MattN.  Sorry to have been such a thickie.

Here's the original patch revised with that suggestion.

Comment 23

[Jed Parsons (use needinfo, please) [:jedp, :jparsons]]

Try push

https://tbpl.mozilla.org/?tree=Try&rev=9a569c157dcd

Comment 24

[Jed Parsons (use needinfo, please) [:jedp, :jparsons]]

Comment on attachment 8454738 [details] [diff] [review]
fix "RP is undefined"; r=MattN

Approval Request Comment
[Feature/regressing bug #]: Bug 929386
[User impact if declined]: Potential crashes and possible need to reboot device, as articulated in Description and Comment 1
[Describe test coverage new/current, TBPL]: tbpl linked in Comment 23
[Risks and why]: Very low risk.
[String/UUID change made/needed]: None

Comment 25

[Matthew N. [:MattN]]

Comment on attachment 8454738 [details] [diff] [review]
fix "RP is undefined"; r=MattN

Review of attachment 8454738 [details] [diff] [review]:
-----------------------------------------------------------------

::: dom/identity/DOMIdentity.jsm
@@ +115,5 @@
>    doBeginAuthenticationCallback: function IDPAC_doBeginAuthCB(aIdentity) {
>      let message = new IDDOMMessage({id: this.id});
>      message.identity = aIdentity;
> +    this.sendAsyncMessage("Identity:IDP:CallBeginAuthenticationCallback",
> +                           message);

Nit: wrong identation

Comment 26

[Jed Parsons (use needinfo, please) [:jedp, :jparsons]]

Attachment: fix "RP is undefined"; r=MattN

Fixed indentation nit; r=MattN

Aurora Approval Request is in Comment 24 and remains unchanged.

Comment 27

[Jed Parsons (use needinfo, please) [:jedp, :jparsons]]

tbpl in Comment 23

Comment 28

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/integration/mozilla-inbound/rev/7c7e14a34c49

Comment 29

[Lawrence Mandel [:lmandel] (use needinfo)]

Will review after this lands on m-c.

Comment 30

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/mozilla-central/rev/7c7e14a34c49

Comment 31

[Maire Reavy [:mreavy]]

Borja, Maria -- Can you verify that Jed's fix (which just landed) fixes this bug?  Lawrence (who grants Aurora approvals) wants to make sure the patch on this bug fixes the problems you reported above.  Thanks!

Comment 32

[Maire Reavy [:mreavy]]

To be clearer: Lawrence will give aurora approval after someone from the Loop mobile team confirms/verifies it fixes this bug report.  Borja, Maria - Do you think someone from your team could test and verify the fix today and then comment in this bug?  Thanks.

Comment 33

[Maria Angeles Oteo (:oteo)]

(In reply to Maire Reavy [:mreavy] (Plz needinfo me) from comment #32)
> To be clearer: Lawrence will give aurora approval after someone from the
> Loop mobile team confirms/verifies it fixes this bug report.  Borja, Maria -
> Do you think someone from your team could test and verify the fix today and
> then comment in this bug?  Thanks.

Borja, following the STR in comment 1, has not been able to reproduce this error in the console using latest master build

Comment 34

[Lawrence Mandel [:lmandel] (use needinfo)]

Comment on attachment 8454763 [details] [diff] [review]
fix "RP is undefined"; r=MattN

Thank you for the confirmation in comment 33. Aurora+

Comment 35

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/releases/mozilla-aurora/rev/883f4666206e