Bug 1548416

The only changes between ntp-4.2.6p5-10.el6_8.2.x86_64 and ntp-4.2.6p5-12.el6_9.2.x86_64 that I think could be relevant here is a fix for the client multicast mode and a fix for parsing invalid configuration (mode/ttl).

Could you please attach your configuration file?

driftfile /var/lib/ntp/drift
restrict default kod nomodify notrap nopeer noquery
restrict 127.0.0.1

statsdir /var/log/ntpstats/
logfile /var/log/ntpstats/ntpd.log

tos orphan 4
broadcast 239.0.1.1 key 1 ttl 1        # multicast server
multicastclient 239.0.1.1              # multicast client

server 127.127.28.0 minpoll 4 maxpoll 4
fudge 127.127.28.0 refid NEMA

server 127.127.28.1 minpoll 4 maxpoll 4 prefer
fudge 127.127.28.1 refid PPS

keys /etc/ntp/keys
trustedkey 1

The following is code from our time adjustment service:

    shm[input]->mode = 1;
    shm[input]->valid = 0;

    // tells compiler ????
    __asm__ __volatile__("":: : "memory");

    shm[input]->leap = LEAP;
    shm[input]->precision = working_precision;
    shm[input]->clockTimeStampSec = (time_t) dagr_time->tv_sec;
    shm[input]->clockTimeStampUSec = (int) dagr_time->tv_usec;
    shm[input]->receiveTimeStampSec = (time_t) local->tv_sec;
    shm[input]->receiveTimeStampUSec = (int) local->tv_usec;

    __asm__ __volatile__("":: : "memory");

    shm[input]->count++;
    shm[input]->valid = 1;

Ok, it seems 10.4.210.2 and 10.4.2.2 are multicast clients of one another.

ntp-4.2.6p5-10.el6_8.2.x86_64 has a bug which causes multicast clients to ignore packets from multicast servers, which was fixed in ntp-4.2.6p5-12.el6_9.2.x86_64.

In your case it seems the observed behavior is opposite of what would be expected. Can you please confirm that you see this issue when both sides have ntp-4.2.6p5-12.el6_9.2.x86_64 installed?

It might help if we could see debug output of ntpd when started in terminal with -D8.

Script started on Mon 26 Feb 2018 05:54:23 PM UTC
^[]0;fsr@medium-6-sib:/etc/init.d^G^[[?1034h[root@medium-6-sib init.d]# /etc/ini^H^[[K^H^[[K^H^[[K^H^[[K^H^[[K^H^[[K^H^[[K^H^[[K^G^G^G^Gsr^H^[[Kervice ntpd restart^M
Shutting down ntpd: ^[[60G[^[[0;32m  OK  ^[[0;39m]^M^M
Starting ntpd: ntpd 4.2.6p5 Mon Dec 18 14:03:55 UTC 2017 (1)^M
filegen_register(peerstats, 0x7f8de4275ea0)^M
adding new filegen^M
filegen_register(loopstats, 0x7f8de4275ee0)^M
adding new filegen^M
filegen_register(clockstats, 0x7f8de4275f20)^M
adding new filegen^M
filegen_register(rawstats, 0x7f8de4275f60)^M
adding new filegen^M
filegen_register(sysstats, 0x7f8de4275fa0)^M
adding new filegen^M
filegen_register(protostats, 0x7f8de4275fe0)^M
adding new filegen^M
filegen_register(cryptostats, 0x7f8de4275e60)^M
adding new filegen^M
26 Feb 17:54:42 ntpd[1499]: set_process_priority: Leave priority alone: priority_done is <2>^M
26 Feb 17:54:42 ntpd[1499]: proto: precision = 0.099 usec^M
loop_config: item 1 freq 0.000000^M
26 Feb 17:54:42 ntpd[1499]: 0.0.0.0 c01d 0d kern kernel time sync enabled^M
event at 0 0.0.0.0 c01d 0d kern kernel time sync enabled^M
Starting parse^M
Entering state 0^M
Reading a token: yylex: lexeme 'driftfile' -> T_Driftfile^M
Next token is token T_Driftfile ()^M
Shifting token T_Driftfile ()^M
Entering state 11^M
Reading a token: yylex: lexeme '/var/lib/ntp/drift' -> T_String^M
Next token is token T_String ()^M
Shifting token T_String ()^M
Entering state 96^M
Reading a token:        <end of command>^M
Next token is token T_EOC ()^M
Reducing stack by rule 208 (line 1014):^M
   $1 = token T_String ()^M
-> $$ = nterm drift_parm ()^M
Stack now 0 11^M
Entering state 97^M
Reducing stack by rule 193 (line 977):^M
   $1 = token T_Driftfile ()^M
   $2 = nterm drift_parm ()^M
-> $$ = nterm miscellaneous_command ()^M
...
...
sent = 0^M
notsent = 0^M
ifindex = 0^M
peercnt = 0^M
phase = 1^M
interface_action: lo 127.0.0.1 IPv4 loopback - listen^M
listen interface lo (127.0.0.1) - by nic rules^M
Searching for addr 127.0.0.1 in list of addresses - NOT FOUND^M
create_interface(127.0.0.1#123)^M
set SO_REUSEADDR to on on 0.0.0.0^M
set SO_REUSEADDR to off on 0.0.0.0^M
setsockopt SO_TIMESTAMP enabled on fd 17 address 127.0.0.1^M
bind(17) AF_INET, addr 127.0.0.1%0#123, flags 0x5^M
flags for fd 17: 0x802^M
26 Feb 17:54:42 ntpd[1499]: Listen normally on 1 lo 127.0.0.1 UDP 123^M
restrict: op 1 addr 127.0.0.1 mask 255.255.255.255 mflags 00003000 flags 00000001^M
Searching for addr 127.0.0.1 in list of addresses - NOT FOUND^M
Added addr 127.0.0.1 to list of addresses^M
created interface #1: fd=17, bfd=-1, name=lo, flags=0x5, ifindex=0, sin=127.0.0.1, mask=255.0.0.0, Enabled:^M
Dumping interface: 0x7f8de55f02b0^M
fd = 17^M
bfd = -1^M
sin = 127.0.0.1,^M
0200007b 7f000001 00000000 00000000 00000000 00000000 00000000 ^M
bcast = 0.0.0.0,^M
0200007b 00000000 00000000 00000000 00000000 00000000 00000000 ^M
mask = 255.0.0.0,^M
0200007b ff000000 00000000 00000000 00000000 00000000 00000000 ^M
name = lo^M
flags = 0x00000005^M
last_ttl = 0^M
addr_refid = 0100007f^M
num_mcast = 0^M
received = 0^M
...
...
sent = 0^M
notsent = 0^M
ifindex = 0^M
peercnt = 0^M
phase = 1^M
peer_refresh_interface: 127.0.0.1->127.127.28.0 mode 3 vers 4 poll 4 4 flags 0x9 0x1 ttl 0 key 00000000: new interface: fd=17, bfd=-1, name=lo, flags=0x5, ifindex=0, sin=127.0.0.1, mask=255.0.0.0^M
peer_refresh_interface: 127.0.0.1->127.127.28.1 mode 3 vers 4 poll 4 4 flags 0x29 0x1 ttl 0 key 00000000: new interface: fd=17, bfd=-1, name=lo, flags=0x5, ifindex=0, sin=127.0.0.1, mask=255.0.0.0^M
Finding broadcast/multicast interface for addr 239.0.1.1 in list of addresses^M
Finding interface for addr 239.0.1.1 in list of addresses^M
findlocalinterface: kernel maps 239.0.1.1 to 10.4.6.2^M
Searching for addr 10.4.6.2 in list of addresses - FOUND^M
Easily found bcast-/mcast- interface index #2 eth0.10^M
Found *-cast interface 10.4.6.2 for address 239.0.1.1^M
peer_refresh_interface: 10.4.6.2->239.0.1.1 mode 5 vers 4 poll 6 10 flags 0x1 0x2 ttl 1 key 00000001: new interface: fd=18, bfd=-1, name=eth0.10, flags=0x19, ifindex=0, sin=10.4.6.2, bcast=10.4.6.255, mask=255.255.255.0^M
setting SO_REUSEADDR on multicast.1.1 to on^M
setting SO_REUSEADDR on eth0.172.20.2 to on^M
setting SO_REUSEADDR on eth0.10.6.2 to on^M
setting SO_REUSEADDR on lo.0.1 to on^M
Broadcast enabled on socket 22 for address 172.20.20.255^M
set SO_REUSEADDR to on on 0.0.0.0^M
set SO_REUSEADDR to off on 0.0.0.0^M
setsockopt SO_TIMESTAMP enabled on fd 22 address 172.20.20.255^M
bind(22) AF_INET, addr 172.20.20.255%0#123, flags 0x39^M
flags for fd 22: 0x802^M
26 Feb 17:54:43 ntpd[1499]: io_setbclient: Opened broadcast client on interface #3 eth0.172^M
Broadcast enabled on socket 23 for address 10.4.6.255^M
set SO_REUSEADDR to on on 0.0.0.0^M
set SO_REUSEADDR to off on 0.0.0.0^M
setsockopt SO_TIMESTAMP enabled on fd 23 address 10.4.6.255^M
bind(23) AF_INET, addr 10.4.6.255%0#123, flags 0x39^M
flags for fd 23: 0x802^M
26 Feb 17:54:43 ntpd[1499]: io_setbclient: Opened broadcast client on interface #2 eth0.10^M
setting SO_REUSEADDR on multicast.1.1 to off^M
setting SO_REUSEADDR on eth0.172.20.2 to off^M
setting SO_REUSEADDR on eth0.10.6.2 to off^M
setting SO_REUSEADDR on lo.0.1 to off^M
io_setbclient: Opened broadcast clients^M
timer: timeout 0.998426^M
timer: time elapsed 1^M
26 Feb 17:54:44 ntpd[1499]: select(): nfound=0, error: No such file or directory^M
refclock_transmit: at 2 127.127.28.0^M
refclock_receive: at 2 127.127.28.0^M
event at 2 SHM(0) 8024 84 reachable^M
refclock_sample: n 2 offset 0.000361 disp 0.000000 jitter 0.000005^M
clock_filter: n 1 off 0.000361 del 0.000000 dsp 7.937502 jit 0.000000^M
select: endpoint -1 -7.937141^M
select: endpoint  0 0.000361^M
select: endpoint  1 7.937864^M
select: survivor 127.127.28.0 5.291668^M
...
...
timer: timeout 0.709617^M
timer: time elapsed 1^M
26 Feb 17:55:03 ntpd[1499]: select(): nfound=0, error: Resource temporarily unavailable^M
select: endpoint -1 -3.937247^M
select: endpoint -1 -3.937216^M
select: endpoint -1 -1.381620^M
select: endpoint  0 -0.000103^M
select: endpoint  0 0.000377^M
select: endpoint  0 0.000390^M
select: endpoint  1 1.381414^M
select: endpoint  1 3.937996^M
select: endpoint  1 3.938001^M
select: survivor 127.127.28.1 2.625211^M
select: survivor 127.127.28.0 2.625213^M
select: survivor 10.1.210.2 2.921552^M
select: combine offset 0.000389778 jitter 0.000012278^M
sendpkt(18, dst=10.4.210.2, src=10.4.6.2, ttl=0, len=68)^M
transmit: at 21 10.4.6.2->10.4.210.2 mode 3 keyid 00000001 len 68 index 0^M
poll_update: at 21 10.4.210.2 poll 6 burst 0 retry 2 head 62 early 2 next 65^M
sendpkt(18, dst=10.5.35.2, src=10.4.6.2, ttl=0, len=68)^M
transmit: at 21 10.4.6.2->10.5.35.2 mode 3 keyid 00000001 len 68 index 0^M
poll_update: at 21 10.5.35.2 poll 6 burst 2 retry 0 head 242 early 2 next 2^M
timer: timeout 0.999395^M
timer: time elapsed 0^M
read_network_packet: fd=18 length 68 from 10.4.210.2^M
fetch_timestamp: system network time stamp: 1519667703.267541^M
receive: at 21 10.4.6.2<-10.4.210.2 flags 39 restrict 5d0^M
restrict: interval 1 headway 8 limit 64^M
receive: at 21 10.4.6.2<-10.4.210.2 mode 4 keyid 00000001 len 68 auth 1^M
poll_update: at 21 10.4.210.2 poll 6 burst 5 retry 0 head 62 early 2 next 2^M
event at 21 10.4.210.2 6024 84 reachable^M
clock_filter: n 1 off 0.000197 del 0.002819 dsp 7.937500 jit 0.000000^M
timer: timeout 0.996477^M
timer: time elapsed 0^M
read_network_packet: fd=18 length 68 from 10.5.35.2^M
fetch_timestamp: system network time stamp: 1519667703.269210^M
receive: at 21 10.4.6.2<-10.5.35.2 flags 39 restrict 5d0^M
restrict: interval 2 headway 20 limit 64^M
receive: at 21 10.4.6.2<-10.5.35.2 mode 4 keyid 00000001 len 68 auth 1^M
clock_filter: old sample 6^M
timer: timeout 0.994845^M
timer: time elapsed 1^M
26 Feb 17:55:04 ntpd[1499]: select(): nfound=0, error: Resource temporarily unavailable^M
sendpkt(18, dst=10.2.1.2, src=10.4.6.2, ttl=0, len=68)^M
transmit: at 22 10.4.6.2->10.2.1.2 mode 3 keyid 00000001 len 68 index 0^M
poll_update: at 22 10.2.1.2 poll 6 burst 3 retry 0 head 182 early 2 next 2^M
timer: timeout 0.999516^M
timer: time elapsed 0^M
read_network_packet: fd=18 length 68 from 10.2.1.2^M
fetch_timestamp: system network time stamp: 1519667704.267886^M
receive: at 22 10.4.6.2<-10.2.1.2 flags 39 restrict 5d0^M
restrict: interval 2 headway 16 limit 64^M
receive: at 22 10.4.6.2<-10.2.1.2 mode 4 keyid 00000001 len 68 auth 1^M

Don't know how much I can paste here. Here is from the /var/log/ntpstats/ntpd.log

RESTARTING HERE                                                                                  

26 Feb 17:54:42 ntpd[25657]: ntpd exiting on signal 15
26 Feb 17:54:42 ntpd[1499]: ntp_io: estimated max descriptors: 1024, initial socket boundary: 16
26 Feb 17:54:42 ntpd[1499]: Listen and drop on 0 v4wildcard 0.0.0.0 UDP 123                     
26 Feb 17:54:42 ntpd[1499]: Listen normally on 1 lo 127.0.0.1 UDP 123                           
26 Feb 17:54:42 ntpd[1499]: Listen normally on 2 eth0.10 10.4.6.2 UDP 123                       
26 Feb 17:54:42 ntpd[1499]: Listen normally on 3 eth0.172 172.20.20.2 UDP 123                   
26 Feb 17:54:42 ntpd[1499]: Listening on routing socket on fd #20 for interface updates         
26 Feb 17:54:42 ntpd[1499]: Listen normally on 4 multicast 239.0.1.1 UDP 123                    
26 Feb 17:54:42 ntpd[1499]: Joined 239.0.1.1 socket to multicast group 239.0.1.1                
26 Feb 17:54:42 ntpd[1499]: 0.0.0.0 c016 06 restart                                             
26 Feb 17:54:42 ntpd[1499]: 0.0.0.0 c012 02 freq_set kernel -13.439 PPM                         
26 Feb 17:54:43 ntpd[1499]: select(): nfound=0, error: Bad address                              
26 Feb 17:54:43 ntpd[1499]: io_setbclient: Opened broadcast client on interface #3 eth0.172     
26 Feb 17:54:43 ntpd[1499]: io_setbclient: Opened broadcast client on interface #2 eth0.10      
26 Feb 17:54:44 ntpd[1499]: select(): nfound=0, error: No such file or directory                
26 Feb 17:54:44 ntpd[1499]: 0.0.0.0 0415 05 clock_sync                                          
26 Feb 17:54:45 ntpd[1499]: select(): nfound=0, error: No such file or directory                
26 Feb 17:54:46 ntpd[1499]: select(): nfound=0, error: No such file or directory                
26 Feb 17:54:47 ntpd[1499]: select(): nfound=0, error: No such file or directory                
26 Feb 17:54:48 ntpd[1499]: select(): nfound=0, error: Resource temporarily unavailable         
26 Feb 17:54:49 ntpd[1499]: select(): nfound=0, error: Resource temporarily unavailable         
26 Feb 17:54:50 ntpd[1499]: select(): nfound=0, error: Resource temporarily unavailable         
26 Feb 17:54:51 ntpd[1499]: select(): nfound=0, error: Resource temporarily unavailable         
26 Feb 17:54:52 ntpd[1499]: select(): nfound=0, error: Resource temporarily unavailable         
26 Feb 17:54:53 ntpd[1499]: select(): nfound=0, error: Resource temporarily unavailable         
26 Feb 17:54:54 ntpd[1499]: select(): nfound=0, error: Resource temporarily unavailable         
26 Feb 17:54:55 ntpd[1499]: select(): nfound=0, error: Resource temporarily unavailable         
26 Feb 17:54:56 ntpd[1499]: select(): nfound=0, error: Resource temporarily unavailable         
26 Feb 17:54:57 ntpd[1499]: select(): nfound=0, error: Resource temporarily unavailable         
26 Feb 17:54:58 ntpd[1499]: select(): nfound=0, error: Resource temporarily unavailable         
26 Feb 17:54:59 ntpd[1499]: select(): nfound=0, error: Resource temporarily unavailable         
26 Feb 17:55:00 ntpd[1499]: select(): nfound=0, error: Resource temporarily unavailable         
26 Feb 17:55:01 ntpd[1499]: select(): nfound=0, error: Resource temporarily unavailable         
26 Feb 17:55:02 ntpd[1499]: select(): nfound=0, error: Resource temporarily unavailable

Performed this on 10.4.6.2 with:
[root@medium-6-sib ntpstats]# rpm -qa | grep ntp
ntpdate-4.2.6p5-12.el6_9.2.x86_64
ntp-4.2.6p5-12.el6_9.2.x86_64

[root@medium-6-sib ntpstats]# ntpdc -nc dmpeers
     remote           local      st poll reach  delay   offset    disp
=======================================================================
.127.127.28.0    127.0.0.1        0   16  377 0.00000 -0.000543 0.01894
 10.1.210.2      10.4.6.2         3   64  377 0.00243 -0.005032 0.03065
*127.127.28.1    127.0.0.1        0   16  377 0.00000 -0.000546 0.01651
 10.4.210.2      10.4.6.2         1   64  376 0.00226 -0.000948 0.03081
.10.5.35.2       10.4.6.2         1   64  376 0.00153 -0.000762 0.03070
 239.0.1.1       10.4.6.2        16   64    0 0.00000  0.000000 4.00000
 10.2.1.2        10.4.6.2         2   64  365 0.00310 -0.000539 0.03084
 10.3.210.2      10.4.6.2         3   64  376 0.00049 -0.000211 0.03091
 10.4.7.2        10.4.6.2         2   64  376 0.00146 -0.001207 0.03058
 10.0.0.125      10.4.6.2         2   64  376 0.00101 -0.000674 0.03072
 10.0.0.126      10.4.6.2         3   64  377 0.00114 -0.000796 0.03056
 10.0.7.2        10.4.6.2         2   64  376 0.00131 -0.006339 0.03072
 10.2.210.2      10.4.6.2         2   64  376 0.00394  0.000403 0.03062
 10.5.210.2      10.4.6.2         1   64  376 0.00766 -0.080998 0.03072
 10.3.35.2       10.4.6.2         2   64  376 0.00217 -0.003602 0.03078
 10.1.2.2        10.4.6.2         3   64  376 0.00227 -0.001194 0.03059

Still can't see 10.4.2.2.

On 10.4.2.2:
[root@medium-2-sib etc]# ntpdc -nc dmpeers
     remote           local      st poll reach  delay   offset    disp
=======================================================================
.127.127.28.0    127.0.0.1        0   16  377 0.00000 -0.000136 0.01559
 10.1.210.2      10.4.2.2         3   64  376 0.00226 -0.004718 0.03056
*127.127.28.1    127.0.0.1        0   16  377 0.00000 -0.000110 0.01564
.10.4.210.2      10.4.2.2         1   64  376 0.00340 -0.000087 0.03075
 10.5.35.2       10.4.2.2         1   64  366 0.00000 -0.001115 0.03093
 239.0.1.1       10.4.2.2        16   64    0 0.00000  0.000000 4.00000
 10.2.1.2        10.4.2.2         2   64  376 0.00000 -0.001677 0.03087
 10.3.210.2      10.4.2.2         2   64  377 0.00087 -0.004517 0.03104
 10.4.7.2        10.4.2.2         2   64  376 0.00000 -0.001270 0.03050
 10.0.0.125      10.4.2.2         2   64  377 0.00233  0.000139 0.03081
 10.0.0.126      10.4.2.2         3   64  377 0.00000 -0.001080 0.03062
 10.0.7.2        10.4.2.2         2   64  377 0.00000 -0.005621 0.03093
 10.2.210.2      10.4.2.2         3   64  377 0.00418  0.000693 0.03088
 10.5.210.2      10.4.2.2         1   64  377 0.00325 -0.085724 0.03058
 10.3.35.2       10.4.2.2         2   64  376 0.00000 -0.004363 0.03084
 10.1.2.2        10.4.2.2         3   64  377 0.00000 -0.002060 0.03075

can't see 10.4.6.2

Can you please collect at least 10 minutes of the debug output? We need to see what happens when the packet from the server is received (if it is actually received). You can add the output as an attachment of this bug instead of posting it as a comment.

Created attachment 1401306 [details]
ntpd.log for 10 mins

Thanks for the logs. Unfortunately, they don't show any packets received from 10.4.2.2, so it's still not clear what is going on here.

Could you please downgrade ntp to the older version on 10.4.6.2, repeat the test and post the debug output, so we could see what the differences?

Will do. We have somebody looking at ntp source code changes and the last that I heard there suspicion about a ttl check with some kind of a system max ttl time variable and the thought was maybe the system max ttl time wasn't being set so it was blowing by the check. Just a thought.

Question - Since both 10.4.6.2 and 10.4.2.2 both have ntp 9.2 and they can't see each other but they can see systems that contain the old ntp 8.2 that works(ie, 10.5.35.2) doesn't it make sense that it is the sending as opposed to the receiving that is not working.

That's a very good point and I think you are right that it's related to the sys_maxttl variable.

The fix for CVE-2017-6464 made a change to prevent reading past the sys_ttl array. However, the sys_ttlmax variable is not set correctly when parsing a config file which does not have a ttl directive. In such case it is set to -1, so the default value of 32 (which should be selected by ttl 1 on the broadcast line) from sys_ttl is ignored and some bogus value is used instead.

Can you please try adding the following line to ntp.conf?

ttl 0 32 64 96 128 160 192 224

Upstream bug report:
https://bugs.ntp.org/show_bug.cgi?id=3465

Hooray, yes that fixed it. Thanks.

I'm closing this bug as there is a workaround and RHEL 6 is now in Maintenance Support 2 Phase of the support and maintenance life cycle. The bug #1550637 is a RHEL7 clone of the bug.

*** Bug 1650089 has been marked as a duplicate of this bug. ***