This isn't 100% reproducible but I see it happen pretty much every time on today's desktop B2G18 w/ a gaia v1-train profile: - build a new B2G profile configured for payments per https://github.com/mozilla/webpay#build-a-custom-b2g-profile - Install the Marketplace Dev app per https://github.com/mozilla/webpay#installing-marketplace-dev - Launch Marketplace Dev - Search for Private Yacht or any paid app - Click the $0.99 to purchase The purchase button does nothing. The buttons calls navigator.id.request() against native-persona.org. In the log, there is nothing out of the ordinary. The log is attached. Here is a screencast: http://screencast.com/t/i2UPlD4ublOu To fix it, all you have to do is press the home key and *relaunch the app*. Then the purchase button will always work until you build a new profile. ------------------------------------------------ The reason why it seems to be Trusted UI related is it also happens when calling navigator.mozPay(). Here are the alternate steps for that - Build a new B2G profile - Install the In-App Payment Tester from the button on this page http://people.mozilla.com/~kmcmillan/mktdev.html - Launch the app - Click the mozPay button Nothing happens. This time there is nothing in the log. The button calls navigator.mozPay(). You can fix it the same way by pressing the home key and re-launching the app. Then the mozPay button will always work until you rebuild the profile. This has happened on the Unagi phone too.

One bug please - TrustedUI tracks all trusted UI issues and is in the tree for marketplace-payments.

The Trusted UI bug you're blocking on is closed so it doesn't show up in the dependency tree for marketplace-payments. I just didn't want to lose track of this one but, no worries, it's in my awesome bar.

(In reply to Kumar McMillan [:kumar] from comment #2) > The Trusted UI bug you're blocking on is closed so it doesn't show up in the > dependency tree for marketplace-payments. I just didn't want to lose track > of this one but, no worries, it's in my awesome bar. I move the bugs over if need be to something that isn't closed.

I am not able to reproduce this bug - hopefully that's a good thing! :) Pulled and built today: My b2g18 tip: 1a13d7ec3f9d My v1-train gaia: 8d413db4 I downloaded mktdev.html, searched for yacht, clicked purchase, and was taken through the expected flow: Identity sign-in, then marketplace purchase flow. (If the bug is reproducible, we'll have to start bisecting. There haven't been any changes to the payment, identity, and trusted_ui system bits for three or four weeks now.)

Tried both cases cited in comment 0 - works for me on 2/14 build on device.

I can confirm that I have seen this bug often enough times for it to be a concern. The problem is that it is not consistently reproducible.

(In reply to krupa raj 82[:krupa] from comment #6) > I can confirm that I have seen this bug often enough times for it to be a > concern. The problem is that it is not consistently reproducible. I will continue to try; and when I'm back with my unagi, I'll try there. If you can get a full 'adb lolcat' while reproducing it, that would be gold.

Close-me timeout has been hit. ==> Incomplete

I hit this regularly on desktop.

I've seen this as well. I'll reopen, but we really badly need to get a logcat here when this reproduces. The nav.id log isn't going to help here - I don't think it's necessarily an identity problem. It's likely a window manager problem. If we can nail down the problem, we might be able to get this in for leo, but not for tef. Going to put user-doc-needed however.

QAWanted to get a logcat. There's a bunch of people testing payments, so the first one that manages to hit this bug again should drop a logcat in here.

User doc needed also - we need help from SUMO folks here to document this known issue for v1 in FF OS in case someone hits this on the marketplace side.

What kind of logcat? I attached one to this bug originally. However, I couldn't see anything of interest in there. It just stalls in the identity startup. If you can tell me which prefs to turn on or which NSPR logs to turn on I can get the output. It is very reproducible for me.

(In reply to Kumar McMillan [:kumar] from comment #13) > What kind of logcat? I attached one to this bug originally. However, I > couldn't see anything of interest in there. It just stalls in the identity > startup. > > If you can tell me which prefs to turn on or which NSPR logs to turn on I > can get the output. It is very reproducible for me. Just full blown everything in the logcat. Your typical run of the mill logcat in this case.

Here is the full logcat leading up to the first click of the purchase button where nothing happens. It took me three tries to reproduce it so it should be easy to catch again. Let me know if there is more verbose logging I can turn on.

Okay, so that doesn't tell us much. Maybe Alive has some ideas here on why we could intermittently fail to get the trusted UI to come up on sign into marketplace.

I cannot figure out anything from the log. :/

(In reply to Alive Kuo [:alive] (Life is a struggle.) from comment #17) > I cannot figure out anything from the log. :/ Is there any preference we could turn on that would give us more information on what's not working here?

leo nom - I think we've got people that can reproduce this that proves this is happening. Sounds like the STR here is using the purchase button for marketplace a few times - it'll eventually reproduce. Although I've seen this happen with identity as well.

Just let me know what logs to turn on and I'll do it. I can turn on NSPR_LOG_MODULES=all:5! Just let me know. Or if there is something more specific, let me know. https://mxr.mozilla.org/mozilla-central/search?string=NSPR_LOG_MODULES (or would offending code be in Gaia?)

Nominating for 1.0.1. I'm concerned that it's possible in our first release for a customer to want to spend actual real money for an app and our UI won't work. We don't have telemetry, so there's no way to know just how often this can happen. We can't risk this in the first release.

(In reply to Dietrich Ayala (:dietrich) from comment #21) > Nominating for 1.0.1. I'm concerned that it's possible in our first release > for a customer to want to spend actual real money for an app and our UI > won't work. We don't have telemetry, so there's no way to know just how > often this can happen. > > We can't risk this in the first release. Agree. Anything breaks the payment flow should be blocking. I'll take a look if this is a gaia bug. Jason, do we have any automation test on payment flow? Is it possible to create one? I recommend we should pay more attention on this item. It just cannot fail. Even if any once.

(In reply to Alive Kuo [:alive] (Life is a struggle.) from comment #22) > (In reply to Dietrich Ayala (:dietrich) from comment #21) > > Nominating for 1.0.1. I'm concerned that it's possible in our first release > > for a customer to want to spend actual real money for an app and our UI > > won't work. We don't have telemetry, so there's no way to know just how > > often this can happen. > > > > We can't risk this in the first release. > > Agree. Anything breaks the payment flow should be blocking. > I'll take a look if this is a gaia bug. > > Jason, do we have any automation test on payment flow? Is it possible to > create one? > I recommend we should pay more attention on this item. It just cannot fail. > Even if any once. No automation at the moment in Gaia UI Tests, but there has been work to look into this. For the full real payment flow, I believe the major blockers for automation in some of the persona areas of automation. Including Zac and Stephen in case they have more points on this one. Might as well nom the other bug then based on the discussions I heard in triage.

Can someone work with me (on IRC?) to get what's needed to track this down? I even have a custom build of B2G from today's moz-central where I can reproduce the bug. Let me know what files to edit or what logs to turn on and I will do it!

(In reply to Kumar McMillan [:kumar] from comment #24) > Can someone work with me (on IRC?) to get what's needed to track this down? > I even have a custom build of B2G from today's moz-central where I can > reproduce the bug. Let me know what files to edit or what logs to turn on > and I will do it! Kumar, I'd prefer to append some log tracking to a gaia branch tomorrow and please take that gaia to try repro. Thanks. If anyone who knows the payment backend would like to provide hint in gecko part, welcome. I wonder this is not a gaia issue and I couldn't do anything if it's a gecko issue. I will still try to make a logged gaia to see what happens.

ok, I will wait for a gaia branch. I'm attaching my log from running desktop b2g built from moz-central. It's not very informative. However, you can see that when the error happens, *no* payment related debug messages can be seen at all. That means, I think, that the initial PaymentManager.receiveMessage() is not called. Again, this is not something I can reproduce every time but I have been able to catch it with some persistence.

I added some debugging to PaymentManager.init(). You can see that the message listeners are set up correctly but the message is not received. I stopped logging after the first attempt at calling navigator.mozPay(). I'll try a few more things to narrow it down...

hmm, my last uploaded log got cut off

ok! I added more logging, this time to the app (JS), and what I found is that navigator.mozPay() isn't even invoked. That is, the button click handler is not firing. When I click a second time, it fires and everything works. I'm going to look at the handlers more closely. Take note that I've seen this in two apps so far: the in-app payment tester and the Marketplace.

(In reply to Kumar McMillan [:kumar] from comment #29) > ok! I added more logging, this time to the app (JS), and what I found is > that navigator.mozPay() isn't even invoked. That is, the button click > handler is not firing. When I click a second time, it fires and everything > works. I'm going to look at the handlers more closely. Take note that I've > seen this in two apps so far: the in-app payment tester and the Marketplace. Sounds you could deal with this by yourself ;)

Could you try to look system/js/payment.js to see if the mozChromeEvent of payment is got by system app?

Here are some more findings. First, forget comment #29, I do indeed see the app calling navigator.mozPay() from the JS log. The trouble is that I can't accurately reproduce the bug with a custom build so I reverted to the nightly build where it is easily reproducible. When the bug happens, it looks like the content script does not load at all. I do not even see the loading message on this line: https://mxr.mozilla.org/mozilla-central/source/b2g/chrome/content/payment.js#12 Yet, when the bug isn't happening, I see that message. When I call navigator.mozPay() in the app, I see this on every call: XXX FIXME : Got a mozContentEvent: undefined Where can I look to find out why content/payment.js is not loading?

I dug into components/PaymentGlue.js It appears that the content object never receives mozContentEvent. Everything else in PaymentGlue seems to be running fine without errors. Because it does not receive the event, content/payment.js is never loaded. Race condition? I am not sure how to proceed. I can reproduce this easily using a nightly build.

The analysis above implies this bug is likely happening in mozPay in the DOM code, not Gaia. Sending this over ferjm for input.

Deassign myself per #34

Thanks Kumar! Very useful information! I am at the performance work week in Paris, but I'll try to take a look at this today.

(In reply to Kumar McMillan [:kumar] from comment #32) > Here are some more findings. First, forget comment #29, I do indeed see the > app calling navigator.mozPay() from the JS log. The trouble is that I can't > accurately reproduce the bug with a custom build so I reverted to the > nightly build where it is easily reproducible. I can't reproduce it with a custom build either :(. I am working with the latest b2g18 and with the latest Gaia master branch. Which branches are being used to build the nightly? Which gaia branch are you using to reproduce this issue? Are you talking about the builds at http://ftp.mozilla.org/pub/mozilla.org/b2g/nightly/ ? > > When the bug happens, it looks like the content script does not load at all. > I do not even see the loading message on this line: > https://mxr.mozilla.org/mozilla-central/source/b2g/chrome/content/payment. > js#12 Yet, when the bug isn't happening, I see that message. > > When I call navigator.mozPay() in the app, I see this on every call: > XXX FIXME : Got a mozContentEvent: undefined > I don't think that message is related to this issue. http://mxr.mozilla.org/mozilla-central/source/b2g/chrome/content/shell.js#636

Also, are you able to reproduce this with a simpler test like the one at http://people.mozilla.com/~kmcmillan/gaia-pay.html ?

(In reply to Fernando Jiménez Moreno [:ferjm] from comment #38) > Also, are you able to reproduce this with a simpler test like the one at > http://people.mozilla.com/~kmcmillan/gaia-pay.html ? Yes, I can. These are my settings: pref("dom.payment.provider.4.name", "mock"); pref("dom.payment.provider.4.description", "mock"); pref("dom.payment.provider.4.uri", "http://people.mozilla.com/~kmcmillan/pay-provider.html?req="); pref("dom.payment.provider.4.type", "mock/payments/inapp/v1"); pref("dom.payment.provider.4.requestMethod", "GET"); Then I open this page in a b2g browser http://people.mozilla.com/~kmcmillan/gaia-pay.html It's the same exact behavior. It doesn't work the first time. When I relaunch the browser, it works. I'm using desktop to reproduce from http://ftp.mozilla.org/pub/mozilla.org/b2g/nightly/latest-mozilla-b2g18/ I don't know exactly which gecko branch that is built from. I think the Gaia part is from the v1-train branch (not master) but this doesn't seem like a Gaia issue. jsmith, do you know which gecko branch?

I really cannot reproduce this :( I downloaded http://ftp.mozilla.org/pub/mozilla.org/b2g/nightly/latest-mozilla-b2g18/b2g-18.0.multi.mac64.dmg and run ./b2g -profile gaia/profile At first I couldn't use the browser app as Gaia looks broken because of bug 845829. Apart from adding the prefs that you mention, what I did was to remove the 'Communications' app from gaia/profile/webapps/webapps.json so I can see the browser icon in the the bottom bar. Once I can launch the Browser app, I went to http://people.mozilla.com/~kmcmillan/gaia-pay.html, clicked on "Pay PMPP" button and the trusted UI just appeared. I tried dozens of times and it just works for me :\ Kumar, could you get a full logcat uncommenting the lines at: https://mxr.mozilla.org/mozilla-central/source/dom/payment/Payment.js#24 https://mxr.mozilla.org/mozilla-central/source/dom/payment/Payment.jsm#30 https://mxr.mozilla.org/mozilla-central/source/b2g/components/PaymentGlue.js#25 and adding some logs to https://github.com/mozilla-b2g/gaia/blob/master/apps/system/js/trusted_ui.js#L80, please? Also, it would be great if you could test in the device instead of the desktop version. Thanks! (In reply to Kumar McMillan [:kumar] from comment #39) > jsmith, do you know which gecko branch? That info is at http://ftp.mozilla.org/pub/mozilla.org/b2g/nightly/latest-mozilla-b2g18/en-US/b2g-18.0.en-US.mac64.txt

I updated to today's nightly desktop b2g18 (http://hg.mozilla.org/releases/mozilla-b2g18/rev/94927529a55f) and pulled the latest v1-train gaia changes. I reproduced the bug and I see this in the tail of the b2g log: ... ###################################### forms.js loaded ############################### browserElementPanning.js loaded ######################## BrowserElementChildPreload.js loaded -*- PaymentManager: Received 'Payment:Pay' message from content process -*- PaymentManager: Registered Payment Providers: {"name":"mock","uri":"http://people.mozilla.com/~kmcmillan/pay-provider.html?req=","description":"mock","requestMethod":"GET"} -*- PaymentManager: Registered Payment Providers: {"name":"firefoxmarketdev","uri":"https://marketplace-dev.allizom.org/mozpay/?req=","description":"marketplace-dev.allizom.org","requestMethod":"GET"} -*- PaymentManager: Registered Payment Providers: {"name":"firefoxmarketstage","uri":"https://marketplace.allizom.org/mozpay/?req=","description":"marketplace.allizom.org","requestMethod":"GET"} -*- PaymentManager: Registered Payment Providers: {"name":"firefoxmarket","uri":"https://marketplace.firefox.com/mozpay/?req=","description":"marketplace.firefox.com","requestMethod":"GET"} -*- PaymentManager: Registered Payment Providers: {"name":"firefoxmarketlocal","uri":"http://localhost:8000/mozpay/?req=","description":"localhost","requestMethod":"GET"} -*- PaymentManager: Payload {"iss":"123456789","aud":"Mock Payment Provider","typ":"mock\/payments\/inapp\/v1","exp":1345259882,"iat":1345256282,"request":{"name":"Piece of Cake","description":"Virtual chocolate cake to fill your virtual tummy","price":[{"country":"US","amount":"5.50","currency":"USD"},{"country":"BR","amount":"8.50","currency":"BRL"}]}} XXX FIXME : Got a mozContentEvent: undefined -*- PaymentManager: Received 'Payment:Pay' message from content process -*- PaymentManager: Payload {"iss":"123456789","aud":"Mock Payment Provider","typ":"mock\/payments\/inapp\/v1","exp":1345259882,"iat":1345256282,"request":{"name":"Piece of Cake","description":"Virtual chocolate cake to fill your virtual tummy","price":[{"country":"US","amount":"5.50","currency":"USD"},{"country":"BR","amount":"8.50","currency":"BRL"}]}} XXX FIXME : Got a mozContentEvent: undefined I added logging to Gaia and the code path is reaching the else block here (i.e. no currentStack): https://github.com/mozilla-b2g/gaia/blob/master/apps/system/js/trusted_ui.js#L86 It never hits this line: https://github.com/mozilla-b2g/gaia/blob/master/apps/system/js/trusted_ui.js#L90 (i.e. the window manager doesn't fire the callback) When I relaunch the app (to workaround the bug) there also is no currentStack but this time the window manager *does* fire the callback. It was easier to add logging and reproduce on desktop. I'll try it on device next...

I'm not sure if it's worth investing much more time into this. It is easy to reproduce on nightly desktop builds (happens every time for me but apparently doesn't happen for others). It's *harder* to reproduce on device. Krupa and I have only seen it rarely on device. I tried today and could not catch it on device.

(In reply to Kumar McMillan [:kumar] from comment #42) > I'm not sure if it's worth investing much more time into this. It is easy to > reproduce on nightly desktop builds (happens every time for me but > apparently doesn't happen for others). It's *harder* to reproduce on device. > Krupa and I have only seen it rarely on device. I tried today and could not > catch it on device. That comment then implies I think a tracking+ - let's try to eventually fix this, but not block. If you disagree, please clarify.

I assume that we still need to document, cause it indeed happens on the device...just rarely. Is that correct?

(In reply to Ibai Garcia [:ibai] from comment #44) > I assume that we still need to document, cause it indeed happens on the > device...just rarely. Is that correct? Yes, good point. I'd still document it just in case. Certainly won't hurt.

(In reply to Kumar McMillan [:kumar] from comment #41) > I added logging to Gaia and the code path is reaching the else block here > (i.e. no currentStack): > https://github.com/mozilla-b2g/gaia/blob/master/apps/system/js/trusted_ui. > js#L86 It never hits this line: > https://github.com/mozilla-b2g/gaia/blob/master/apps/system/js/trusted_ui. > js#L90 (i.e. the window manager doesn't fire the callback) > > When I relaunch the app (to workaround the bug) there also is no > currentStack but this time the window manager *does* fire the callback. > Thanks Kumar! Very helpful. Could you also add a few logs to https://github.com/mozilla-b2g/gaia/blob/master/apps/system/js/window_manager.js#L908 , please? (In reply to Kumar McMillan [:kumar] from comment #42) > I'm not sure if it's worth investing much more time into this. It is easy to > reproduce on nightly desktop builds (happens every time for me but > apparently doesn't happen for others). It's *harder* to reproduce on device. > Krupa and I have only seen it rarely on device. I tried today and could not > catch it on device. It's ok to debug this issue on desktop. Thanks.

Aha. So, this is the problem: https://github.com/mozilla-b2g/gaia/blob/601f50f4b498dd952008f60dca0be1db4e2ba2ed/apps/system/js/window_manager.js#L959 The first time it enters that function, displayedApp == homescreen. This prevents the trusted UI from opening. When you close and relaunch the app, displayedApp is set to the correct app URL. In my case it is set to http://inapp-pay-test.paas.allizom.org/ and the trusted UI opens. Tim, Alberto, Alive, any ideas for the right way to fix this? I tried this patch below (which fixes it) but the side effect was that it became hard to click the app icon from the homescreen to launch it : diff --git a/apps/system/js/window_manager.js b/apps/system/js/window_manager.js index e18ee44..d9788af 100644 --- a/apps/system/js/window_manager.js +++ b/apps/system/js/window_manager.js @@ -700,6 +700,7 @@ var WindowManager = (function() { // set the size of the opening app setAppSize(origin); + displayedApp = origin; if (origin === homescreen) { // We cannot apply background screenshot to home screen app since // the screenshot is encoded in JPEG and the alpha channel is @@ -720,7 +721,6 @@ var WindowManager = (function() { openFrame.classList.add('homescreen'); openFrame.firstChild.focus(); setOpenFrame(null); - displayedApp = origin; return; }

Re-nominating. Without extremely clear vision into how often this can happen in the shipping devices in the field, not at all comfortable shipping with this bug.

(In reply to Dietrich Ayala (:dietrich) from comment #48) > Re-nominating. Without extremely clear vision into how often this can happen > in the shipping devices in the field, not at all comfortable shipping with > this bug. I don't think I agree on this one. We've exhausted analysis here. We do have proof of reproducibility in this bug and through our smoke tests - it's very low on device - the analysis proves it by what Jed/myself/ferjm have looked at it, our smoke test runs on a daily basis twice a day don't reveal it as a smoke test failure, etc. The impact doesn't cause data loss and the impact to the user isn't significant - in the case that a user does hit this bug, they'll hit the button for the payment/identify flow again, which will start it up no problem.

I think I've pinpointed the root cause (maybe). If someone can give me ideas on where best to define displayedApp per comment #47 then I can try out some different patches.

(tef- for now, but once we have a patch landed in v1-train and can assess the risk of an uplift and have agreed on how often this may occur in the wild lets take a 3rd look for v1.0.1)

Kumar, could you try the patch at https://github.com/ferjm/gaia/commit/6ec2b46addcc7fc5a5b935ead976b11827bf4b97 ?

Pointer to Github pull-request

Nice! First, I updated b2g18/gaia and made sure I could still reproduce the bug a few times. Next, I applied your patch and tried to reproduce it about 8 times, each one a new profile. Your fix is working for me. I could never reproduce the bug after the patch.

Comment on attachment 724021 [details] Pointer to Github pull request: https://github.com/mozilla-b2g/gaia/pull/8601 Thanks Kumar!

Comment on attachment 724021 [details] Pointer to Github pull request: https://github.com/mozilla-b2g/gaia/pull/8601 Alive, could you take a look at the window_manager.js changes? This is basically what you proposed some time ago about getting rid of the trusted UI specific functionality from the window manager.

Comment on attachment 724021 [details] Pointer to Github pull request: https://github.com/mozilla-b2g/gaia/pull/8601 "I Feel Friendly."

(In reply to Fernando Jiménez Moreno [:ferjm] from comment #56) > Comment on attachment 724021 [details] > Pointer to Github pull request: https://github.com/mozilla-b2g/gaia/pull/8601 > > Alive, could you take a look at the window_manager.js changes? This is > basically what you proposed some time ago about getting rid of the trusted > UI specific functionality from the window manager. Sweet! Any change to lessen the code amount in WM is welcome! <3

Thanks! https://github.com/mozilla-b2g/gaia/commit/07be1290ffca3c1c6387e19273ec8b05fbce468d

Might be worth asking for approval-b2g18 here.

Comment on attachment 724021 [details] Pointer to Github pull request: https://github.com/mozilla-b2g/gaia/pull/8601 NOTE: Please see https://wiki.mozilla.org/Release_Management/B2G_Landing to better understand the B2G approval process and landings. [Approval Request Comment] Bug caused by (feature/regressing bug #): - User impact if declined: The user won't be able to start a purchase flow on her first attempt. She would be able to do it on a second try. Testing completed: Local testing. Waiting for QA verification. Risk to taking this patch (and alternatives if risky): After QA validation, the risk should be low. String or UUID changes made by this patch: None.

Not possible to verify from QA's side (or at least reliably). I never managed to get a solid consistent STR, only Kumar managed to get it a consistent STR on his end. Kumar has verified this patch already, so I trust that verification has already happened here sufficiently. We could regression test this, but that's better done on b2g18 at this point. I think we're good to uplift.

I was not able to uplift this bug to v1-train. If this bug has dependencies which are not marked in this bug, please comment on this bug. If this bug depends on patches that aren't approved for v1-train, we need to re-evaluate the approval. Otherwise, if this is just a merge conflict, you might be able to resolve it with: git checkout v1-train git cherry-pick -x -m1 07be1290ffca3c1c6387e19273ec8b05fbce468d <RESOLVE MERGE CONFLICTS> git commit

Sorry for the delay, I was on PTO during the last week. https://github.com/mozilla-b2g/gaia/commit/79710fcbe37ab6ce488539b38799ad534b6f6ac6