NTP not starting automatically

keithl · November 26, 2017, 8:06pm

I am running build 999.201711072137 and everytime I reboot I have to manually start NTP daemon with sudo systemctl restart ntp

If I run show NTP is says not started, but when I run above command it starts up ans stays running until next reboot.

syncer · November 26, 2017, 9:35pm

Hi,
that is likely bug.

Line2 · November 26, 2017, 10:18pm

I can’t reproduce this on 999.201711232137. NTP is running after boot.

config is:

name-server 127.0.0.1 ntp { server time.domain.intern { prefer } }

carl.byington · November 27, 2017, 1:12am

I cannot reproduce this on 999.201711072137, but it is running in a KVM, not on bare metal.

keithl · November 30, 2017, 1:33am

OK, let me try a newer build. I also have an issue with polices not staying after reboot. I will post on that when I am near computer, but I have a bunch of policy rules that based on IP set DSCP tag, but one rule after reboot reset the IP for that rule back to 0.0.0.0 thus taking all traffic. If I update the rule it works fine u til next reboot.

It is disappointing that I can’t get either the GA or RC2 build to install on my new Intel hardware as I am not a fan of having to run beta nightly builds.i may go back to Hyper-V as I was able to run 1.1.7 fine on it.

bertimus9 · November 30, 2017, 5:08am

I’m having this problem too. I’m running 999.201711232137 on a device I just got, a
Protectli With 6x Gigabit Intel LAN Ports, Intel i3, 4GB RAM, 32GB mSATA.

It must have worked at some point because the time was pretty close to accurate, but as I’ve been configuring it I noticed ntp doesn’t start on boot anymore.

Here is an excerpt from my /var/log/messages. I removed a hundred lines, which I can add back in. I can add or attach my configuration too. The short story is i have eth0 as my wan, eth1-5 are basically bridged together with vlans 1. 20, 30, and 40. EDIT: Note that ntp starts and dies within seconds of coming up.

Nov 29 20:51:54 vyos /opt/vyatta/bin/sudo-users/vyatta-reboot.pl: Reboot now requested by vyos Nov 29 20:52:32 vyos ntpdate[1677]: no servers can be used, exiting Nov 29 20:52:32 vyos kernel: [ 0.000000] Linux version 4.4.95-amd64-vyos (jenkins@jessie-build) (gcc version 4.9.2 (Debian 4.9.2-10) ) #1 SMP Wed Nov 22 09:09:39 EST 2017 Nov 29 20:52:32 vyos kernel: [ 0.000000] Kernel command line: BOOT_IMAGE=/boot/999.201711232137/vmlinuz boot=live quiet vyos-union=/boot/999.201711232137 console=ttyS0,115200n8 console=tty0 Nov 29 20:52:32 vyos kernel: [ 0.267041] ACPI: Executed 31 blocks of module-level executable AML code Nov 29 20:52:32 vyos kernel: [ 0.275796] [Firmware Bug]: ACPI: BIOS _OSI(Linux) query ignored Nov 29 20:52:32 vyos ntpd[1733]: ntpd [email protected] Fri Jul 22 17:30:51 UTC 2016 (1) Nov 29 20:52:32 vyos ntpd[1738]: proto: precision = 0.123 usec Nov 29 20:52:32 vyos zebra[1757]: Zebra 0.99.20.1 starting: vty@0 Nov 29 20:52:32 vyos ripd[1759]: RIPd 0.99.20.1 starting: vty@0 Nov 29 20:52:32 vyos ripngd[1761]: RIPNGd 0.99.20.1 starting: vty@0 Nov 29 20:52:32 vyos ospfd[1763]: OSPFd 0.99.20.1 starting: vty@0 Nov 29 20:52:32 vyos ospf6d[1765]: OSPF6d (Quagga-0.99.20.1 ospf6d-0.9.7r) starts: vty@0 Nov 29 20:52:32 vyos bgpd[1767]: BGPd 0.99.20.1 starting: vty@0, bgp@<all>:179 Nov 29 20:52:34 vyos zebra[1757]: interface br30 index 8 <BROADCAST,MULTICAST> added. Nov 29 20:52:34 vyos zebra[1757]: interface br30 index 8 changed <UP,BROADCAST,RUNNING,MULTICAST>. < ... 35 lines like these, bridges and interfaces added and coming up ...> Nov 29 20:52:38 vyos zebra[1757]: interface eth2.20 index 20 <BROADCAST,MULTICAST> added. Nov 29 20:52:38 vyos zebra[1757]: interface eth2.20 index 20 changed <UP,BROADCAST,MULTICAST>. Nov 29 20:52:39 vyos zebra[1757]: interface eth0 index 2 changed <UP,BROADCAST,RUNNING,MULTICAST>. Nov 29 20:52:40 vyos ntpd[1738]: ntpd exiting on signal 15

carl.byington · December 1, 2017, 7:24pm

Does your vyos config reference the ntp servers by name or by ip address? If you use names for the ntp servers, where do you point “system name-server”, and is that dns server accessible before any wan links come up? NTP may be giving up too early.

bertimus9 · December 1, 2017, 9:19pm

Thanks for the reply. I’m using [size=small][font=Monaco, Consolas, Courier, monospace]0.us.pool.ntp.org [/font][/size]domain names, and the system name server points to google’s DNS servers. Config and log excerpt below.

I have a few vlans bridged over 4 interfaces, and my hardware seems slower than running on a VM on my other machine, so maybe it’s a race condition that is causing just enough of a delay for ntpd to give up. I can sanitize and upload my configuration file (or commands) if you’d like – it’s not short and it doesn’t have any firewall stuff in it yet.

Below are my system config section and my /var/log/messages file with nothing removed between the kernel command line and ntpd dying.

ntpdate fails within the first half second of the kernel loading, long before the network interfaces come up.
ntpd dies within a second of the WAN (eth0) coming up, 19.5 seconds after the kernel loads:

system { // default stuff ... name-server 8.8.8.8 name-server 8.8.4.4 ntp { server 0.us.pool.ntp.org { } server 1.us.pool.ntp.org { } server 2.us.pool.ntp.org { } server 3.us.pool.ntp.org { } } // more default stuff ... }

[code]Dec 1 12:52:43 vyos kernel: [ 0.000000] Kernel command line: BOOT_IMAGE=/boot/999.201711232137/vmlinuz boot=live quiet vyos-union=/boot/999.201711232137 console=ttyS0,115200n8 console=tty03 vyos kernel: [ 0.000000] tsc: Unable to calibrate against PIT
Dec 1 12:52:43 vyos kernel: [ 0.039209] ACPI: 10 ACPI AML tables successfully acquired and loaded
Dec 1 12:52:43 vyos kernel: [ 0.041064] ENERGY_PERF_BIAS: Set to ‘normal’, was ‘performance’
Dec 1 12:52:43 vyos kernel: [ 0.041065] ENERGY_PERF_BIAS: View and update with x86_energy_perf_policy(8)
Dec 1 12:52:43 vyos kernel: [ 0.153563] #2 #3
Dec 1 12:52:43 vyos kernel: [ 0.267157] ACPI: Executed 31 blocks of module-level executable AML code
Dec 1 12:52:43 vyos kernel: [ 0.275912] [Firmware Bug]: ACPI: BIOS _OSI(Linux) query ignored
Dec 1 12:52:43 vyos kernel: [ 0.279087] ACPI: Dynamic OEM Table Load:
Dec 1 12:52:43 vyos kernel: [ 0.279093] ACPI: SSDT 0xFFFF880087A49000 000651 (v02 PmRef Cpu0Ist 00003000 INTL 20160422)
Dec 1 12:52:43 vyos kernel: [ 0.280019] ACPI: Executed 1 blocks of module-level executable AML code
Dec 1 12:52:43 vyos kernel: [ 0.281502] ACPI: Dynamic OEM Table Load:
Dec 1 12:52:43 vyos kernel: [ 0.281507] ACPI: SSDT 0xFFFF880087A58C00 0003FF (v02 PmRef Cpu0Cst 00003001 INTL 20160422)
Dec 1 12:52:43 vyos kernel: [ 0.282400] ACPI: Executed 1 blocks of module-level executable AML code
Dec 1 12:52:43 vyos kernel: [ 0.282867] ACPI: Dynamic OEM Table Load:
Dec 1 12:52:43 vyos kernel: [ 0.282872] ACPI: SSDT 0xFFFF880087A49800 00065C (v02 PmRef ApIst 00003000 INTL 20160422)
Dec 1 12:52:43 vyos kernel: [ 0.284068] ACPI: Executed 1 blocks of module-level executable AML code
Dec 1 12:52:43 vyos kernel: [ 0.284217] ACPI: Dynamic OEM Table Load:
Dec 1 12:52:43 vyos kernel: [ 0.284221] ACPI: SSDT 0xFFFF8800879A3600 00018A (v02 PmRef ApCst 00003000 INTL 20160422)
Dec 1 12:52:43 vyos kernel: [ 0.285124] ACPI: Executed 1 blocks of module-level executable AML code
Dec 1 12:52:43 vyos ntpdate[1676]: no servers can be used, exiting
Dec 1 12:52:43 vyos dbus[1697]: [system] Successfully activated service ‘org.freedesktop.systemd1’
Dec 1 12:52:43 vyos kernel: [ 0.491083] ACPI: Enabled 4 GPEs in block 00 to 7F
Dec 1 12:52:43 vyos kernel: [ 0.491276] SCSI subsystem initialized
Dec 1 12:52:43 vyos kernel: [ 0.521452] amd_nb: Cannot enumerate AMD northbridges
Dec 1 12:52:43 vyos kernel: [ 0.985948] audit: type=2000 audit(1512161553.010:1): initialized
Dec 1 12:52:43 vyos kernel: [ 1.020531] Key type dns_resolver registered
Dec 1 12:52:43 vyos kernel: [ 1.030725] random: systemd-udevd: uninitialized urandom read (16 bytes read, 3 bits of entropy available)
Dec 1 12:52:43 vyos kernel: [ 1.402647] scsi 0:0:0:0: Direct-Access ATA Hoodisk SSD 01.0 PQ: 0 ANSI: 5
Dec 1 12:52:43 vyos kernel: [ 1.402857] sd 0:0:0:0: Attached scsi generic sg0 type 0
Dec 1 12:52:43 vyos kernel: [ 1.402877] sd 0:0:0:0: [sda] 62533296 512-byte logical blocks: (32.0 GB/29.8 GiB)
Dec 1 12:52:43 vyos kernel: [ 1.403101] sd 0:0:0:0: [sda] Write Protect is off
Dec 1 12:52:43 vyos kernel: [ 1.403156] sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn’t support DPO or FUA
Dec 1 12:52:43 vyos kernel: [ 1.404031] sd 0:0:0:0: [sda] Attached SCSI disk
Dec 1 12:52:43 vyos kernel: [ 7.467647] random: systemd: uninitialized urandom read (16 bytes read, 29 bits of entropy available)
Dec 1 12:52:43 vyos kernel: [ 7.634704] random: systemd-sysv-ge: uninitialized urandom read (16 bytes read, 33 bits of entropy available)
Dec 1 12:52:43 vyos kernel: [ 7.767071] random: systemd-sysv-ge: uninitialized urandom read (16 bytes read, 33 bits of entropy available)
Dec 1 12:52:43 vyos kernel: [ 7.778963] random: systemd: uninitialized urandom read (16 bytes read, 33 bits of entropy available)
Dec 1 12:52:43 vyos kernel: [ 7.779082] random: systemd: uninitialized urandom read (16 bytes read, 33 bits of entropy available)
Dec 1 12:52:43 vyos kernel: [ 7.779178] random: systemd: uninitialized urandom read (16 bytes read, 33 bits of entropy available)
Dec 1 12:52:43 vyos kernel: [ 7.782956] random: systemd: uninitialized urandom read (16 bytes read, 33 bits of entropy available)
Dec 1 12:52:43 vyos kernel: [ 7.783027] random: systemd: uninitialized urandom read (16 bytes read, 33 bits of entropy available)
Dec 1 12:52:43 vyos kernel: [ 7.783055] random: systemd: uninitialized urandom read (16 bytes read, 33 bits of entropy available)
Dec 1 12:52:43 vyos ntpd[1732]: ntpd [email protected] Fri Jul 22 17:30:51 UTC 2016 (1)
Dec 1 12:52:44 vyos ntpd[1737]: proto: precision = 0.109 usec
Dec 1 12:52:44 vyos zebra[1756]: Zebra 0.99.20.1 starting: vty@0
Dec 1 12:52:44 vyos ripd[1758]: RIPd 0.99.20.1 starting: vty@0
Dec 1 12:52:44 vyos ripngd[1760]: RIPNGd 0.99.20.1 starting: vty@0
Dec 1 12:52:44 vyos ospfd[1762]: OSPFd 0.99.20.1 starting: vty@0
Dec 1 12:52:44 vyos ospf6d[1764]: OSPF6d (Quagga-0.99.20.1 ospf6d-0.9.7r) starts: vty@0
Dec 1 12:52:44 vyos bgpd[1766]: BGPd 0.99.20.1 starting: vty@0, bgp@:179
Dec 1 12:52:45 vyos zebra[1756]: interface br30 index 8 <BROADCAST,MULTICAST> added.
Dec 1 12:52:45 vyos zebra[1756]: interface br30 index 8 changed <UP,BROADCAST,RUNNING,MULTICAST>.
Dec 1 12:52:45 vyos zebra[1756]: interface br30 index 8 changed <UP,BROADCAST,MULTICAST>.
Dec 1 12:52:45 vyos zebra[1756]: interface br1 index 9 <BROADCAST,MULTICAST> added.
Dec 1 12:52:45 vyos zebra[1756]: interface br1 index 9 changed <UP,BROADCAST,RUNNING,MULTICAST>.
Dec 1 12:52:46 vyos zebra[1756]: interface br20 index 10 <BROADCAST,MULTICAST> added.
Dec 1 12:52:46 vyos zebra[1756]: interface br20 index 10 changed <UP,BROADCAST,RUNNING,MULTICAST>.
Dec 1 12:52:46 vyos zebra[1756]: interface br40 index 11 <BROADCAST,MULTICAST> added.
Dec 1 12:52:46 vyos zebra[1756]: interface br40 index 11 changed <UP,BROADCAST,RUNNING,MULTICAST>.
Dec 1 12:52:46 vyos zebra[1756]: interface eth2 index 4 changed <UP,BROADCAST,MULTICAST>.
Dec 1 12:52:46 vyos zebra[1756]: interface br1 index 9 changed <UP,BROADCAST,RUNNING,MULTICAST>.
Dec 1 12:52:46 vyos zebra[1756]: interface br1 index 9 changed <UP,BROADCAST,MULTICAST>.
Dec 1 12:52:46 vyos zebra[1756]: interface br20 index 10 changed <UP,BROADCAST,MULTICAST>.
Dec 1 12:52:46 vyos zebra[1756]: interface br40 index 11 changed <UP,BROADCAST,MULTICAST>.
Dec 1 12:52:47 vyos zebra[1756]: interface eth4 index 6 changed <UP,BROADCAST,MULTICAST>.
Dec 1 12:52:47 vyos zebra[1756]: interface eth1 index 3 changed <UP,BROADCAST,MULTICAST>.
Dec 1 12:52:48 vyos zebra[1756]: interface eth3 index 5 changed <UP,BROADCAST,MULTICAST>.
Dec 1 12:52:49 vyos zebra[1756]: interface eth0 index 2 changed <UP,BROADCAST,MULTICAST>.
Dec 1 12:52:49 vyos zebra[1756]: interface eth0 index 2 changed <BROADCAST,MULTICAST>.
Dec 1 12:52:49 vyos zebra[1756]: interface eth2 index 4 changed <UP,BROADCAST,RUNNING,MULTICAST>.
Dec 1 12:52:49 vyos zebra[1756]: interface eth0 index 2 changed <UP,BROADCAST,MULTICAST>.
Dec 1 12:52:50 vyos zebra[1756]: interface eth5 index 7 changed <UP,BROADCAST,MULTICAST>.
Dec 1 12:52:50 vyos zebra[1756]: interface eth3.40 index 12 <BROADCAST,MULTICAST> added.
Dec 1 12:52:50 vyos zebra[1756]: interface eth3.40 index 12 changed <UP,BROADCAST,MULTICAST>.
Dec 1 12:52:50 vyos zebra[1756]: interface eth3.30 index 13 <BROADCAST,MULTICAST> added.
Dec 1 12:52:50 vyos zebra[1756]: interface eth3.30 index 13 changed <UP,BROADCAST,MULTICAST>.
Dec 1 12:52:50 vyos zebra[1756]: interface eth3.20 index 14 <BROADCAST,MULTICAST> added.
Dec 1 12:52:50 vyos zebra[1756]: interface eth3.20 index 14 changed <UP,BROADCAST,MULTICAST>.
Dec 1 12:52:50 vyos zebra[1756]: interface eth2.40 index 15 <BROADCAST,MULTICAST> added.
Dec 1 12:52:50 vyos zebra[1756]: interface eth2.40 index 15 changed <UP,BROADCAST,RUNNING,MULTICAST>.
Dec 1 12:52:50 vyos zebra[1756]: interface eth4.20 index 16 <BROADCAST,MULTICAST> added.
Dec 1 12:52:50 vyos zebra[1756]: interface eth4.20 index 16 changed <UP,BROADCAST,MULTICAST>.
Dec 1 12:52:50 vyos zebra[1756]: interface eth2.30 index 17 <BROADCAST,MULTICAST> added.
Dec 1 12:52:50 vyos zebra[1756]: interface eth2.30 index 17 changed <UP,BROADCAST,RUNNING,MULTICAST>.
Dec 1 12:52:50 vyos zebra[1756]: interface eth4.40 index 18 <BROADCAST,MULTICAST> added.
Dec 1 12:52:50 vyos zebra[1756]: interface eth4.40 index 18 changed <UP,BROADCAST,MULTICAST>.
Dec 1 12:52:50 vyos zebra[1756]: interface eth4.30 index 19 <BROADCAST,MULTICAST> added.
Dec 1 12:52:50 vyos zebra[1756]: interface eth4.30 index 19 changed <UP,BROADCAST,MULTICAST>.
Dec 1 12:52:50 vyos zebra[1756]: interface eth2.20 index 20 <BROADCAST,MULTICAST> added.
Dec 1 12:52:50 vyos zebra[1756]: interface eth2.20 index 20 changed <UP,BROADCAST,RUNNING,MULTICAST>.
Dec 1 12:52:52 vyos zebra[1756]: interface eth1 index 3 changed <UP,BROADCAST,RUNNING,MULTICAST>.
Dec 1 12:52:52 vyos ntpd[1737]: ntpd exiting on signal 15
Dec 1 12:52:53 vyos dhcpd: WARNING: Host declarations are global. They are not limited to the scope you declared them in.
Dec 1 12:52:54 vyos commit: Successful change to active configuration by user root on
Dec 1 12:52:54 vyos kernel: [ 21.449796] random: nonblocking pool is initialized
Dec 1 12:53:19 vyos zebra[1756]: interface br1 index 9 changed <UP,BROADCAST,RUNNING,MULTICAST>.
Dec 1 12:53:21 vyos zebra[1756]: interface br40 index 11 changed <UP,BROADCAST,RUNNING,MULTICAST>.
Dec 1 12:53:21 vyos zebra[1756]: interface br20 index 10 changed <UP,BROADCAST,RUNNING,MULTICAST>.
Dec 1 12:53:21 vyos zebra[1756]: interface br30 index 8 changed <UP,BROADCAST,RUNNING,MULTICAST>.
<>

[/code]

keithl · December 13, 2017, 1:59am

One would hope if NTP can’t reach a server in the list it would not stop the daemon, but just retry again in some period of time.