moztrap Case #10744: https://moztrap.mozilla.org/manage/case/10744/ Reproduce steps: 1. Open E-mail app If no account has been set up on the device the first time E-mail set up will be displayed. 2. Set up an e-mail account Drop down and toggle will be displayed after inputting credentials to be able to turn on notification.(Make sure it is toggled on and make sure the "Check for new messages" is set to a time and not manual) 3. Tap the Home button 4. Send e-mail to test device and wait for a while [actual] No notification appears. [excepted] A notification will be display on the top of the phone when the phone auto checks for new messages. Tarako 1.3t build:20140312064823 gaia: a1e70877

Please provide the information requested at https://wiki.mozilla.org/Gaia/Email/RequiredBugInfo. This bug is not actionable without information.

Test environment -------------------------------------------------------------------------- Device: Tarako Build: v1.3t 20140312064823 gaia: "a1e70877a251448160a6e52e52ec418f8516c8ee" gecko: "7780260787cd36929bba12fcc12022b6e8150eca" Email Account: Tested using both gmail and hotmail. Neither of them received email notification. WIFI: enabled Reproduce steps ---------------------------------------------------------------------------- 1. Open E-mail app 2. Set up an e-mail account using gmail or hotmail (Set "Check for new messages" to a time and not manual) 3. Tap the Home button 4. Send e-mail to test device and wait for a while [actual] No notification appears. [excepted] A notification will be display on the top of the phone when the phone auto checks for new messages. I think this might be because of Tarako's limit memory and it kills Email app when we send it to background. So no notification could be received.

pcheng, if it is killed due to OOM, we should follow : https://wiki.mozilla.org/B2G/Debugging_OOMs#Step_1:_Verify_that_it.27s_actually_an_OOM Also to note you can get about_memory information as well through : https://wiki.mozilla.org/B2G/QA/Tips_And_Tricks#Debugging_OOMs Can you collect this information and place it in this bug please?

One of the core things we're looking for from https://wiki.mozilla.org/Gaia/Email/RequiredBugInfo is the logcat that shows us what the e-mail app was actually doing. Also relevant is knowing: - Does the device have a cellular data connection - whether the device is charging when you are running the tests Note that we almost certainly expect gmail sync to not work because of bug 977867 which is only fixed on v1.4/master right now. hotmail is a better test right now, but for IMAP testing, anything but gmail should also work. (Yahoo, mozilla.com zimbra, etc.)

Test start at : 03-13 13:59:13.650

@Naoki, this is not OOM crash(I didn't find sigkill from adb shell dmesg output). Tarako will kill Email app if it's in background. @asuth, please see attached adb logcat and answers for ur questions bellow. - Does the device have a cellular data connection ---- NO. I was using WIFI for testing. - whether the device is charging when you are running the tests. ---- NO. This should be the same issue with bug 977867 since Email app was killed. Since this blocks smoketest, is it possible to include the fix in 1.3t?

Andrew, will you be able to take this bug? Thanks

tl;dr: I am declaring this a platform/device network problem, internet connection problem with the wi-fi network in use, or known bug 907028. XHR requests to the hotmail servers are repeatedly timing out after 30 seconds. The e-mail app needs a working network to perform periodic sync and the network is clearly flakey. There is a potential e-mail mitigation of adding more retries to the core sync process, but that might not be great either, instead of taking 30 seconds to fail, we could end up taking 60 or 90 seconds to fail. (In reply to pcheng from comment #6) > @asuth, please see attached adb logcat and answers for ur questions bellow. > - Does the device have a cellular data connection ---- NO. I was using WIFI > for testing. > - whether the device is charging when you are running the tests. ---- NO. > This should be the same issue with bug 977867 since Email app was killed. > Since this blocks smoketest, is it possible to include the fix in 1.3t? We don't expect sync to work at all in this case. If you are using wi-fi and the device is not charging (connected via powered USB), then the only network connection (wi-fi) will be turned off when the screen is off by default behaviour. The e-mail app does not / is not able to turn on the wi-fi when it is off. This is bug 907028. Although I am confused because it does look like the Tarako device is staying connected to wi-fi when the screen turns off? E-mail does seem to always think it is online. Is it possible there is a platform bug that lies about the status of the wi-fi connection? That would definitely explain the timeouts. I only see indication of ActiveSync activity, consistent with my comment about gmail IMAP being broken on v1.3/v1.3T right now. The primary problem seems to be ActiveSync XHR timeouts. Specifically, I see 3 syncs: === sync 1: fails because of XHR timeout in withConnection() code-path that is fatal 03-13 13:51:38.010 I/GeckoDump( 2745): LOG: email oncronsyncstart: 0 03-13 13:52:08.440 I/Gecko ( 2745): WERR: Error: Error getting OPTIONS URL 03-13 13:52:08.450 I/Gecko ( 2745): WERR: Error connecting to ActiveSync: Error: Error getting OPTIONS URL 03-13 13:52:08.450 I/Gecko ( 2745): WLOG: Sync Completed! undefined messages synced 03-13 13:52:08.490 I/GeckoDump( 2745): LOG: email oncronsyncstop: 0 === sync 2: complicated overlap of UI-triggered behaviour and periodic sync: -- the UI is displayed: 03-13 13:56:31.550 I/GeckoDump( 3038): LOG: pushCard for type: message_list -- I don't think a sync is triggered because we're within the 10 minute window where we don't auto-refresh. -- a downloadBodies is enqueued; presumably for snippet retrieval 03-13 13:56:34.500 I/Gecko ( 3038): WLOG: queueOp 0 downloadBodies 03-13 13:56:34.500 I/Gecko ( 3038): WLOG: runOp(do: {"type":"downloadBodies","longtermId":"0/1","lifecycle":"do","localStatus":"done","serverStatu s":"doing","tryCount":0,"humanOp":"downloadBodies","messages":[{"s) -- the sync timer fires, probably scheduling a sync, but in the mutex queue after the snippet fetch 03-13 13:56:38.130 I/GeckoDump( 3038): LOG: email oncronsyncstart: 0 -- the UI gives up on the snippet request (6 second delay) and issues another one 03-13 13:56:45.250 I/Gecko ( 3038): WLOG: queueOp 0 downloadBodies -- the snippet-fetch command times-out. the inference is that the OPTIONS request did succeed 03-13 13:57:13.880 I/Gecko ( 3038): WERR: Error: Error getting command URL 03-13 13:57:13.900 I/Gecko ( 3038): WERR: Error: Error getting command URL -- the snippet-fetch job actually completes (having failed). delay is weird. this will release the mutex for the sync logic. 03-13 13:57:23.780 I/Gecko ( 3038): WLOG: runOp_end(do: {"type":"downloadBodies","longtermId":"0/1","lifecycle":"do","localStatus":"done","serverStatus":"doing","tryCount":0,"humanOp":"downloadBodies","messages":[{"s) -- the snippet-fetch job gets rescheduled, but it won't be able to acquire the mutex 03-13 13:57:23.840 I/Gecko ( 3038): WLOG: runOp(do: {"type":"downloadBodies","longtermId":"0/1","lifecycle":"do","localStatus":"done","serverStatus":"doing","tryCount":5,"humanOp":"downloadBodies","messages":[{"s) -- the sync process completes acceptably, but now it wants a snippet and the UI may also have issued another snippet fetch request 03-13 13:57:31.810 I/Gecko ( 3038): WLOG: Sync completed: added 1, changed 0, deleted 0 03-13 13:57:31.820 I/Gecko ( 3038): WLOG: onNewHeader: [object Object] 03-13 13:57:31.820 I/Gecko ( 3038): WLOG: Sync Completed! 1 messages synced 03-13 13:57:31.860 I/Gecko ( 3038): WLOG: cronsync: Asking for snippets for 1 headers 03-13 13:57:31.860 I/Gecko ( 3038): WLOG: queueOp 0 downloadBodies 03-13 13:57:32.160 I/Gecko ( 3038): WLOG: queueOp 0 downloadBodies -- it seems like the UI must have issued a sync request too at some point? 03-13 13:57:33.360 I/Gecko ( 3038): WLOG: Sync completed with empty response 03-13 13:57:33.360 I/Gecko ( 3038): WLOG: Sync Completed! 0 messages synced -- the snippet fetch runs to completion, as do a whole bunch more that had accumulated 03-13 13:57:34.320 I/Gecko ( 3038): WLOG: runOp_end(do: {"type":"downloadBodies","longtermId":"0/1","lifecycle":"do","localStatus":"done","serverStatus":"doing","tryCount":5,"humanOp":"downloadBodies","messages":[{"s) 03-13 13:57:34.320 I/Gecko ( 3038): 03-13 13:57:34.340 I/Gecko ( 3038): WLOG: runOp(do: {"type":"downloadBodies","longtermId":"0/2","lifecycle":"do","localStatus":"done","serverStatus":"doing","tryCount":0,"humanOp":"downloadBodies","messages":[{"s) 03-13 13:57:34.370 I/Gecko ( 3038): WLOG: runOp_end(do: {"type":"downloadBodies","longtermId":"0/2","lifecycle":"do","localStatus":"done","serverStatus":"doing","tryCount":0,"humanOp":"downloadBodies","messages":[{"s) 03-13 13:57:34.370 I/Gecko ( 3038): 03-13 13:57:34.370 I/Gecko ( 3038): WLOG: runOp(do: {"type":"downloadBodies","longtermId":"0/3","lifecycle":"do","localStatus":"done","serverStatus":"doing","tryCount":0,"humanOp":"downloadBodies","messages":[{"i) 03-13 13:57:34.950 I/GeckoDump( 3038): LOG: htmlCache.save: 16013 in 8 segments 03-13 13:57:35.210 I/Gecko ( 3038): WLOG: runOp_end(do: {"type":"downloadBodies","longtermId":"0/3","lifecycle":"do","localStatus":"done","serverStatus":"doing","tryCount":0,"humanOp":"downloadBodies","messages":[{"i) -- cronsync notifies: 03-13 13:57:35.220 I/Gecko ( 3038): WLOG: cronsync: Notifying for 1 headers -- another snippet fetch runs: 03-13 13:57:35.240 I/Gecko ( 3038): WLOG: runOp(do: {"type":"downloadBodies","longtermId":"0/4","lifecycle":"do","localStatus":"done","serverStatus":"doing","tryCount":0,"humanOp":"downloadBodies","messages":[{"s) 03-13 13:57:35.280 I/Gecko ( 3038): WLOG: runOp_end(do: {"type":"downloadBodies","longtermId":"0/4","lifecycle":"do","localStatus":"done","serverStatus":"doing","tryCount":0,"humanOp":"downloadBodies","messages":[{"s) -- cronsync completes, but leaves the app open because the UI was shown 03-13 13:57:35.430 I/GeckoDump( 3038): LOG: email oncronsyncstop: 0 === sync 3: cronsync sync works but the snippet fetch appears to be destined for a timeout; the logcat ends right before our timeout would fire. 03-13 14:01:38.190 I/GeckoDump( 3038): LOG: email oncronsyncstart: 0 03-13 14:01:38.200 I/GeckoDump( 3038): LOG: cronsync-main: ensureSync called 03-13 14:01:38.240 I/GeckoDump( 3038): LOG: cronsync-main: success: mozAlarms.add for IDs: 0 at 300000ms 03-13 14:01:38.250 I/Gecko ( 3038): WLOG: cronsync: received an syncEnsured via a message handler 03-13 14:01:38.250 I/Gecko ( 3038): 03-13 14:01:47.760 I/Gecko ( 3038): WLOG: Sync completed: added 1, changed 0, deleted 0 03-13 14:01:47.760 I/Gecko ( 3038): WLOG: onNewHeader: [object Object] 03-13 14:01:47.770 I/Gecko ( 3038): WLOG: Sync Completed! 1 messages synced 03-13 14:01:47.770 I/Gecko ( 3038): WLOG: cronsync: Asking for snippets for 1 headers 03-13 14:01:47.770 I/Gecko ( 3038): 03-13 14:01:47.780 I/Gecko ( 3038): WLOG: queueOp 0 downloadBodies 03-13 14:01:47.780 I/Gecko ( 3038): WLOG: runOp(do: {"type":"downloadBodies","longtermId":"0/5","lifecycle":"do","localStatus":"done","serverStatu s":"doing","tryCount":0,"humanOp":"downloadBodies","messages":[{"i) 03-13 14:01:47.910 I/Gecko ( 3038): WLOG: queueOp 0 downloadBodies ==== Aside: the log indicated that at one point gmail thinks your are connecting from a suspicious IP or something like that, which it appears you corrected. Better processing that error is bug 847803.

(In reply to Andrew Sutherland (:asuth) from comment #8) > tl;dr: I am declaring this a platform/device network problem, internet > connection problem with the wi-fi network in use, or known bug 907028. XHR > requests to the hotmail servers are repeatedly timing out after 30 seconds. > The e-mail app needs a working network to perform periodic sync and the > network is clearly flakey. Can QA test with different Tarako devices? to make sure this is not a single device connectivity issue? iirc, Wifi isn't completely stable on tarako yet

The app was killed before any notification was given. This is with : user_pref("browser.dom.window.dump.enabled", true); 772 was the email process; I used a hotmail email address. This happened on 2 different tarakos. 03-13 13:19:53.030: I/Gecko:ProcessPriorityManager(81): [Homescreen, child-id=2, pid=387] Changing priority from BACKGROUND_HOMESCREEN:CPU_LOW to FOREGROUND:CPU_LOW. 03-13 13:19:53.030: I/Gonk(81): Setting nice for pid 387 to 18 03-13 13:19:53.030: I/Gonk(81): Changed nice for pid 387 from 18 to 18. 03-13 13:19:53.030: I/Gecko:ProcessPriorityManager(81): KillBackgroundApps 03-13 13:19:53.030: I/Gecko:ProcessPriorityManager(81): About to force kill pid: 772 03-13 13:19:53.030: I/Gecko:ProcessPriorityManager(81): Remove ChildID(7) from LRU pool 03-13 13:19:53.140: W/WifiHW(81): wifi_command: SIGNAL_POLL 03-13 13:19:53.140: D/wpa_supplicant(405): nl80211: survey data missing! 03-13 13:19:53.150: E/[Gralloc-ERROR](81): int gralloc_unregister_buffer(const gralloc_module_t*, const native_handle_t*):274 Trying to unregister buffer 0x4411bec0 from process 81 that was not created in current process: 81 03-13 13:19:53.150: E/[Gralloc-ERROR](81): int gralloc_unregister_buffer(const gralloc_module_t*, const native_handle_t*):274 Trying to unregister buffer 0x44175fb0 from process 81 that was not created in current process: 81 03-13 13:19:53.200: I/Gecko(81): [Parent 81] WARNING: pipe error (95): Connection reset by peer: file /var/lib/jenkins/jobs/B2G.v1.3.0.Tarako/workspace/gecko/ipc/chromium/src/chrome/common/ipc_channel_posix.cc, line 446 03-13 13:19:53.200: I/Gecko(81): ###!!! [Parent][MessageChannel] Error: Channel error: cannot send/recv 03-13 13:19:53.230: I/Gecko:ProcessPriorityManager(81): [child-id=7, pid=-1] Destroying ParticularProcessPriorityManager. 03-13 13:19:53.230: I/Gecko(81): [Parent 81] WARNING: waitpid failed pid:772 errno:10: file /var/lib/jenkins/jobs/B2G.v1.3.0.Tarako/workspace/gecko/ipc/chromium/src/base/process_util_posix.cc, line 254 03-13 13:19:53.460: E/[Gralloc-ERROR](81): int gralloc_register_buffer(const gralloc_module_t*, const native_handle_t*):79 Unable to register handle 0x44c99560 coming from different process: 81 03-13 13:19:53.460: E/[Gralloc-ERROR](81): int gralloc_register_buffer(const gralloc_module_t*, const native_handle_t*):79 Unable to register handle 0x44c99600 coming from different process: 81 03-13 13:19:53.480: E/[Gralloc-ERROR](81): int gralloc_register_buffer(const gralloc_module_t*, const native_handle_t*):79 Unable to register handle 0x44c996a0 coming from different process: 81 03-13 13:19:53.480: E/[Gralloc-ERROR](81): int gralloc_register_buffer(const gralloc_module_t*, const native_handle_t*):79 Unable to register handle 0x44c99740 coming from different process: 81 03-13 13:19:53.490: E/[Gralloc-ERROR](81): int gralloc_register_buffer(const gralloc_module_t*, const native_handle_t*):79 Unable to register handle 0x44c997e0 coming from different process: 81 03-13 13:19:53.490: E/[Gralloc-ERROR](81): int gralloc_register_buffer(const gralloc_module_t*, const native_handle_t*):79 Unable to register handle 0x44c99880 coming from different process: 81 03-13 13:19:53.880: I/GeckoDump(81): XXX FIXME : Got a mozContentEvent: nfc-hardware-state-change 03-13 13:19:53.900: I/GeckoDump(81): XXX FIXME : Got a mozContentEvent: nfc-hardware-state-change 03-13 13:19:53.980: E/[Gralloc-ERROR](81): int gralloc_unregister_buffer(const gralloc_module_t*, const native_handle_t*):274 Trying to unregister buffer 0x44c99600 from process 81 that was not created in current process: 81 03-13 13:19:53.980: E/[Gralloc-ERROR](81): int gralloc_unregister_buffer(const gralloc_module_t*, const native_handle_t*):274 Trying to unregister buffer 0x44c99560 from process 81 that was not created in current process: 81 03-13 13:19:53.990: E/[Gralloc-ERROR](81): int gralloc_unregister_buffer(const gralloc_module_t*, const native_handle_t*):274 Trying to unregister buffer 0x44c99740 from process 81 that was not created in current process: 81 03-13 13:19:53.990: E/[Gralloc-ERROR](81): int gralloc_unregister_buffer(const gralloc_module_t*, const native_handle_t*):274 Trying to unregister buffer 0x44c996a0 from process 81 that was not created in current process: 81 03-13 13:19:53.990: E/[Gralloc-ERROR](81): int gralloc_unregister_buffer(const gralloc_module_t*, const native_handle_t*):274 Trying to unregister buffer 0x44c99880 from process 81 that was not created in current process: 81 03-13 13:19:53.990: E/[Gralloc-ERROR](81): int gralloc_unregister_buffer(const gralloc_module_t*, const native_handle_t*):274 Trying to unregister buffer 0x44c997e0 from process 81 that was not created in current process: 81 03-13 13:19:55.230: I/Gecko(81): [Parent 81] WARNING: waitpid failed pid:772 errno:10: file /var/lib/jenkins/jobs/B2G.v1.3.0.Tarako/workspace/gecko/ipc/chromium/src/base/process_util_posix.cc, line 254 03-13 13:19:55.230: I/Gecko(81): [Parent 81] WARNING: Failed to deliver SIGKILL to 772!(3).: file /var/lib/jenkins/jobs/B2G.v1.3.0.Tarako/workspace/gecko/ipc/chromium/src/chrome/common/process_watcher_posix_sigchld.cc, line 118 03-13 13:19:58.140: W/WifiHW(81): wifi_command: SIGNAL_POLL

Fuller logcat from the time that email app was relaunched, set to background and an email to the hotmail account was sent. Account was setup with ActiveSync E-Mail app_812 812 356 75648 28644 ffffffff 400b5518 S /system/b2g/plugin-container It looks like email app gets killed when the phone goes to sleep? I'm going to try another run of keeping the phone awake and waiting.

This time I logcatted with the email app in the background and I kept the device awake. This is a hotmail account w/ sync every 5 minutes. No notification appeared after the data sync. Email app was still alive in the background ( E-Mail 1257 ) It looks like you do have to keep the phone awake else the email app will get killed from sleep/wake.

rebooted the phone and tried the same thing again: hotmail with the phone kept away and email in the background. email pid : 602 I got an error in the notification : 03-13 14:01:22.970: I/Gecko(81): A coding exception was thrown in a Promise resolution callback. 03-13 14:01:22.970: I/Gecko(81): Full message: TypeError: this.byTag[origin] is undefined

Sounds like Naoki confirmed this is reproducible on different tarako devices & on a different network, so I'm removing qawanted here.

Andrew, can you please take a further look? Thanks

(In reply to Naoki Hirata :nhirata (please use needinfo instead of cc) from comment #13) > 03-13 14:01:22.970: I/Gecko(81): A coding exception was thrown in a Promise > resolution callback. > 03-13 14:01:22.970: I/Gecko(81): Full message: TypeError: this.byTag[origin] > is undefined This appears to be bug 963130 which was uplifted to 1.3t on Friday, March 14th. Context: https://hg.mozilla.org/releases/mozilla-b2g28_v1_3t/rev/57f27d290aea https://hg.mozilla.org/releases/mozilla-b2g28_v1_3t/pushloghtml?changeset=57f27d290aea Note that bug 962977 also was uplifted and it relates to bugs in the lower notification levels. I looked at the remainder of the logs provided, e-mail appears to work fine and run to completion during its syncs. So I expect this should be WFM once we confirm that things work fine with a working notifications layer.

We're still seeing an error: I/Gecko ( 3499): WERR: Error: Error getting command URL I/Gecko ( 3499): WERR: Error syncing folder: Error: Error getting command URL I/Gecko ( 3499): WLOG: Sync Completed! undefined messages synced I/GeckoDump( 3499): LOG: email oncronsyncstop: 0 I/GeckoDump( 3499): LOG: email: clearing wake locks for "id0" Using: Gaia 15385efaf840090391d182d821eaeda6d25cf0e0 caution: filename not matched: chrome/toolkit/content/global/buildconfig.html BuildID 20140317060055 Version 28.0 ro.build.version.incremental=113 ro.build.date=Mon Mar 17 06:10:08 CST 2014 Tarako

That looks like a network problem that the e-mail app is handling appropriately. It's just an XMLHttpRequest. It's on the RIL or system or the network being used. If you have a tcpdump that covers the request we can have a better idea of the exact cause, but there's not much the e-mail app can do about it.

Also, please make sure your logcats are generated using "-v time" so it's more obvious when the problem is a timeout versus an explicit failure path.

Packet sniffed while getting the error : https://wiki.mozilla.org/B2G/Packet_Sniffing_with_Wireshark

Corresponding logcat from launch of email app to placing it in the background and waiting for the message to try to come out.

Thank you for the pcap! Unfortunately, the logcat and pcap indicate that periodic sync was successful in this case and that 1 message was notified for. Did you see a notification? If not, are you sure the build has the 1.3T notification fixes?

No, I did not get the notification. This build is from: http://release1-qa.corp.tpe1.mozilla.com:8080/job/B2G.v1.3.0.Tarako.eng/81/ According to : https://git.mozilla.org/?p=releases/gecko.git;a=blob;f=dom/src/notification/NotificationDB.jsm;h=fa42873a4aa2736e7b9e31336e06c2e897ce4e09;hb=HEAD#l60 Yes, the code is in the build.

I also tested in today's build 20140318104052, but still get no notification. gaia revision="abf210d0ea2f6bf1c43be46fde67521aa36af0db" gecko revision="3fb98dffed72c590ad831ae56a711ce406239720" I checked adb locat. It seems email periodic sync works. But not sure why I get no notification.

I'll see if there are any uplifts we are missing and test periodic sync on a buri/hamachi with a 1.3T build since I don't have a tarako and the notifications bug does not seem likely to be device-specific.

It seems like Andrew trying to fix this without an actual target device is like shooting fish in a barrel. What needs to happen to get him a device?

I believe Dylan has a device that we can ship to asuth

Shipped it today.

I didn't see this bug on today's build: gaia: "8132b88334f61288060a2680857c54c7af82cdc5" gecko: "57625761da9e5c35d1ddd516221ce274a3575d15" build id: 20140324121117

I guess that makes this a works for me then per comment 29.

adb log for build 20140326061134. test starts at: 03-26 19:40:24.847

adb log for build 20140324121117 tests start at 03-26 19:23:29.740

I need to reopen this bug since it happens on following build again: - Gaia f6a7afd0d716f7a38dfc1808ee0aab3e06ba2f1d - Gecko fb7149d9b320d939d716011f865ec34661ebc353 - BuildID 20140326061134 - Version 28.1 - ro.build.version.incremental=68 - ro.build.date=Wed Mar 26 06:17:50 CST 2014 * ADB logcat for build 20140326061134. It seems it got a MessageChannel error. for details, please see attachment adblog_0326.log ---------------------------------------------------------------------------- 03-26 18:47:51.032 W/WifiHW ( 81): wifi_command: SIGNAL_POLL 03-26 18:47:51.032 D/wpa_supplicant( 396): nl80211: survey data missing! 03-26 18:47:52.822 I/Gonk ( 81): Setting nice for pid 1028 to 18 03-26 18:47:52.822 I/Gonk ( 81): Changed nice for pid 1028 from 0 to 18. 03-26 18:47:53.162 I/GeckoDump( 864): [32mLOG: cronsync-main: wake locks acquired: [object MozWakeLock] for account IDs: 0[0m 03-26 18:47:53.592 I/Gecko ( 864): [32mWLOG: Email knows that it is: online and previously was: online[0m 03-26 18:47:53.602 I/Gecko ( 864): [32mWLOG: deferring getConfig call until ready[0m 03-26 18:47:53.602 I/Gecko ( 864): [32mWLOG: cronsync: received an alarm via a message handler 03-26 18:47:53.602 I/Gecko ( 864): [0m 03-26 18:47:53.622 I/Gecko ( 864): [32mWLOG: main thread reports DB ready[0m 03-26 18:47:53.622 I/Gecko ( 864): [32mWLOG: issuing getConfig call to main thread[0m 03-26 18:47:53.902 I/Gonk ( 81): Setting nice for pid 864 to 18 03-26 18:47:53.902 I/Gonk ( 81): Changed nice for pid 864 from 7 to 18. 03-26 18:47:54.002 I/Gecko ( 81): 03-26 18:47:54.002 I/Gecko ( 81): ###!!! [Parent][MessageChannel] Error: Channel error: cannot send/recv 03-26 18:47:54.002 I/Gecko ( 81): 03-26 18:47:54.012 I/Gecko ( 81): [Parent 81] WARNING: waitpid failed pid:864 errno:10: file /var/lib/jenkins/jobs/B2G.v1.3.0.Tarako.v1.3t/workspace/gecko/ipc/chromium/src/base/process_util_posix.cc, line 254 03-26 18:47:54.702 I/Gecko ( 1028): ###################################### forms.js loaded 03-26 18:47:54.732 I/Gecko ( 1028): ############################### browserElementPanning.js loaded 03-26 18:47:54.752 I/Gecko ( 1028): ######################## BrowserElementChildPreload.js loaded 03-26 18:47:56.012 I/Gecko ( 81): [Parent 81] WARNING: waitpid failed pid:864 errno:10: file /var/lib/jenkins/jobs/B2G.v1.3.0.Tarako.v1.3t/workspace/gecko/ipc/chromium/src/base/process_util_posix.cc, line 254 03-26 18:47:56.012 I/Gecko ( 81): [Parent 81] WARNING: Failed to deliver SIGKILL to 864!(3).: file /var/lib/jenkins/jobs/B2G.v1.3.0.Tarako.v1.3t/workspace/gecko/ipc/chromium/src/chrome/common/process_watcher_posix_sigchld.cc, line 118 03-26 18:47:56.032 W/WifiHW ( 81): wifi_command: SIGNAL_POLL * Logcat for build 20140324121117 on which this feature works is also attached as: attachment adb log_0324.log. From the log you can see notifications are received successfully.

BTW， I also tested on build 20140325060053 and can also reproduce this (using the same device/network/steps). But actually, this build has the same gaia/gecko/gonk revision with build 20140324121117. It's weird that I can reproduce on 20140325060053 but not 20140324121117.

Andrew, do you mind taking another look at this? thanks

We happenned to get the notification once on today's build. And then later we can consistently reproduced this bug again. It seems to be a random bug with very high reproduce rate(9/10). It may caused by some memory leak or memory pressure which we could not get a clue now. So I think it would be better to keep this on track for future builds. The build today: Gaia d8ff994bd96c37ba9a93c343932a5441a78a0eec Gecko 6db37b3f76b4fe2aa6f8fb5ae9e036ed99344772 BuildID 20140327060053

Yes, I'm still working this by cleaning up our JS marionette tests so I can just run a tarako (or other device) in constant automation mode while also automatically monitoring key stuff like processes, etc. and then automatically pull the state out of the guts of the relevant system app stuff / gecko backend stuff.

Turns out I was right originally - this does fall under our 49 smoketest list, so re-adding the smoketest keyword.

I tried about 8 times on build 20140328060053, the notification for email can be displayed. Let's keep this bug open, and test for several builds. ----------------------------------------------- Gaia ecbd79aab76e119a7987092b59cbafc97f7ba72f Gecko f23735074dc673457426afa5d87a67f934a18a9b BuildID 20140328060053 Version 28.1

Can we get on the same page on the STR that is used to reproduce this? We're jumping all over the place here saying this & isn't reproducing on certain days, which is confusing people on the bug.

Gaia ecbd79aab76e119a7987092b59cbafc97f7ba72f Gecko f23735074dc673457426afa5d87a67f934a18a9b BuildID 20140328060053 Version 28.1 ro.build.version.incremental=70 ro.build.date=Fri Mar 28 06:17:40 CST 2014 I'm testing this on today's build and it seems to be working fine; I just had two different notations come in on two different phones according to the original STR. I'll remove the smoketest blocking flag, but with one caveat - my display timeout settings are never. What are your display timeout settings?

So I AM seeing a different behavior depending on whether I'm using a data connection or wifi. When connecting over Wifi, I am not getting the notification. I'll try to repro again and attach a logcat.

Note that under wifi, if that is the only data connection available, the phone turns off wifi after a time when the screen goes off, if not connected to power, so email cannot successfully connect in that situation. This is a known issue, tracked in bug 907028. So, to summarize, in the cases where wifi is the only data connection available, and the phone turns off wifi, the periodic sync in email will not work.

Aaaand, I completely take that back. I AM seeing this issue repro about 5/7 times regardless of the connection type. So this bug is still valid, IMO.

So to sum up, the mails are coming in, regardless of the connection type. The problem is that we're not seeing the notifications.

As a new-sprint update on the e-mail engineering side, the plan continues to be that of comment 37. Get the integration tests working, run them semi-manually against the Tarako, hopefully the problem becomes super obvious. I'm explicitly marking the dependency to this end. If I don't have significant progress by the end of the week (juggling some other blockers too) we'll revisit and look at asking for help from systems front-end. (The theory is that right now we can have a net saving of effort by letting our integration tests do the heavy lifting.)

Running smoketest on todays Tarako build (2014/04/04) and this issue is no longer occurring. Email notifications are appearing properly. v1.3T Environmental Variables: Device: Tarako v1.3T MOZ BuildID: 20140404004001 Gaia: acd18bbd94ebfa534e252a24a75a0617e4b5d5ae Gecko: 91a1b54da4a6 Version: 28.1 Firmware Version: sp8810

[Environment] * Buri Gaia 553da99ab09b6b894d9f95bb06b16b6e1ddbf0a1 Gecko https://hg.mozilla.org/mozilla-central/rev/5b6e82e7bbbf BuildID 20140414160205 Version 31.0a1 ro.build.version.incremental=eng.archermind.20131114.105818 ro.build.date=Thu Nov 14 10:58:33 CST 2013 * Tarako Gaia 23488b1a45221c17e6a32fdd4c9d0fdbdcf2d021 Gecko https://hg.mozilla.org/releases/mozilla-b2g28_v1_3t/rev/72055108f470 BuildID 20140414164002 Version 28.1 ro.build.version.incremental=eng.cltbld.20140414.200743 ro.build.date=Mon Apr 14 20:07:51 EDT 2014 [Reault] All PASS