Well, I'm about to give up.
My logs are getting flooded with "Connection refused" messages and I
can't find why, much less how to stop them.
This is a rather oldish RH Linux box with two network cards. One is
connected to the bad world outside via an ADSL router, the other to the
internal network (192.168.x.x). It gets its time from stratum 2 servers
and provides time to the internal network.
I've been running ntp on that box since 2001. In June 2005, I upgraded
to ntp 4.2.0.
Life was beautiful for more than a year until, last week, I suddenly
started getting "Connection refused" messages in syslog.
> Sep 3 04:06:32 gida ntpd[4796]: recvfrom(193.190.230.65) fd=9:
Connection refused
> Sep 3 04:06:32 gida ntpd[4796]: recvfrom(193.190.230.65) fd=9:
Connection refused
> Sep 3 04:07:36 gida ntpd[4796]: recvfrom(193.190.230.65) fd=9:
Connection refused
> Sep 3 04:07:36 gida ntpd[4796]: recvfrom(193.190.230.65) fd=9:
Connection refused
> Sep 3 04:08:40 gida ntpd[4796]: recvfrom(192.168.1.3) fd=9:
Connection refused
> Sep 3 04:08:40 gida ntpd[4796]: recvfrom(192.168.1.3) fd=9:
Connection refused
> Sep 3 04:09:44 gida ntpd[4796]: recvfrom(192.168.1.3) fd=9:
Connection refused
> Sep 3 04:09:44 gida ntpd[4796]: recvfrom(192.168.1.3) fd=9:
Connection refused
I've been getting "Connection refused" before (which is why I upped to
4.2.0 because that shows the failing IP). At the time it turned out that
our friendly ISP had blocked port 123 in the ADSL router. Phoned them to
complain and they opened it again.
This is not the case now, ntpd can reach the outside servers and syncs
and serves the internal network just fine. Also, 'ntpq -p' showed 'reach
377' for all servers, including 193.190.230.65. Besides, fd 9 is the
socket on the ADSL-facing card (192.168.254.2), so packets to/from the
internal 192.168.1.3 have no business going there.
Firewall rules haven't changed in over a month, and in any case, any
rejected UDP/123 packets are supposed to be logged and there is nothing
to be seen.
After 8 hours or so, the critters went away. I hate problems going away
just like that. Fortunately (not!), they came back two days later, on
Sep 5 08:01:15. They left again at 10:58:19, only to reappear the next
day at 08:01:17 and leave again at 11:44:13. Back again next day, Sep 7
00:01:18 and lasted until 09:23 when I stopped ntpd.
This is because I checked the mailing list and decided to upgrade to
4.2.2p3. Almost as soon as I started the new version, the "connection
refused" was back, but different now:
> Sep 7 09:24:25 gida ntpd[26405]: ntpd [EMAIL PROTECTED] Thu Sep 7
07:05:22 UTC
> 2006 (1)
> Sep 7 09:24:25 gida ntpd[26406]: precision = 1.000 usec
> Sep 7 09:24:25 gida ntpd: ntpd startup succeeded
> Sep 7 09:24:26 gida ntpd[26406]: Listening on interface wildcard,
0.0.0.0#123 Disabled
> Sep 7 09:24:26 gida ntpd[26406]: Listening on interface lo,
127.0.0.1#123 Enabled
> Sep 7 09:24:26 gida ntpd[26406]: Listening on interface eth0,
192.168.1.23#123
> Enabled
> Sep 7 09:24:26 gida ntpd[26406]: Listening on interface eth1,
192.168.254.2#123 Enabled
> Sep 7 09:24:26 gida ntpd[26406]: kernel time sync status 0040
> Sep 7 09:24:32 gida ntpd[26406]: frequency initialized 128.381 PPM
from /etc/ntp/drift
> Sep 7 09:24:32 gida ntpd[26406]: recvfrom(0.0.0.0) fd=51: Connection
refused
> Sep 7 09:24:32 gida ntpd[26406]: recvfrom(0.0.0.0) fd=51: Connection
refused
> Sep 7 09:25:34 gida ntpd[26406]: recvfrom(0.0.0.0) fd=51: Connection
refused
> Sep 7 09:25:34 gida ntpd[26406]: recvfrom(0.0.0.0) fd=51: Connection
refused
> Sep 7 09:26:38 gida ntpd[26406]: recvfrom(0.0.0.0) fd=51: Connection
refused
> Sep 7 09:26:38 gida ntpd[26406]: recvfrom(0.0.0.0) fd=51: Connection
refused
> Sep 7 09:27:42 gida ntpd[26406]: recvfrom(0.0.0.0) fd=51: Connection
refused
> Sep 7 09:27:42 gida ntpd[26406]: recvfrom(0.0.0.0) fd=51: Connection
refused
> Sep 7 09:27:50 gida ntpd[26406]: synchronized to 193.190.230.66,
stratum 1
> Sep 7 09:27:50 gida ntpd[26406]: kernel time sync enabled 0001
> Sep 7 09:28:46 gida ntpd[26406]: recvfrom(0.0.0.0) fd=51: Connection
refused
Note that, at startup, it says "Listening on interface wildcard,
0.0.0.0#123 Disabled" but that seems a blatant lie since lsof shows that
it does have a socket open there.
The 'refused' messages come two at a time and in 64 second intervals.
I tried adding a line 'manycastclient 224.1.1.1' to ntp.conf. The
messages stopped and came back. So it doesn't make a difference.
I tried removing the 'restrict' lines from ntp.conf but it doesn't
make a difference.
I then pulled 4.2.3p39 from dev and tried again. Same thing, the only
difference is that it doesn't mention the wildcard IF at startup.
I noticed that 193.190.230.66 is a stratum 1 server and not a 2 like
the others. Either I missed that when I added it to ntp.conf in May 2005
or they changed from 2 to 1 since then. In any case I removed it but it
doesn't make any difference.
I tried the debug output but it doesn't tell me anything. All I can
make of it is that there is only one 'refused' in the debug output and
two in the syslog. Also, the 'refused' comes after several seconds of
silence in the debug output. It doesn't tell me why it thinks it should
call recvfrom.
Needless to say, "tcpdump -i eth1 port ntp" (eth1 being fd 51)
doesn't show activity that might be related to the refusals.
One thing that I should add is that I can't ntpq locally on that
machine. It says "Name or service not known". From what I can see with
strace it seems to be looking in /etc/services from something. But I
wouldn't know what, "ntp" is definitely in there. In any case, this
started happening one year ago so it should have nothing to do with the
"refused" messages (but maybe with the ntp 4.1.x to 4.2.x transition). I
can query the box remotely, from another Linux, without problems.
Below are the relevant syslog lines, the ntpd debug output between
two 'refused's and the content of ntp.conf.
I"d appreciate if somebody could tell me what to do to make this
stop. I'd also like to know what's going on.
TIA,
Luc Pardon
#--------------------------
$ tail -f /var/log/messages | grep ntp
Sep 8 11:24:54 gida ntpd[8768]: ntpd [EMAIL PROTECTED] Fri Sep 8
08:57:05 UTC 2006 (3)
Sep 8 11:24:54 gida ntpd[8769]: precision = 1.000 usec
Sep 8 11:24:54 gida ntpd: ntpd startup succeeded
Sep 8 11:24:54 gida ntpd[8769]: Listening on interface #1 lo,
127.0.0.1#123 Enabled
Sep 8 11:24:54 gida ntpd[8769]: Listening on interface #2 eth0,
192.168.1.23#123 Enabled
Sep 8 11:24:54 gida ntpd[8769]: Listening on interface #3 eth1,
192.168.254.2#123 Enabled
Sep 8 11:24:54 gida ntpd[8769]: kernel time sync status 0040
Sep 8 11:24:54 gida ntpd[8769]: frequency initialized 129.083 PPM from
/etc/ntp/drift
Sep 8 11:25:04 gida ntpd[8769]: recvfrom(0.0.0.0) fd=51: Connection refused
Sep 8 11:25:04 gida ntpd[8769]: recvfrom(0.0.0.0) fd=51: Connection refused
#--------------------------
$ lsof -i -n | grep ntp
ntpd 8769 root 48u IPv4 92307937 UDP *:ntp
ntpd 8769 root 49u IPv4 92307973 UDP 127.0.0.1:ntp
ntpd 8769 root 50u IPv4 92307975 UDP 192.168.1.23:ntp
ntpd 8769 root 51u IPv4 92307977 UDP 192.168.254.2:ntp
#-------------------------------------------------
# partial output of ntpd -q -d -d -d -d -d
# (between two 'connection refused')
#-------------------------------------------------
auth_agekeys: at 420 keys 1 expired 0
sendpkt(fd=51 dst=145.238.110.68, src=192.168.254.2, ttl=0, len=48)
transmit: at 452 192.168.254.2->145.238.110.68 mode 3
poll_update: at 452 145.238.110.68 flags 0041 poll 6 burst 0 last 452
next 516
read_network_packet: fd=51 length 48 from 91ee6e44 145.238.110.68
receive: at 452 192.168.254.2<-145.238.110.68 flags 19 restrict 1c0
receive: at 452 192.168.254.2<-145.238.110.68 mode 4 code 1 auth 0
poll_update: at 452 145.238.110.68 flags 0041 poll 6 burst 0 last 452
next 518
clock_filter: discard 0
sendpkt(fd=51 dst=130.159.196.118, src=192.168.254.2, ttl=0, len=48)
transmit: at 455 192.168.254.2->130.159.196.118 mode 3
poll_update: at 455 130.159.196.118 flags 0001 poll 6 burst 0 last 455
next 521
read_network_packet: fd=51 length 48 from 829fc476 130.159.196.118
receive: at 455 192.168.254.2<-130.159.196.118 flags 19 restrict 1c0
receive: at 455 192.168.254.2<-130.159.196.118 mode 4 code 1 auth 0
poll_update: at 455 130.159.196.118 flags 0001 poll 6 burst 0 last 455
next 518
clock_filter: discard 0
sendpkt(fd=51 dst=129.240.64.3, src=192.168.254.2, ttl=0, len=48)
transmit: at 456 192.168.254.2->129.240.64.3 mode 3
poll_update: at 456 129.240.64.3 flags 0001 poll 6 burst 0 last 456 next 520
read_network_packet: fd=51 length 48 from 81f04003 129.240.64.3
receive: at 456 192.168.254.2<-129.240.64.3 flags 19 restrict 1c0
receive: at 456 192.168.254.2<-129.240.64.3 mode 4 code 1 auth 0
poll_update: at 456 129.240.64.3 flags 0001 poll 6 burst 0 last 456 next 520
clock_filter: n 8 off 0.001595 del 0.053788 dsp 0.001001 jit 0.002848, age 0
select: endpoint -1 -0.176856
select: endpoint -1 -0.155725
select: endpoint -1 -0.114353
select: endpoint -1 -0.105808
select: endpoint -1 -0.073520
select: endpoint 0 -0.016682
select: endpoint 0 -0.004989
select: endpoint 0 -0.004133
select: endpoint 0 -0.001493
select: endpoint 0 0.001595
select: endpoint 1 0.070534
select: endpoint 1 0.106086
select: endpoint 1 0.108998
select: endpoint 1 0.143492
select: endpoint 1 0.145747
select: drop 195.13.1.153 select 0.014654 jitter 0.002537
select: drop 129.240.64.3 select 0.005345 jitter 0.002848
cluster: survivor 145.238.110.68 metric 2.072027
cluster: survivor 130.159.196.118 metric 2.107403
cluster: survivor 138.195.130.71 metric 2.110219
select: combine offset -0.003086
poll_update: at 456 145.238.110.68 flags 0041 poll 6 burst 0 last 452
next 516
sendpkt(fd=51 dst=138.195.130.71, src=192.168.254.2, ttl=0, len=48)
transmit: at 457 192.168.254.2->138.195.130.71 mode 3
poll_update: at 457 138.195.130.71 flags 0001 poll 6 burst 0 last 457
next 521
read_network_packet: fd=51 length 48 from 8ac38247 138.195.130.71
receive: at 457 192.168.254.2<-138.195.130.71 flags 19 restrict 1c0
receive: at 457 192.168.254.2<-138.195.130.71 mode 4 code 1 auth 0
poll_update: at 457 138.195.130.71 flags 0001 poll 6 burst 0 last 457
next 521
clock_filter: discard 0
sendpkt(fd=51 dst=195.13.1.153, src=192.168.254.2, ttl=0, len=48)
transmit: at 458 192.168.254.2->195.13.1.153 mode 3
poll_update: at 458 195.13.1.153 flags 0001 poll 6 burst 0 last 458 next 522
read_network_packet: fd=51 length 48 from c30d0199 195.13.1.153
receive: at 458 192.168.254.2<-195.13.1.153 flags 19 restrict 1c0
receive: at 458 192.168.254.2<-195.13.1.153 mode 4 code 1 auth 0
poll_update: at 458 195.13.1.153 flags 0001 poll 6 burst 0 last 458 next 524
clock_filter: n 8 off -0.017358 del 0.018838 dsp 0.001999 jit 0.002931,
age 0
select: endpoint -1 -0.114383
select: endpoint -1 -0.105838
select: endpoint -1 -0.097190
select: endpoint -1 -0.093209
select: endpoint -1 -0.073550
select: endpoint 0 -0.017358
select: endpoint 0 -0.004989
select: endpoint 0 -0.004133
select: endpoint 0 -0.001493
select: endpoint 0 0.001595
select: endpoint 1 0.062475
select: endpoint 1 0.070564
select: endpoint 1 0.083232
select: endpoint 1 0.106116
select: endpoint 1 0.109028
select: drop 195.13.1.153 select 0.015320 jitter 0.002848
select: drop 129.240.64.3 select 0.005345 jitter 0.002848
cluster: survivor 145.238.110.68 metric 2.072057
cluster: survivor 138.195.130.71 metric 2.079832
cluster: survivor 130.159.196.118 metric 2.088221
select: combine offset -0.003347
poll_update: at 458 145.238.110.68 flags 0041 poll 6 burst 0 last 452
next 516
addto_syslog: recvfrom(0.0.0.0) fd=51: Connection refused
read_network_packet: fd=51 dropped (bad recvfrom)
#------------------------------------------
# ntp.conf (minus the comment lines)
#------------------------------------------
restrict default ignore
restrict 127.0.0.1
restrict 192.168.0.0 mask 255.255.0.0 nomodify notrap
server ntp.obspm.fr
restrict ntp.obspm.fr mask 255.255.255.255 nomodify notrap noquery
server ntp.via.ecp.fr
restrict ntp.via.ecp.fr mask 255.255.255.255 nomodify notrap noquery
server ntp.cs.strath.ac.uk
restrict ntp.cs.strath.ac.uk mask 255.255.255.255 nomodify notrap noquery
server ntp2.belbone.be
restrict ntp2.belbone.be mask 255.255.255.255 nomodify notrap noquery
driftfile /etc/ntp/drift
_______________________________________________
questions mailing list
[email protected]
https://lists.ntp.isc.org/mailman/listinfo/questions
