Closed Bug 1141490 Opened 7 years ago Closed 7 years ago

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

Categories

(Firefox OS Graveyard :: NFC, defect)

ARM
Gonk (Firefox OS)
defect
Not set
normal

Tracking

(blocking-b2g:2.5?, b2g-v2.2 unaffected, b2g-master fixed)

VERIFIED FIXED
2.2 S9 (3apr)
blocking-b2g 2.5?
Tracking Status
b2g-v2.2 --- unaffected
b2g-master --- fixed

People

(Reporter: gerard-majax, Assigned: tauzen)

References

Details

(Keywords: regression)

Attachments

(4 files)

[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
Marking as a regression, because this clearly used to work a couple of weeks ago.
Keywords: regression
And I don't reproduce this on Flame.
And that's not reproduced now.
Status: NEW → RESOLVED
Closed: 7 years ago
Resolution: --- → WORKSFORME
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.
Status: RESOLVED → REOPENED
Resolution: WORKSFORME → ---
Summary: [Shinano][Aries] Missing NFC icon in statusbar → [Shinano][Aries] Missing NFC icon in statusbar after reboot
Summary: [Shinano][Aries] Missing NFC icon in statusbar after reboot → [Shinano][Aries][Flame] Missing NFC icon in statusbar after reboot
Enabling then disabling the airplane mode makes the icon re-appear.
(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.
Flags: needinfo?(nhirata.bugzilla)
qawanted for branch checks.
Keywords: qawanted
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.
Removing qawanted since Naoki took care of the branch check. Let's get a regression window here.
Attached file 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):
QA Contact: pcheng
No matter this is caused by 1098168, :tauzen could you take a look if you have bandwidth?
Flags: needinfo?(kmioduszewski)
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.
Flags: needinfo?(kmioduszewski)
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.
double posted by accident
Flags: needinfo?(kmioduszewski)
Comment 11 already figured out the cause.
QA Whiteboard: [QAnalyst-Triage?]
Flags: needinfo?(ktucker)
QA Whiteboard: [QAnalyst-Triage?] → [QAnalyst-Triage+]
Flags: needinfo?(ktucker)
Assignee: nobody → kmioduszewski
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
Flags: needinfo?(kmioduszewski)
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?
Flags: needinfo?(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.
Flags: needinfo?(alive)
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.
Blocks: NFC-Gaia
Component: Gaia::System → NFC
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!
(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.
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.
Flags: needinfo?(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.
Flags: needinfo?(alive)
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?
Attachment #8579546 - Flags: feedback?(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!
Attachment #8579546 - Flags: feedback?(alive) → feedback+
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?
Attachment #8579546 - Flags: review?(alive)
Comment on attachment 8579546 [details] [review]
[gaia] tauzen:Bug1141490_hw_states_refined > mozilla-b2g:master

Great work, thanks!
Attachment #8579546 - Flags: review?(alive) → review+
Thank you very much for all the help Alive!
Keywords: checkin-needed
Status: REOPENED → RESOLVED
Closed: 7 years ago7 years ago
Resolution: --- → FIXED
Target Milestone: --- → 2.2 S9 (3apr)
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.
QA Whiteboard: [QAnalyst-Triage+] → [QAnalyst-Triage+][MGSEI-Triage+]
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
Status: RESOLVED → VERIFIED
QA Whiteboard: [QAnalyst-Triage+][MGSEI-Triage+] → [QAnalyst-Triage?][MGSEI-Triage+]
Flags: needinfo?(ktucker)
QA Whiteboard: [QAnalyst-Triage?][MGSEI-Triage+] → [QAnalyst-Triage+][MGSEI-Triage+]
Flags: needinfo?(ktucker)
You need to log in before you can comment on or make changes to this bug.