Clock out of sync on resume from suspend

[Jean-Baptiste Lallement]

When the device is resumed by pressing the power button and the device is not connected over USB the clock is out of sync

You need another system to compare the time to verify this bug report, and make sure both clocks are in sync.

TEST CASE
1. Unplug the device from its USB cable
2. Press the power button to switch to suspend mode or wait until it goes to suspend
3. Wait 2 or more minutes
4. Press the power button again to resume the device
5. Compare the time on the greeter and indicator with the time on the other system

EXPECTED RESULT
Clocks are in sync

ACTUAL RESULT
Time on the device is behind by several minutes.

The use case are people who use their device as a watch. You usually resume it, check the time, suspend it.

ProblemType: Bug
DistroRelease: Ubuntu 14.10
Package: unity8 7.88+14.10.20140606-0ubuntu1
Uname: Linux 3.4.0-5-mako armv7l
ApportVersion: 2.14.3-0ubuntu1
Architecture: armhf
Date: Tue Jun 10 19:11:42 2014
InstallationDate: Installed on 2014-06-10 (0 days ago)
InstallationMedia: Ubuntu Utopic Unicorn (development branch) - armhf (20140610)
SourcePackage: unity8
UpgradeStatus: No upgrade log present (probably fresh install)

[Jean-Baptiste Lallement (jibel)]

Works fine with the non-split greeter. Closing

[Jean-Baptiste Lallement (jibel)]

Reopening, it is still the case with build #91. The time difference can be several minutes.

[Michał Sawicz (saviq)]

TBH I don't understand how :|

It's using the same source for the clock that the panel has...

[Michał Sawicz (saviq)]

Michael, do you have an idea how to explain this still? Can anyone else reproduce?

[Michael Terry (mterry)]

I know that I was seeing some time-zone oddities when I tied the clock to the phone_greeter menu model we got from the indicator (instead of just phone). This was when the greeter was split out.

But after unsplitting, I haven't noticed any problems. But this description makes it sound like the indicator and the greeter are both in agreement, they are just both wrong.

In which case, this should likely be an indicator-datetime bug because it is giving unity8 the wrong data.

[Michał Sawicz (saviq)]

Hmm or we're not compositing / pushing the last frame on screen? Which might be the case, since we've been suspended we weren't rendering, and maybe it takes a while to catch up? We'd need to inspect what the indicator data is at the point of power on. Or the labels' text property, for that matter.

[Renato Araujo Oliveira Filho (renatofilho)]

happens with me on image: r117

[Selene ToyKeeper (toykeeper)]

Confirmed on Utopic 161.

I unplugged the mako from USB, turned its screen off, and let it sit for 10 minutes next to a computer with a known-good clock. When I turned it back on, its clock updated within one second from T-2m to T-1m -- that is, it was just over a minute behind, after being idle for only 10 minutes. About 20 seconds later the clock updated again to the current time. I assume that was when NTP kicked in.

So, it seems that the clock gets behind at a rate of roughly 6 seconds per minute. That's pretty bad, as far as clocks go. And it presumably doesn't update until it can get online.

[Selene ToyKeeper (toykeeper)]

Note, given the behavior I saw, it's also possible that it was only behind by about 40 seconds, and the second screen update wasn't related to NTP or data from cell towers. The first (immediate) update could have been the usual split second before the screen redraws on resume. In any case, that's still losing 4 seconds per minute, which it shouldn't be doing. I think the usual tolerance is more like 0.5 seconds per hour, at most.

[Selene ToyKeeper (toykeeper)]

Wow. So, when I tried again 13 minutes later, the clock was already 5 minutes behind. Apparently the speed isn't consistent.

It figured out the correct time again about 30 seconds later, but it seems the onboard clock might be way off without help from the network (cell or wifi).

[Selene ToyKeeper (toykeeper)]

Or maybe it's not the onboard clock, but just the display widget. If I open the actual clock app, I can see two different times -- one in the indicator, one in the app. So apparently the welcome time widget and indicator widget just get out of sync with the system clock.

[Michał Sawicz (saviq)]

I can't reproduce this now, I see consistently synced clocks between wizard, panel and clock app.

[Jean-Baptiste Lallement (jibel)]

It happens to me all the time, your device have to be unplugged from usb. Sometimes the time different is not a couple of minutes but like half an hour.

[Michał Sawicz (saviq)]

Right, mine are constantly connected over USB so just don't suspend...

The issue seems to be that the indicator does not send the time updates when device is suspended, *or* unity8 does not react to the updates it does send.

If the latter, we just need to resync on wakeup, if the former, the indicator would have to do something smarter here.

[Michał Sawicz (saviq)]

I'm saying this is critical as in normal phone usage your phone will be 8 hours behind for up to a minute in the morning...

[Michael Zanetti (mzanetti)]

Being away for a while and not having the phone plugged in all the time this happened to me too all the time. But the panel seems to lag behind too. It's in sync, but outdated. The time only updates when the next minute update is triggered which in worst case leaves you with an outdated clock for 59 seconds.

[Jean-Baptiste Lallement (jibel)]

The proof! :)

The watch (time is set by GPS) indicates 23:17 and the phone indicates 23:16 in the indicator and the greeter

[Jean-Baptiste Lallement (jibel)]

And on this photo, 1 minute later...

The time on the watch is 23:18 and on the phone it's 23:18 on the clock and 23:16 in the indicator (and the greeter before I unlocked it)

The time on these 2 devices was in sync at the beginning of the test.

[Jean-Baptiste Lallement (jibel)]

The difference can be several hours. This morning, at 07:38 the time on the phone was 04:09

[Jean-Baptiste Lallement (jibel)]

On this photo mako shows 9:10 but it's 9:13 (both devices were in sync at the beginning of the test)

[Jean-Baptiste Lallement (jibel)]

9:14 on the watch, 9:14 on the clock of the phone and 9:10 in the indicator (and the greeter before I unlocked it)

[Oliver Grawert (ogra)]

i must say that you are very lucky only getting teh clock being off by a few minutes ...
*every* morning when i go to the landing meeting which starts at 10:30 for me the notification for that particular meeting goes off at 10:40 or 10:45 ... when the screen turns on with the notification both, the lock screen and indicator still show a time around 10:20 ..

this is reproducable every morning for me ...

[Dave Morley (davmor2)]

Also see bug 1357307 which was introduced at the same time

[Charles Kerr (charlesk)]

Where does the greeter get its time from?

Indicator-datetime ultimately gets its time from a call to g_date_time_new_now_local() + the system timezone, and (unless there's a bug) is updated at least once per minute. But several people here (jibel, ogra, more) are reporting the clock being /far/ out of sync.

Could one of you please attach the output of this run from phablet-shell next time you see the datetime clock dramatically out of sync?

$ dbus-send --print-reply --dest=com.canonical.indicator.datetime \
  "/com/canonical/indicator/datetime/phone" "org.gtk.Menus.Start" array:uint32:0,1,2,3,4

[Charles Kerr (charlesk)]

Okay I've talked to mterry and he's confirmed that the greeter gets its time and date from indicator-datetime. So this is good news of a sort, it means the bug is probably only in datetime, rather than some larger strangeness :)

[Michał Sawicz (saviq)]

Here's the requested output:

http://paste.ubuntu.com/8057589/

What's weird... my indicator says 8:06 and the greeter 8:22 now... Both over an hour out of sync.

After a greeter cycle the greeter came around to correct 9:45, panel still off...

[Charles Kerr (charlesk)]

I'm seeing this bug in image 191 and found something interesting: the datetime service is still pushing the right information to the bus, but for some reason the panel and greeter aren't seeing it.

You can ask the datetime service what time it thinks it is by calling this from phablet shell:

$ dbus-send --print-reply --dest=com.canonical.indicator.datetime \
 "/com/canonical/indicator/datetime" "org.gtk.Actions.Describe" string:"phone-header"

Which will give you something like:

> method return sender=:1.33 -> dest=:1.78 reply_serial=2
> struct {
> boolean true
> signature ""
> array [
> variant array [
> dict entry(
> string "title"
> variant string "Upcoming"
> )
> dict entry(
> string "visible"
> variant boolean true
> )
> dict entry(
> string "label"
> variant string " 8:30 PM"
> )
> dict entry(
> string "accessible-desc"
> variant string " 8:30 PM"
> )
> ]
> ]

The "label" here is updated at least every minute and should be updated by the panel, but for some reason isn't.

The two screenshots above show this visually: the phone's panel and greeter say it's 8:17 PM, but the system clock and indicatator-datetime service say that it's 8:29 (screenshot 1) and 8:30 (screenshot 2). I took the second to confirm that the service was still updating its label each minute.

[Charles Kerr (charlesk)]

In the ~/.cache/upstart/unity8 log for the phone tested above, there are several error warnings about a null property in Panel/Indicators/DefaultIndicatorWidget.qml:76 and

(process:2451): GLib-GIO-CRITICAL **: g_dbus_connection_signal_subscribe: assertion 'object_path == NULL || g_variant_is_object_path (object_path)' failed

(process:2451): GLib-GIO-CRITICAL **: g_dbus_connection_call_internal: assertion 'object_path != NULL && g_variant_is_object_path (object_path)' failed

[Charles Kerr (charlesk)]

Lastly, it looks like indicator-datetime is continuing to correctly publish the updated time when the minute changes.

You can reproduce this test on an affected system by running this from phablet-shell:

$ dbus-monitor "path=/com/canonical/indicator/datetime"

Expected results: when the minute changes, indicator-datetime should publish new header information, formatted similar to comment:30 but with the correct time in its header label.

[Launchpad Janitor (janitor)]

Status changed to 'Confirmed' because the bug affects multiple users.

[Ted Gould (ted)]

Just got this on my phone from letting it run over the weekend. Verified the value passed over DBus is correct from the indicator:

$ gdbus call --session --dest com.canonical.indicator.datetime --object-path /com/canonical/indicator/datetime --method org.gtk.Actions.Describe phone-header
((true, signature '', [<{'title': <'Upcoming'>, 'visible': <true>, 'label': <' 9:41 AM'>, 'accessible-desc': <' 9:41 AM'>}>]),)

Where the panel is saying that it's "6:13 PM"

[Charles Kerr (charlesk)]

Marking this as Invalid for indicator-datetime as -- similar to bug#1357311 -- the service is correctly pushing out menuitems and the header label to the bus.

[Launchpad Janitor (janitor)]

This bug was fixed in the package unity8 - 8.00+14.10.20140820-0ubuntu1

---------------
unity8 (8.00+14.10.20140820-0ubuntu1) utopic; urgency=low

  [ CI bot ]
  * Resync trunk

  [ Nick Dedekind ]
  * Fixed CachedUnityMenuModel destruction unhinging indicators. (LP:
    #1328646)

  [ Mirco Müller ]
  * Temporarily disable any opacity-animation for notifications to
    unblock the train due to LP: 1354406. (LP: #1354406)
 -- Ubuntu daily release <email address hidden> Wed, 20 Aug 2014 20:03:55 +0000

[cm-t 🦄🏂🌈🎵 (cm-t)]

Hi,

Just to be sure: does the patch is now landing is an image (I am using mako as daily purpose, with channel devel on utopic image 203).

If it is suposing to be landed, then I can see this behavior's bug is still here: always (and I mean always, everytime I need to check the time) must open the clock apps after resuming the phone to be sure I read the real time, not a cache'ed time that is not refreshed on the lockscreen/time indicator.(if I get lost and it is not the same bug, then tell me, I'll open a new one).

Libement

[Michał Sawicz (saviq)]

@cm-t, there is a new bug about this: bug #1365530