Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

NTPD | Time to sync exceeds acceptable levels #1445

Closed
midwan opened this issue Jan 31, 2018 · 31 comments
Closed

NTPD | Time to sync exceeds acceptable levels #1445

midwan opened this issue Jan 31, 2018 · 31 comments
Milestone

Comments

@midwan
Copy link

midwan commented Jan 31, 2018

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:
image

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?

No

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
Copy link
Author

midwan commented Jan 31, 2018

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
Copy link
Author

midwan commented Jan 31, 2018

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 midwan closed this as completed Jan 31, 2018
@midwan midwan reopened this Jan 31, 2018
@midwan
Copy link
Author

midwan commented Jan 31, 2018

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 Fourdee changed the title DietPi-Software | Pi-hole: Fails to install? NTPD | DietPi-Software | Pi-hole: Fails to install? Feb 1, 2018
@Fourdee Fourdee added this to the v6.2 milestone Feb 1, 2018
@Fourdee
Copy link
Collaborator

Fourdee commented Feb 1, 2018

@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
Copy link
Collaborator

Fourdee commented Feb 1, 2018

@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
Copy link
Author

midwan commented Feb 1, 2018

@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
Copy link
Collaborator

Fourdee commented Feb 1, 2018

@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 [email protected] 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
Copy link
Author

midwan commented Feb 1, 2018

root@DietPi:~# killall -w ntpd
ntpd: no process found
root@DietPi:~# ntpd -g -q
 1 Feb 18:15:34 ntpd[16308]: ntpd [email protected] 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
Copy link
Contributor

k-plan commented Feb 1, 2018

@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 [email protected] 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
Copy link
Collaborator

Fourdee commented Feb 1, 2018

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 😉 ): Fourdee@cb2915a

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
Copy link
Collaborator

Fourdee commented Feb 1, 2018

@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

@Fourdee Fourdee changed the title NTPD | DietPi-Software | Pi-hole: Fails to install? NTPD | Time to sync exceeds acceptable levels Feb 1, 2018
@midwan
Copy link
Author

midwan commented Feb 1, 2018

@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 [email protected] 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
Copy link
Author

midwan commented Feb 1, 2018

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 [email protected] 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
Copy link
Contributor

k-plan commented Feb 2, 2018

@midwan

SBC Device | RPi Zero (armv6l)

What did you use on RPi-Zero?

  • USB Ethernet dongle ? Typ?

  • USB WiFi dongle ? Typ?

@midwan
Copy link
Author

midwan commented Feb 2, 2018

@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
Copy link
Collaborator

Fourdee commented Feb 2, 2018

@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
Copy link
Author

midwan commented Feb 2, 2018

@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
Copy link
Contributor

k-plan commented Feb 2, 2018

@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
Copy link
Author

midwan commented Feb 2, 2018

@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 [email protected] 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
Copy link
Collaborator

Fourdee commented Feb 2, 2018

@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
Copy link
Contributor

k-plan commented Feb 2, 2018

@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 message NTP 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 [email protected] 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
Copy link
Author

midwan commented Feb 2, 2018

@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
Copy link
Contributor

k-plan commented Feb 2, 2018

@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
Copy link

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 [email protected] 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 [email protected] 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
Copy link
Collaborator

Fourdee commented Feb 12, 2018

@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
Copy link

infinitejones commented Feb 12, 2018

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 [email protected] 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
Copy link
Collaborator

Fourdee commented Feb 12, 2018

@infinitejones

Thanks.

Can we please see results from:

route
ifconfig

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

@MichaIng
Copy link
Owner

@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
Copy link

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.

@Fourdee Fourdee modified the milestones: v6.2, v6.3 Feb 18, 2018
@Fourdee Fourdee modified the milestones: v6.3, v6.4, v6.5 Mar 7, 2018
@wuxmedia
Copy link

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 Fourdee modified the milestones: v6.5, v6.6, v6.7 Mar 28, 2018
@Fourdee Fourdee modified the milestones: v6.7, v6.8 Apr 15, 2018
@Fourdee Fourdee modified the milestones: v6.8, v6.9 May 13, 2018
@Fourdee
Copy link
Collaborator

Fourdee commented May 21, 2018

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.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

6 participants