NTPD | Time to sync exceeds acceptable levels

MichaIng / DietPi

Lightweight justice for your single-board computer!

https://dietpi.com/

GNU General Public License v2.0

4.89k stars 497 forks source link

NTPD | Time to sync exceeds acceptable levels #1445

Closed midwan closed 6 years ago

midwan commented 6 years ago

Creating a bug report/issue:

Required Information:

DietPi Version | v6.1
SBC Device | RPi Zero (armv6l) (index=1)
Distro | stretch (index=4)
Command | Connection test: http://install.pi-hole.net
Error Handler | G_ERROR_HANDLER

Additional Information (if applicable):

Software title | DietPi-Software
Can this issue be replicated on a fresh installation of DietPi? YES

Expected behaviour:

Selecting to install Pi-hole from the menu, should eventually leave us with Pi-hole installed.

Actual behaviour:

Pi-Hole fails to install, reporting this error:

Steps to reproduce:

Flash latest RPI image to sdcard Boot and enter Optimized Software Select to install Pi-hole Begin installation process

Did you submit a `dietpi-bugreport`?

Extra details:

Using a usb-to-ethernet adapter, so the Pi is connected over ethernet with a static IP.
Manually reaching the mentioned page does not show an invalid Certificate on the browser.
The same setup worked with v1.59, this is a fresh flash just to upgrade to 1.60
The NTP service also failed to resolve for some reason. I had to Override it to proceed.

Additional logs:

Log file contents:
Spider mode enabled. Check if remote file exists.
--2018-01-10 12:39:30--  http://install.pi-hole.net/
Resolving install.pi-hole.net (install.pi-hole.net)... 104.236.99.8, 2604:a880:800:10::4b2:a001
Connecting to install.pi-hole.net (install.pi-hole.net)|104.236.99.8|:80... connected.
HTTP request sent, awaiting response... 301 Moved Permanently
Location: https://install.pi-hole.net/ [following]
Spider mode enabled. Check if remote file exists.
--2018-01-10 12:39:31--  https://install.pi-hole.net/
Connecting to install.pi-hole.net (install.pi-hole.net)|104.236.99.8|:443... connected.
ERROR: The certificate of ‘install.pi-hole.net’ is not trusted.
ERROR: The certificate of ‘install.pi-hole.net’ is not yet activated.
The certificate has not yet been activated

midwan commented 6 years ago

Looking at the above, it seems rather obvious now: Since the NTPD failed to update the time, I'm assuming the Pi has an older time and so the certificate appears to be valid sometime in the future... :)

The question then is, why did the NTPD fail (and still does)?

midwan commented 6 years ago

Manually selecting another NTP server (Europe in my case) seems to work, and I can proceed. Closing this issue (though weird the default didn't work?)

midwan commented 6 years ago

Actually I take that back.. when going back to installing Pi-Hole, the NTPD time sync keeps failing in the same way... :-( I thought it worked.

The Pi time is still incorrect (in the past).

Edit: I can proceed with the installation if I set the correct date/time manually, but the reason for this issue's existence is to find out and resolve the failure of NTPD.. ;-)

Fourdee commented 6 years ago

@midwan

Actually I take that back.. when going back to installing Pi-Hole, the NTPD time sync keeps failing in the same way... :-( I thought it worked. The Pi time is still incorrect (in the past).

Strange, we'll try to replicate. We may need to debug your system and the NTPD process, but, i'll try to verify same results locally 1st.

Fourdee commented 6 years ago

@midwan

The NTP service also failed to resolve for some reason. I had to Override it to proceed.

Did you select retry 1st, before then selecting override? Or override in 1st instance the prompt showed up?

Failing NTP sync depends vastly on the network performance and ntp mirror. It can take longer than 30 seconds in some cases (all we allow for before the prompt), however, in most cases, selecting retry for the NTP time sync at this point will succeed.

Local testing is fine for me with default settings. NTPD syncs usually at the 10/30 mark during boot.

midwan commented 6 years ago

@Fourdee I tried retry a few times first, but it didn't seem to help.

Testing DietPi on another board (pine64), showed the exact same problem as well. I tried changing the mirror to a local one as well (se.pool.ntp.org), but even though I could get a ping from it in around 23ms, the time sync still failed.

I had to manually set the date/time to proceed.

Fourdee commented 6 years ago

@midwan

Thanks 👍

Any chance you can run the following and paste results:

killall -w ntpd
ntpd -g -q

Success should result in:

root@DietPi:~# ntpd -g -q
 1 Feb 16:03:27 ntpd[2307]: ntpd 4.2.8p10@1.3728-o Sat Oct  7 14:29:08 UTC 2017 (1): Starting
 1 Feb 16:03:27 ntpd[2307]: Command line: ntpd -g -q
 1 Feb 16:03:27 ntpd[2307]: proto: precision = 1.406 usec (-19)
 1 Feb 16:03:27 ntpd[2307]: Listen and drop on 0 v6wildcard [::]:123
 1 Feb 16:03:27 ntpd[2307]: Listen and drop on 1 v4wildcard 0.0.0.0:123
 1 Feb 16:03:27 ntpd[2307]: Listen normally on 2 lo 127.0.0.1:123
 1 Feb 16:03:27 ntpd[2307]: Listen normally on 3 eth0 192.168.0.104:123
 1 Feb 16:03:27 ntpd[2307]: Listen normally on 4 lo [::1]:123
 1 Feb 16:03:27 ntpd[2307]: Listen normally on 5 eth0 [fe80::ba27:ebff:fe8e:535b%2]:123
 1 Feb 16:03:27 ntpd[2307]: Listening on routing socket on fd #22 for interface updates
 1 Feb 16:03:28 ntpd[2307]: Soliciting pool server 139.59.199.215
 1 Feb 16:03:29 ntpd[2307]: Soliciting pool server 93.93.129.102
 1 Feb 16:03:29 ntpd[2307]: Soliciting pool server 178.79.152.182
 1 Feb 16:03:30 ntpd[2307]: Soliciting pool server 85.199.213.50
 1 Feb 16:03:30 ntpd[2307]: Soliciting pool server 195.219.205.9
 1 Feb 16:03:30 ntpd[2307]: Soliciting pool server 195.195.221.100
 1 Feb 16:03:31 ntpd[2307]: Soliciting pool server 178.62.16.103
 1 Feb 16:03:31 ntpd[2307]: Soliciting pool server 83.170.75.28
 1 Feb 16:03:31 ntpd[2307]: Soliciting pool server 129.250.35.250
 1 Feb 16:03:32 ntpd[2307]: Soliciting pool server 178.79.162.34
 1 Feb 16:03:32 ntpd[2307]: Soliciting pool server 178.79.162.34
 1 Feb 16:03:32 ntpd[2307]: Soliciting pool server 192.146.137.13
 1 Feb 16:03:33 ntpd[2307]: Soliciting pool server 89.238.136.135
 1 Feb 16:03:34 ntpd[2307]: Soliciting pool server 158.43.128.33
 1 Feb 16:03:37 ntpd[2307]: ntpd: time slew +0.000205 s
ntpd: time slew +0.000205s

midwan commented 6 years ago

root@DietPi:~# killall -w ntpd
ntpd: no process found
root@DietPi:~# ntpd -g -q
 1 Feb 18:15:34 ntpd[16308]: ntpd 4.2.8p10@1.3728-o Sat Oct  7 14:29:08 UTC 2017                                                         (1): Starting
 1 Feb 18:15:34 ntpd[16308]: Command line: ntpd -g -q
 1 Feb 18:15:34 ntpd[16308]: proto: precision = 2.000 usec (-19)
 1 Feb 18:15:34 ntpd[16308]: Listen and drop on 0 v6wildcard [::]:123
 1 Feb 18:15:34 ntpd[16308]: Listen and drop on 1 v4wildcard 0.0.0.0:123
 1 Feb 18:15:34 ntpd[16308]: Listen normally on 2 lo 127.0.0.1:123
 1 Feb 18:15:34 ntpd[16308]: Listen normally on 3 eth0 192.168.1.61:123
 1 Feb 18:15:34 ntpd[16308]: Listen normally on 4 lo [::1]:123
 1 Feb 18:15:34 ntpd[16308]: Listen normally on 5 eth0 [fe80::8eae:4cff:fef5:532                                                        d%2]:123
 1 Feb 18:15:34 ntpd[16308]: Listening on routing socket on fd #22 for interface                                                         updates
 1 Feb 18:15:35 ntpd[16308]: Soliciting pool server 31.220.5.58
 1 Feb 18:15:36 ntpd[16308]: Soliciting pool server 85.197.153.193
 1 Feb 18:15:37 ntpd[16308]: Soliciting pool server 213.251.52.202
 1 Feb 18:15:38 ntpd[16308]: Soliciting pool server 192.36.143.130
 1 Feb 18:16:39 ntpd[16308]: Soliciting pool server 94.254.0.48
 1 Feb 18:16:41 ntpd[16308]: Soliciting pool server 193.228.143.22
 1 Feb 18:16:42 ntpd[16308]: Soliciting pool server 62.209.166.40
 1 Feb 18:16:43 ntpd[16308]: Soliciting pool server 83.251.214.239
 1 Feb 18:17:45 ntpd[16308]: Soliciting pool server 79.136.86.176
 1 Feb 18:17:47 ntpd[16308]: Soliciting pool server 193.228.143.13
 1 Feb 18:17:47 ntpd[16308]: Soliciting pool server 193.11.114.43
 1 Feb 18:17:47 ntpd[16308]: Soliciting pool server 62.181.96.214
 1 Feb 18:18:51 ntpd[16308]: Soliciting pool server 82.102.5.110
 1 Feb 18:18:51 ntpd[16308]: Soliciting pool server 192.36.143.153
 1 Feb 18:18:52 ntpd[16308]: Soliciting pool server 94.246.113.189
 1 Feb 18:18:54 ntpd[16308]: Soliciting pool server 88.129.241.195
 1 Feb 18:19:55 ntpd[16308]: Soliciting pool server 2001:440:1880:5555::2
 1 Feb 18:19:55 ntpd[16308]: Soliciting pool server 192.36.143.130
 1 Feb 18:19:57 ntpd[16308]: Soliciting pool server 85.197.153.193
 1 Feb 18:20:00 ntpd[16308]: Soliciting pool server 31.220.5.58
 1 Feb 18:21:01 ntpd[16308]: Soliciting pool server 2a05:e840:851::1
 1 Feb 18:21:01 ntpd[16308]: Soliciting pool server 94.254.0.48
 1 Feb 18:21:02 ntpd[16308]: Soliciting pool server 194.71.144.71
 1 Feb 18:21:04 ntpd[16308]: Soliciting pool server 79.136.86.176
 1 Feb 18:22:06 ntpd[16308]: Soliciting pool server 2001:470:df57:2::9
 1 Feb 18:22:08 ntpd[16308]: Soliciting pool server 217.75.106.216
 1 Feb 18:22:09 ntpd[16308]: Soliciting pool server 82.102.5.110
 1 Feb 18:22:11 ntpd[16308]: Soliciting pool server 193.228.143.13
 1 Feb 18:23:10 ntpd[16308]: Soliciting pool server 2a00:1a28:1157:149::36a4
 1 Feb 18:23:14 ntpd[16308]: Soliciting pool server 62.209.166.40
 1 Feb 18:23:14 ntpd[16308]: Soliciting pool server 91.216.111.52
 1 Feb 18:23:17 ntpd[16308]: Soliciting pool server 178.73.198.130
 1 Feb 18:24:15 ntpd[16308]: Soliciting pool server 194.71.144.71
 1 Feb 18:24:19 ntpd[16308]: Soliciting pool server 213.251.52.202
 1 Feb 18:24:20 ntpd[16308]: Soliciting pool server 91.216.111.52
 1 Feb 18:24:24 ntpd[16308]: Soliciting pool server 94.254.0.48
 1 Feb 18:25:21 ntpd[16308]: Soliciting pool server 83.251.214.239
 1 Feb 18:25:23 ntpd[16308]: Soliciting pool server 85.197.153.193
 1 Feb 18:25:27 ntpd[16308]: Soliciting pool server 178.73.198.130
 1 Feb 18:25:31 ntpd[16308]: Soliciting pool server 79.136.86.176
 1 Feb 18:26:25 ntpd[16308]: Soliciting pool server 82.102.5.110
 1 Feb 18:26:27 ntpd[16308]: Soliciting pool server 193.11.114.43
 1 Feb 18:26:34 ntpd[16308]: Soliciting pool server 94.246.113.189
 1 Feb 18:26:38 ntpd[16308]: Soliciting pool server 62.209.166.40
 1 Feb 18:27:29 ntpd[16308]: Soliciting pool server 193.228.143.22
 1 Feb 18:27:33 ntpd[16308]: Soliciting pool server 88.129.241.195
 1 Feb 18:27:39 ntpd[16308]: Soliciting pool server 62.181.96.214
 1 Feb 18:27:42 ntpd[16308]: Soliciting pool server 192.36.143.153
 1 Feb 18:28:33 ntpd[16308]: Soliciting pool server 2a05:e840:851::1
 1 Feb 18:28:39 ntpd[16308]: Soliciting pool server 31.220.5.58
 1 Feb 18:28:45 ntpd[16308]: Soliciting pool server 85.197.153.193
 1 Feb 18:28:46 ntpd[16308]: Soliciting pool server 193.11.114.43
 1 Feb 18:29:40 ntpd[16308]: Soliciting pool server 2001:440:1880:5555::2
 1 Feb 18:29:44 ntpd[16308]: Soliciting pool server 82.102.5.110
 1 Feb 18:29:52 ntpd[16308]: Soliciting pool server 217.75.106.216
 1 Feb 18:29:53 ntpd[16308]: Soliciting pool server 194.71.144.71
 1 Feb 18:30:47 ntpd[16308]: Soliciting pool server 2a00:1a28:1157:149::36a4
 1 Feb 18:30:50 ntpd[16308]: Soliciting pool server 94.254.0.48
 1 Feb 18:30:56 ntpd[16308]: Soliciting pool server 62.209.166.40
 1 Feb 18:30:59 ntpd[16308]: Soliciting pool server 79.136.86.176
 1 Feb 18:31:52 ntpd[16308]: Soliciting pool server 2001:470:df57:2::9
 1 Feb 18:31:57 ntpd[16308]: Soliciting pool server 88.129.241.195
 1 Feb 18:32:00 ntpd[16308]: Soliciting pool server 193.228.143.13
 1 Feb 18:32:05 ntpd[16308]: Soliciting pool server 192.36.143.153
 1 Feb 18:32:57 ntpd[16308]: Soliciting pool server 79.136.86.176
 1 Feb 18:33:04 ntpd[16308]: Soliciting pool server 213.251.52.202
 1 Feb 18:33:05 ntpd[16308]: Soliciting pool server 193.228.143.22
 1 Feb 18:33:06 ntpd[16308]: Soliciting pool server 62.209.166.40
 1 Feb 18:33:11 ntpd[16308]: Soliciting pool server 85.197.153.193
 1 Feb 18:33:12 ntpd[16308]: Soliciting pool server 31.220.5.58
 1 Feb 18:33:13 ntpd[16308]: Soliciting pool server 217.75.106.216
 1 Feb 18:33:14 ntpd[16308]: Soliciting pool server 193.228.143.13
 1 Feb 18:33:18 ntpd[16308]: ntpd: time slew +0.071045 s
ntpd: time slew +0.071045s

k-plan commented 6 years ago

@Fourdee

seem to happen from time to time.

Fresh image RPi-Zero (dietpi.txt only change hostname):

Ethernet is a USB adapter: Bus 001 Device 002: ID 0b95:772b ASIX Electronics Corp. AX88772B

IP-address and DNS: via DHCP

1.) boot => resize fs
2.) boot => auto update v6.-1 => v6.1 :

....
[  OK  ] Verified: SOFTWARE_WIFI_HOTSPOT_KEY
[  OK  ] Verified: SOFTWARE_WIFI_HOTSPOT_CHANNEL
[  OK  ] Verified: DEV_GITBRANCH
[  OK  ] Verified: DEV_GITOWNER
[  OK  ] dietpi.txt verification completed
[  OK  ] verify_dietpi.txt  | Completed

 DietPi-Update Updating DietPi
-----------------------------------------------------
 Mode:

[ INFO ] Current Version : 6.-1
[ INFO ] Server Version  : 6.1

[ INFO ] Patching 6.-1 to 6.0

 DietPi-Set_Software
-----------------------------------------------------
 Mode: locale (en_GB.UTF-8)

[  OK  ] dpkg-reconfigure -f noninteractive locales
[  OK  ] locale en_GB.UTF-8 | Completed
[ INFO ] Creating core DietPi environment, please wait...
[ INFO ] Configuring .bashrc:
[ INFO ] Creating DietPi User Account:
useradd: user 'dietpi' already exists
[ INFO ] Configuring Sudo UID bit:
[ INFO ] Configuring DietPi Directories:
[ INFO ] Configuring DietPi Services:
[ INFO ] Configuring Cron:
[ INFO ] Configuring: prefer wlan/eth naming for networked devices:
[ INFO ] Disabling apt-daily services on Stretch+ (prevents random APT cache lock):
[ INFO ] Setting vm.swappiness=1:
[  OK  ] Completed DietPi core environment
[ INFO ] APT removal for: debian-keyring, please wait...
Reading package lists...
Building dependency tree...
Reading state information...
Package 'debian-keyring' is not installed, so not removed
0 upgraded, 0 newly installed, 0 to remove and 5 not upgraded.
[  OK  ] G_AGP: debian-keyring
[  OK  ] Patch 6.0 completed

 DietPi-Update Updating DietPi
-----------------------------------------------------
 Mode:

[ INFO ] Current Version : 6.0
[ INFO ] Server Version  : 6.1

[ INFO ] Patching 6.0 to 6.1
[  OK  ] Patch 6.1 completed

 DietPi-Update
-----------------------------------------------------
 Mode: Completed

[ INFO ] Current Version : 6.-1
[ INFO ] Server Version  : 6.1
[  OK  ] Update completed

Please reboot your system now, using the command reboot

3.) boot:

---------------------------------------
 DietPi     | 19:21 | Thu 01/02/18
 ---------------------------------------
 v6.1       | RPi Zero (armv6l)
 ---------------------------------------
 IP eth0    | 192.168.100.191
 ---------------------------------------

 Welcome to DietPi-Software

[ INFO ] NTPD: Waiting for completion of time sync (1/30)
[ INFO ] NTPD: Waiting for completion of time sync (2/30)
[ INFO ] NTPD: Waiting for completion of time sync (3/30)
[ INFO ] NTPD: Waiting for completion of time sync (4/30)
[ INFO ] NTPD: Waiting for completion of time sync (5/30)
[ INFO ] NTPD: Waiting for completion of time sync (6/30)
[ INFO ] NTPD: Waiting for completion of time sync (7/30)
[ INFO ] NTPD: Waiting for completion of time sync (8/30)
[ INFO ] NTPD: Waiting for completion of time sync (9/30)
[ INFO ] NTPD: Waiting for completion of time sync (10/30)
[ INFO ] NTPD: Waiting for completion of time sync (11/30)
[ INFO ] NTPD: Waiting for completion of time sync (12/30)
[ INFO ] NTPD: Waiting for completion of time sync (13/30)
[ INFO ] NTPD: Waiting for completion of time sync (14/30)
[ INFO ] NTPD: Waiting for completion of time sync (15/30)
[ INFO ] NTPD: Waiting for completion of time sync (16/30)
[ INFO ] NTPD: Waiting for completion of time sync (17/30)
[ INFO ] NTPD: Waiting for completion of time sync (18/30)
[ INFO ] NTPD: Waiting for completion of time sync (19/30)
[ INFO ] NTPD: Waiting for completion of time sync (20/30)
[ INFO ] NTPD: Waiting for completion of time sync (21/30)
[ INFO ] NTPD: Waiting for completion of time sync (22/30)
[ INFO ] NTPD: Waiting for completion of time sync (23/30)
[ INFO ] NTPD: Waiting for completion of time sync (24/30)
[ INFO ] NTPD: Waiting for completion of time sync (25/30)
[ INFO ] NTPD: Waiting for completion of time sync (26/30)
[ INFO ] NTPD: Waiting for completion of time sync (27/30)
[ INFO ] NTPD: Waiting for completion of time sync (28/30)
[ INFO ] NTPD: Waiting for completion of time sync (29/30)
[ INFO ] NTPD: Waiting for completion of time sync (30/30)
[FAILED] NTPD: time sync | An issue has occured
[ INFO ] NTPD: Please check the log file for more information:
[ INFO ] NTPD: /var/log/ntpd.log

/var/log/ntpd.log

root@RPi-Zero:~# cat /var/log/ntpd.log
 1 Feb 19:20:52 ntpd[558]: ntpd 4.2.8p10@1.3728-o Sat Oct  7 14:29:08 UTC 2017 (1): Starting
 1 Feb 19:20:52 ntpd[558]: Command line: ntpd -gq -l /var/log/ntpd.log
 1 Feb 19:20:52 ntpd[558]: proto: precision = 2.000 usec (-19)
 1 Feb 19:20:52 ntpd[558]: Listen and drop on 0 v6wildcard [::]:123
 1 Feb 19:20:52 ntpd[558]: Listen and drop on 1 v4wildcard 0.0.0.0:123
 1 Feb 19:20:52 ntpd[558]: Listen normally on 2 lo 127.0.0.1:123
 1 Feb 19:20:52 ntpd[558]: Listen normally on 3 lo [::1]:123
 1 Feb 19:20:52 ntpd[558]: Listen normally on 4 eth0 [fe80::250:b6ff:fe17:5083%2]:123
 1 Feb 19:20:52 ntpd[558]: Listening on routing socket on fd #21 for interface updates
 1 Feb 19:20:53 ntpd[558]: error resolving pool 0.debian.pool.ntp.org: Temporary failure in name resolution (-3)
 1 Feb 19:20:54 ntpd[558]: error resolving pool 1.debian.pool.ntp.org: Temporary failure in name resolution (-3)
 1 Feb 19:20:55 ntpd[558]: error resolving pool 2.debian.pool.ntp.org: Temporary failure in name resolution (-3)
 1 Feb 19:20:56 ntpd[558]: error resolving pool 3.debian.pool.ntp.org: Temporary failure in name resolution (-3)
 1 Feb 19:20:58 ntpd[558]: Listen normally on 5 eth0 192.168.88.91:123
 1 Feb 19:21:57 ntpd[558]: Soliciting pool server 90.187.7.5
 1 Feb 19:21:58 ntpd[558]: Soliciting pool server 131.188.3.221
 1 Feb 19:21:59 ntpd[558]: Soliciting pool server 131.234.137.63
 1 Feb 19:22:00 ntpd[558]: Soliciting pool server 37.58.57.238
 1 Feb 19:22:00 ntpd[558]: Soliciting pool server 5.9.56.53
 1 Feb 19:22:01 ntpd[558]: Soliciting pool server 129.70.132.34
 1 Feb 19:22:01 ntpd[558]: Soliciting pool server 92.240.244.202
 1 Feb 19:22:02 ntpd[558]: Soliciting pool server 131.188.3.220
 1 Feb 19:22:02 ntpd[558]: Soliciting pool server 213.251.53.234
 1 Feb 19:22:03 ntpd[558]: Soliciting pool server 85.25.210.112
 1 Feb 19:22:03 ntpd[558]: Soliciting pool server 213.227.164.24
 1 Feb 19:22:03 ntpd[558]: Soliciting pool server 66.228.42.59
 1 Feb 19:22:04 ntpd[558]: Soliciting pool server 27.124.125.251
 1 Feb 19:22:04 ntpd[558]: Soliciting pool server 2001:628:21f0:80::80:29
 1 Feb 19:22:04 ntpd[558]: Soliciting pool server 80.65.85.94
 1 Feb 19:22:15 ntpd[558]: ntpd: time set +10.516205 s

Fourdee commented 6 years ago

Thanks guys 👍

@midwan

15+ minutes to sync 😨

@k-plan

1+ minute to sync

Notes:

Below: most likely due to ntpd being started, prior to DNS being available during boot. However, it seems to recover regardless:

error resolving pool 2.debian.pool.ntp.org: Temporary failure in name resolution (-3)
...
Listen normally on 5 eth0 192.168.88.91:123
Soliciting pool server 90.187.7.5

Linked for reference as its the only major ntpd specific change (that I can remember 😉 ): https://github.com/Fourdee/DietPi/commit/cb2915a11d50a98e36ad2600ed0527c74178c680

Curious if we get same results from SystemD based timesync and/or other mirrors. IPv6?

Congested, deadpool (lol film)? https://lists.debian.org/debian-user/2017/06/msg00253.html

Fourdee commented 6 years ago

@midwan @k-plan

Did either of you notice any changes/improvements when using alternative NTPD mirrors (if changed)?

As I cant replicate the issue here, if you have the time, i'd appreciate it if we could try the following change:

nano /etc/ntp.conf

At the bottom replace all 4 pool entries, with server, eg:

server 0.debian.pool.ntp.org iburst
server 1.debian.pool.ntp.org iburst
server 2.debian.pool.ntp.org iburst
server 3.debian.pool.ntp.org iburst

Save changes
reboot
verify sync time:
```
killall -w ntpd
time ntpd -g -q
```

atypical result:

root@DietPi:~# time ntpd -g -q
ntpd: time slew +0.006696s

real    0m7.047s
user    0m0.020s
sys     0m0.020s

midwan commented 6 years ago

@Fourdee When I changed servers, I didn't notice any difference - it still tried 30 times and finally gave up.

After making the changes suggested above:

root@DietPi:~# killall -w ntpd
root@DietPi:~# time ntpd -g -q
 1 Feb 22:40:25 ntpd[2277]: ntpd 4.2.8p10@1.3728-o Sat Oct  7 14:29:08 UTC 2017 (1): Starting
 1 Feb 22:40:25 ntpd[2277]: Command line: ntpd -g -q
 1 Feb 22:40:26 ntpd[2277]: proto: precision = 2.000 usec (-19)
 1 Feb 22:40:26 ntpd[2277]: Listen and drop on 0 v6wildcard [::]:123
 1 Feb 22:40:26 ntpd[2277]: Listen and drop on 1 v4wildcard 0.0.0.0:123
 1 Feb 22:40:26 ntpd[2277]: Listen normally on 2 lo 127.0.0.1:123
 1 Feb 22:40:26 ntpd[2277]: Listen normally on 3 eth0 192.168.1.61:123
 1 Feb 22:40:26 ntpd[2277]: Listen normally on 4 lo [::1]:123
 1 Feb 22:40:26 ntpd[2277]: Listen normally on 5 eth0 [fe80::8eae:4cff:fef5:532d%2]:123
 1 Feb 22:40:26 ntpd[2277]: Listening on routing socket on fd #22 for interface updates

...still hasn't come back after 30 minutes

midwan commented 6 years ago

Had to cancel my way out:

root@DietPi:~# killall -w ntpd
root@DietPi:~# time ntpd -g -q
 1 Feb 22:40:25 ntpd[2277]: ntpd 4.2.8p10@1.3728-o Sat Oct  7 14:29:08 UTC 2017 (1): Starting
 1 Feb 22:40:25 ntpd[2277]: Command line: ntpd -g -q
 1 Feb 22:40:26 ntpd[2277]: proto: precision = 2.000 usec (-19)
 1 Feb 22:40:26 ntpd[2277]: Listen and drop on 0 v6wildcard [::]:123
 1 Feb 22:40:26 ntpd[2277]: Listen and drop on 1 v4wildcard 0.0.0.0:123
 1 Feb 22:40:26 ntpd[2277]: Listen normally on 2 lo 127.0.0.1:123
 1 Feb 22:40:26 ntpd[2277]: Listen normally on 3 eth0 192.168.1.61:123
 1 Feb 22:40:26 ntpd[2277]: Listen normally on 4 lo [::1]:123
 1 Feb 22:40:26 ntpd[2277]: Listen normally on 5 eth0 [fe80::8eae:4cff:fef5:532d%2]:123
 1 Feb 22:40:26 ntpd[2277]: Listening on routing socket on fd #22 for interface updates
^C 1 Feb 23:12:05 ntpd[2277]: ntpd exiting on signal 2 (Interrupt)
 1 Feb 23:12:05 ntpd[2277]: 194.71.144.71 local addr 192.168.1.61 -> <null>
 1 Feb 23:12:05 ntpd[2277]: 213.251.52.202 local addr 192.168.1.61 -> <null>
 1 Feb 23:12:05 ntpd[2277]: 85.197.153.193 local addr 192.168.1.61 -> <null>
 1 Feb 23:12:05 ntpd[2277]: 79.136.86.176 local addr 192.168.1.61 -> <null>

real    31m39.165s
user    0m0.200s
sys     0m0.250s
root@DietPi:~#

k-plan commented 6 years ago

@midwan

SBC Device | RPi Zero (armv6l)

What did you use on RPi-Zero?

USB Ethernet dongle ? Typ?
USB WiFi dongle ? Typ?

midwan commented 6 years ago

@k-plan I used a USB Ethernet adapter, specifically this one: https://www.amazon.co.uk/gp/product/B00RM3KXAU/ref=oh_aui_detailpage_o06_s00?ie=UTF8&psc=1

I've been using the same setup with DietPi for the last two years or so, only now upgraded to the latest so I had to re-flash the distro and set things up from scratch.

Fourdee commented 6 years ago

@midwan

Aside from the pool change (which you have reverted in testing), the only change I can think of is kernel version. We now use the default APT RPi kernel 4.9.59. However, if you had this install for 2 years, its probably an older kernel either way.

The only things I can suggest to try is:

Set STATIC IP and google DNS in dietpi-config, then retest
Update the RPI kernel G_RPI_UPDATE (runs rpi-update), reboot, then retest
Reboot router (you never know 😃 )

midwan commented 6 years ago

@Fourdee Thanks for the suggestions.

I already have set a Static IP and the Google DNS in the config. :)
Will try and report back
Did that already as part of the tests

k-plan commented 6 years ago

@Fourdee

Set STATIC IP and google DNS in dietpi-config, then retest

Sorry to bother, but @midwan has installed PiHole.

He should have a STATIC IP but setting google DNS as STATIC DNS in dietpi-config for host/RPi-Zero/DietPi didn't work, because of running PiHole

2018-02-02

root@RPi-Zero:~# cat /etc/resolv.conf
# Dynamic resolv.conf(5) file for glibc resolver(3) generated by resolvconf(8)
#     DO NOT EDIT THIS FILE BY HAND -- YOUR CHANGES WILL BE OVERWRITTEN
nameserver 127.0.0.1

2018-02-02 16-09-14

midwan commented 6 years ago

@k-plan Correct, I am running Pi-hole on this. The DNS is set to Google from Pi-hole's options, since you are not allowed to change them in dietpi-config.

However, the issue with the NTPD sync failure came up before installing Pi-hole also. In fact, it stopped me from installing it, because due to the time skew the site's certificate looked invalid (had a "future" timestamp).

@Fourdee Regarding the Pi Zero:

Tried updating the firmware to the latest version. Results showed:


root@DietPi:~# killall -w ntpd
root@DietPi:~# time ntpd -g -q
2 Feb 18:50:12 ntpd[2235]: ntpd 4.2.8p10@1.3728-o Sat Oct  7 14:29:08 UTC 2017                                   (1): Starting
2 Feb 18:50:12 ntpd[2235]: Command line: ntpd -g -q
2 Feb 18:50:12 ntpd[2235]: proto: precision = 2.000 usec (-19)
2 Feb 18:50:12 ntpd[2235]: Listen and drop on 0 v6wildcard [::]:123
2 Feb 18:50:12 ntpd[2235]: Listen and drop on 1 v4wildcard 0.0.0.0:123
2 Feb 18:50:12 ntpd[2235]: Listen normally on 2 lo 127.0.0.1:123
2 Feb 18:50:12 ntpd[2235]: Listen normally on 3 eth0 192.168.1.61:123
2 Feb 18:50:12 ntpd[2235]: Listen normally on 4 lo [::1]:123
2 Feb 18:50:12 ntpd[2235]: Listen normally on 5 eth0 [fe80::8eae:4cff:fef5:532d                                  %2]:123
2 Feb 18:50:12 ntpd[2235]: Listening on routing socket on fd #22 for interface                                   updates
2 Feb 18:50:13 ntpd[2235]: Soliciting pool server 194.71.144.71
2 Feb 18:50:14 ntpd[2235]: Soliciting pool server 94.254.0.48
2 Feb 18:50:15 ntpd[2235]: Soliciting pool server 192.36.143.130
2 Feb 18:50:16 ntpd[2235]: Soliciting pool server 213.251.52.202
2 Feb 18:51:17 ntpd[2235]: Soliciting pool server 62.209.166.40
2 Feb 18:51:19 ntpd[2235]: Soliciting pool server 192.36.143.153
2 Feb 18:51:22 ntpd[2235]: Soliciting pool server 217.75.106.216
2 Feb 18:51:22 ntpd[2235]: Soliciting pool server 85.197.153.193
2 Feb 18:52:22 ntpd[2235]: Soliciting pool server 193.11.114.43
2 Feb 18:52:23 ntpd[2235]: Soliciting pool server 91.216.111.52
2 Feb 18:52:27 ntpd[2235]: Soliciting pool server 62.181.96.214
2 Feb 18:52:29 ntpd[2235]: Soliciting pool server 82.102.5.110
2 Feb 18:53:26 ntpd[2235]: Soliciting pool server 79.136.86.176
2 Feb 18:53:30 ntpd[2235]: Soliciting pool server 94.246.113.189
2 Feb 18:53:31 ntpd[2235]: Soliciting pool server 88.129.241.195
2 Feb 18:53:35 ntpd[2235]: Soliciting pool server 178.73.198.130
2 Feb 18:54:31 ntpd[2235]: Soliciting pool server 213.251.52.202
2 Feb 18:54:37 ntpd[2235]: Soliciting pool server 192.36.143.130
2 Feb 18:54:38 ntpd[2235]: Soliciting pool server 2001:440:1880:5555::2
2 Feb 18:54:39 ntpd[2235]: Soliciting pool server 194.71.144.71
2 Feb 18:55:38 ntpd[2235]: Soliciting pool server 193.11.114.43
2 Feb 18:55:42 ntpd[2235]: Soliciting pool server 83.251.214.239
2 Feb 18:55:43 ntpd[2235]: Soliciting pool server 2001:16d8:c016:0:dead:beef:b00b:216
2 Feb 18:55:45 ntpd[2235]: Soliciting pool server 62.209.166.40
2 Feb 18:56:42 ntpd[2235]: Soliciting pool server 94.254.0.48
2 Feb 18:56:49 ntpd[2235]: Soliciting pool server 193.228.143.24
2 Feb 18:56:49 ntpd[2235]: Soliciting pool server 82.102.5.110
2 Feb 18:56:50 ntpd[2235]: Soliciting pool server 2a05:e840:851::1
2 Feb 18:56:50 ntpd[2235]: Soliciting pool server 178.73.198.130
2 Feb 18:57:06 ntpd[2235]: ntpd: time set +9.810414 s
ntpd: time set +9.810414s

real 6m54.901s user 0m0.060s sys 0m0.090s


- I also had the exact same error on a pine64 with the latest version of DietPi, so I'm not sure this is related to the firmware of the RPI specifically...

Fourdee commented 6 years ago

@midwan

I also had the exact same error on a pine64 with the latest version of DietPi, so I'm not sure this is related to the firmware of the RPI specifically

Thanks for testing 👍

kernel is an improvement, but still not good enough.

Really don't know where to go from here as I cant replicate on any device, I can only assuming network is the factor. We rely on ntpd binary to complete its task, and as far as I can see, all the settings are standard and valid for ntpd.

We've not had other reports (aside from @k-plan but thats only 1 minute, @k-plan during the prompt of NTPD failure, did the retry option work afterwards?), and if the issue is common, we would see alot more reports.

k-plan commented 6 years ago

@Fourdee

@k-plan but thats only 1 minute, @k-plan during the prompt of NTPD failure, did the retry option work afterwards?)

Yes, but by hitting chancel .^^ I open a second SSH terminal, to get a look into log file and like magic, get messageNTP sync on first terminal. Have a look at the time stamps. I have done nothing, but 1 min later NTP synchronizing.

root@RPI-Zero:~# cat /var/log/ntpd.log
 2 Feb 16:19:46 ntpd[540]: ntpd 4.2.8p10@1.3728-o Sat Oct  7 14:29:08 UTC 2017 (1): Starting
 2 Feb 16:19:46 ntpd[540]: Command line: ntpd -gq -l /var/log/ntpd.log
 2 Feb 16:19:46 ntpd[540]: proto: precision = 3.000 usec (-18)
 2 Feb 16:19:46 ntpd[540]: Listen and drop on 0 v6wildcard [::]:123
 2 Feb 16:19:46 ntpd[540]: Listen and drop on 1 v4wildcard 0.0.0.0:123
 2 Feb 16:19:46 ntpd[540]: Listen normally on 2 lo 127.0.0.1:123
 2 Feb 16:19:46 ntpd[540]: Listen normally on 3 lo [::1]:123
 2 Feb 16:19:46 ntpd[540]: Listen normally on 4 eth0 [fe80::250:b6ff:fe17:5083%2]:123
 2 Feb 16:19:46 ntpd[540]: Listening on routing socket on fd #21 for interface updates
 2 Feb 16:19:47 ntpd[540]: error resolving pool 0.debian.pool.ntp.org: Temporary failure in name resolution (-3)
 2 Feb 16:19:48 ntpd[540]: error resolving pool 1.debian.pool.ntp.org: Temporary failure in name resolution (-3)
 2 Feb 16:19:49 ntpd[540]: error resolving pool 2.debian.pool.ntp.org: Temporary failure in name resolution (-3)
 2 Feb 16:19:50 ntpd[540]: error resolving pool 3.debian.pool.ntp.org: Temporary failure in name resolution (-3)
 2 Feb 16:19:52 ntpd[540]: Listen normally on 5 eth0 192.168.88.91:123
 2 Feb 16:20:52 ntpd[540]: Soliciting pool server 62.210.244.146
 2 Feb 16:20:53 ntpd[540]: Soliciting pool server 212.83.160.142
 2 Feb 16:20:53 ntpd[540]: Soliciting pool server 91.220.110.116
 2 Feb 16:20:54 ntpd[540]: Soliciting pool server 193.25.222.240
 2 Feb 16:20:54 ntpd[540]: Soliciting pool server 209.208.79.69
 2 Feb 16:20:54 ntpd[540]: Soliciting pool server 5.9.150.40
 2 Feb 16:20:55 ntpd[540]: Soliciting pool server 141.30.228.4
 2 Feb 16:20:55 ntpd[540]: Soliciting pool server 103.242.68.68
 2 Feb 16:20:55 ntpd[540]: Soliciting pool server 192.150.149.245
 2 Feb 16:20:55 ntpd[540]: Soliciting pool server 91.198.10.1
 2 Feb 16:20:56 ntpd[540]: Soliciting pool server 85.254.216.1
 2 Feb 16:20:56 ntpd[540]: Soliciting pool server 5.9.143.126
 2 Feb 16:20:56 ntpd[540]: Soliciting pool server 212.59.0.2
 2 Feb 16:20:57 ntpd[540]: Soliciting pool server 149.202.2.105
 2 Feb 16:20:57 ntpd[540]: Soliciting pool server 88.198.12.78
 2 Feb 16:20:58 ntpd[540]: Soliciting pool server 185.41.243.30
 2 Feb 16:20:58 ntpd[540]: Soliciting pool server 2a01:4f8:141:282::5:1

@midwan

can we please leave it alone for some day to see what will happen and pick back later? If we get more NTP related error issue?

midwan commented 6 years ago

@k-plan No problem from me, as I had a manual workaround. I only opened this up because I thought it might need looking into.

k-plan commented 6 years ago

@midwan

No problem from me

nice to hear this. We have to settle down a little bit. To many open ends because of v6.x

I only opened this up because I thought it might need looking into.

👍 Well done!

infinitejones commented 6 years ago

This happens for me on three different devices (Pine64, RPi 2 Model B, RPi Zero W), all with freshly flashed DietPi_v6.0 Stretch images.

Here's the output from the Zero W, but the other devices are the same. (Installation was aborted because I Exited out of dietpi-software in order to manually run ntpd -gq)

 ───────────────────────────────────────
 DietPi     | 13:09 | Thu 11/01/18 
 ───────────────────────────────────────
 v6.1       | RPi Zero W (armv6l)
 ───────────────────────────────────────
 IP wlan0    | 10.0.0.16
 ───────────────────────────────────────
[FAILED] 
 Installation Aborted by User 
 Installation must be completed prior to using DietPi 
 Please run dietpi-software to restart the installation 

root@soundBug:~# ntpd -gq
11 Jan 13:09:43 ntpd[3361]: ntpd 4.2.8p10@1.3728-o Sat Oct  7 14:29:08 UTC 2017 (1): Starting
11 Jan 13:09:43 ntpd[3361]: Command line: ntpd -gq
11 Jan 13:09:43 ntpd[3361]: proto: precision = 2.000 usec (-19)
11 Jan 13:09:43 ntpd[3361]: Listen and drop on 0 v6wildcard [::]:123
11 Jan 13:09:43 ntpd[3361]: Listen and drop on 1 v4wildcard 0.0.0.0:123
11 Jan 13:09:43 ntpd[3361]: Listen normally on 2 lo 127.0.0.1:123
11 Jan 13:09:43 ntpd[3361]: Listen normally on 3 wlan0 10.0.0.16:123
11 Jan 13:09:43 ntpd[3361]: Listen normally on 4 lo [::1]:123
11 Jan 13:09:43 ntpd[3361]: Listen normally on 5 wlan0 [fe80::ba27:ebff:fe9c:3f84%2]:123
11 Jan 13:09:43 ntpd[3361]: Listening on routing socket on fd #22 for interface updates
11 Jan 13:09:45 ntpd[3361]: Soliciting pool server 45.76.113.31
11 Jan 13:09:45 ntpd[3361]: Soliciting pool server 192.189.54.33
11 Jan 13:09:47 ntpd[3361]: Soliciting pool server 103.76.40.155
11 Jan 13:09:47 ntpd[3361]: Soliciting pool server 144.48.166.166

It just runs indefinitely, soliciting new pool servers.

It's not network issues - I can ping randomly selected servers the ntpd is soliciting:

root@soundBug:~# ntpd -gq
11 Jan 13:09:43 ntpd[3361]: ntpd 4.2.8p10@1.3728-o Sat Oct  7 14:29:08 UTC 2017 (1): Starting
11 Jan 13:09:43 ntpd[3361]: Command line: ntpd -gq
11 Jan 13:09:43 ntpd[3361]: proto: precision = 2.000 usec (-19)
11 Jan 13:09:43 ntpd[3361]: Listen and drop on 0 v6wildcard [::]:123
11 Jan 13:09:43 ntpd[3361]: Listen and drop on 1 v4wildcard 0.0.0.0:123
11 Jan 13:09:43 ntpd[3361]: Listen normally on 2 lo 127.0.0.1:123
11 Jan 13:09:43 ntpd[3361]: Listen normally on 3 wlan0 10.0.0.16:123
11 Jan 13:09:43 ntpd[3361]: Listen normally on 4 lo [::1]:123
11 Jan 13:09:43 ntpd[3361]: Listen normally on 5 wlan0 [fe80::ba27:ebff:fe9c:3f84%2]:123
11 Jan 13:09:43 ntpd[3361]: Listening on routing socket on fd #22 for interface updates
11 Jan 13:09:45 ntpd[3361]: Soliciting pool server 45.76.113.31
11 Jan 13:09:45 ntpd[3361]: Soliciting pool server 192.189.54.33
11 Jan 13:09:47 ntpd[3361]: Soliciting pool server 103.76.40.155
11 Jan 13:09:47 ntpd[3361]: Soliciting pool server 144.48.166.166
11 Jan 13:10:49 ntpd[3361]: Soliciting pool server 203.7.149.150
11 Jan 13:10:51 ntpd[3361]: Soliciting pool server 27.124.125.252
11 Jan 13:10:51 ntpd[3361]: Soliciting pool server 13.55.50.68
11 Jan 13:10:51 ntpd[3361]: Soliciting pool server 223.252.23.219
^C11 Jan 13:11:29 ntpd[3361]: ntpd exiting on signal 2 (Interrupt)
11 Jan 13:11:29 ntpd[3361]: 103.214.220.220 local addr 10.0.0.16 -> <null>
11 Jan 13:11:29 ntpd[3361]: 27.124.125.251 local addr 10.0.0.16 -> <null>
11 Jan 13:11:29 ntpd[3361]: 103.38.120.36 local addr 10.0.0.16 -> <null>
11 Jan 13:11:29 ntpd[3361]: 203.114.73.24 local addr 10.0.0.16 -> <null>
root@soundBug:~# ping 192.189.54.33
PING 192.189.54.33 (192.189.54.33) 56(84) bytes of data.
64 bytes from 192.189.54.33: icmp_seq=1 ttl=249 time=71.3 ms
64 bytes from 192.189.54.33: icmp_seq=2 ttl=249 time=61.3 ms
64 bytes from 192.189.54.33: icmp_seq=3 ttl=249 time=50.6 ms
64 bytes from 192.189.54.33: icmp_seq=4 ttl=249 time=94.4 ms
64 bytes from 192.189.54.33: icmp_seq=5 ttl=249 time=23.8 ms
^C
--- 192.189.54.33 ping statistics ---
5 packets transmitted, 5 received, 0% packet loss, time 4006ms
rtt min/avg/max/mdev = 23.868/60.329/94.401/23.265 ms
root@soundBug:~# ping 103.76.40.155
PING 103.76.40.155 (103.76.40.155) 56(84) bytes of data.
64 bytes from 103.76.40.155: icmp_seq=1 ttl=58 time=50.9 ms
64 bytes from 103.76.40.155: icmp_seq=2 ttl=58 time=81.7 ms
64 bytes from 103.76.40.155: icmp_seq=3 ttl=58 time=57.8 ms
64 bytes from 103.76.40.155: icmp_seq=4 ttl=58 time=64.9 ms
^C
--- 103.76.40.155 ping statistics ---
4 packets transmitted, 4 received, 0% packet loss, time 3005ms
rtt min/avg/max/mdev = 50.916/63.878/81.796/11.472 ms
root@soundBug:~# ping 203.114.73.24
PING 203.114.73.24 (203.114.73.24) 56(84) bytes of data.
64 bytes from 203.114.73.24: icmp_seq=1 ttl=54 time=66.3 ms
64 bytes from 203.114.73.24: icmp_seq=2 ttl=54 time=56.0 ms
^C
--- 203.114.73.24 ping statistics ---
2 packets transmitted, 2 received, 0% packet loss, time 1001ms
rtt min/avg/max/mdev = 56.022/61.162/66.302/5.140 ms
root@soundBug:~# ping 223.252.23.219
PING 223.252.23.219 (223.252.23.219) 56(84) bytes of data.
64 bytes from 223.252.23.219: icmp_seq=1 ttl=51 time=68.0 ms
64 bytes from 223.252.23.219: icmp_seq=2 ttl=51 time=63.5 ms
64 bytes from 223.252.23.219: icmp_seq=3 ttl=51 time=55.5 ms
64 bytes from 223.252.23.219: icmp_seq=4 ttl=51 time=67.6 ms
^C
--- 223.252.23.219 ping statistics ---
4 packets transmitted, 4 received, 0% packet loss, time 3004ms
rtt min/avg/max/mdev = 55.507/63.699/68.050/5.056 ms

Let me know if any further info needed.

Fourdee commented 6 years ago

@infinitejones

Thanks for the report 👍

Lets try switching back to server, instead of pool.

Please copy and paste all, then retest with ntpd -gq

sed -i '/^[[:blank:]#;]*server [0-9]/d' /etc/ntp.conf
sed -i '/^[[:blank:]#;]*pool [0-9]/d' /etc/ntp.conf
cat << _EOF_ >> /etc/ntp.conf
server 0.debian.pool.ntp.org iburst
server 1.debian.pool.ntp.org iburst
server 2.debian.pool.ntp.org iburst
server 3.debian.pool.ntp.org iburst
_EOF_
ntpd -gq

infinitejones commented 6 years ago

Now it gets this far and hangs (I've included the full ntp.conf):

root@soundBug:~# cat /etc/ntp.conf
# /etc/ntp.conf, configuration for ntpd; see ntp.conf(5) for help

driftfile /var/lib/ntp/ntp.drift

# Enable this if you want statistics to be logged.
#statsdir /var/log/ntpstats/

statistics loopstats peerstats clockstats
filegen loopstats file loopstats type day enable
filegen peerstats file peerstats type day enable
filegen clockstats file clockstats type day enable

# You do need to talk to an NTP server or two (or three).
#server ntp.your-provider.example

# pool.ntp.org maps to about 1000 low-stratum NTP servers.  Your server will
# pick a different set every time it starts up.  Please consider joining the
# pool: <http://www.pool.ntp.org/join.html>

# Access control configuration; see /usr/share/doc/ntp-doc/html/accopt.html for
# details.  The web page <http://support.ntp.org/bin/view/Support/AccessRestrictions>
# might also be helpful.
#
# Note that "restrict" applies to both servers and clients, so a configuration
# that might be intended to block requests from certain clients could also end
# up blocking replies from your own upstream servers.

# By default, exchange time with everybody, but don't allow configuration.
restrict -4 default kod notrap nomodify nopeer noquery limited
restrict -6 default kod notrap nomodify nopeer noquery limited

# Local users may interrogate the ntp server more closely.
restrict 127.0.0.1
restrict ::1

# Needed for adding pool entries
restrict source notrap nomodify noquery

# Clients from this (example!) subnet have unlimited access, but only if
# cryptographically authenticated.
#restrict 192.168.123.0 mask 255.255.255.0 notrust

# If you want to provide time to your local subnet, change the next line.
# (Again, the address is an example only.)
#broadcast 192.168.123.255

# If you want to listen to time broadcasts on your local subnet, de-comment the
# next lines.  Please do this only if you trust everybody on the network!
#disable auth
#broadcastclient
server 0.debian.pool.ntp.org iburst
server 1.debian.pool.ntp.org iburst
server 2.debian.pool.ntp.org iburst
server 3.debian.pool.ntp.org iburst
root@soundBug:~# ntpd -gq
13 Jan 07:56:46 ntpd[3777]: ntpd 4.2.8p10@1.3728-o Sat Oct  7 14:29:08 UTC 2017 (1): Starting
13 Jan 07:56:46 ntpd[3777]: Command line: ntpd -gq
13 Jan 07:56:46 ntpd[3777]: proto: precision = 1.000 usec (-20)
13 Jan 07:56:46 ntpd[3777]: Listen and drop on 0 v6wildcard [::]:123
13 Jan 07:56:46 ntpd[3777]: Listen and drop on 1 v4wildcard 0.0.0.0:123
13 Jan 07:56:46 ntpd[3777]: Listen normally on 2 lo 127.0.0.1:123
13 Jan 07:56:46 ntpd[3777]: Listen normally on 3 wlan0 10.0.0.16:123
13 Jan 07:56:46 ntpd[3777]: Listen normally on 4 lo [::1]:123
13 Jan 07:56:46 ntpd[3777]: Listen normally on 5 wlan0 [fe80::ba27:ebff:fe9c:3f84%2]:123
13 Jan 07:56:46 ntpd[3777]: Listening on routing socket on fd #22 for interface updates

Time is still not synced. From a different ssh session:

root@soundBug:~# date
Sat 13 Jan 07:57:53 GMT 2018

Final output from ntpd -gq when I ctrl-c'd out of it:

^C13 Jan 08:01:42 ntpd[3777]: ntpd exiting on signal 2 (Interrupt)
13 Jan 08:01:42 ntpd[3777]: 27.124.125.252 local addr 10.0.0.16 -> <null>
13 Jan 08:01:42 ntpd[3777]: 144.48.166.166 local addr 10.0.0.16 -> <null>
13 Jan 08:01:42 ntpd[3777]: 129.250.35.251 local addr 10.0.0.16 -> <null>
13 Jan 08:01:42 ntpd[3777]: 27.124.125.251 local addr 10.0.0.16 -> <null>

Fourdee commented 6 years ago

@infinitejones

Thanks.

Can we please see results from:

route
ifconfig

And also home router make/model (if known)?

MichaIng commented 6 years ago

@midwan @infinitejones @Fourdee Would be also interesting if:

disabling IPv6 (via dietpi-config) does change something, at least in case your local network does not necessarily depend on it
switching to systemd-timesyncd has same issues: dietpi-config > advanced > time sync mode > deamon

infinitejones commented 6 years ago

tl;dr: switching to daemon+drift appears to have worked.

However when rebooting, it still needs 10-15 attempts to get a response from whatever server it's soliciting, ie. Waiting for completion of systemd-timesyncd gets up to about 10-15/30.

I'd already generated the output to route, ifconfig etc by the time I tried daemon+drift, so for the sake of completeness, here it is:

root@soundBug:~# route
Kernel IP routing table
Destination     Gateway         Genmask         Flags Metric Ref    Use Iface
default         10.0.0.1        0.0.0.0         UG    0      0        0 wlan0
10.0.0.0        0.0.0.0         255.255.255.0   U     0      0        0 wlan0
root@soundBug:~# ifconfig
lo: flags=73<UP,LOOPBACK,RUNNING>  mtu 65536
        inet 127.0.0.1  netmask 255.0.0.0
        loop  txqueuelen 1  (Local Loopback)
        RX packets 0  bytes 0 (0.0 B)
        RX errors 0  dropped 0  overruns 0  frame 0
        TX packets 0  bytes 0 (0.0 B)
        TX errors 0  dropped 0 overruns 0  carrier 0  collisions 0

wlan0: flags=4163<UP,BROADCAST,RUNNING,MULTICAST>  mtu 1500
        inet 10.0.0.16  netmask 255.255.255.0  broadcast 10.0.0.255
        ether b8:27:eb:9c:3f:84  txqueuelen 1000  (Ethernet)
        RX packets 170  bytes 12382 (12.0 KiB)
        RX errors 0  dropped 0  overruns 0  frame 0
        TX packets 137  bytes 26534 (25.9 KiB)
        TX errors 0  dropped 0 overruns 0  carrier 0  collisions 0

Gateway IP is correct (10.0.0.1). The modem/router is a Sagemcom F@st5535, which is the standard device provided by our main ISP here in Australia. The device hasn't changed since the last time ntpd worked for Dietpi, which was before v6 was released (the "old" v159).

ntpd -gq works fine on my Mac connected to the same network.

wuxmedia commented 6 years ago

not sure it's useful but I had the same thing until I edited the /etc/ntp.conf with nano - it had a bunch of /@?@? in the file just before the server list, I deleted those and everything ran normally... I have of course deleted the file, no idea if it was me that added them - or it was there already (I did look at the file fairly sure I didn't spam it and save it )

Fourdee commented 6 years ago

Ok, will mark this as closed for now, should be resolved with v6.9 and switch to SystemD timesyncd by default: https://github.com/Fourdee/DietPi/pull/1628

However, should users still experience this past v6.9, please reopen and we'll restart investigations.

MichaIng / DietPi

NTPD | Time to sync exceeds acceptable levels #1445

Creating a bug report/issue:

Required Information:

Additional Information (if applicable):

Expected behaviour:

Actual behaviour:

Steps to reproduce:

Did you submit a dietpi-bugreport?

Extra details:

Additional logs:

Did you submit a `dietpi-bugreport`?