You are not logged in.
- Topics: Active | Unanswered
#1 2015-04-20 16:20:42
- Enverex
- Member
- From: UK
- Registered: 2007-06-13
- Posts: 159
- Website
NTPd Doesn't Work Unless Ran as Root
I noticed some clock skew on my server today and it seems that NTPd isn't working. There are no errors in the logs, but it's drifting. A check of "ntpq -p" says "No association ID's returned" which shows it's not connecting out to anywhere.
Running it via the command line shows something's going rather wrong:
ntpd -u ntp:ntp -g -d
20 Apr 16:57:21 ntpd[12154]: ntpd 4.2.8p2@1.3265-o Tue Apr 7 19:08:30 UTC 2015 (1): Starting
20 Apr 16:57:21 ntpd[12154]: Command line: ntpd -u ntp:ntp -g -d
20 Apr 16:57:21 ntpd[12154]: proto: precision = 0.104 usec (-23)
Finished Parsing!!
move_fd: estimated max descriptors: 1024, initial socket boundary: 16
20 Apr 16:57:21 ntpd[12154]: Listen and drop on 0 v4wildcard 0.0.0.0:123
20 Apr 16:57:21 ntpd[12154]: Listen normally on 1 lo 127.0.0.1:123
restrict: op 1 addr 127.0.0.1 mask 255.255.255.255 mflags 00003000 flags 00000001
20 Apr 16:57:21 ntpd[12154]: Listen normally on 2 eth0 10.0.0.2:123
restrict: op 1 addr 10.0.0.2 mask 255.255.255.255 mflags 00003000 flags 00000001
20 Apr 16:57:21 ntpd[12154]: Listening on routing socket on fd #19 for interface updates
restrict: op 1 addr 0.0.0.0 mask 0.0.0.0 mflags 00000000 flags 000005f0
restrict: op 1 addr :: mask :: mflags 00000000 flags 000005f0
restrict: op 1 addr 127.0.0.1 mask 255.255.255.255 mflags 00000000 flags 00000000
restrict: op 1 addr 10.0.0.0 mask 255.255.255.0 mflags 00000000 flags 00000000
event at 0 0.0.0.0 c01d 0d kern kernel time sync enabled
event at 0 0.0.0.0 c012 02 freq_set kernel 17.978 PPM
event at 0 0.0.0.0 c016 06 restart
intres: EAI_SYSTEM errno 11 (Resource temporarily unavailable) means try again, right?
intres: EAI_SYSTEM errno 11 (Resource temporarily unavailable) means try again, right?
intres: EAI_SYSTEM errno 11 (Resource temporarily unavailable) means try again, right?
intres: EAI_SYSTEM errno 11 (Resource temporarily unavailable) means try again, right?
intres: EAI_SYSTEM errno 11 (Resource temporarily unavailable) means try again, right?
intres: EAI_SYSTEM errno 11 (Resource temporarily unavailable) means try again, right?
intres: EAI_SYSTEM errno 11 (Resource temporarily unavailable) means try again, right?
intres: EAI_SYSTEM errno 11 (Resource temporarily unavailable) means try again, right?
intres: EAI_SYSTEM errno 11 (Resource temporarily unavailable) means try again, right?
intres: EAI_SYSTEM errno 11 (Resource temporarily unavailable) means try again, right?
intres: EAI_SYSTEM errno 11 (Resource temporarily unavailable) means try again, right?
sleep until 16:57:24 scheduled at 16:57:22 (>= 01:00:00)
select() returned -1: Interrupted system call
auth_agekeys: at 1 keys 0 expired 0
select() returned -1: Interrupted system call
intres: EAI_SYSTEM errno 11 (Resource temporarily unavailable) means try again, right?
intres: EAI_SYSTEM errno 11 (Resource temporarily unavailable) means try again, right?
intres: EAI_SYSTEM errno 11 (Resource temporarily unavailable) means try again, right?
intres: EAI_SYSTEM errno 11 (Resource temporarily unavailable) means try again, right?
intres: EAI_SYSTEM errno 11 (Resource temporarily unavailable) means try again, right?
intres: EAI_SYSTEM errno 11 (Resource temporarily unavailable) means try again, right?
intres: EAI_SYSTEM errno 11 (Resource temporarily unavailable) means try again, right?
intres: EAI_SYSTEM errno 11 (Resource temporarily unavailable) means try again, right?
intres: EAI_SYSTEM errno 11 (Resource temporarily unavailable) means try again, right?
intres: EAI_SYSTEM errno 11 (Resource temporarily unavailable) means try again, right?
intres: EAI_SYSTEM errno 11 (Resource temporarily unavailable) means try again, right?
intres: EAI_SYSTEM errno 11 (Resource temporarily unavailable) means try again, right?
sleep until 16:57:28 scheduled at 16:57:24 (>= 01:00:00)
select() returned -1: Interrupted system call
select() returned -1: Interrupted system call
select() returned -1: Interrupted system call
select() returned -1: Interrupted system call
intres: EAI_SYSTEM errno 11 (Resource temporarily unavailable) means try again, right?
intres: EAI_SYSTEM errno 11 (Resource temporarily unavailable) means try again, right?
intres: EAI_SYSTEM errno 11 (Resource temporarily unavailable) means try again, right?
intres: EAI_SYSTEM errno 11 (Resource temporarily unavailable) means try again, right?
intres: EAI_SYSTEM errno 11 (Resource temporarily unavailable) means try again, right?
intres: EAI_SYSTEM errno 11 (Resource temporarily unavailable) means try again, right?
intres: EAI_SYSTEM errno 11 (Resource temporarily unavailable) means try again, right?
intres: EAI_SYSTEM errno 11 (Resource temporarily unavailable) means try again, right?
intres: EAI_SYSTEM errno 11 (Resource temporarily unavailable) means try again, right?
intres: EAI_SYSTEM errno 11 (Resource temporarily unavailable) means try again, right?
intres: EAI_SYSTEM errno 11 (Resource temporarily unavailable) means try again, right?
sleep until 16:57:36 scheduled at 16:57:28 (>= 01:00:00)
intres: EAI_SYSTEM errno 11 (Resource temporarily unavailable) means try again, right?
select() returned -1: Interrupted system call
select() returned -1: Interrupted system call
select() returned -1: Interrupted system call
select() returned -1: Interrupted system call
select() returned -1: Interrupted system call
select() returned -1: Interrupted system call
select() returned -1: Interrupted system call
select() returned -1: Interrupted system call
intres: EAI_SYSTEM errno 11 (Resource temporarily unavailable) means try again, right?
intres: EAI_SYSTEM errno 11 (Resource temporarily unavailable) means try again, right?
intres: EAI_SYSTEM errno 11 (Resource temporarily unavailable) means try again, right?
intres: EAI_SYSTEM errno 11 (Resource temporarily unavailable) means try again, right?
intres: EAI_SYSTEM errno 11 (Resource temporarily unavailable) means try again, right?
intres: EAI_SYSTEM errno 11 (Resource temporarily unavailable) means try again, right?
intres: EAI_SYSTEM errno 11 (Resource temporarily unavailable) means try again, right?
intres: EAI_SYSTEM errno 11 (Resource temporarily unavailable) means try again, right?
intres: EAI_SYSTEM errno 11 (Resource temporarily unavailable) means try again, right?
intres: EAI_SYSTEM errno 11 (Resource temporarily unavailable) means try again, right?
intres: EAI_SYSTEM errno 11 (Resource temporarily unavailable) means try again, right?
sleep until 16:57:52 scheduled at 16:57:36 (>= 01:00:00)
intres: EAI_SYSTEM errno 11 (Resource temporarily unavailable) means try again, right?
select() returned -1: Interrupted system callI can't see why this is happening though and the error message itself isn't too specific. Increasing debugging results in this:
ntpd -u ntp:ntp -g -dd
20 Apr 17:18:05 ntpd[1173]: ntpd 4.2.8p2@1.3265-o Tue Apr 7 19:08:30 UTC 2015 (1): Starting
20 Apr 17:18:05 ntpd[1173]: Command line: ntpd -u ntp:ntp -g -dd
ntp_rlimit: STACK: 50 4k pages
ntp_rlimit: MEMLOCK: 32 MB
20 Apr 17:18:05 ntpd[1173]: set_process_priority: Leave priority alone: priority_done is <2>
20 Apr 17:18:05 ntpd[1173]: proto: precision = 0.103 usec (-23)
Finished Parsing!!
create_sockets(123)
move_fd: estimated max descriptors: 1024, initial socket boundary: 16
20 Apr 17:18:05 ntpd[1173]: Listen and drop on 0 v4wildcard 0.0.0.0:123
created interface #0: fd=16, bfd=-1, name=v4wildcard, flags=0x89, ifindex=0, sin=0.0.0.0, bcast=0.0.0.0, mask=255.255.255.255, Disabled:
create_interface(127.0.0.1#123)
20 Apr 17:18:05 ntpd[1173]: Listen normally on 1 lo 127.0.0.1:123
restrict: op 1 addr 127.0.0.1 mask 255.255.255.255 mflags 00003000 flags 00000001
created interface #1: fd=17, bfd=-1, name=lo, flags=0x5, ifindex=1, sin=127.0.0.1, mask=255.0.0.0, Enabled:
create_interface(10.0.0.2#123)
20 Apr 17:18:05 ntpd[1173]: Listen normally on 2 eth0 10.0.0.2:123
restrict: op 1 addr 10.0.0.2 mask 255.255.255.255 mflags 00003000 flags 00000001
created interface #2: fd=18, bfd=-1, name=eth0, flags=0x19, ifindex=2, sin=10.0.0.2, bcast=10.0.0.255, mask=255.255.255.0, Enabled:
create_sockets: Total interfaces = 3
20 Apr 17:18:05 ntpd[1173]: Listening on routing socket on fd #19 for interface updates
restrict: op 1 addr 0.0.0.0 mask 0.0.0.0 mflags 00000000 flags 000005f0
restrict: op 1 addr :: mask :: mflags 00000000 flags 000005f0
getnetnum given 127.0.0.1, got 127.0.0.1
restrict: op 1 addr 127.0.0.1 mask 255.255.255.255 mflags 00000000 flags 00000000
getnetnum given 10.0.0.0, got 10.0.0.0
getnetnum given 255.255.255.0, got 255.255.255.0
restrict: op 1 addr 10.0.0.0 mask 255.255.255.0 mflags 00000000 flags 00000000
loop_config: item 12 freq 17.978000
blocking_getaddrinfo given node 0.uk.pool.ntp.org serv ntp fam 0 flags 0
loop_config: item 1 freq 0.000000
event at 0 0.0.0.0 c01d 0d kern kernel time sync enabled
event at 0 0.0.0.0 c012 02 freq_set kernel 17.978 PPM
local_clock: mu 0 state 2 poll 3 count 0
event at 0 0.0.0.0 c016 06 restart
blocking_getaddrinfo given node 1.uk.pool.ntp.org serv ntp fam 0 flags 0
blocking_getaddrinfo given node 2.uk.pool.ntp.org serv ntp fam 0 flags 0
intres: resolver returned: Name or service not known (-2), retrying
intres: EAI_SYSTEM errno 11 (Resource temporarily unavailable) means try again, right?
intres: resolver returned: System error (-11), retrying
intres: EAI_SYSTEM errno 11 (Resource temporarily unavailable) means try again, right?
intres: resolver returned: System error (-11), retrying
blocking_getaddrinfo given node 3.uk.pool.ntp.org serv ntp fam 0 flags 0
intres: EAI_SYSTEM errno 11 (Resource temporarily unavailable) means try again, right?
intres: resolver returned: System error (-11), retrying
sleep until 17:18:07 scheduled at 17:18:05 (>= 01:00:00)
select() returned -1: Interrupted system call
auth_agekeys: at 1 keys 0 expired 0
select() returned -1: Interrupted system call
timer: interface update
blocking_getaddrinfo given node 0.uk.pool.ntp.org serv ntp fam 0 flags 0
blocking_getaddrinfo given node 1.uk.pool.ntp.org serv ntp fam 0 flags 0
intres: EAI_SYSTEM errno 11 (Resource temporarily unavailable) means try again, right?
intres: resolver returned: System error (-11), retrying
blocking_getaddrinfo given node 2.uk.pool.ntp.org serv ntp fam 0 flags 0
intres: EAI_SYSTEM errno 11 (Resource temporarily unavailable) means try again, right?
intres: resolver returned: System error (-11), retrying
blocking_getaddrinfo given node 3.uk.pool.ntp.org serv ntp fam 0 flags 0
intres: EAI_SYSTEM errno 11 (Resource temporarily unavailable) means try again, right?
intres: resolver returned: System error (-11), retrying
sleep until 17:18:11 scheduled at 17:18:07 (>= 01:00:00)
intres: EAI_SYSTEM errno 11 (Resource temporarily unavailable) means try again, right?
intres: resolver returned: System error (-11), retrying
select() returned -1: Interrupted system call
select() returned -1: Interrupted system call
select() returned -1: Interrupted system call
select() returned -1: Interrupted system call
blocking_getaddrinfo given node 0.uk.pool.ntp.org serv ntp fam 0 flags 0
blocking_getaddrinfo given node 1.uk.pool.ntp.org serv ntp fam 0 flags 0
intres: EAI_SYSTEM errno 11 (Resource temporarily unavailable) means try again, right?
intres: resolver returned: System error (-11), retrying
blocking_getaddrinfo given node 2.uk.pool.ntp.org serv ntp fam 0 flags 0
intres: EAI_SYSTEM errno 11 (Resource temporarily unavailable) means try again, right?
intres: resolver returned: System error (-11), retrying
blocking_getaddrinfo given node 3.uk.pool.ntp.org serv ntp fam 0 flags 0
intres: EAI_SYSTEM errno 11 (Resource temporarily unavailable) means try again, right?
intres: resolver returned: System error (-11), retrying
intres: EAI_SYSTEM errno 11 (Resource temporarily unavailable) means try again, right?
intres: resolver returned: System error (-11), retrying
sleep until 17:18:19 scheduled at 17:18:11 (>= 01:00:00)
select() returned -1: Interrupted system call
select() returned -1: Interrupted system callBut I still can't tell what it can't do or why. But, if I run it as root, it works fine:
ntpd -g -d
20 Apr 17:19:13 ntpd[1200]: ntpd 4.2.8p2@1.3265-o Tue Apr 7 19:08:30 UTC 2015 (1): Starting
20 Apr 17:19:13 ntpd[1200]: Command line: ntpd -g -d
20 Apr 17:19:13 ntpd[1200]: proto: precision = 0.105 usec (-23)
Finished Parsing!!
move_fd: estimated max descriptors: 1024, initial socket boundary: 16
20 Apr 17:19:13 ntpd[1200]: Listen and drop on 0 v4wildcard 0.0.0.0:123
20 Apr 17:19:13 ntpd[1200]: Listen normally on 1 lo 127.0.0.1:123
restrict: op 1 addr 127.0.0.1 mask 255.255.255.255 mflags 00003000 flags 00000001
20 Apr 17:19:13 ntpd[1200]: Listen normally on 2 eth0 10.0.0.2:123
restrict: op 1 addr 10.0.0.2 mask 255.255.255.255 mflags 00003000 flags 00000001
20 Apr 17:19:13 ntpd[1200]: Listening on routing socket on fd #19 for interface updates
restrict: op 1 addr 0.0.0.0 mask 0.0.0.0 mflags 00000000 flags 000005f0
restrict: op 1 addr :: mask :: mflags 00000000 flags 000005f0
restrict: op 1 addr 127.0.0.1 mask 255.255.255.255 mflags 00000000 flags 00000000
restrict: op 1 addr 10.0.0.0 mask 255.255.255.0 mflags 00000000 flags 00000000
event at 0 0.0.0.0 c01d 0d kern kernel time sync enabled
event at 0 0.0.0.0 c012 02 freq_set kernel 17.978 PPM
event at 0 0.0.0.0 c016 06 restart
peer_name_resolved(0.uk.pool.ntp.org) rescode 0
key_expire: at 0 associd 63796
peer_clear: at 0 next 3 associd 63796 refid INIT
event at 0 217.114.59.3 8011 81 mobilize assoc 63796
newpeer: 10.0.0.2->217.114.59.3 mode 3 vers 4 poll 6 10 flags 0x1 0x1 ttl 0 key 00000000
select() returned -1: Interrupted system call
auth_agekeys: at 1 keys 0 expired 0
peer_name_resolved(1.uk.pool.ntp.org) rescode 0
key_expire: at 1 associd 63797
peer_clear: at 1 next 1 associd 63797 refid INIT
event at 1 82.219.4.30 8011 81 mobilize assoc 63797
newpeer: 10.0.0.2->82.219.4.30 mode 3 vers 4 poll 6 10 flags 0x1 0x1 ttl 0 key 00000000
peer_name_resolved(2.uk.pool.ntp.org) rescode 0
key_expire: at 1 associd 63798
peer_clear: at 1 next 4 associd 63798 refid INIT
event at 1 176.74.25.228 8011 81 mobilize assoc 63798
newpeer: 10.0.0.2->176.74.25.228 mode 3 vers 4 poll 6 10 flags 0x1 0x1 ttl 0 key 00000000
select() returned -1: Interrupted system call
transmit: at 2 10.0.0.2->82.219.4.30 mode 3 len 48
receive: at 2 10.0.0.2<-82.219.4.30 mode 4 len 48
event at 2 82.219.4.30 8024 84 reachable
clock_filter: n 1 off -0.003430 del 0.047655 dsp 7.937501 jit 0.000000
select: combine offset -0.003430446 jitter 0.000000000
event at 2 82.219.4.30 903a 8a sys_peer
clock_update: at 2 sample 2 associd 63797
event at 2 0.0.0.0 c615 05 clock_sync
local_clock: offset -0.003430446 jit 0.001212846 freq 17.978 stab 0.000 poll 6
peer_name_resolved(3.uk.pool.ntp.org) rescode 0
key_expire: at 2 associd 63799
peer_clear: at 2 next 5 associd 63799 refid INIT
event at 2 178.18.118.14 8011 81 mobilize assoc 63799
newpeer: 10.0.0.2->178.18.118.14 mode 3 vers 4 poll 6 10 flags 0x1 0x1 ttl 0 key 00000000
select() returned -1: Interrupted system call
select: combine offset -0.003430446 jitter 0.000000000
transmit: at 3 10.0.0.2->217.114.59.3 mode 3 len 48
receive: at 3 10.0.0.2<-217.114.59.3 mode 4 len 48
event at 3 217.114.59.3 8024 84 reachable
clock_filter: n 1 off -0.007498 del 0.058837 dsp 7.937501 jit 0.000000
select: combine offset -0.005567560 jitter 0.004938812
event at 3 217.114.59.3 903a 8a sys_peer
clock_update: at 3 sample 3 associd 63796
local_clock: offset -0.005567560 jit 0.001363095 freq 17.978 stab 0.000 poll 6
select() returned -1: Interrupted system call
select: combine offset -0.005567530 jitter 0.004938824
transmit: at 4 10.0.0.2->176.74.25.228 mode 3 len 48
receive: at 4 10.0.0.2<-176.74.25.228 mode 4 len 48
event at 4 176.74.25.228 8024 84 reachable
clock_filter: n 1 off -0.013765 del 0.060631 dsp 7.937501 jit 0.000000
select: combine offset -0.007479089 jitter 0.006564200... and "ntpq -p" confirms it's working:
ntpq -p
remote refid st t when poll reach delay offset jitter
==============================================================================
*ntp0.cis.strath 193.62.22.90 2 u 6 64 1 27.928 -1.486 0.000
+mail1.ugh.no 104.232.5.3 3 u 9 64 1 16.446 -1.857 0.000
-resntp-a-vip.lo 178.18.118.14 3 u 9 64 1 13.054 -2.331 0.000
+head1.mirror.ca 195.66.241.2 2 u 8 64 1 19.656 -1.828 0.000I've Googled this and seen a few similar issues, but no-one mentioning an actual resolution. Anyone have any ideas?
Offline