How do I start a service after 'ntpd: time set'?

This forum is for topics specific to the Raspberry Pi and Arch Linux ARM

How do I start a service after 'ntpd: time set'?

Postby welp » Tue Oct 28, 2014 4:37 pm

Alright, I've enabled systemd-networkd.service and systemd-networkd-wait-online.service

Added After=network-online.target in the .service itself under [Unit], however the service still starts way before the 'ntpd: time set' event, almost two minutes earlier. I need it to start after time has been properly set:

$this->bbcode_second_pass_code('', 'Jan 01 02:01:40 pi ntpd[129]: Listen normally on 2 ppp0 10.144.155.20:123
Jan 01 02:01:40 pi ntpd[129]: new interface(s) found: waking up resolver
Jan 01 02:01:40 pi ntpd[129]: 1 Jan 02:01:40 ntpd[129]: Listen normally on 2 ppp0 10.144.155.20:123
Jan 01 02:01:40 pi ntpd[129]: 1 Jan 02:01:40 ntpd[129]: new interface(s) found: waking up resolver
Oct 28 16:56:17 pi ntpd[129]: ntpd: time set +1414508064.070065 s')
welp
 
Posts: 14
Joined: Tue Apr 15, 2014 10:26 am

Re: How do I start a service after 'ntpd: time set'?

Postby sdjf » Sun Nov 02, 2014 2:19 am

You could try a udev rule that did not take action until after the time has been set. Not sure how you would do that, however. I have never used ntpd.
sdjf
 
Posts: 178
Joined: Wed May 08, 2013 1:55 pm

Re: How do I start a service after 'ntpd: time set'?

Postby welp » Sun Nov 09, 2014 1:38 pm

Thanks, but I don't know how to set that either.

I experimented further, however I still cannot quite figure it out. It occurred to me that having:
$this->bbcode_second_pass_code('', '[Install]
WantedBy=multi-user.target')
might be the reason why the service starts too early and I tried different scenarios:
a) replacing it with
$this->bbcode_second_pass_code('', '[Install]
WantedBy=network-online.target')
and also adding After=network-online.target in the [Unit] section: in this case the service simply won't start during boot.

b) Not having [Install] section at all instead I added "Requires" to the [Unit] section as follows:
$this->bbcode_second_pass_code('', 'Requires=network-online.target
After=network-online.target')
And when I manually started the service I could see in the journal:
$this->bbcode_second_pass_code('', 'Nov 09 13:44:27 pi systemd[1]: Reloading.
Nov 09 13:46:00 pi systemd[1]: Starting Wait for Network to be Configured...')
I waited for it about 10 minutes but nothing happened, it's as if Network is never configured.

From the boot log (further down the post) it appears to me network target is reached too early - right after 'Started Automatic wired network connection using netctl profiles.', maybe I need to disable netctl since I've enabled systemd-networkd?! On the other hand netctl doesn't show active profiles
$this->bbcode_second_pass_code('', '
[root@pi system]# netctl list
eth0')

Or could it be that since network is set by umtskeeper via ppp?!

$this->bbcode_second_pass_quote('', 'J')an 01 02:00:12 pi systemd[1]: Found device SMSC9512/9514 Fast Ethernet Adapter.
Jan 01 02:00:12 pi systemd-logind[129]: New seat seat0.
Jan 01 02:00:12 pi systemd[1]: Started Login Service.
Jan 01 02:00:13 pi systemd[1]: Starting Automatic wired network connection using netctl profiles...
Jan 01 02:00:13 pi systemd[1]: Started Automatic wired network connection using netctl profiles.
Jan 01 02:00:13 pi systemd[1]: Starting Network.
Jan 01 02:00:13 pi systemd[1]: Reached target Network.
Jan 01 02:00:13 pi systemd[1]: Starting OpenSSH Daemon...
Jan 01 02:00:13 pi systemd[1]: Started OpenSSH Daemon.
Jan 01 02:00:13 pi systemd[1]: Starting One-Shot Network Time Service...
Jan 01 02:00:13 pi kernel: smsc95xx 1-1.1:1.0 eth0: hardware isn't capable of remote wakeup
Jan 01 02:00:13 pi systemd[1]: Starting Getty on tty1...
Jan 01 02:00:13 pi ifplugd[160]: ifplugd 0.28 initializing.
Jan 01 02:00:13 pi ifplugd[160]: Using interface eth0/B8:27:EB:97:29:D9 with driver <smsc95xx> (version: 22-Aug-2005)
Jan 01 02:00:13 pi ifplugd[160]: Using detection mode: SIOCETHTOOL
Jan 01 02:00:13 pi ifplugd[160]: Initialization complete, link beat not detected.
Jan 01 02:00:13 pi ntpd[162]: ntpd 4.2.7p441@1.2483-o Thu May 8 18:24:13 UTC 2014 (1): Starting
Jan 01 02:00:13 pi ntpd[162]: Command line: /usr/bin/ntpd -q -n -g -u ntp:ntp
Jan 01 02:00:13 pi systemd[1]: Started Getty on tty1.
Jan 01 02:00:13 pi systemd[1]: Starting Serial Getty on ttyAMA0...
Jan 01 02:00:13 pi systemd[1]: Started Serial Getty on ttyAMA0.
Jan 01 02:00:13 pi systemd[1]: Starting Login Prompts.
Jan 01 02:00:13 pi systemd[1]: Reached target Login Prompts.
Jan 01 02:00:13 pi ntpd[162]: 1 Jan 02:00:13 ntpd[162]: ntpd 4.2.7p441@1.2483-o Thu May 8 18:24:13 UTC 2014 (1): Starting
Jan 01 02:00:13 pi ntpd[162]: 1 Jan 02:00:13 ntpd[162]: Command line: /usr/bin/ntpd -q -n -g -u ntp:ntp
Jan 01 02:00:13 pi ntpd[162]: proto: precision = 3.000 usec (-18)
Jan 01 02:00:13 pi ntpd[162]: Listen and drop on 0 v4wildcard 0.0.0.0:123
Jan 01 02:00:13 pi ntpd[162]: Listen normally on 1 lo 127.0.0.1:123
Jan 01 02:00:13 pi ntpd[162]: Listening on routing socket on fd #18 for interface updates
Jan 01 02:00:13 pi ntpd[162]: 1 Jan 02:00:13 ntpd[162]: proto: precision = 3.000 usec (-18)
Jan 01 02:00:13 pi ntpd[162]: 1 Jan 02:00:13 ntpd[162]: Listen and drop on 0 v4wildcard 0.0.0.0:123
Jan 01 02:00:13 pi ntpd[162]: 1 Jan 02:00:13 ntpd[162]: Listen normally on 1 lo 127.0.0.1:123
Jan 01 02:00:13 pi ntpd[162]: 1 Jan 02:00:13 ntpd[162]: Listening on routing socket on fd #18 for interface updates
Jan 01 02:00:13 pi sshd[161]: Server listening on 0.0.0.0 port 22.
Jan 01 02:00:16 pi haveged[132]: haveged: ver: 1.9.1; arch: generic; vend: ; build: (gcc 4.8.2 CTV); collect: 128K
Jan 01 02:00:16 pi haveged[132]: haveged: cpu: (VC); data: 16K (D); inst: 16K (D); idx: 8/40; sz: 15248/74244
Jan 01 02:00:16 pi haveged[132]: haveged: tot tests(BA8): A:1/1 B:1/1 continuous tests(B): last entropy estimate 7.99705
Jan 01 02:00:16 pi haveged[132]: haveged: fills: 0, generated: 0
Jan 01 02:01:01 pi crond[3373]: pam_unix(crond:account): account root has password changed in future
Jan 01 02:01:01 pi crond[3373]: pam_unix(crond:session): session opened for user root by (uid=0)
Jan 01 02:01:01 pi CROND[3375]: (root) CMD (run-parts /etc/cron.hourly)
Jan 01 02:01:01 pi CROND[3373]: pam_unix(crond:session): session closed for user root
Jan 01 02:01:01 pi anacron[3380]: Anacron started on 1970-01-01
Jan 01 02:01:01 pi anacron[3380]: Normal exit (0 jobs run)
Jan 01 02:01:20 pi pppd[4354]: pppd options in effect:
Jan 01 02:01:20 pi pppd[4354]: -detach # (from command line)
Jan 01 02:01:20 pi pppd[4354]: logfd -1 # (from command line)
Jan 01 02:01:20 pi pppd[4354]: maxfail 3 # (from command line)
Jan 01 02:01:20 pi pppd[4354]: ktune # (from command line)
Jan 01 02:01:20 pi pppd[4354]: dump # (from command line)
Jan 01 02:01:20 pi pppd[4354]: noauth # (from command line)
Jan 01 02:01:20 pi pppd[4354]: name alarmpi # (from command line)
Jan 01 02:01:20 pi pppd[4354]: user globul # (from command line)
Jan 01 02:01:20 pi pppd[4354]: password ?????? # (from command line)
Jan 01 02:01:20 pi pppd[4354]: usehostname # (from command line)
Jan 01 02:01:20 pi pppd[4354]: /dev/ttyUSB0 # (from command line)
Jan 01 02:01:20 pi pppd[4354]: 460800 # (from command line)
Jan 01 02:01:20 pi pppd[4354]: lock # (from command line)
Jan 01 02:01:20 pi pppd[4354]: connect /bin/chat -v -f /tmp/pppd.tmp.2035 # (from command line)
Jan 01 02:01:20 pi pppd[4354]: crtscts # (from command line)
Jan 01 02:01:20 pi pppd[4354]: modem # (from command line)
Jan 01 02:01:20 pi pppd[4354]: asyncmap 0 # (from /etc/ppp/options)
Jan 01 02:01:20 pi pppd[4354]: lcp-echo-failure 4 # (from /etc/ppp/options)
Jan 01 02:01:20 pi pppd[4354]: lcp-echo-interval 30 # (from /etc/ppp/options)
Jan 01 02:01:20 pi pppd[4354]: hide-password # (from /etc/ppp/options)
Jan 01 02:01:20 pi pppd[4354]: noipdefault # (from command line)
Jan 01 02:01:20 pi pppd[4354]: defaultroute # (from command line)
Jan 01 02:01:20 pi pppd[4354]: proxyarp # (from /etc/ppp/options)
Jan 01 02:01:20 pi pppd[4354]: usepeerdns # (from command line)
Jan 01 02:01:20 pi pppd[4354]: noipx # (from /etc/ppp/options)
Jan 01 02:01:20 pi pppd[4354]: pppd 2.4.6 started by root, uid 0
Jan 01 02:01:20 pi kernel: PPP generic driver version 2.4.2
Jan 01 02:01:21 pi chat[4382]: abort on (NO CARRIER)
Jan 01 02:01:21 pi chat[4382]: abort on (NO DIALTONE)
Jan 01 02:01:21 pi chat[4382]: abort on (BUSY)
Jan 01 02:01:21 pi chat[4382]: abort on (ERROR)
Jan 01 02:01:21 pi chat[4382]: abort on (NO ANSWER)
Jan 01 02:01:21 pi chat[4382]: send (ATZ^M)
Jan 01 02:01:21 pi chat[4382]: expect (OK)
Jan 01 02:01:21 pi chat[4382]: ATZ^M^M
Jan 01 02:01:21 pi chat[4382]: OK
Jan 01 02:01:21 pi chat[4382]: -- got it
Jan 01 02:01:21 pi chat[4382]: send (ATD*99#^M)
Jan 01 02:01:21 pi pppd[4354]: Serial connection established.
Jan 01 02:01:21 pi pppd[4354]: Using interface ppp0
Jan 01 02:01:21 pi pppd[4354]: Connect: ppp0 <--> /dev/ttyUSB0
Jan 01 02:01:22 pi pppd[4354]: CHAP authentication succeeded
Jan 01 02:01:22 pi pppd[4354]: CHAP authentication succeeded
Jan 01 02:01:22 pi kernel: PPP BSD Compression module registered
Jan 01 02:01:22 pi kernel: PPP Deflate Compression module registered
Jan 01 02:01:24 pi pppd[4354]: Could not determine remote IP address: defaulting to 10.64.64.64
Jan 01 02:01:24 pi systemd-networkd[155]: rtnl: received address for a nonexistent link, ignoring
Jan 01 02:01:24 pi systemd-networkd[155]: rtnl: received address for a nonexistent link, ignoring
Jan 01 02:01:24 pi systemd-networkd[155]: rtnl: received address for a nonexistent link, ignoring
Jan 01 02:01:24 pi pppd[4354]: Cannot determine ethernet address for proxy ARP
Jan 01 02:01:24 pi pppd[4354]: local IP address 10.130.73.161
Jan 01 02:01:24 pi pppd[4354]: remote IP address 10.64.64.64
Jan 01 02:01:24 pi pppd[4354]: primary DNS address 85.118.197.4
Jan 01 02:01:24 pi pppd[4354]: secondary DNS address 85.118.197.68
Jan 01 02:01:25 pi ntpd[162]: Listen normally on 2 ppp0 10.130.73.161:123
Jan 01 02:01:25 pi ntpd[162]: new interface(s) found: waking up resolver
Jan 01 02:01:25 pi ntpd[162]: 1 Jan 02:01:25 ntpd[162]: Listen normally on 2 ppp0 10.130.73.161:123
Jan 01 02:01:25 pi ntpd[162]: 1 Jan 02:01:25 ntpd[162]: new interface(s) found: waking up resolver
Nov 09 14:30:30 pi ntpd[162]: ntpd: time set +1415536137.017495 s
Nov 09 14:30:30 pi systemd[1]: Time has been changed
Nov 09 14:30:30 pi ntpd[162]: 9 Nov 14:30:30 ntpd[162]: ntpd: time set +1415536137.017495 s
Nov 09 14:30:30 pi ntpd[162]: ntpd: time set +1415536137.017495s
welp
 
Posts: 14
Joined: Tue Apr 15, 2014 10:26 am

Re: How do I start a service after 'ntpd: time set'?

Postby welp » Sun Nov 09, 2014 2:12 pm

I also disabled netctl-ifplugd@eth0.service but that didn't help either.

$this->bbcode_second_pass_code('', '[root@pi system]# systemctl disable netctl-ifplugd@eth0.service
rm '/etc/systemd/system/multi-user.target.wants/netctl-ifplugd@eth0.service'')
welp
 
Posts: 14
Joined: Tue Apr 15, 2014 10:26 am

Re: How do I start a service after 'ntpd: time set'?

Postby krabat » Sun Nov 09, 2014 3:04 pm

network-online.target is addressing the fact that starting a service configuring the network doesn't mean the network is available yet.
The corresponding binary systemd-network-wait-online tries to detect the latter. Thus services that need the network available to start successfully can be placed after network-online.target.
All this only works with connections handled by systemd-networkd.

Your problem is somewhat different, though. You seem to be using the regular ntpd service. But much as starting a service configuring the network doesn't provide a means to detect when the connection is available starting ntpd doesn't provide a means to know when the system time is set as ntpd takes some time to do so (detect servers, test their reliability etc.).

There are two solutions:
Either use systemd-timesyncd. It's using SNTP to synchronize the system time each time a network link changes, saves the system time in a file on shutdown hence assuring some kind of monotonical progress and, what is most, activates time-sync.target. Using systemd-timesyncd and placing your service behind time-sync.target should do.
Also, you could define your own service unit setting the time at once by running ntpd -gq or something like that. You could make this unit depend on time-sync.target much like systemd-timesyncd.service itself (note the different parameters in its [Unit] stanza) and place the unit of the service needing synced time after time-sync.target much as with systemd-timesyncd itself.
krabat
 
Posts: 57
Joined: Wed Jun 04, 2014 8:03 pm

Re: How do I start a service after 'ntpd: time set'?

Postby welp » Tue Dec 02, 2014 8:33 am

Thanks for the hints!

After some hiccups and headaches I manged to do it.

In essence I put this in the [Unit] section of the .service file:
$this->bbcode_second_pass_code('', 'Requires=time-sync.target
After=time-sync.target')

In order for that to work I had to make systemd-timesyncd and systemd-networkd work first too.
welp
 
Posts: 14
Joined: Tue Apr 15, 2014 10:26 am


Return to Raspberry Pi

Who is online

Users browsing this forum: No registered users and 37 guests