timesync.service

Just tried to install nvidia drivers 375.39 on Ubuntu 17.04. Those drivers are advertised as ‘Proprietary, tested’. The system is brand new. Before installing the proprietary drivers I was running the nouveau drivers. Average time to boot (from grub to lightDM) : about 5 sec (system on SSD). After installing Nvidia drivers 375.39, average time to boot : about 45 sec.

systemd-analyze blame tells me timesync.service is to blame (like 32 sec or so). I must say I don’t see the relation between timesync and nvidia but why not…

Is there something to do to fix it?

Thx

Eric

P.S. Also tested 340.102 : nightmare. The system doesn’t even boot.

What is the output of ‘systemctl status timesync.service’?

Do you perhaps mean systemd-timesyncd.service?
If so, what is the output of ‘journalctl -b -u systemd-timesyncd.service’ and the content of
“/etc/systemd/timesyncd.conf”?

Thanks for your quick answer,

The output of journalctl -b -u systemd-timesyncd.service:

-- Logs begin at Sat 2017-04-22 21:16:44 CEST, end at Sat 2017-04-22 21:20:59 CEST. --
avril 22 21:16:45 unbox systemd[1]: Starting Network Time Synchronization...
avril 22 21:17:19 unbox systemd[1]: Started Network Time Synchronization.
avril 22 21:17:49 unbox systemd-timesyncd[830]: Synchronized to time server [2001:67c:1560:8003::c7]:123 (ntp.ubuntu.com).

The content of /etc/systemd/timesyncd.conf:

[Time]
#NTP=
#FallbackNTP=ntp.ubuntu.com

Notice the timestamps. It took 64 seconds to synchronize.
That is why there is a delay.
Try a different time server.
I use time1.google.com (despite systemd’s documentation suggesting not to do so) and it takes 6 seconds only.

Actually try one of the ubuntu ntp.org names https://help.ubuntu.com/lts/serverguide/NTP.html#timeservers-conf

Just uncomment #NTP= and change it to NTP=0.ubuntu.pool.ntp.org for example.

Yes, obviously there’s a delay here (which didn’t exist when I was running the Nouveau driver) and that is what’s puzzling me.

So I tried time1.google.com,0.ubuntu.pool.ntp.org and a couple servers from here : http://www.pool.ntp.org/fr/zone/fr : no change at all. The duration is as far as I can tell exactly the same.

The output of systemd-analyze blame (unchanged):

34.282s systemd-timesyncd.service
          1.166s fwupd.service
           534ms systemd-resolved.service
           371ms dev-sda5.device
           339ms networking.service
           114ms upower.service
            67ms alsa-restore.service
            60ms ModemManager.service
            58ms accounts-daemon.service
            51ms plymouth-start.service
            47ms keyboard-setup.service
            42ms grub-common.service
            39ms systemd-udev-trigger.service
            37ms NetworkManager.service
            37ms irqbalance.service
            37ms gpu-manager.service
            34ms apparmor.service
            34ms systemd-fsck@dev-disk-by\x2duuid-66FC\x2dF1F3.service
            29ms lightdm.service
            29ms apport.service
            29ms speech-dispatcher.service
            28ms plymouth-quit-wait.service
            28ms udisks2.service
            27ms systemd-udevd.service
            26ms repowerd.service
            25ms systemd-journald.service
            24ms pppd-dns.service
            23ms thermald.service
            22ms systemd-logind.service
            22ms rsyslog.service
            20ms polkit.service
            20ms snapd.autoimport.service
            16ms systemd-tmpfiles-setup-dev.service
            16ms user@1000.service
            14ms systemd-modules-load.service
            11ms plymouth-read-write.service
             9ms ureadahead-stop.service
             9ms systemd-backlight@backlight:acpi_video0.service
             8ms dev-sda6.swap
             7ms colord.service
             6ms systemd-tmpfiles-setup.service
             6ms avahi-daemon.service
             6ms sys-kernel-debug.mount
             5ms dev-hugepages.mount
             5ms dev-mqueue.mount
             4ms kmod-static-nodes.service
             4ms systemd-sysctl.service
             4ms ufw.service
             4ms systemd-remount-fs.service
             3ms systemd-update-utmp-runlevel.service
             3ms systemd-journal-flush.service
             3ms systemd-random-seed.service
             2ms resolvconf.service
             2ms boot-efi.mount
             2ms systemd-update-utmp.service
             2ms dns-clean.service
             1ms rtkit-daemon.service
             1ms console-setup.service
             1ms systemd-user-sessions.service
             1ms setvtrgb.service
             1ms sys-fs-fuse-connections.mount
           932us openvpn.service
           927us nvidia-persistenced.service

Try entering an IP address instead. Perhaps the delay is in resolving the hostname of the ntp server.
It is also possible the service is waiting for something else to finish first.

Apart from that, maybe one of the NVIDIA developers can take a look at why NVIDIA driver is delaying networking operations on your system.

Not a DNS problem. I tried an IP address: same thing.

Not sure it’s important but there is some kind of pattern here. After I pick Ubuntu on the GRub, the screen remains blank but it kinda flickers once at 30 sec then another time at 37 sec then at around 41 sec lightDM pops up and it takes another few seconds to display the wallpaper.

Oh and btw, even if it’s not related, tty consoles are messed up. Resolution is wrong. But I’m used to it with nvidia drivers. It’s been years they mess up the consoles…

If you do ‘systemctl restart systemd-timesyncd’ in one terminal and ‘journalctl -b --follow -u systemd-timesyncd’ in another one, is there also a delay in time synchronization? Or is this only at boot?

avril 22 21:16:45 unbox systemd[1]: Starting Network Time Synchronization…
avril 22 21:17:19 unbox systemd[1]: Started Network Time Synchronization.

That’s 34 seconds just for starting the service before it queried for an updated time. This likely means it was waiting for a dependency to start especially if ‘systemctl restart systemd-timesyncd’ doesn’t result in a delay.

What does “systemctl list-dependencies systemd-timesyncd.service” say?

The first flickering may be due to loading the nvidia driver. If that is the case, placing “nvidia nvidia_modeset nvidia_uvm nvidia_drm” in the initramfs image to load the driver early may work around it. You will need to consult your distribution’s documentation for doing so.

Either way, my knowledge is mostly in Linux kernel/systemd. If this is a NVIDIA driver issue, hopefully NVIDIA developers will take a look.

It is only at boot:

avril 23 16:58:08 ubox systemd[1]: Stopping Network Time Synchronization...
avril 23 16:58:08 ubox systemd[1]: Stopped Network Time Synchronization.
avril 23 16:58:08 ubox systemd[1]: Starting Network Time Synchronization...
avril 23 16:58:08 ubox systemd[1]: Started Network Time Synchronization.
avril 23 16:58:08 ubox systemd-timesyncd[4499]: Synchronized to time server 178.33.111.48:123 (178.33.111.48).

No delay here.

Output of systemctl list-dependencies systemd-timesyncd.service:

ebo@ubox:~$ systemctl list-dependencies systemd-timesyncd.service
systemd-timesyncd.service
● ├─-.mount
● ├─system.slice
● └─time-sync.target

Well, anyway thank you for taking time to answer.

Like you said maybe some nvidia dev will read that.

I don’t see any indication that this is really a driver issue. Is it really taking 45 seconds, or is systemd-timesyncd fast-forwarding the clock by 45 seconds because it was running slow?

It might be worth checking your X.Org log to see if something there is taking a lot of time to start.

I don’t see any indication that this is really a driver issue. Is it really taking 45 seconds, or is systemd-timesyncd fast-forwarding the clock by 45 seconds because it was running slow?

Right now I don’t see how to make the difference.

Xorg.0.log : https://pastebin.com/AcBRVDyK

A stopwatch might help. If you boot without the ‘quiet’ option, I think you can start the stopwatch as soon as you see the first messages from the kernel.

It looks like your X server starts at 36.645 seconds and the driver is done initializing by 37.133, right after it prints this message:

[    37.133] (II) Indirect GLX disabled.

Removed the quiet option and used a stopwatch. Same time. I see no error whatsoever. Everything is OK.
It takes like 5 seconds to get to :

[ OK ] Mounted /boot/efi.

Then it just sits there for 40 sec or so until lightDM pops up.

Ok, now I’m pretty sure it has nothing to do with timesyncd.

Here : http://pasteboard.co/90watI7Ea.png

First terminal on the left shows who’s to blame today (or at least at the previous boot), so today it’s not timesyncd.
Second terminal on the right, systemctl get-default & systemctl status graphical.target ouput
Third terminal at the bottom : systemctl list-dependencies graphical.target output.

Something’s going on here…