1161257 - [Flame] [E-mail] Not receiving emails nor the notification

Status: RESOLVED WONTFIX

(Firefox OS Graveyard :: Gaia::E-Mail, defect)

Description

[Gabriela [:gaby2300]]

Since last week I'm not receiving emails even having enabled "Check every 5 minutes". I have to check manually every time. I don't receive the sound notification either.

Bug found using FFOS 3.0, today's OTA and

Build ID               20150504010202
Gaia Revision          e18cce173840d6ff07fb6f1f0e0ffb58b99aab3e
Gaia Date              2015-05-02 04:27:01
Gecko Revision         n/a
Gecko Version          40.0a1
Device Name            flame
Firmware(Release)      4.4.2
Firmware(Incremental)  eng.cltbld.20150212.043653
Firmware Date          Thu Feb 12 04:37:04 EST 2015
Bootloader             L1TC000118D0

Comment 1

[Andrew Sutherland [:asuth] (he/him)]

Is this on a Flame configured to only have 319 Megabytes of RAM available?  It's possible we're getting Out-of-memory killed.  Either way a logcat, should help make it obvious what's going on.  See https://wiki.mozilla.org/Gaia/Email/RequiredBugInfo on providing the logcat.  In order to make it easier to reproduce, if you use the secret debug menu described at https://wiki.mozilla.org/Gaia/Email/SecretDebugMode you can set the periodic sync interval to 60 seconds which should mean you only need to wait a little over a minute to reliaby retrieve a log.  (20 seconds could also work.)

Comment 2

[Gabriela [:gaby2300]]

(In reply to Andrew Sutherland [:asuth] from comment #1)
> Is this on a Flame configured to only have 319 Megabytes of RAM available? 
> It's possible we're getting Out-of-memory killed.  Either way a logcat,
> should help make it obvious what's going on.  See
> https://wiki.mozilla.org/Gaia/Email/RequiredBugInfo on providing the logcat.
> In order to make it easier to reproduce, if you use the secret debug menu
> described at https://wiki.mozilla.org/Gaia/Email/SecretDebugMode you can set
> the periodic sync interval to 60 seconds which should mean you only need to
> wait a little over a minute to reliaby retrieve a log.  (20 seconds could
> also work.)

No Andrew, the Flame has it's default RAM available. Running  adb logcat -v time -s GeckoDump:V Gecko:V GeckoConsole:V OomLogger:V  I got the following log, hope it helps! If not complete or if you need something else, please contact me!



Microsoft Windows [Versión 6.1.7601]
Copyright (c) 2009 Microsoft Corporation. Reservados todos los derechos.

C:\Users\Gabriela>adb logcat -v time -s GeckoDump:V Gecko:V GeckoConsole:V OomLo
gger:V
--------- beginning of /dev/log/system
--------- beginning of /dev/log/main
05-04 18:39:58.456 I/Gecko   (  240): ++++ MEMORY REPORTING: IncrementNumChildPr
ocesses --> 6
05-04 18:39:59.696 I/Gecko   (20728): ###################################### for
ms.js loaded
05-04 18:39:59.706 I/Gecko   (20728): ############################### browserEle
mentPanning.js loaded
05-04 18:39:59.726 I/Gecko   (20728): ######################## BrowserElementChi
ldPreload.js loaded
05-04 18:40:01.086 I/GeckoDump(20728): ←[32mLOG: startupData: {
05-04 18:40:01.086 I/GeckoDump(20728):   "view": "message_list",
05-04 18:40:01.086 I/GeckoDump(20728):   "entry": "request-sync"
05-04 18:40:01.086 I/GeckoDump(20728): }←[0m
05-04 18:40:01.296 I/GeckoDump(20728): ←[32mLOG: mozSetMessageHandler: received
a request-sync←[0m
05-04 18:40:01.296 I/GeckoDump(20728): ←[32mLOG: cronsync-main: wake locks acqui
red: [object MozWakeLock] for account IDs: 0←[0m
05-04 18:40:01.296 I/GeckoDump(20728): ←[32mLOG: cronsync-main: request-sync sta
rted at Mon May 04 2015 18:40:01 GMT-0300 (ART)←[0m
05-04 18:40:01.656 I/Gecko   (20728): ←[32mWLOG: Email knows that it is: offline
 and previously was: online←[0m
05-04 18:40:01.656 I/Gecko   (20728): ←[32mWLOG: deferring getConfig call until
ready←[0m
05-04 18:40:01.666 I/Gecko   (20728): ←[32mWLOG: main thread reports DB ready←[0
m
05-04 18:40:01.666 I/Gecko   (20728): ←[32mWLOG: issuing getConfig call to main
thread←[0m
05-04 18:40:02.166 I/Gecko   (20728): ←[32mWLOG: cronsync: ensureSync called
05-04 18:40:02.166 I/Gecko   (20728): ←[0m
05-04 18:40:02.166 I/Gecko   (20728): ←[32mWLOG: Mail universe/bridge created an
d notified!←[0m
05-04 18:40:02.166 I/Gecko   (20728): ←[32mWLOG: cronsync: received a requestSyn
c via a message handler
05-04 18:40:02.166 I/Gecko   (20728): ←[0m
05-04 18:40:02.166 I/Gecko   (20728): ←[32mWLOG: cronsync: syncAccount early exi
t: online: false, enabled: true
05-04 18:40:02.166 I/Gecko   (20728): ←[0m
05-04 18:40:02.176 I/GeckoDump(20728): ←[32mLOG: cronsync-main: ensureSync calle
d←[0m
05-04 18:40:02.176 I/GeckoDump(20728): ←[32mLOG: email oncronsyncstart: 0←[0m
05-04 18:40:02.176 I/GeckoDump(20728): ←[32mLOG: cronsync-main: success!←[0m
05-04 18:40:02.176 I/GeckoDump(20728): ←[32mLOG: cronsync-main: existing sync ta
sk is OK: 300000←[0m
05-04 18:40:02.176 I/GeckoDump(20728): ←[32mLOG: cronsync-main: existing sync ta
sk is OK: 600000←[0m
05-04 18:40:02.176 I/GeckoDump(20728): ←[32mLOG: cronsync-main: ensureSync compl
eted←[0m
05-04 18:40:02.176 I/Gecko   (20728): ←[32mWLOG: cronsync: received an syncEnsur
ed via a message handler
05-04 18:40:02.176 I/Gecko   (20728): ←[0m
05-04 18:40:02.186 I/GeckoDump(20728): ←[32mLOG: email oncronsyncstop: 0←[0m
05-04 18:40:02.186 I/GeckoDump(20728): ←[32mLOG: email: clearing wake locks for
"id0"←[0m
05-04 18:40:02.186 I/GeckoDump(20728): ←[32mLOG: sync completed in 0.009 seconds
, closing mail app←[0m
05-04 18:40:02.196 I/GeckoDump(20728): ←[32mLOG: WRITING LOCAL STORAGE ITEM: dat
a_has_account yes←[0m
05-04 18:40:02.276 I/Gecko   (  240): ++++ MEMORY REPORTING: DecrementNumChildPr
ocesses --> 5
05-04 18:44:58.297 I/Gecko   (  240): ++++ MEMORY REPORTING: IncrementNumChildPr
ocesses --> 6
05-04 18:44:59.596 I/Gecko   (20950): ###################################### for
ms.js loaded
05-04 18:44:59.606 I/Gecko   (20950): ############################### browserEle
mentPanning.js loaded
05-04 18:44:59.626 I/Gecko   (20950): ######################## BrowserElementChi
ldPreload.js loaded
05-04 18:45:01.256 I/GeckoDump(20950): ←[32mLOG: startupData: {
05-04 18:45:01.256 I/GeckoDump(20950):   "view": "message_list",
05-04 18:45:01.256 I/GeckoDump(20950):   "entry": "request-sync"
05-04 18:45:01.256 I/GeckoDump(20950): }←[0m
05-04 18:45:01.466 I/GeckoDump(20950): ←[32mLOG: mozSetMessageHandler: received
a request-sync←[0m
05-04 18:45:01.466 I/GeckoDump(20950): ←[32mLOG: cronsync-main: wake locks acqui
red: [object MozWakeLock] for account IDs: 1,2←[0m
05-04 18:45:01.466 I/GeckoDump(20950): ←[32mLOG: cronsync-main: request-sync sta
rted at Mon May 04 2015 18:45:01 GMT-0300 (ART)←[0m
05-04 18:45:01.506 I/GeckoDump(20950): ←[32mLOG: mozSetMessageHandler: received
a request-sync←[0m
05-04 18:45:01.506 I/GeckoDump(20950): ←[32mLOG: cronsync-main: wake locks acqui
red: [object MozWakeLock] for account IDs: 0←[0m
05-04 18:45:01.506 I/GeckoDump(20950): ←[32mLOG: cronsync-main: request-sync sta
rted at Mon May 04 2015 18:45:01 GMT-0300 (ART)←[0m
05-04 18:45:01.836 I/Gecko   (20950): ←[32mWLOG: Email knows that it is: offline
 and previously was: online←[0m
05-04 18:45:01.836 I/Gecko   (20950): ←[32mWLOG: deferring getConfig call until
ready←[0m
05-04 18:45:01.846 I/Gecko   (20950): ←[32mWLOG: main thread reports DB ready←[0
m
05-04 18:45:01.846 I/Gecko   (20950): ←[32mWLOG: issuing getConfig call to main
thread←[0m
05-04 18:45:02.356 I/Gecko   (20950): ←[32mWLOG: cronsync: ensureSync called
05-04 18:45:02.356 I/Gecko   (20950): ←[0m
05-04 18:45:02.366 I/Gecko   (20950): ←[32mWLOG: Mail universe/bridge created an
d notified!←[0m
05-04 18:45:02.366 I/Gecko   (20950): ←[32mWLOG: cronsync: received a requestSyn
c via a message handler
05-04 18:45:02.366 I/Gecko   (20950): ←[0m
05-04 18:45:02.366 I/Gecko   (20950): ←[32mWLOG: cronsync: syncAccount early exi
t: online: false, enabled: true
05-04 18:45:02.366 I/Gecko   (20950): ←[0m
05-04 18:45:02.366 I/GeckoDump(20950): ←[32mLOG: cronsync-main: ensureSync calle
d←[0m
05-04 18:45:02.376 I/GeckoDump(20950): ←[32mLOG: email oncronsyncstart: 1,2←[0m
05-04 18:45:02.376 I/Gecko   (20950): ←[32mWLOG: cronsync: syncAccount early exi
t: online: false, enabled: true
05-04 18:45:02.376 I/Gecko   (20950): ←[0m
05-04 18:45:02.376 I/GeckoDump(20950): ←[32mLOG: cronsync-main: success!←[0m
05-04 18:45:02.376 I/Gecko   (20950): ←[32mWLOG: cronsync: received a requestSyn
c via a message handler
05-04 18:45:02.376 I/Gecko   (20950): ←[0m
05-04 18:45:02.376 I/GeckoDump(20950): ←[32mLOG: cronsync-main: existing sync ta
sk is OK: 300000←[0m
05-04 18:45:02.376 I/Gecko   (20950): ←[32mWLOG: cronsync: syncAccount early exi
t: online: false, enabled: true
05-04 18:45:02.376 I/Gecko   (20950): ←[0m
05-04 18:45:02.376 I/GeckoDump(20950): ←[32mLOG: cronsync-main: existing sync ta
sk is OK: 600000←[0m
05-04 18:45:02.376 I/GeckoDump(20950): ←[32mLOG: cronsync-main: ensureSync compl
eted←[0m
05-04 18:45:02.376 I/GeckoDump(20950): ←[32mLOG: email oncronsyncstart: 0←[0m
05-04 18:45:02.386 I/Gecko   (20950): ←[32mWLOG: cronsync: received an syncEnsur
ed via a message handler
05-04 18:45:02.386 I/Gecko   (20950): ←[0m
05-04 18:45:02.386 I/GeckoDump(20950): ←[32mLOG: email oncronsyncstop: 0←[0m
05-04 18:45:02.386 I/GeckoDump(20950): ←[32mLOG: email: clearing wake locks for
"id0"←[0m
05-04 18:45:02.386 I/GeckoDump(20950): ←[32mLOG: WRITING LOCAL STORAGE ITEM: dat
a_has_account yes←[0m

Comment 3

[Andrew Sutherland [:asuth] (he/him)]

Thanks for the logcat contents!  (Aside: it's usually preferable to attach as an attachment.  Bugzilla will let you paste an attachment too if you toggle from attaching a file, so it shouldn't be too bad.)

In both of the example runs, the email app thinks it's offline.  Which is confusing if the device is not offline.  Assuming this log is representative of your usage where sync has not been working, can you elaborate about your network configuration (cellular data and/or wi-fi) and the battery interaction with it (ex: if the device is operating on battery power and you're using wi-fi so the wi-fi is off when the email app tries to run).  This matters because the email app won't turn on wi-fi if it's not already on via some other setting, etc.

Comment 4

[Gabriela [:gaby2300]]

Attachment: Attaching required log

I'm afraid it's all I got. I tried twice with the same result.

Comment 5

[Gabriela [:gaby2300]]

(In reply to Andrew Sutherland [:asuth] from comment #3)
> Thanks for the logcat contents!  (Aside: it's usually preferable to attach
> as an attachment.  Bugzilla will let you paste an attachment too if you
> toggle from attaching a file, so it shouldn't be too bad.)
> 
> In both of the example runs, the email app thinks it's offline.  Which is
> confusing if the device is not offline.  Assuming this log is representative
> of your usage where sync has not been working, can you elaborate about your
> network configuration (cellular data and/or wi-fi) and the battery
> interaction with it (ex: if the device is operating on battery power and
> you're using wi-fi so the wi-fi is off when the email app tries to run). 
> This matters because the email app won't turn on wi-fi if it's not already
> on via some other setting, etc.

I'm sorry for the earlier log, I didn't realize the wifi had not turned on. It's another bug I have. The above attachment is the result with wifi turned on. I wonder if it's correct this time, it seems so little information... 

I tried again and I got a very different result, I'll attach it!

Comment 6

[Gabriela [:gaby2300]]

Attachment: I hope I got it right this time

Comment 7

[Andrew Sutherland [:asuth] (he/him)]

(In reply to Gabriela [:gaby2300] from comment #6)
> Created attachment 8601173 [details]
> I hope I got it right this time

This sync looks like it ran successfully.  If you can capture a failure case, that'd be great, but otherwise I'll try and keep an eye on other incoming bug reports and my own testing.

However, if you could clarify: does your device use cellular data, or is it always using wi-fi?  Does it spend much of its time plugged in when you'd be using it (like if you sit at a desk and keep it plugged in) or running on battery?

Comment 8

[Gabriela [:gaby2300]]

(In reply to Andrew Sutherland [:asuth] from comment #7)
> (In reply to Gabriela [:gaby2300] from comment #6)
> > Created attachment 8601173 [details]
> > I hope I got it right this time
> 
> This sync looks like it ran successfully.  If you can capture a failure
> case, that'd be great, but otherwise I'll try and keep an eye on other
> incoming bug reports and my own testing.
> 
I would appreciate you telling me how could I capture a failure case! If you receive similar bug reports, please add me to the CC list so I can follow them!

> However, if you could clarify: does your device use cellular data, or is it
> always using wi-fi?  Does it spend much of its time plugged in when you'd be
> using it (like if you sit at a desk and keep it plugged in) or running on battery?

I use wifi at home where I obtained the above log. When not at home and at a non wifi place I sometimes get a data connection. It usually runs on battery, however at the time of the log it was connected with the USB cable and thus charging.

Comment 9

[Andrew Sutherland [:asuth] (he/him)]

(In reply to Gabriela [:gaby2300] from comment #8)
> I would appreciate you telling me how could I capture a failure case! If you
> receive similar bug reports, please add me to the CC list so I can follow
> them!

On v3.0 builds, VolumeUp+sleep will capture logs to disk; see https://developer.mozilla.org/en-US/Firefox_OS/Debugging/On-device_console_logging#Hardware_buttons_%28VolumeUp.2Bsleep%29_to_save_system_log.

Practically speaking, this isn't going to be useful since you'll have no idea when the email app is doing stuff and failing to do stuff.
 
> I use wifi at home where I obtained the above log. When not at home and at a
> non wifi place I sometimes get a data connection. It usually runs on
> battery, however at the time of the log it was connected with the USB cable
> and thus charging.

This sounds like the problem is that the email app won't cause wi-fi to be established on its own but requires it to already be operating.  Bug 971183 tracks some issues related to this but there may be other bugs, I'm having trouble finding them now.

I think my best suggestion right now is to go to the settings UI wi-fi menu and make sure "wi-fi" sleep is disabled.  If it's already disabled and you didn't have some other app on the device that would run in the background and hold a wake-lock, then maybe there has been a system regression to explain the change in behaviour you're experiencing.

Aside: Bug 1114453 which introduced that settings UI option has a neat state machine diagram for wi-fi sleep: https://wiki.mozilla.org/images/c/c6/WifiPowerModeState.svg

Comment 10

[Gabriela [:gaby2300]]

(In reply to Andrew Sutherland [:asuth] from comment #9)


> On v3.0 builds, VolumeUp+sleep will capture logs to disk; see
> https://developer.mozilla.org/en-US/Firefox_OS/Debugging/On-
> device_console_logging#Hardware_buttons_%28VolumeUp.
> 2Bsleep%29_to_save_system_log.
> 
> Practically speaking, this isn't going to be useful since you'll have no
> idea when the email app is doing stuff and failing to do stuff.

Then I won't even try.
>  
> > I use wifi at home where I obtained the above log. When not at home and at a
> > non wifi place I sometimes get a data connection. It usually runs on
> > battery, however at the time of the log it was connected with the USB cable
> > and thus charging.
> 
> This sounds like the problem is that the email app won't cause wi-fi to be
> established on its own but requires it to already be operating.  Bug 971183
> tracks some issues related to this but there may be other bugs, I'm having
> trouble finding them now.

I added  myself to follow the bug. Thanks!
> 
> I think my best suggestion right now is to go to the settings UI wi-fi menu
> and make sure "wi-fi" sleep is disabled.  If it's already disabled and you
> didn't have some other app on the device that would run in the background
> and hold a wake-lock, then maybe there has been a system regression to
> explain the change in behaviour you're experiencing.

"Wifi" sleep is always disabled in my case as I want to notice the email's notifications as soon as they are received. So if it's actually a system regression, is there something else I should besides reporting this bug? 
I'll be installing every OTA update as soon as available and check this bug afterwards. Maybe the issue will be fixed in some future update?

> 
> Aside: Bug 1114453 which introduced that settings UI option has a neat state
> machine diagram for wi-fi sleep:
> https://wiki.mozilla.org/images/c/c6/WifiPowerModeState.svg

I don't quite understand the diagram, sorry.

Many thanks for your help!!

Comment 11

[Andrew Sutherland [:asuth] (he/him)]

(In reply to Gabriela [:gaby2300] from comment #10)
> "Wifi" sleep is always disabled in my case as I want to notice the email's
> notifications as soon as they are received. So if it's actually a system
> regression, is there something else I should besides reporting this bug? 

Some combination of me emailing the dev-gaia/dev-b2g lists, requesting qawanted on the bug, and/or trying to reproduce locally is probably the next step.

But useful info for me to know before that next step is: what is your wifi quality at home?  Specifically, do you have great wifi coverage throughout, or are there places where the reception is bad and the signal might drop and then FxOS needs to intentionally reconnect rather than just staying connected?  Thanks!

Comment 12

[Gabriela [:gaby2300]]

(In reply to Andrew Sutherland [:asuth] from comment #11)

> But useful info for me to know before that next step is: what is your wifi
> quality at home?  Specifically, do you have great wifi coverage throughout,
> or are there places where the reception is bad and the signal might drop and
> then FxOS needs to intentionally reconnect rather than just staying
> connected?  Thanks!

At home I have a good coverage, all the lines of the indicator are always full. (I've searched for some kind of wifi meter in Marketplace but I couldn't find one). 
The phone is usually in my room and that's where the wifi modem is. It doesn't seem to get disconnected, not even when the dispaly goes black. It worked just fine till some time last week or the one before that. I took no notice because I thought it would be solved in a few updates, but it wasn't. That's why I created this bug.

Comment 13

[Andrew Sutherland [:asuth] (he/him)]

Thanks for the details and thanks for filing the bug!  I'll mail dev-gaia since I've heard some other reports of wi-fi wackiness as of late.

Comment 14

[Gabriela [:gaby2300]]

Right, I'm on that list so I'll be able to follow your posts there. Many thanks for your help!

Comment 15

[Eric Chang [:ericcc] [:echang]]

Hi Teri, Could you check if we have this issue on 2.2, thank you.

Comment 16

[Teri Wen [:twen]]

Email receiving and notification is working fine on Nexus-5-L v2.2 and v3.0.

*********** V2.2
Gaia-Rev        c6a6996841860ab335bf46b273477dc4bef19c95
Gecko-Rev       https://hg.mozilla.org/releases/mozilla-b2g37_v2_2/rev/c7fafa53b4e7
Build-ID        20150506162500
Version         37.0
Device-Name     hammerhead
FW-Release      5.1
FW-Incremental  eng.cltbld.20150506.195728
FW-Date         Wed May  6 19:57:45 EDT 2015
Bootloader      HHZ12d

*********** V3.0
Gaia-Rev        426fe6450ab8da92bb473fef12ccb39c6c920dd0
Gecko-Rev       https://hg.mozilla.org/mozilla-central/rev/5593ac626826
Build-ID        20150506160205
Version         40.0a1
Device-Name     hammerhead
FW-Release      5.1
FW-Incremental  eng.cltbld.20150506.192419
FW-Date         Wed May  6 19:24:33 EDT 2015
Bootloader      HHZ12d

This is also working fine on Flame 2.2.

Gaia-Rev        fa88af3a8e175be6a35ddd3e88b4446976027894
Gecko-Rev       https://hg.mozilla.org/releases/mozilla-b2g37_v2_2/rev/006e0cf17e6f
Build-ID        20150507162502
Version         37.0
Device-Name     flame
FW-Release      4.4.2
FW-Incremental  eng.cltbld.20150507.195426
FW-Date         Thu May  7 19:54:37 EDT 2015
Bootloader      L1TC000118D0

Comment 17

[Gabriela [:gaby2300]]

Still not working for me at all on Flame v3.0 with the latest OTA update and base image 18D.

Comment 18

[BMO Automation]

Firefox OS is not being worked on