Arch Linux

kokoko3k

Member

Registered: 2008-11-14

Posts: 2,394

ntp server startup slow

-EDIT-
At first i thought it did not work, but after some minutes (3 to 5) it starts serving, still i wonder if there is away to speed-up the process!
-/EDIT-

I'd like to serve time from my arch box.
So far, i succeded through openntp, but for some reason, i'm unable to do the same with extra/ntp.
I've no firewall and the tests i'm doing are between a windows box and arch machine on the same network.

/etc/ntp.conf:

# cat /etc/ntp.conf |grep -v ^#
server 0.arch.pool.ntp.org
server 1.arch.pool.ntp.org
server 2.arch.pool.ntp.org
server 3.arch.pool.ntp.org
        server 127.127.1.1
        fudge  127.127.1.1 stratum 12
restrict -4 127.0.0.1
restrict ::1
restrict default nomodify nopeer

As i start it in debug mode, i get:

root@Gozer# /usr/bin/ntpd -g -u ntp:ntp -d debug
 4 Aug 10:10:39 ntpd[22380]: ntpd 4.2.8p10@1.3728-o Mon Apr 24 18:57:17 UTC 2017 (1): Starting
 4 Aug 10:10:39 ntpd[22380]: Command line: /usr/bin/ntpd -g -u ntp:ntp -d debug
 4 Aug 10:10:39 ntpd[22380]: proto: precision = 0.040 usec (-24)
Finished Parsing!!
restrict: op 1 addr 127.0.0.1 mask 255.255.255.255 mflags 00000000 flags 00000000
restrict: op 1 addr ::1 mask ffff:ffff:ffff:ffff:ffff:ffff:ffff:ffff mflags 00000000 flags 00000000
restrict: op 1 addr 0.0.0.0 mask 0.0.0.0 mflags 00000000 flags 00000090
restrict: op 1 addr :: mask :: mflags 00000000 flags 00000090
move_fd: estimated max descriptors: 1024, initial socket boundary: 16
 4 Aug 10:10:39 ntpd[22380]: Listen and drop on 0 v6wildcard [::]:123
 4 Aug 10:10:39 ntpd[22380]: Listen and drop on 1 v4wildcard 0.0.0.0:123
 4 Aug 10:10:39 ntpd[22380]: Listen normally on 2 lo 127.0.0.1:123
restrict: op 1 addr 127.0.0.1 mask 255.255.255.255 mflags 00003000 flags 00000001
 4 Aug 10:10:39 ntpd[22380]: Listen normally on 3 eth0 my.ip.address.masked:123
restrict: op 1 addr my.ip.address.masked mask 255.255.255.255 mflags 00003000 flags 00000001
 4 Aug 10:10:39 ntpd[22380]: Listen normally on 4 eth1 192.168.117.20:123
restrict: op 1 addr 192.168.117.20 mask 255.255.255.255 mflags 00003000 flags 00000001
 4 Aug 10:10:39 ntpd[22380]: Listen normally on 5 tun1 192.168.8.1:123
restrict: op 1 addr 192.168.8.1 mask 255.255.255.255 mflags 00003000 flags 00000001
 4 Aug 10:10:39 ntpd[22380]: Listen normally on 6 tincvpn 192.168.11.1:123
restrict: op 1 addr 192.168.11.1 mask 255.255.255.255 mflags 00003000 flags 00000001
 4 Aug 10:10:39 ntpd[22380]: Listen normally on 7 tun0 192.168.40.2:123
restrict: op 1 addr 192.168.40.2 mask 255.255.255.255 mflags 00003000 flags 00000001
 4 Aug 10:10:39 ntpd[22380]: Listening on routing socket on fd #24 for interface updates
key_expire: at 0 associd 20612
peer_clear: at 0 next 1 associd 20612 refid INIT
event at 0 LOCAL(1) 8011 81 mobilize assoc 20612
newpeer: 127.0.0.1->127.127.1.1 mode 3 vers 4 poll 6 6 flags 0x9 0x1 ttl 0 key 00000000
event at 0 0.0.0.0 c01d 0d kern kernel time sync enabled
event at 0 0.0.0.0 c012 02 freq_set kernel 0.000 PPM
event at 0 0.0.0.0 c011 01 freq_not_set
event at 0 0.0.0.0 c016 06 restart
peer_name_resolved(0.arch.pool.ntp.org) rescode 0
key_expire: at 0 associd 20613
peer_clear: at 0 next 2 associd 20613 refid INIT
event at 0 212.45.144.3 8011 81 mobilize assoc 20613
newpeer: my.ip.address.masked->212.45.144.3 mode 3 vers 4 poll 6 10 flags 0x1 0x1 ttl 0 key 00000000
peer_name_resolved(1.arch.pool.ntp.org) rescode 0
key_expire: at 0 associd 20614
peer_clear: at 0 next 0 associd 20614 refid INIT
event at 0 193.204.114.233 8011 81 mobilize assoc 20614
newpeer: my.ip.address.masked->193.204.114.233 mode 3 vers 4 poll 6 10 flags 0x1 0x1 ttl 0 key 00000000
peer_name_resolved(2.arch.pool.ntp.org) rescode 0
key_expire: at 0 associd 20615
peer_clear: at 0 next 5 associd 20615 refid INIT
event at 0 31.14.131.188 8011 81 mobilize assoc 20615
newpeer: my.ip.address.masked->31.14.131.188 mode 3 vers 4 poll 6 10 flags 0x1 0x1 ttl 0 key 00000000
peer_name_resolved(3.arch.pool.ntp.org) rescode 0
key_expire: at 0 associd 20616
peer_clear: at 0 next 0 associd 20616 refid INIT
event at 0 188.213.165.209 8011 81 mobilize assoc 20616
newpeer: my.ip.address.masked->188.213.165.209 mode 3 vers 4 poll 6 10 flags 0x1 0x1 ttl 0 key 00000000
sleep until 10:10:41 scheduled at 10:10:39 (>= 01:00:00)
peer_xmit: at 1 my.ip.address.masked->188.213.165.209 mode 3 len 48 xmt 0xdd2eaa80.3f846bec
peer_xmit: at 1 my.ip.address.masked->193.204.114.233 mode 3 len 48 xmt 0xdd2eaa80.3f85cb20
refclock_transmit: at 1 127.127.1.1
refclock_receive: at 1 127.127.1.1
event at 1 LOCAL(1) 8014 84 reachable
refclock_sample: n 1 offset 0.000000 disp 0.010000 jitter 0.000000
clock_filter: n 1 off 0.000000 del 0.000000 dsp 7.937500 jit 0.000000
auth_agekeys: at 1 keys 0 expired 0
event at 1 193.204.114.233 8014 84 reachable
clock_filter: n 1 off -0.024450 del 0.014856 dsp 7.937500 jit 0.000000
peer_xmit: at 2 my.ip.address.masked->212.45.144.3 mode 3 len 48 xmt 0xdd2eaa81.3f84bad9
sleep until 10:10:44 scheduled at 10:10:41 (>= 01:00:00)
peer_xmit: at 5 my.ip.address.masked->31.14.131.188 mode 3 len 48 xmt 0xdd2eaa84.3f847b58
sleep until 10:10:48 scheduled at 10:10:44 (>= 01:00:00)

Then, when windows box tries to sync the time, i've:

fast_xmit: at 117 my.ip.address.masked->windows.ip.address.masked mode 4 len 48

But windows says no servers could be reached.

In the journal there is the following:

ago 04 10:10:39 Gozer ntpd[22380]: Command line: /usr/bin/ntpd -g -u ntp:ntp -d debug
ago 04 10:10:39 Gozer ntpd[22380]: proto: precision = 0.040 usec (-24)
ago 04 10:10:39 Gozer ntpd[22380]: Listen and drop on 0 v6wildcard [::]:123
ago 04 10:10:39 Gozer ntpd[22380]: Listen and drop on 1 v4wildcard 0.0.0.0:123
ago 04 10:10:39 Gozer ntpd[22380]: Listen normally on 2 lo 127.0.0.1:123
ago 04 10:10:39 Gozer ntpd[22380]: Listen normally on 3 eth0 my.ip.address.masked:123
ago 04 10:10:39 Gozer ntpd[22380]: Listen normally on 4 eth1 192.168.117.20:123
ago 04 10:10:39 Gozer ntpd[22380]: Listen normally on 5 tun1 192.168.8.1:123
ago 04 10:10:39 Gozer ntpd[22380]: Listen normally on 6 tincvpn 192.168.11.1:123
ago 04 10:10:39 Gozer ntpd[22380]: Listen normally on 7 tun0 192.168.40.2:123
ago 04 10:10:39 Gozer ntpd[22380]: Listening on routing socket on fd #24 for interface updates

...and it is listening correctly:

netstat -an|grep :123

root@Gozer# netstat -an|grep :123
udp        0      0 192.168.40.2:123        0.0.0.0:*                          
udp        0      0 192.168.11.1:123        0.0.0.0:*                          
udp        0      0 192.168.8.1:123         0.0.0.0:*                          
udp        0      0 192.168.117.20:123      0.0.0.0:*                          
udp        0      0 my.ip.address.masked:123     0.0.0.0:*                          
udp        0      0 127.0.0.1:123           0.0.0.0:*                          
udp        0      0 0.0.0.0:123             0.0.0.0:*                          
udp6       0      0 :::123                  :::*       

Any clue about what is going on? I repeat, via openntpd it works.

-EDIT-
It just started working (about five minutes later), but i did not change anything... WHY !?ù

-EDIT-
Maybe this?

Frequency Discipline
The ntpd behavior at startup depends on whether the frequency file, usually ntp.drift, exists. This file contains the latest estimate of clock frequency error. When the ntpd is started and the file does not exist, the ntpd enters a special mode designed to quickly adapt to the particular system clock oscillator time and frequency error. This takes approximately 15 minutes, after which the time and frequency are set to nominal values and the ntpd enters normal mode, where the time and frequency are continuously tracked relative to the server. After one hour the frequency file is created and the current frequency offset written to it. When the ntpd is started and the file does exist, the ntpd frequency is initialized from the file and enters normal mode immediately. After that the current frequency offset is written to the file at hourly intervals.

I'll wait an hour and check if next startup will be faster.

Why do i bother?

Because trying out different configurations that way would take the whole day and not knowing if it is rejecting clients because of a bad configuration or because it just needs more time make things worse...

-EDIT-
I let it run for an hour, then the drift file was created, relaunched the service, but nothing changed, i've still 5 minutes delay.

Last edited by kokoko3k (2017-08-04 09:47:08)

---

Help me to improve ssh-rdp !
Retroarch User? Try my koko-aio shader !

Painless

Member

Registered: 2006-02-06

Posts: 233

Re: ntp server startup slow

There is no way to speed up the process.  Your NTP service must first get it's own time synchronised before it can start serving.  This usually takes 5 to 15 minutes.  This is not a service that is typically switched off and on alot.