Closed Bug 1069863 Opened 10 years ago Closed 10 years ago

[Flame]Date and Time won't keep modification after reboot

Categories

(Firefox OS Graveyard :: Vendcom, defect)

Product:
Firefox OS Graveyard
Component:
Vendcom
Platform:
ARM
Gonk (Firefox OS)
Type:
defect
Priority:
Not set
Severity:
normal

Tracking

(Not tracked)

Status:
RESOLVED DUPLICATE of bug 1061797

People

(Reporter: mlien, Unassigned)

References

Details

Attachments

(2 files)

logcat.log
3.54 KB, text/x-log
Details
timelog.log
6.79 KB, text/x-log
Details
Attached file logcat.log — 
[Device & Build]
  Flame JB and KK build: v123, v16x, and v180
---------------------------------------------
STR:
  1. Launch Settings -> Date & Time
  2. Change the Date/Time
  3. Reboot Flame
  4. Verify Date & Time

Actual Result:
  Date & Time won't keep modification after reboot

Reproduce Rate:
  10%
Depends on: 1048154
I have this issue in 2.0 and 2.1 with base image 123. It happens every time I reboot or power off my Flame.
Dear Mozilia:
D/QC-time-services(  237): Lib:time_genoff_operation: pargs->base = 2
D/QC-time-services(  237): Lib:time_genoff_operation: pargs->operation = 0
D/QC-time-services(  237): Lib:time_genoff_operation: pargs->ts_val = 18446744073685311568
D/QC-time-services(  237): Lib:time_genoff_operation: Send to server  passed!!
E/QC-time-services(  323): Daemon: Time-services: Waiting to acceptconnection

Frome the log ,it seems that pargs->ts_val = 18446744073685311568 64int overflow 。This is caused by
time-server.js.
I have fixed this in soul3.5 ff by adding dump mesg between Calculating  new time time and setting new time.But I do not know why because I am goot at C not javascipt.

diff --git a/b2g_time/timeservice.js b/b2g_time/timeservice.js
index 4e074ff..bafe6e9 100644
--- a/b2g_time/timeservice.js
+++ b/b2g_time/timeservice.js
@@ -72,12 +72,14 @@ timeservice.prototype = {
         return;
       }
 
+      dump('timeservice.js deltaMs=' + deltaMs);
       // Calculate new time
       var currentTime = ctypes.cast(time_set.ts_val,
                                     ctypes.int64_t.ptr).contents;
       var currentTimeJSInt = parseInt(currentTime.toString(), 10) +
                                       deltaMs;
 
+      dump('timeservice.js Settime=' + currentTimeJSInt);
       // Set system time
       time_set.time_bases_type = ctypes.int(ATS_USER);
       time_set.ts_val = ctypes.cast(
The timeerver.js is provided by Qualcomm.You can find it in /system/b2g/distribution/bundles/b2g_time/timeservice.js.

Best Regards  Shiqian Zhou
System Engineer T2Mobile Limited
Direct Phone : +86 021 31362685 Ext: 62685 
Mobile: +86 13917863617
Room 203. Building W2. No.1000. Chenhui Road,Zhangjiang High-tech Park,Shanghai 201203,China
As this is fixed in soul 3.5 we expect same for the coming 2.0 build, pls help on it, tks.
Flags: needinfo?(youlong.jiang)
(In reply to Wesly Huang from comment #5)
> As this is fixed in soul 3.5 we expect same for the coming 2.0 build, pls
> help on it, tks.

hi wesly -

our point is all gaia/gecko bug fixed in Moz develop branch, which is based on the reason that developer get base image and maybe would re-flash gaia/gecko part, so these issues would also exist in system.
Flags: needinfo?(youlong.jiang)
[Blocking Requested - why for this release]:
Please ignore comment 9. Although I do wonder whether this should be marked as a blocker...
verify with Flame KK base image v184, still has this problem
I've just run into yet another issue caused by this: I use Google Authenticator for 2FA on a number of important services and always obtained my access code using the Authenticator app. Not so with the Flame and its broken system clock: since Google Authenticator codes are generated using a time-based function the results are totally useless on the Flame.
(In reply to Mike Lien[:mlien] from comment #11)
> verify with Flame KK base image v184, still has this problem

hi Mike -

we've take patch from soul3.5 into v184, but issue still exist. now the main problem is we can't reproduce this bug on our local side. could you pls show the reproduce step in detail.

tks.
I change the date fast forward or back to 1970/01/01
Sometimes this issue still happen but reproduce rate is pretty low (10%)
(In reply to Mike Lien[:mlien] from comment #14)
> I change the date fast forward or back to 1970/01/01
> Sometimes this issue still happen but reproduce rate is pretty low (10%)

Rebooting the phone is usually more than enough to reproduce it, but that's because there's a problem with the system RTC. Here's a snippet from the dmesg output of my Flame:

<6>[    3.154143] using rtc device, qpnp_rtc, for alarms
<6>[    3.162988] qcom,qpnp-rtc qpnp-rtc-eed12400: rtc core: registered qpnp_rtc as rtc0
<6>[    4.726685] qcom,qpnp-rtc qpnp-rtc-eed12400: setting system clock to 1970-01-10 00:22:41 UTC (778961)
<6>[   13.358998] alarm_set_rtc: Failed to set RTC, time will be lost on reboot
<6>[   23.366702] alarm_set_rtc: Failed to set RTC, time will be lost on reboot
Blocks: 1052245
HI  Gabriele:

   The  rtc register is read only with the time powering on。Qualcomm rtc driver has no alarm_set_rtc callback .If you force seting rtc register ,the phone will crash into 9006.So the message “alarm_set_rtc: Failed to set RTC, time will be lost on reboot” is right.
   You will ask how time is keeping. At present /data/time/ats_1 keep the time last power off . When reboot,
the time_service daemon will add rtc register time with /data/time/ats_1.Then the system time is ok.
HI  Gabriele:
 Can you offer a logcat with grep “QC-time-services” at the latest system img
HI  Gabriele:
 Can you offer a logcat with grep “QC-time-services” at the latest system img
Hi Mike:

Would you help get some more log and attach, as vendor put many people to repro. but still not get the issue now?

In the mean time vendor is highlight to their QA team to perform more pressure on the test.

Thank you in advance.
Flags: needinfo?(mlien)
Attached file timelog.log — 
after I set to 1970/01/01, the log show "write into file 1271303075 time 06:44:35 04/15/2010"
Flags: needinfo?(mlien)
Hi Mike:
 D/QC-time-services(  298): Daemon:genoff_send_modem: Sending data to MODEM !
 D/QC-time-services(  298): Daemon: Base = 2, Value being sent to MODEM = 18446743757775864858
 
 This is a Qualcomm bug. genoff_args.ts_val is a void pointer.  "*(uint64_t *)genoff_args.ts_val = ptime_genoff->generic_offset"  is wrong beause no memory alloced .You can check it in next version.

diff --git a/time_daemon_qmi.c b/time_daemon_qmi.c
index 3ef2158..4491e38 100644
--- a/time_daemon_qmi.c
+++ b/time_daemon_qmi.c
@@ -772,7 +772,7 @@ static void genoff_handler(void *recv_arg)
                                        modem_qmi_initialized) {
                                TIME_LOGE("Daemon:Update to modem bit set\n");
                                /* Send only offset to modem instead of full-time */
-                               *(uint64_t *)genoff_args.ts_val = ptime_genoff->generic_offset;
+                               genoff_args.ts_val = (uint64_t *)&ptime_genoff->generic_offset;
                                if ((rc = genoff_send_modem(&genoff_args)) < 0)
                                        TIME_LOGE("Daemon:Unable to send data to MODEM\n");
                        }
Hi Shiqian:

Could you patch this, or get QCT's support to fix it?
Flags: needinfo?(shiqian.zhou)
Hi Wesly:
    Qualcomm modem time will be updated when time setting.But modem time is start with 1980/01/01 .App time is start with 1970/01/01/. So seting 1970/1/01 will caulse this bug.You must disable setting time before 1980/01/01
Flags: needinfo?(shiqian.zhou)
Hi Wesly:
    Qualcomm modem time will be updated when time setting.But modem time is start with 1980/01/01 .App time is start with 1970/01/01/. So seting 1970/1/01 will caulse this bug.You must disable setting time before 1980/01/01
(In reply to Wesly Huang from comment #19)
> Hi Mike:
> 
> Would you help get some more log and attach, as vendor put many people to
> repro. but still not get the issue now?
> 
> In the mean time vendor is highlight to their QA team to perform more
> pressure on the test.
> 
> Thank you in advance.

hi all -

the status until now is our val team also can't reproduce this issue. and per our analysis of code, we found two suspicious points,

1. there is a NULL pointer problem in time daemon component of qcom code base
2. as shiqian mentioned before, if set time before 1980/01/01, maybe will cause time sync issue from AP to modem

for NO.1, we'll release a tmp image for you to verify, and about NO.2 pls try to test setting time after key point and observe.

tks.
Per discussion with Mike the reproduce rate seems quite low now unless we set it to 1970/01/01(still not 100% repro. per my test, and ok even when I set it to some dates before 1980/1/1, like 1979/12/31, 1976/12/31, and 1970/12/31), which is rare use case from my view. So I propose lower priority of this issue and not block the coming Flame KK image that we are waiting for some time.
FWIW, I just tried on my Flame:
* v184 base, latest mozilla-central nightly
* I have a SIM with SIM security (a PIN code)
* no configured Wi-Fi network

After a reboot, the time is off.

Other fun facts:
* the time after the reboot was always the same (today, 2:12pm) (tried twice)
* then I went to the Settings > Date&Time panel, and the time zone automatically changed to America/New York (which is likely the default from FTU?) and the date/time warped to yesterday, 8:12pm.
* yesterday, 8:11pm is the timestamp for the /system/b2g/b2g binary

This means that contrary to what comment 26 says, the reproduce rate is still 100%, even in a normal situation (SIM with SIM security, no Wi-Fi, is IMO a normal situation).

Yes, if the SIM is not PIN-protected, or if we connect to a Wi-Fi network, then we can work around the situation. However, these are just other normal cases just as frequent.


I don't think this should block the upcoming KK image because, after all, the issue existed in the JB image too. But we need to fix this, this is painful.
Thanks Julien's sharing!

1. I noticed you not only used v184 base but also with latest nightly (I use v184 full image only) so maybe that's one possible clue.
2. Just to be sure, before you restart device, device time is never set manually, nor automatically (via mobile network, even no WIFI)? In my test I reset phone w/o SIM, skip all FTU steps so neither set phone time by hand nor WIFI/network.
Flags: needinfo?(felash)
Yep I didn't set anything in FTU when I tested ! Can be a clue !
Flags: needinfo?(felash)
Thanks Jan's  help and Julien's feedback.

My guess is, since you skip all FTU so device actually use the default time setting, so after power cycle it still sometime around default time, so "feel" like it got reset?

The only thing I'm not sure is, if the time was automatically set by mobile network even you used a PIN-locked SIM? If the device time was set by it then got reset after power cycle, then the severity is bigger then I thought in my comment#26.

My another suspect point is latest nightly is used in your test so maybe another factor?

Anyway I agree with you that we should keep following it though not a blocker for coming SW.
(In reply to Wesly Huang from comment #31)
> Thanks Jan's  help and Julien's feedback.
> 
> My guess is, since you skip all FTU so device actually use the default time
> setting, so after power cycle it still sometime around default time, so
> "feel" like it got reset?
> 
> The only thing I'm not sure is, if the time was automatically set by mobile
> network even you used a PIN-locked SIM?

yes, I got a correct time from the network :) then I reboot and I see what I described earlier.

> If the device time was set by it
> then got reset after power cycle, then the severity is bigger then I thought
> in my comment#26.
> 
> My another suspect point is latest nightly is used in your test so maybe
> another factor?

I'll try with a JB-based v2.0 build later and report :)
I think I am seeing something similar as well on my Flame which I flashed about a week ago. If I try creating a timestamp using Date.now() in apps/system/js/bootstrap.js at the end of window load, the timestamp is off, and it appears to be pretty close to when I last flashed the device, a week ago.

So I tried doing this as an experiment:

adb shell echo '$EPOCHREALTIME' && adb reboot && adb wait-for-device && adb shell echo '$EPOCHREALTIME'

which output:

1413490249.115725
7561142.180834

Another issue is that if you look at all the timestamps in window.performance.timing in the System app, they never change to reflect the recent re-start of the System app from reboot, they are always around the same time as the last time I flashed the device:

{
  "navigationStart": 1412885981391,
  "unloadEventStart": 0,
  "unloadEventEnd": 0,
  "redirectStart": 1412885981391,
  "redirectEnd": 1412885981391,
  "fetchStart": 1412885981391,
  "domainLookupStart": 1412885981391,
  "domainLookupEnd": 1412885981391,
  "connectStart": 1412885981391,
  "connectEnd": 1412885981391,
  "requestStart": 1412885981391,
  "responseStart": 1412885981391,
  "responseEnd": 1412885981391,
  "domLoading": 1412885981413,
  "domInteractive": 1412885982183,
  "domContentLoadedEventStart": 1412885983873,
  "domContentLoadedEventEnd": 1412885983873,
  "domComplete": 1412885983996,
  "loadEventStart": 1412885983996,
  "loadEventEnd": 1412885984369
}

Running any of these through Date:

navigationStart, new Date(1412885981391) = Thu Oct 09 2014 15:19:41 GMT-0500 (CDT)
$EPOCHREALTIME before reboot, new Date(1413490249.115725 * 1000) = Thu Oct 16 2014 15:10:49 GMT-0500 (CDT)
$EPOCHREALTIME right after reboot, new Date(7561142.180834 * 1000) = Sun Mar 29 1970 06:19:02 GMT-0600 (CDT)
Blocks: 1070615
Status: NEW → RESOLVED
Closed: 10 years ago
Resolution: --- → DUPLICATE
I can reproduce the bug using v188 base image and 2.2 with today's OTA update.
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: