1021698 - Last Update date in settings says that is was on January 8, 1970

Status: RESOLVED DUPLICATE of bug 1061797

(Firefox OS Graveyard :: Gaia::Settings, defect)

Description

[Pascal Chevrel:pascalc]

Attachment: Screenshot of the Settings panel

I have a Flame. It was updated once over the air. 
Version ID: 20140604040204
Platform 32.0a1
Update channel: nightly
Git sha1: 1d4f6f73

The date in settings is incorrect, it says that the last update was in 1970 (see screenshot).

Comment 1

[Arthur Chen [:arthurcc][inactive after 6/30]]

Dave, any idea on this issue?

Comment 2

[Dave Hylands [:dhylands]]

This looks like a legitimate issue.

I just flashed my flame and set the date/time using the FTU app. I then did:

> adb shell reboot

and it came back with the right year, but the wrong time.

I then went into Settings and corrected things. This time when I rebooted, the date and time were both incorrect, and the year showed 1970.

I don't have a SIM, and didn't connect to Wifi to ensure that it couldn't sync the time from there.

So there is definitely something weird going on.

Comment 3

[Marcia Knous [:marcia]]

I am still seeing this using today's 2.0 build, updating from the 16th build to the 17th.

Comment 4

[Jason Smith [:jsmith]]

Switching to qawanted to first to do branch checks here before going after a window, as I want to make sure we know what releases this is happening on & if it's a base image issue.

Comment 5

[Duane Dixon [:ddixon]]

Branch Check

Issue DOES occur in Flame 2.1

Device: Flame Master
BuildID: 20140820040203
Gaia: df39c463259d348396ef7f143c2c780eeb8f02d8
Gecko: ffdd1a398105
Version: 34.0a1 (Master) 
Firmware Version: v123
User Agent: Mozilla/5.0 (Mobile; rv:34.0) Gecko/34.0 Firefox/34.0
------------------------------------------------------------------------------------------
------------------------------------------------------------------------------------------
Issue DOES NOT occur in Flame 2.0, 1.4  (1.3 not applicable).  

Device: Flame 2.0
BuildID: 20140820000201
Gaia: 88db39a0826086024631049d83ae6aa397f0918d
Gecko: 2092ac87eceb
Version: 32.0 (2.0) 
Firmware Version: v123
User Agent: Mozilla/5.0 (Mobile; rv:32.0) Gecko/32.0 Firefox/32.0
------------------------------------------------------------------------------------------
Device: Flame 1.4
BuildID: 20140819000201
Gaia: 3e53eb07bf1c2cafeba53812ebe91835089723d3
Gecko: c45814bfd93b
Version: 30.0 (1.4) 
Firmware Version: v123
User Agent: Mozilla/5.0 (Mobile; rv:30.0) Gecko/30.0 Firefox/30.0
------------------------------------------------------------------------------------------

Unable to check Flame 1.3 (system will not OTA from 1.3 upwards).

Comment 6

[Jason Smith [:jsmith]]

Josh - Can you provide a blocking triage analysis here?

Comment 7

[Joshua Mitchell (Inactive)]

[Blocking Requested - why for this release]: Very bad UX - incorrect date - will probably cause users to question if they have successfully updated or not.

Comment 8

[Duane Dixon [:ddixon]]

*Nightly* Central Regression Window

Unable to provide a deeper regression window in Mozilla Inbound branch.  The Mozilla Inbound branch does not receive OTA updates.  Therefore, the tester cannot install a new update to check the "Last Updated" date. 

Last Working

Device: Flame Master
BuildID: 20140801040326
Gaia: 04ea7e1a4034a50d4a7a4f5b95a04a2ed8313908
Gecko: 104254bd1fc8
Version: 34.0a1 (Master) 
Firmware Version: v123
User Agent: Mozilla/5.0 (Mobile; rv:34.0) Gecko/34.0 Firefox/34.0

First Broken 

Device: Flame Master
Build ID: 20140802040202
Gaia: 5fd14b8bc428f87f9b5cf9cc49f9a4f362a970fb
Gecko: a4f779bd7cc2
Version: 34.0a1 (Master)
Firmware Version: v123
User Agent: Mozilla/5.0 (Mobile; rv:34.0) Gecko/34.0 Firefox/34.0

Last Working Gaia and First Broken Gecko
Issue DOES occur here. 
Gaia: 04ea7e1a4034a50d4a7a4f5b95a04a2ed8313908
Gecko: a4f779bd7cc2

Last Working Gecko and First Broken Gaia
Issue DOES NOT occur here. 
Gaia: 5fd14b8bc428f87f9b5cf9cc49f9a4f362a970fb
Gecko: 104254bd1fc8

Gecko Pushlog: 
http://hg.mozilla.org/mozilla-central/pushloghtml?fromchange=104254bd1fc8&tochange=a4f779bd7cc2

Comment 9

[Joshua Mitchell (Inactive)]

this push-log is a bit out of my scope to analyze - I'll venture one unconfident guess that it might be bug 1044737 - Vicamo - can you take a look?

Comment 10

[Vicamo Yang [:vicamo][:vyang]]

(In reply to Joshua Mitchell [:Joshua_M] from comment #9)
> this push-log is a bit out of my scope to analyze - I'll venture one
> unconfident guess that it might be bug 1044737 - Vicamo - can you take a
> look?

Not even close ;P

Bug 1044737 is about network stats, not OTA. Gabriele seems to be a more appropriate person for this from a glance over `git log --no-merges apps/wappush/`.

Comment 11

[Gabriele Svelto [:gsvelto]]

This shouldn't have anything to do with WAP Push but since I'm already investigating OTA issues on Flame (bug 1051083) I might as well have a look. Leaving the NI flag for now.

Comment 12

[howie [:howie]]

Triage: blocking

Comment 13

[Tim Guan-tin Chien [:timdream] (please needinfo)]

:gsvelto, any luck here? Also, could you move this bug to a better component? Thanks!

Comment 14

[Aus Lacroix [:aus]]

I'm pretty sure this is a duplicate of bug 1048154. Jason, wdyt?

Comment 15

[Aus Lacroix [:aus]]

A Flame with KK should *not* exhibit this problem. Please confirm.

Comment 16

[Jason Smith [:jsmith]]

(In reply to Ghislain Aus Lacroix [:aus] from comment #14)
> I'm pretty sure this is a duplicate of bug 1048154. Jason, wdyt?

If this was reproducing on 1.4, then I would think that would be true. However, this apparently is working on 2.0, broken on 2.1, and has a range above, so I think something else broke this.

Comment 17

[[:fabrice] Fabrice Desré]

Dave, can you post the logcat of b2g startup when you reproduced the issue?

Comment 18

[Gabriele Svelto [:gsvelto]]

Quick update, I didn't have time to look into this yet but I'll do tomorrow since I'm running new tests in bug 1051083.

Comment 19

[Duane Dixon [:ddixon]]

(In reply to Ghislain Aus Lacroix [:aus] from comment #15)
> A Flame with KK should *not* exhibit this problem. Please confirm.

I am currently blocked from completing your request by: Bug 1063237 - flame-kk needs to query for updates differently from flame jb

Please feel free to reactivate 'qawanted' tag after Bug 1063237 has been fixed.

Comment 21

[Gabriele Svelto [:gsvelto]]

I think I've figured out what's happening here and I think it's part of the wonky system clock issues we've been seen on the Flame. The time we use to populate that field is stored in the deviceinfo.last_updated preference and that's done here:

http://hg.mozilla.org/mozilla-central/file/2db5b64f6d49/b2g/components/UpdatePrompt.js#l199

Now I've noticed that for some reason when starting up the Flame often defaults to a time close to the epoch. You can usually notice it in the FTU when restarting a freshly flashed Flame.

I haven't verified when we invoke UpdateCheckListener.showUpdateInstalled() but if it's done during startup then there's good chance it will pick up a wrong date.

Comment 22

[Dave Hylands [:dhylands]]

Attachment: 01 - Log from pulling battery just after a fresh flash with FTU enabled

I did ./flash.sh and as soon as it was finished flashing, I pulled the battery.

I waited for about 20 seconds, reinserted the battery, and booted into the FTU app, where I changed the time to be correct (16:29).

Comment 23

[Dave Hylands [:dhylands]]

Attachment: 02 - After reboot - then corrected time in settings app.

Comment 24

[Dave Hylands [:dhylands]]

Attachment: 03 - rebooted (after correcting time in settings app)

Comment 25

[Dave Hylands [:dhylands]]

Here are 3 logs, along with some commentary. I copied and pasted complete lines from the logcat and included the last line at a particular time, and then the line after the time jump.

From 01 logcat

I pulled the battery, so the initial year is 1970 - expected

> 12-31 16:00:12.179   278   278 I Vold    : Vold 2.1 (the revenge - dh) firing up
...
> 12-31 16:00:22.809   294   516 D AudioResourceManager:  setParameter fm_volume=1.0000000000:
> 09-11 16:20:07.130   305   305 I Gecko   : -*- WifiWorker component: Determined that scanning is stuck, turning on background scanning!

I'm not sure why the date/time changed here. This is yesterday's date.

> 09-11 16:20:41.080   305   305 I Gecko   : *** UTM:SVC TimerManager:notify - notified @mozilla.org/b2g/webapps-update-timer;1
> 09-12 15:59:30.800   305   401 I VolumeManager: SetUnmountRequested for volume sdcard to 0 CanBeMounted = 1

The 09-12 15:59 corresponds to the build time (i.e. this is the timestamp on system.img)


> 09-12 15:59:44.230   284   709 E BandwidthController: No such iface wlan0 to delete
> 09-12 16:29:20.971   305   305 I GeckoDump: XXX FIXME : Got a mozContentEvent: inputmethod-update-layouts

I entered the correct time in the FTU app (16:29)

> 09-12 16:30:10.971   305   305 I Gecko   : -*- WifiWorker component: Event coming in: WPS-AP-AVAILABLE 
> 09-11 16:21:33.370   305   305 D qdhwcomposer: hwc_blank: Blanking display: 0

I think that this when I did the adb shell reboot command. I'm not sure why the time went backwards here.

-------------------------------------------------------------------------------
From 02 logcat

Bootup from after doing reboot

> 12-31 16:04:03.870   265   265 I Vold    : Vold 2.1 (the revenge - dh) firing up

Looks like we're back at 1970

> 12-31 16:04:10.269   280   280 I Gecko   : -*- WifiWorker component: Do nothing when initial settings for SETTINGS_WIFI_TETHERING_ENABLED flag is false.
> 09-12 15:59:30.050   874   874 I Gecko   : ###################################### forms.js loaded

Changed to the build date/time.

> 09-12 16:00:42.270   280   280 I Gecko   : -*- WifiWorker component: Event coming in: WPS-AP-AVAILABLE 
> 09-12 16:23:04.255   909   909 D wpa_supplicant: wlan0: Starting AP scan for wildcard SSID

I went into settings app and corrected the time.

-------------------------------------------------------------------------------
From 03 logcat

Rebooted again

> 12-31 16:06:18.030   265   265 I Vold    : Vold 2.1 (the revenge - dh) firing up
- back to 1970

> 12-31 16:06:25.499   281   504 D AudioResourceManager:  setParameter fm_volume=1.0000000000:
> 09-12 15:59:30.350   881   881 I Gecko   : ###################################### forms.js loaded

updated to match build time

Comment 26

[Dave Hylands [:dhylands]]

The above logcats were using master (synced/built just prior)
VARIANT=user, flame, v123 base

Comment 29

[howie [:howie]]

Hi Dave, do you mind put assignee as you? thanks.

Comment 30

[:gerard-majax]

I've already observed it several times, and I concurr to what Gabriele said: it's just a consequence of bug 1069863. We should maybe dupe this.

Comment 32

[Dietrich Ayala (:dietrich)]

Reopening. The bug is still unfixed for me, after updating to all new base images, etc.

I've never seen it be correct, even when all other dates/times in the system are correct.

Flame, nightly channel (m-c + gaia master), eng build from pvt server.

Comment 33

[Kai-Chih Hu [:khu]]

Arthur, what is your opinion on this bug? Thanks.