961687 - [NFC] The URL sharing doesn't work well - Not sending out sometimes

Status: VERIFIED FIXED

(Firefox OS Graveyard :: NFC, defect)

Description

[Walter Chen[:ypwalter][:wachen]]

Using most up-to-date pvt build 2014/1/20 (mako)

STR:
1. Enable "NFC" in Settings App
2. Launch browser
3. Tap 2 phones with NFC enabled together
4. After seeing shrinking UI, slide to send

Expected Result:
The receiving phone should launch browser for opening the website sent

Actual Result:
Sometimes, you don't see the browser launched

Comment 1

[Walter Chen[:ypwalter][:wachen]]

It's 100% reproducible in recent tests

Comment 2

[Walter Chen[:ypwalter][:wachen]]

sorry, wrong comment. It still sometime reproducible. However, not receiving is 100% now -> will open another bug

Comment 3

[saminath]

Attachment: uri_test.patch

Please find attachment of patch to test the URI handler function invoked or not with corresponding log files.

Two Log messages are enabled in the nfc_handlePeerConnectvity () function, ENTER and EXIT.

In working scenario, 
After the “NFC_NOTIFICATION_TCH_DISCOVERED” the nfc_handlePeerConnectvity () should invoke.  Whenever it enters into the handler function, it always transmitting NFC messages.  Nothing was missed in between.

I/Gecko   (  178): Nfc Worker: NFC_NOTIFICATION_TECH_DISCOVERED
E/BrcmNfcNfa(  180): llcp_dlc_proc_connect_pdu (): Unregistered Service:urn:nfc:xsn:samsung.com:band
D/nfcd    (  180):  44 of bytes to be sent... data=0xb84b4e4c ret=0
……
D/nfcd    (  180): void P2pLinkManager::push(NdefMessage&): send NDEF by SNEP client
D/nfcd    (  180): void SnepMessenger::sendMessage(SnepMessage&): enter
D/nfcd    (  180): void SnepMessenger::sendMessage(SnepMessage&): exit

E/GeckoConsole(  178): Content JS ERROR at app://browser.gaiamobile.org/js/nfc.js:132 in nfc_handlePeerConnectvity: Enter Handle peer connectivity ...
E/GeckoConsole(  178): Content JS ERROR at app://browser.gaiamobile.org/js/nfc.js:159 in nfc_handlePeerConnectvity: Exit Handle peer connectivity...
D/nfcd    (  180): SnepMessage* SnepMessenger::getMessage(): exit

In Failure case, After Shrinking UI, Slide to send. It does not reaches the nfc_handlePeerConnectvity () function. So that NFC messages not send out.

I/Gecko   (  178): Nfc Worker: NFC_NOTIFICATION_TECH_DISCOVERED
E/BrcmNfcNfa(  180): llcp_dlc_proc_connect_pdu (): Unregistered Service:urn:nfc:xsn:samsung.com:band
I/Gonk    (  178): Setting nice for pid 982 to 18
I/Gonk    (  178): Changed nice for pid 982 from 1 to 18.
….
D/BroadcomNfc(  180): PeerToPeer::nfaClientCallback: NFA_P2P_DEACTIVATED_EVT: conn handle: 0x521
D/BroadcomNfc(  180): PeerToPeer::llcpDeactivatedHandler: enter
D/nfcd    (  180): static void NfcService::notifyLlcpLinkDeactivated(IP2pDevice*): enter
D/BroadcomNfc(  180): doRegisterNdefTypeHandler
….
D/nfcd    (  180): void HandoverClient::close(): exit
D/nfcd    (  180): void HandoverClient::close(): enter
D/nfcd    (  180): void HandoverClient::close(): exit
D/nfcd    (  180): processNotificaton notification=2002
D/nfcd    (  180): void NfcIpcSocket::writeToOutgoingQueue(uint8_t*, size_t) enter, data=0xb84be970, dataLen=8
D/nfcd    (  180): Writing 8 bytes to gecko 
I/Gecko   (  178): Nfc Worker: NFC_NOTIFICATION_TECH_LOST
I/Gecko   (  178): Nfc Worker: sessionId = 175

Comment 4

[saminath]

Attachment: Logcat_log_uri_8.txt

Comment 5

[psiddh]

Hi Sami, Walter , Please look at this bug :https://bugzilla.mozilla.org/show_bug.cgi?id=963488

Gaia certified apps should not declare "nfc_manager" permissions in their manifest file.
Only System App should. 

Also in the recently added code in browser app, there is lot of unnecessary code that got added to create a simple ndef url in browser.

We are currently working on shared lib that gaia certified apps can use to create ndef records. Recent browser code for nfc should be cleaned up a bit.

Comment 6

[Wesley Huang [:wesley_huang] (EPM) (NI me)]

I guess Sami is not available for handling this bug now.

Comment 7

[Ken Chang[:kenkai]]

Wesley, will you get help from browser team?

Comment 8

[Wesley Huang [:wesley_huang] (EPM) (NI me)]

Call out to Ben.

Comment 9

[Ben Francis [:benfrancis]]

What exactly is needed here? I'm not sure if I can personally help as I didn't work on this feature and don't have the necessary hardware to test it. Is there someone who does have the hardware who could try to debug this?

Comment 10

[Wesley Huang [:wesley_huang] (EPM) (NI me)]

Both Nexus4 and Flame are target developer device for NFC features. I believe Mozillians will at least have Flame by April/E.

Comment 11

[Ben Francis [:benfrancis]]

Saminath, do you have any idea what's going on here?

Comment 12

[Peter Dolanjski [:pdol]]

I'm blocking 1.5 on this on the assumption that the overall NFC capabilities make the release.  If they do, it cannot ship without this fixed.  
At the same time, this fix in the current browser will only move forward if it looks unlikely that the System Browser will be ready in 1.5.

Comment 13

[Ken Chang[:kenkai]]

Saminath is a contributor and no longer working on this bug. Ni?Garner. To know if he has idea for this.

Comment 14

[Garner Lee]

I can take a look.

From the perspective the discovery and lost cycle has already happened according to the logs when it failed, it seems like the events to and from the app are working. I'll have to look at the application side implemenation. We also updated the NfcUtils code, so the applcation needs some re-writing to use the new code as well.

Comment 15

[Garner Lee]

It's quite possible bug is a dup of Bug 959059. URL handling just happens after the P2P callback is setup.

Comment 16

[Ken Chang[:kenkai]]

Mark it as a duplicate. If the conclusion is changed..:-(, please reopen this bug.

Comment 17

[Walter Chen[:ypwalter][:wachen]]

It's not the same bug though. The shrinking and sending animation used to be pretty slow, and sometimes it will stucked when it didn't send out. This is what the bug is.

Bug 959059 is saying that it will shrink even if the device is not touched/tapped together, I can't tell why it is dup.

Comment 18

[Garner Lee]

Sorry, for the confusion. Please keep it open. What needs additional investigation is if the out of order messages is confusing the ShrinkUI logic (the phones might not actually be linked all the way down at the NFCD level, but it had a start message in Gaia anyway, allowing a send).

Comment 19

[Garner Lee]

Notes: I'm starting from the home screen each time on the target android device. Sending device is Firefox, on the same hardware (LG mako, Nexus 4).

It seems sometimes android (Nexus 4 JB target device) has a low frequency unexplained behavior, but with the fix in Bug 959059 and the landed fix in Bug 998111, it works quite well so far from the FirefoxOS perspective.

The one time it did fail (near the end of about ~30 tries), the android device took a few extra seconds to launch the browser, after the sending Firefox OS phone was removed.

Comment 20

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

Have you checked saminath's log?

E/GeckoConsole(  178): [JavaScript Error: "TypeError: this.current.appFrame is null" {file: "app://system.gaiamobile.org/js/shrinking_ui.js" line: 332}]

Comment 21

[Garner Lee]

Still investigating. Not entirely, the logs no longer match the code. _setup() does touch the appFrame map however.

Comment 22

[Garner Lee]

Reproduction steps for the this.current.appFrame = null UI JS error issue:

1) Set transition time to 10 times longer (5 and 3 seconds) so you can try to manually trigger the problem with a much higher frequency.

2) Nfcd is occasionally (incorrectly?) sending techlost and techDiscovered in the middle of an animation tilting back (this is part of the "blinking" problem being seen: techLost causes an instant transition).
--> Send the URL before it finishes, causing "send animation" to start (incidentally, this is probaly where the non-sending part likely happened before the dependent bug fixes: sessionToken was invalid).

3) If "unlucky", NFCD sends techLost, and a TechDiscovered while the send animation is happening. Animation "cancelled", and the appFrame is nulled due to stop(). 

  --> typeError is printed on the invalidated appFrame.

sendNDEF still happens in the browser despite the error in shrinkUI.

Comment 23

[Garner Lee]

Hi Greg, wanted to run some ideas by you:

I have a few ideas on a proper "small" fix for the null appFrame, although none are as good as being able to animate/interpolate the transition between unfinished stop and start animations due to P2P techLost and techDiscovery happening during send animations (or possibly other scenarios).

Some things I checked:

One that I haven't fully checked is: keep a ShrinkUI var to track any new addEventListeners, and in _cleanEffects, clear the correct transitionEnd callback actually being animated at the time. So far, it most likely isn't cleaning itself (ShinkUI._cleanEffects) with removeEventListener. This seems to work fine, but it does effectively cancel that particular callback function's "end callback" as well, which may well be _cleanEffects() of the animation that will eventually hit the null.

  Partial WIP code here:
    https://github.com/svic/gaia/commit/552d1440d4537972d75a30c05edddcae800c672e

Other: Another possibility is merely check for (this.current.appFrame == null) everywhere. This also seems inelegant (the callbacks should be avoiding this state).

Comment 24

[Garner Lee]

I've updated the WIP. The start/stop events appear correct.

It appears clearing all the callbacks set will fix the appFrame == null issue:

  https://github.com/svic/gaia/commit/85375da099f878c96bb5e6b1aeedf449f1de8b8a

Keep a list of set callbacks for cbDone, tsEnd, etc. cleared or not. It will also unfortunately mean they are kept longer in memory (WIP).

If you slide repeatedly to share, you'll also keep adding more and new callback definitions watching for the next transition step (cancelling one won't work). But, we can clear them all (on 'transitionend') if _cleanEffects is called on the entire set.

So, I believe we'd need better state management (ShrinkUI._state()) to fix this properly.

Comment 25

[Greg Weng [:snowmantw][:gweng][:λ]]

I think it's OK to keep such callbacks in memory while sharing. Because once we end the sharing it should be cleared, and this should not be a long time.

I'll try it after I find some devices.

Comment 26

[Garner Lee]

Attachment: Fix mismatched callbacks patch.

Comment 27

[Garner Lee]

By the way, there are no unit test cases for this P2P timing bug yet (unit nor marionette).

Comment 28

[Greg Weng [:snowmantw][:gweng][:λ]]

Comment on attachment 8418473 [details] [review]
Fix mismatched callbacks patch.

It looks good and the sharing now would success 100% percent. So I give the r+.
Thanks for the fixing.

Let's see if QA can verify this successfully, too.

Comment 29

[Garner Lee]

Greg, thanks! I fixed a misspelled comment (nit) as well.

Comment 30

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

https://github.com/mozilla-b2g/gaia/commit/df0c0f16f05a3c64ad522b4f858e9ef398d88e2c

Comment 31

[Alison Shiue]

Verified on
Gaia      4f352142a54f7f7ae2c460aad9049eda4b0edb14
Gecko     https://hg.mozilla.org/mozilla-central/rev/9ac3e2dd0898
BuildID   20140508160203
Version   32.0a1