1141490 - [Shinano][Aries][Flame] Missing NFC icon in statusbar after reboot

Status: VERIFIED FIXED

(Firefox OS Graveyard :: NFC, defect)

Description

[:gerard-majax]

[Blocking Requested - why for this release]:

This is something I have spotted a couple of days ago already. NFC itself works (approaching devices makes them vibrates, I can use Android Beam).

STR:
 0. Build/Flash current Shinano/Aries master tree
 1. Enable NFC

Expected:
 I see NFC icon in status bar

Actual:
 No NFC icon in statusbar

Comment 1

[:gerard-majax]

Marking as a regression, because this clearly used to work a couple of weeks ago.

Comment 2

[:gerard-majax]

And I don't reproduce this on Flame.

Comment 3

[:gerard-majax]

And that's not reproduced now.

Comment 4

[:gerard-majax]

Actually, not only that it is not fixed, but it reproduces also on Flame. The missing step is: reboot.

After reboot, then one see the issue described here, on all my devices.

Comment 5

[:gerard-majax]

Enabling then disabling the airplane mode makes the icon re-appear.

Comment 6

[:gerard-majax]

(In reply to Alexandre LISSY :gerard-majax from comment #5)
> Enabling then disabling the airplane mode makes the icon re-appear.

And that's 100% repro:
 0. Have NFC enabled, with icon visible in statusbar
 1. Reboot

Expected:
 NFC icon visible

Actual:
 NFC icon not visible

Then:
 2. Enable/Disable airplane mode

That makes the NFC icon reappear.

Comment 7

[Michael Henretty [:mikehenrty][:mhenretty]]

qawanted for branch checks.

Comment 8

[Naoki Hirata :nhirata (please use needinfo instead of cc)]

Doesn't occur on 2.2;
Build ID               20150310002536
Gaia Revision          166491b92278dc9e648f8d49ab02d9ca00d74421
Gaia Date              2015-03-06 18:26:27
Gecko Revision         https://hg.mozilla.org/releases/mozilla-b2g37_v2_2/rev/1cda026f8996
Gecko Version          37.0
Device Name            flame
Firmware(Release)      4.4.2
Firmware(Incremental)  eng.cltbld.20150310.040219
Firmware Date          Tue Mar 10 04:02:29 EDT 2015
Bootloader             L1TC000118D0


Occurs on 3.0 branch only.

Comment 9

[KTucker [:KTucker][Inactive 3/4/2016]]

Removing qawanted since Naoki took care of the branch check. Let's get a regression window here.

Comment 10

[Naoki Hirata :nhirata (please use needinfo instead of cc)]

Attachment: logcat.txt

I found this in the log:

I/Gecko   (  208): -*- SettingsService: settings 'handle' for nfc.debugging.enabled callback threw an exception, dropping: [Exception... "Component does not have requested interface [nsISettingsServiceCallback.handle]"  nsresult: "0x80004002 (NS_NOINTERFACE)"  location: "JS frame :: jar:file:///system/b2g/omni.ja!/components/SettingsService.js :: callHandle :: line 206"  data: no]
I/Gecko   (  208): 
W/GeckoConsole(  208): [JavaScript Error: "Settings queue head blocked at {9f621449-0f59-4a70-a41a-f17fe7bcb72f} for 23068845.368 secs, Settings API may be soft lockup. Lock from: SettingsServiceLock@jar:file:///system/b2g/omni.ja!/components/SettingsService.js:80:17
W/GeckoConsole(  208): createLock@jar:file:///system/b2g/omni.ja!/components/SettingsService.js:291:16
W/GeckoConsole(  208): RadioInterface@jar:file:///system/b2g/omni.ja!/components/RadioInterfaceLayer.js:1668:14
W/GeckoConsole(  208): RadioInterfaceLayer@jar:file:///system/b2g/omni.ja!/components/RadioInterfaceLayer.js:1397:31
W/GeckoConsole(  208): XPCOMUtils__getFactory/factory.createInstance@resource://gre/modules/XPCOMUtils.jsm:303:19
W/GeckoConsole(  208): @jar:file:///system/b2g/omni.ja!/components/RILContentHelper.js:78:13
W/GeckoConsole(  208): XPCU_defineLazyGetter/<.get@resource://gre/modules/XPCOMUtils.jsm:197:21
W/GeckoConsole(  208): RILContentHelper@jar:file:///system/b2g/omni.ja!/components/RILContentHelper.js:127:3
W/GeckoConsole(  208): XPCOMUtils__getFactory/factory.createInstance@resource://gre/modules/XPCOMUtils.jsm:303:19
W/GeckoConsole(  208): " {file: "resource://gre/modules/SettingsRequestManager.jsm" line: 1031}]
I/Gecko   (  208): -*- SettingsRequestManager: Settings queue head blocked at {9f621449-0f59-4a70-a41a-f17fe7bcb72f} for 23068845.368 secs, Settings API may be soft lockup. Lock from: SettingsServiceLock@jar:file:///system/b2g/omni.ja!/components/SettingsService.js:80:17
I/Gecko   (  208): createLock@jar:file:///system/b2g/omni.ja!/components/SettingsService.js:291:16
I/Gecko   (  208): RadioInterface@jar:file:///system/b2g/omni.ja!/components/RadioInterfaceLayer.js:1668:14
I/Gecko   (  208): RadioInterfaceLayer@jar:file:///system/b2g/omni.ja!/components/RadioInterfaceLayer.js:1397:31
I/Gecko   (  208): XPCOMUtils__getFactory/factory.createInstance@resource://gre/modules/XPCOMUtils.jsm:303:19
I/Gecko   (  208): @jar:file:///system/b2g/omni.ja!/components/RILContentHelper.js:78:13
I/Gecko   (  208): XPCU_defineLazyGetter/<.get@resource://gre/modules/XPCOMUtils.jsm:197:21
I/Gecko   (  208): RILContentHelper@jar:file:///system/b2g/omni.ja!/components/RILContentHelper.js:127:3
I/Gecko   (  208): XPCOMUtils__getFactory/factory.createInstance@resource://gre/modules/XPCOMUtils.jsm:303:19
I/Gecko   (  208): 
W/GeckoConsole(  208): [JavaScript Error: "Settings queue head blocked at {9f621449-0f59-4a70-a41a-f17fe7bcb72f} for 23068845.372 secs, Settings API may be soft lockup. Lock from: SettingsServiceLock@jar:file:///system/b2g/omni.ja!/components/SettingsService.js:80:17
W/GeckoConsole(  208): createLock@jar:file:///system/b2g/omni.ja!/components/SettingsService.js:291:16
W/GeckoConsole(  208): RadioInterface@jar:file:///system/b2g/omni.ja!/components/RadioInterfaceLayer.js:1668:14
W/GeckoConsole(  208): RadioInterfaceLayer@jar:file:///system/b2g/omni.ja!/components/RadioInterfaceLayer.js:1397:31
W/GeckoConsole(  208): XPCOMUtils__getFactory/factory.createInstance@resource://gre/modules/XPCOMUtils.jsm:303:19
W/GeckoConsole(  208): @jar:file:///system/b2g/omni.ja!/components/RILContentHelper.js:78:13
W/GeckoConsole(  208): XPCU_defineLazyGetter/<.get@resource://gre/modules/XPCOMUtils.jsm:197:21
W/GeckoConsole(  208): RILContentHelper@jar:file:///system/b2g/omni.ja!/components/RILContentHelper.js:127:3
W/GeckoConsole(  208): XPCOMUtils__getFactory/factory.createInstance@resource://gre/modules/XPCOMUtils.jsm:303:19
W/GeckoConsole(  208): " {file: "resource://gre/modules/SettingsRequestManager.jsm" line: 1031}]
I/Gecko   (  208): -*- SettingsRequestManager: Settings queue head blocked at {9f621449-0f59-4a70-a41a-f17fe7bcb72f} for 23068845.372 secs, Settings API may be soft lockup. Lock from: SettingsServiceLock@jar:file:///system/b2g/omni.ja!/components/SettingsService.js:80:17
I/Gecko   (  208): createLock@jar:file:///system/b2g/omni.ja!/components/SettingsService.js:291:16
I/Gecko   (  208): RadioInterface@jar:file:///system/b2g/omni.ja!/components/RadioInterfaceLayer.js:1668:14
I/Gecko   (  208): RadioInterfaceLayer@jar:file:///system/b2g/omni.ja!/components/RadioInterfaceLayer.js:1397:31
I/Gecko   (  208): XPCOMUtils__getFactory/factory.createInstance@resource://gre/modules/XPCOMUtils.jsm:303:19
I/Gecko   (  208): @jar:file:///system/b2g/omni.ja!/components/RILContentHelper.js:78:13
I/Gecko   (  208): XPCU_defineLazyGetter/<.get@resource://gre/modules/XPCOMUtils.jsm:197:21
I/Gecko   (  208): RILContentHelper@jar:file:///system/b2g/omni.ja!/components/RILContentHelper.js:127:3
I/Gecko   (  208): XPCOMUtils__getFactory/factory.createInstance@resource://gre/modules/XPCOMUtils.jsm:303:19
I/Gecko   (  208):

Comment 11

[(inactive after 6/18) Alive Kuo [:alive]]

No matter this is caused by 1098168, :tauzen could you take a look if you have bandwidth?

Comment 12

[Krzysztof Mioduszewski[:tauzen]]

I should be able to investigate this later today/tomorrow morning, as I'm focused on Secure Element Nexus 5 porting issues right now. Leaving ni? as a reminder.

Comment 13

[Krzysztof Mioduszewski[:tauzen]]

I should be able to investigate this later today/tomorrow morning, as I'm focused on Secure Element Nexus 5 porting issues right now. Leaving ni? as a reminder.

Comment 14

[Krzysztof Mioduszewski[:tauzen]]

double posted by accident

Comment 15

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

Comment 11 already figured out the cause.

Comment 16

[Krzysztof Mioduszewski[:tauzen]]

So actually I'm not 100% sure that this bug is caused only by Base Icon bug 1098168. It seems that after reboot lockscreen startup is quicker then nfc.enabled setting change. I think this wasn't happening earlier (in 2.2 at least). 

Right now, after the initial nfc setting change, when NfcManager calculates the next state [0], |Service.locked| is true, and the hwState goes directly to |DISABLE_DISCOVERY| which does not update the icon later on.

[0] - https://github.com/mozilla-b2g/gaia/blob/a15fab2b2f381c97e136ab094c1822b632485d78/apps/system/js/nfc_manager.js#L263

Comment 17

[Krzysztof Mioduszewski[:tauzen]]

This solves the problem: https://github.com/tauzen/gaia/commit/72f26fbdc95716e9b284c36b566def8e0c1f47d2

But I think we should implement a proper state machine pattern for handling nfcHw changes NfcManager in a followup bug. Alive is this solution acceptable for you?

Comment 18

[(inactive after 6/18) Alive Kuo [:alive]]

(In reply to Krzysztof Mioduszewski[:tauzen] from comment #17)
> This solves the problem:
> https://github.com/tauzen/gaia/commit/
> 72f26fbdc95716e9b284c36b566def8e0c1f47d2
> 
> But I think we should implement a proper state machine pattern for handling
> nfcHw changes NfcManager in a followup bug. Alive is this solution
> acceptable for you?

For your last comment: yes, we should not expect the loading of lockscreen and nfcManager is in certain order.

1. When rebooted, lockscreen state is locked so nfc hw is in disabling-discovery state. No icon in lockscreen statusbar.
2. When rebooted, lockscreen state is locked (but lockscreen is not enabled) so nfc manager is in disabling-discovery state. But after lockscreen window manager read the lockscreen.enabled state, it changes screen.locked to false without telling you, so you are keeping in disabling-discovery mode and there is neither lockscreen nor nfc icon.

Which one is the case you met?

If it's 2., let's fix by listening to lockscreen-enabling/disabling state.

Comment 19

[Krzysztof Mioduszewski[:tauzen]]

So the workaround for this issues is in comment 17. I have discussed this with Alive on IRC, and since we have some time here, I would like to use this bug to refine the overall nfc hw state transitions.

Comment 20

[(inactive after 6/18) Alive Kuo [:alive]]

Here is some notes while working on nfcManager:
1. Let's use BaseModule.EVENTS and remove event registration in _start and unregistration in _stop
2. Remove NfcManager.prototype.handleEvent and add these functions
   _handle_lockscreen-appopened
   _handle_lockscreen-appclosed
   _handle_screenchange
   _handle_shrinking-sent
   the top three functions might call another function inside NfcManager, maybe your state machine entry function.
3. '_observe_nfc.enabled' is the same with _nfcSettingsChanged, let's deprecate _nfcSettingsChanged and move things in it into '_observe_nfc.enabled'. You could access the settings value by this._settings['nfc.enabled'] outside the function
4. '_observe_nfc.debugging.enabled' is the same with _nfcSettingsChanged so let's do the same thing as 3.

Thanks!

Comment 21

[(inactive after 6/18) Alive Kuo [:alive]]

(In reply to Alive Kuo [:alive][NEEDINFO!] from comment #20)
> Here is some notes while working on nfcManager:
> 1. Let's use BaseModule.EVENTS and remove event registration in _start and
> unregistration in _stop
> 2. Remove NfcManager.prototype.handleEvent and add these functions
>    _handle_lockscreen-appopened
>    _handle_lockscreen-appclosed
>    _handle_screenchange
>    _handle_shrinking-sent
>    the top three functions might call another function inside NfcManager,
> maybe your state machine entry function.
> 3. '_observe_nfc.enabled' is the same with _nfcSettingsChanged, let's
> deprecate _nfcSettingsChanged and move things in it into
> '_observe_nfc.enabled'. You could access the settings value by
> this._settings['nfc.enabled'] outside the function
> 4. '_observe_nfc.debugging.enabled' is the same with _nfcSettingsChanged so
> let's do the same thing as 3.
> 
> Thanks!

Let's ignore 4.
4': BaseModule has a native this.debug() function; let's remove NfcManager._debug and do this:
_observe_nfc.debugging.enabled: function(value) {
  this.DEBUG = value;
}

And replace all _debug() with debug()
So each time you call debug(), BaseModule will check this.DEBUG before printing the logs. And since we could this.DEBUG by observing nfc.debugging.enabled, you have the same effect as now.

Comment 22

[:gerard-majax]

Alive, I've noticed the same behavior with the silent mode icon on my Nexus S. Could it be possible the regression may hit any of the icons ?

What I saw was: missing silent mode icon after a reboot, but silent mode was here.

Comment 23

[(inactive after 6/18) Alive Kuo [:alive]]

(In reply to Alexandre LISSY :gerard-majax from comment #22)
> Alive, I've noticed the same behavior with the silent mode icon on my Nexus
> S. Could it be possible the regression may hit any of the icons ?
> 
> What I saw was: missing silent mode icon after a reboot, but silent mode was
> here.

According to tauzen's investigation this one is NOT bug 1098168's regression.
It's an internal problem of nfc manager.
Please file another bug for your issue. Thanks.

Comment 24

[GitHub Autolander Bot]

Attachment: [gaia] tauzen:Bug1141490_hw_states_refined > mozilla-b2g:master

Comment 25

[Krzysztof Mioduszewski[:tauzen]]

Attachment: NfcManager - Nfc HW state machine

Comment 26

[Krzysztof Mioduszewski[:tauzen]]

Comment on attachment 8579546 [details] [review]
[gaia] tauzen:Bug1141490_hw_states_refined > mozilla-b2g:master

Hi Alive, could I have your feedback on this patch?

Comment 27

[(inactive after 6/18) Alive Kuo [:alive]]

Comment on attachment 8579546 [details] [review]
[gaia] tauzen:Bug1141490_hw_states_refined > mozilla-b2g:master

This is a nice work. No big issue, but I left some opinions in github, feel free to ping me here if you have problems. Thank you!

Comment 28

[Krzysztof Mioduszewski[:tauzen]]

Comment on attachment 8579546 [details] [review]
[gaia] tauzen:Bug1141490_hw_states_refined > mozilla-b2g:master

Hi Alive, thank you very much for your feedback. I've implemented most of your remarks and added unit tests. Could you review this?

Comment 29

[(inactive after 6/18) Alive Kuo [:alive]]

Comment on attachment 8579546 [details] [review]
[gaia] tauzen:Bug1141490_hw_states_refined > mozilla-b2g:master

Great work, thanks!

Comment 30

[Krzysztof Mioduszewski[:tauzen]]

Thank you very much for all the help Alive!

Comment 31

[GitHub Autolander Bot]

Pull request has landed in master: https://github.com/mozilla-b2g/gaia/commit/ac2523cc7da1c3ca59c4c8a9fa561318c7e0cb15

Comment 32

[Shally Li（leave from Mozilla）]

Per Comment 31.

Comment 33

[Shally Li（leave from Mozilla）]

This bug has been verified as "pass" on latest Nightly build of Flame v3.0 and Nexus 5 v3.0 by the STR in comment 6.

Actual results: The NFC icon displays normally on the status bar after reboot.
See attachment: verified_v3.0.3gp
Reproduce rate: 0/6


Device: Flame v3.0 build(Verified)
Build ID               20150623010204
Gaia Revision          311c4e59936a407e64509f54fecb440d8a78e3c8
Gaia Date              2015-06-20 20:21:42
Gecko Revision         https://hg.mozilla.org/mozilla-central/rev/be81b8d6fae9
Gecko Version          41.0a1
Device Name            flame
Firmware(Release)      4.4.2
Firmware(Incremental)  eng.cltbld.20150623.043033
Firmware Date          Tue Jun 23 04:30:44 EDT 2015
Bootloader             L1TC000118D0

Device: Nexus 5 v3.0 build(Verified)
Build ID               20150623160205
Gaia Revision          311c4e59936a407e64509f54fecb440d8a78e3c8
Gaia Date              2015-06-20 20:21:42
Gecko Revision         https://hg.mozilla.org/mozilla-central/rev/be81b8d6fae9
Gecko Version          41.0a1
Device Name            hammerhead
Firmware(Release)      5.1
Firmware(Incremental)  eng.cltbld.20150623.191953
Firmware Date          Tue Jun 23 19:20:11 EDT 2015
Bootloader             HHZ12f

--------------------------------------------------
Waiting for someone may verify the Shinano/Aries master.

Comment 34

[Shally Li（leave from Mozilla）]

Attachment: verified_v3.0.3gp

Comment 35

[Jayme Mercado [:JMercado] (Inactive 3/4/2016)]

This issue is verified fixed on the latest Dogfood Nightly Spark Aries build.

Actual Results: The NFC icon appears after restart. (5/5 attempts)

Environmental Variables:
Device: Aries 3.0
BuildID: 20150626120208
Gaia: 8a1e4ae522c121c5cacd39b20a5386ec9055db82
Gecko: 56e207dbb3bd
Gonk: 2916e2368074b5383c80bf5a0fba3fc83ba310bd
Version: 41.0a1 (3.0) 
Firmware Version: D5803_23.1.A.1.28_NCB.ftf
User Agent: Mozilla/5.0 (Mobile; rv:41.0) Gecko/41.0 Firefox/41.0