recvfrom(0.0.0.0) fd=51: Connection refused - NTP

This is a discussion on recvfrom(0.0.0.0) fd=51: Connection refused - NTP ; 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 ...

+ Reply to Thread
Results 1 to 15 of 15

Thread: recvfrom(0.0.0.0) fd=51: Connection refused

  1. recvfrom(0.0.0.0) fd=51: Connection refused

    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 4.2.2p3@1.1577-o 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 4.2.3p39@1.1395-o 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
    questions@lists.ntp.isc.org
    https://lists.ntp.isc.org/mailman/listinfo/questions


  2. Re: recvfrom(0.0.0.0) fd=51: Connection refused

    While this is not your core problem, I see you are using hostnames for your
    'restrict' targets.

    Please see the first few lines of:

    http://ntp.isc.org/Support/AccessRestrictions

    H

  3. Re: recvfrom(0.0.0.0) fd=51: Connection refused

    Hmmm, yes. And further down it says:

    You may use either a hostname or IP address on the server line.
    You must use an IP address on the restrict line.

    This must be a mistake in that page. See the official docs at:

    http://www.eecis.udel.edu/~mills/ntp/html/accopt.html

    where it says:

    restrict address [mask mask] [flag][...]
    The address argument expressed in dotted-quad form is
    the address of a host or network. Alternatively, the
    address argument can be a valid host DNS name.

    If you couldn't use hostnames, it would render access restrictions
    rather useless. Many public servers ask that you use DNS names rather
    than IP addresses. It doesn't seem to make sense to query them using the
    hostname and "restrict" (allow the replies in) using a (volatile) IP.

    Furthermore, hostnames work just fine, the replies are accepted. Have
    been for at least five years or so.

    That doesn't mean I'm not willing to change it if that helps diagnose
    the problem.

    Thanks for responding nonetheless.

    Luc Pardon



    Harlan Stenn wrote:
    > While this is not your core problem, I see you are using hostnames

    for your
    > 'restrict' targets.
    >
    > Please see the first few lines of:
    >
    > http://ntp.isc.org/Support/AccessRestrictions
    >
    > H
    >
    > _______________________________________________
    > questions mailing list
    > questions@lists.ntp.isc.org
    > https://lists.ntp.isc.org/mailman/listinfo/questions


    Harlan Stenn wrote:
    > While this is not your core problem, I see you are using hostnames for your
    > 'restrict' targets.
    >
    > Please see the first few lines of:
    >
    > http://ntp.isc.org/Support/AccessRestrictions
    >
    > H
    >
    > _______________________________________________
    > questions mailing list
    > questions@lists.ntp.isc.org
    > https://lists.ntp.isc.org/mailman/listinfo/questions

    _______________________________________________
    questions mailing list
    questions@lists.ntp.isc.org
    https://lists.ntp.isc.org/mailman/listinfo/questions


  4. Re: recvfrom(0.0.0.0) fd=51: Connection refused

    xntp@skopos.be (Luc Pardon) writes:

    > 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

    This error message from the kernel is a bit unusual, but you said it was running on Linux...

    >
    > 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 4.2.2p3@1.1577-o 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
    >
    > 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 socket being bound does not allow you to call that a lie. The Disabled information just documents that pakets received on that
    socket will be discarded.

    > The 'refused' messages come two at a time and in 64 second intervals.
    >

    So it seems to be related with some query activity.

    > 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.

    restrict is not related to this behavior.

    >
    > 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.

    The socket seems to be ready for reading (select && SIGIO). when ntpd reads from it it gets the error message from the kernel. As I said getting that on a recvfrom is unusal
    and delivered from the kernel - ntpd just documents that.

    >
    > Needless to say, "tcpdump -i eth1 port ntp" (eth1 being fd 51) doesn't show activity that might be related to the refusals.

    I suspect that icmp messages (probably port unreachable) being received. So try "tcpdump -i eth1 port ntp or icmp" and see whether
    such icmp messages show up and who sends them.

    >
    > 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.

    This looks like a local setup problem other system have following line in /etc/services:
    ntp 123/udp # Network Time Protocol

    Frank

  5. Re: recvfrom(0.0.0.0) fd=51: Connection refused

    Luc Pardon wrote:
    > Hmmm, yes. And further down it says:
    >
    > You may use either a hostname or IP address on the server line.
    > You must use an IP address on the restrict line.
    >
    > This must be a mistake in that page. See the official docs at:
    >


    Yes, that is a mistake. However, due to the current implementation you
    need to be careful if the name has more than one A or AAAA record,
    particularly if it has both since the restrict line can pick up a
    different IP address than the one used on the server line.

    > http://www.eecis.udel.edu/~mills/ntp/html/accopt.html
    >
    > where it says:
    >
    > restrict address [mask mask] [flag][...]
    > The address argument expressed in dotted-quad form is
    > the address of a host or network. Alternatively, the
    > address argument can be a valid host DNS name.
    >
    > If you couldn't use hostnames, it would render access restrictions
    > rather useless. Many public servers ask that you use DNS names rather
    > than IP addresses. It doesn't seem to make sense to query them using the
    > hostname and "restrict" (allow the replies in) using a (volatile) IP.
    >
    > Furthermore, hostnames work just fine, the replies are accepted. Have
    > been for at least five years or so.
    >


    No, you are correct.

    > That doesn't mean I'm not willing to change it if that helps diagnose
    > the problem.
    >


    It's unrelated.

    Danny
    _______________________________________________
    questions mailing list
    questions@lists.ntp.isc.org
    https://lists.ntp.isc.org/mailman/listinfo/questions


  6. Re: recvfrom(0.0.0.0) fd=51: Connection refused

    Danny,

    A name in the 'restrict' line may work for him now, and this issue may be
    resolved in the future, but in general at this time it is a Bad Idea unless
    there is Good Reason to believe a single address will be returned for
    the name both now and in the future.

    IE, the current BCP is to use IPs for 'restrict' addresses. I do not know
    why this is not the BCP for server/peer targets as well, but that is a
    different matter.

    H

  7. Re: recvfrom(0.0.0.0) fd=51: Connection refused

    Harlan Stenn wrote:
    > Danny,
    >
    > A name in the 'restrict' line may work for him now, and this issue may be
    > resolved in the future, but in general at this time it is a Bad Idea unless
    > there is Good Reason to believe a single address will be returned for
    > the name both now and in the future.
    >
    > IE, the current BCP is to use IPs for 'restrict' addresses. I do not know
    > why this is not the BCP for server/peer targets as well, but that is a
    > different matter.
    >


    No, that's exactly the issue. People use the pool a lot and get a
    different address each time. Use IP addresses for the restrict line is
    almost impossible for pool addresses.

    This needs to be fixed properly a different way.

    Danny
    > H
    >

    _______________________________________________
    questions mailing list
    questions@lists.ntp.isc.org
    https://lists.ntp.isc.org/mailman/listinfo/questions


  8. Re: recvfrom(0.0.0.0) fd=51: Connection refused

    Danny,

    We agree that it needs to be fixed.

    That does not address the BCP issue with current code.

    How about you focus less on these discussions and more on the 4.2.4
    blockers and bug 701?

    H
    --
    > Harlan Stenn wrote:
    > > Danny,
    > >
    > > A name in the 'restrict' line may work for him now, and this issue may be
    > > resolved in the future, but in general at this time it is a Bad Idea unless
    > > there is Good Reason to believe a single address will be returned for
    > > the name both now and in the future.
    > >
    > > IE, the current BCP is to use IPs for 'restrict' addresses. I do not know
    > > why this is not the BCP for server/peer targets as well, but that is a
    > > different matter.
    > >

    >
    > No, that's exactly the issue. People use the pool a lot and get a
    > different address each time. Use IP addresses for the restrict line is
    > almost impossible for pool addresses.
    >
    > This needs to be fixed properly a different way.
    >
    > Danny
    > > H
    > >

    _______________________________________________
    questions mailing list
    questions@lists.ntp.isc.org
    https://lists.ntp.isc.org/mailman/listinfo/questions


  9. Re: recvfrom(0.0.0.0) fd=51: Connection refused

    Frank Kardel wrote:
    > xntp@skopos.be (Luc Pardon) writes:
    >> Needless to say, "tcpdump -i eth1 port ntp" (eth1 being fd 51) doesn't show activity that might be related to the refusals.

    > I suspect that icmp messages (probably port unreachable) being received. So try "tcpdump -i eth1 port ntp or icmp" and see whether
    > such icmp messages show up and who sends them.


    Bang, spot on!

    The culprit is ntp1.belbone.be, sending icmp packets to my box for
    whatever reason.

    The interesting thing is, this server is not in my ntp.conf. It was
    in there - for a short time - a few days ago. But as best I can tell it
    was not in there when the "refused" messages started on Sept 2. His
    brother, ntp2.belbone.be, has been there all the time, but has a
    different IP.

    Of course this got me wondering if ntp1.belbone.be is the only
    culprit. You'll remember that, while I still had ntp 4.2.0 installed,
    the "connection refused" messages showed not 0.0.0.0 but several
    different IP's, including internal ones.

    As it turns out, 4.2.0 is plain wrong.

    I briefly reverted to ntp 4.2.0 and it seems to show a left-over IP
    from the previous packet exchange.

    For example, I see a normal udp/123 query/response to/from the ntp
    server at IP 195.13.1.153 (ntp2.belbone.be). Then, 24 seconds later,
    comes the next icmp packet from ntp1.belbone.be. It's IP is 195.13.23.5
    but the syslog entry has the ntp2.belbone.be IP:

    > Sep 11 09:26:44 gida ntpd[30638]: recvfrom(195.13.1.153) fd=9: Connection refused
    > Sep 11 09:26:44 gida ntpd[30638]: recvfrom(195.13.1.153) fd=9: Connection refused


    Same for other icmp's. If it comes right after an incoming time query
    from one of the internal clients, that client's internal IP is what
    shows up in syslog.

    So, this (reporting the wrong source) was a bug in 4.2.0 that is now
    more or less fixed in 4.2.3p39.

    I say more or less because I still think that ntpd should at least
    display the correct IP, i.e. 195.13.23.5 instead of 0.0.0.0. If I had
    seen all the "refused"s coming from a single IP I might have tcpdumped
    all the traffic to/from that IP and I might have seen the icmp's.

    In fact, I would expect this packet to be ignored, if only because of
    the "restrict default ignore", no?

    Finally, the message is logged twice. Once would have been enough to
    flood my logs .


    Bottom line, my conclusions for now are:

    1) the problem seems external, probably something is broken at
    ntp1.belbone.be.

    2) improvement in ntpd's logging could have saved me many hours of
    debugging (conclusion, not criticism)

    3) to make this stop (i.e. keep the message out of my logs), I can
    only firewall him out (and contact the operator - if he's listening on
    tcp/25 - but I'm not sure what to tell him).

    4) there is nothing I can do at this point to prevent this from
    happening in the future.

    Please correct me if I'm wrong.

    Any light that can be shedded on the 'why' of this would be welcome too.

    Thanks for all the help.

    Luc

    _______________________________________________
    questions mailing list
    questions@lists.ntp.isc.org
    https://lists.ntp.isc.org/mailman/listinfo/questions


  10. Re: recvfrom(0.0.0.0) fd=51: Connection refused

    xntp@skopos.be (Luc Pardon) writes:

    > Frank Kardel wrote:
    >> xntp@skopos.be (Luc Pardon) writes:
    >>> Needless to say, "tcpdump -i eth1 port ntp" (eth1 being fd 51) doesn't show activity that might be related to the refusals.

    >> I suspect that icmp messages (probably port unreachable) being received. So try "tcpdump -i eth1 port ntp or icmp" and see whether
    >> such icmp messages show up and who sends them.

    >
    > Bang, spot on!

    Glad to help !
    >
    > The culprit is ntp1.belbone.be, sending icmp packets to my box for whatever reason.
    >
    > The interesting thing is, this server is not in my ntp.conf. It was in there - for a short time - a few days ago. But as best I can tell it was not in there when the "refused" messages started on Sept 2. His brother, ntp2.belbone.be, has been there all the time, but has a different IP.
    >
    > Of course this got me wondering if ntp1.belbone.be is the only culprit. You'll remember that, while I still had ntp 4.2.0 installed, the "connection refused" messages showed not 0.0.0.0 but several different IP's, including internal ones.
    >
    > As it turns out, 4.2.0 is plain wrong.
    >
    > I briefly reverted to ntp 4.2.0 and it seems to show a left-over IP from the previous packet exchange.
    >
    > For example, I see a normal udp/123 query/response to/from the ntp server at IP 195.13.1.153 (ntp2.belbone.be). Then, 24 seconds later, comes the next icmp packet from ntp1.belbone.be. It's IP is 195.13.23.5 but the syslog entry has the ntp2.belbone.be IP:
    >

    I cannot speculate what happens there, these pakets might even forged and sent
    with the wrong source address. I have no Idea why.

    >> Sep 11 09:26:44 gida ntpd[30638]: recvfrom(195.13.1.153) fd=9: Connection refused
    >> Sep 11 09:26:44 gida ntpd[30638]: recvfrom(195.13.1.153) fd=9: Connection refused

    >
    > Same for other icmp's. If it comes right after an incoming time query from one of the internal clients, that client's internal IP is what shows up in syslog.
    >
    > So, this (reporting the wrong source) was a bug in 4.2.0 that is now more or less fixed in 4.2.3p39.
    >
    > I say more or less because I still think that ntpd should at least display the correct IP, i.e. 195.13.23.5 instead of 0.0.0.0. If I had seen all the "refused"s coming from a single IP I might have tcpdumped all the traffic to/from that IP and I might have seen the icmp's.

    Actually ntpd does not know where these paket come from - it just gets a read error from the kernel without
    any address indication.
    What ntpd lists as address is the local address to which the socket is bound where the read error occurred.

    > In fact, I would expect this packet to be ignored, if only because of the "restrict default ignore", no?

    There is actually no paket - just a failed recvfrom(). So nothing to ignore.

    >
    > Finally, the message is logged twice. Once would have been enough to flood my logs .

    As these read errors are logged with LOG_ERR could it be that your syslog configuration
    is a bit strange in that the error level messages are logged into the same file which also
    logs lower level messages. The message is only generated once in ntpd, but the above scenario
    would duplicate messages above a certain level. Please check your syslog configuration.

    >
    >
    > Bottom line, my conclusions for now are:
    >
    > 1) the problem seems external, probably something is broken at ntp1.belbone.be.

    Could be anything, misconfiguration there, forged source addresses (unlikely but possible).

    >
    > 2) improvement in ntpd's logging could have saved me many hours of debugging (conclusion, not criticism)

    The daemon does not have a chance, no address data is given from the kernel to the daemon. I am not even sure
    whether Linux should report those icmp pakets as read errors - ECONNREFUSED is not even an allowed errorcode
    in NetBSD's recvfrom for comparison. This might be a confusion helped by implementation details of Linux (or the version you use).

    >
    > 3) to make this stop (i.e. keep the message out of my logs), I can only firewall him out (and contact the operator - if he's listening on tcp/25 - but I'm not sure what to tell him).

    Block his icmp messages.
    But I think notification would be a good thing. Maybe something bigger is wrong there.

    >
    > 4) there is nothing I can do at this point to prevent this from happening in the future.

    block icmps dealing with ntp port. Try out other versions of Linux, *BSD and other Unix variants.

    >
    > Please correct me if I'm wrong.

    See above for my thoughts.

    >
    > Any light that can be shedded on the 'why' of this would be welcome too.
    >

    No real idea, but This is the first time I see this reported. I am still not
    sure whether Linux behaves correctly here - I would have to look into the
    specs though.

    > Thanks for all the help.
    >
    > Luc
    >
    > _______________________________________________
    > questions mailing list
    > questions@lists.ntp.isc.org
    > https://lists.ntp.isc.org/mailman/listinfo/questions


    Regards,
    Frank

  11. Re: recvfrom(0.0.0.0) fd=51: Connection refused

    >>> Finally, the message is logged twice.
    >> As these read errors are logged with LOG_ERR could it be that your

    syslog configuration
    >> is a bit strange


    Yoy must have been a diplomat in a previous life. Of course it was
    "a bit strange". Fixed now, thanks (again).

    >> 2) improvement in ntpd's logging could have saved me many hours

    of debugging (conclusion, not criticism)
    > The daemon does not have a chance, no address data is given from the

    kernel to the daemon.

    I see. A glance at the man pages seem to say the address ought to
    be filled in, but it's not clear if that's true also in case of error.
    In any case, I had a look at ntp_io.c and I don't see anything obvious
    where it would get lost.

    > I am not even sure whether Linux should report those icmp pakets as

    read errors - ECONNREFUSED is not
    > even an allowed errorcode in NetBSD's recvfrom for comparison.


    FWIW, ECONNREFUSED is listed in man (2) recvfrom on one Linux
    system with a 2.4.20 kernel and on another one with a 2.6.17 kernel.

    Also, I am absolutely sure that I got "connection refused" errors
    last year when my ISP had blocked port 123 in the ADSL router so my
    client couldn't reach the servers. I also saw them when some server was
    temporarily down. I'm less sure it was on recvfrom, but I think so.

    >> 3) to make this stop (i.e. keep the message out of my logs), I

    can only firewall him out (and contact the operator - if he's listening
    on tcp/25 - but I'm not sure what to tell him).
    > Block his icmp messages.
    > But I think notification would be a good thing. Maybe something

    bigger is wrong there.

    Working on that. Meaning: contacted them, they're working and I'm
    watching (the logs). There was some progress yesterday, none today.
    There are no more icmp packets. Now it's just udp/123 replies to
    requests that I didn't send. But at least they don't appear in syslog.


    >> Any light that can be shedded on the 'why' of this would be

    welcome too.
    >>

    > No real idea, but This is the first time I see this reported. I am

    still not
    > sure whether Linux behaves correctly here - I would have to look into the
    > specs though.


    There is not much I can do to help at this point, I suppose?

    The strange packets are no longer coming in and in any case, I don't
    have the resources right now to hook up a Linux box with a more recent
    kernel to see what would happen.


    Luc Pardon
    _______________________________________________
    questions mailing list
    questions@lists.ntp.isc.org
    https://lists.ntp.isc.org/mailman/listinfo/questions


  12. Re: recvfrom(0.0.0.0) fd=51: Connection refused

    xntp@skopos.be (Luc Pardon) writes:

    > >>> Finally, the message is logged twice.
    > >> As these read errors are logged with LOG_ERR could it be that your syslog configuration
    > >> is a bit strange

    >
    > Yoy must have been a diplomat in a previous life. Of course it was "a bit strange". Fixed now, thanks (again).

    Almost true. I am a consultant - not an insultant (most of the time).

    >
    > >> 2) improvement in ntpd's logging could have saved me many hours of debugging (conclusion, not criticism)

    > > The daemon does not have a chance, no address data is given from the

    > kernel to the daemon.
    >
    > I see. A glance at the man pages seem to say the address ought to be filled in, but it's not clear if that's true also in case of error. In any case, I had a look at ntp_io.c and I don't see anything obvious where it would get lost.


    The usual Unix rule of system call interfaces is that nothing is changed when an error occurs. In case of ECONNREFUSED the behaviour across all
    platforms ntpd runs on is at best undefined (though some/all versions of Linux may fill it in). So we are a bit limited of what we can
    reliably dig out. NetBSD would not give such errors on recvfrom for example. Linux apparently does.

    >
    > > I am not even sure whether Linux should report those icmp pakets as read errors - ECONNREFUSED is not
    > > even an allowed errorcode in NetBSD's recvfrom for comparison.

    >
    > FWIW, ECONNREFUSED is listed in man (2) recvfrom on one Linux system with a 2.4.20 kernel and on another one with a 2.6.17 kernel.
    >
    > Also, I am absolutely sure that I got "connection refused" errors last year when my ISP had blocked port 123 in the ADSL router so my client couldn't reach the servers. I also saw them when some server was temporarily down. I'm less sure it was on recvfrom, but I think so.
    >

    I don't deny that. But is seems to be more and more an implementation detail for a specific platform.

    > >> 3) to make this stop (i.e. keep the message out of my logs), I can only firewall him out (and contact the operator - if he's listening on tcp/25 - but I'm not sure what to tell him).

    > > Block his icmp messages.
    > > But I think notification would be a good thing. Maybe something bigger is wrong there.

    >
    > Working on that. Meaning: contacted them, they're working and I'm watching (the logs). There was some progress yesterday, none today. There are no more icmp packets. Now it's just udp/123 replies to requests that I didn't send. But at least they don't appear in syslog.
    >

    You are not NATting anything ? A broken NAT config/device could give this too if other systems from your network do queries that get mapped
    to your primary system - but that's just a guess. Just like forged send IP would be. Maybe you could double check at your outgoing link
    (inner and outer interface) for correlations like that.

    >
    > >> Any light that can be shedded on the 'why' of this would be welcome too.
    > >>

    > > No real idea, but This is the first time I see this reported. I am still not
    > > sure whether Linux behaves correctly here - I would have to look into the
    > > specs though.

    >
    > There is not much I can do to help at this point, I suppose?
    >
    > The strange packets are no longer coming in and in any case, I don't have the resources right now to hook up a Linux box with a more recent kernel to see what would happen.
    >

    Well, at least things did a bit improve, didn't they :-) ?

    >
    > Luc Pardon
    > _______________________________________________
    > questions mailing list
    > questions@lists.ntp.isc.org
    > https://lists.ntp.isc.org/mailman/listinfo/questions


    Frank

  13. Re: recvfrom(0.0.0.0) fd=51: Connection refused



    Frank Kardel wrote:
    > You are not NATting anything ? A broken NAT config/device could give this too if other systems from your network do queries that get mapped
    > to your primary system - but that's just a guess. Just like forged send IP would be. Maybe you could double check at your outgoing link
    > (inner and outer interface) for correlations like that.


    None of the internal systems should query outside servers. And even
    if they did, they should not have started doing that all of a sudden a
    week or so ago. Never say never, though, so I double-checked already, in
    various ways. I'm pretty sure it's not coming from behind my back.

    What I don't control is the ADSL router in front of me, though. If
    my friendly ISP decided last week that it would be nice to sync it to
    that belbone server, and if they forward the replies right through to
    the network behind, then that might be the cause.

    In fact, there is an indication that this might be what's going on.
    Here is a tcpdump of one such reply:

    > 19:59:19.083130 ntp1.belbone.be.ntp > adsl-gida.ntp: v1 server strat

    2 poll 0 prec -20 (DF) [tos 0x10]

    Note that it says "v1"... That's not in reply to an (x)ntp request.

    If it is indeed the router, the master of time at belbone would see
    requests coming in from over here (this is why I double-checked they're
    not mine ). I haven't heard back from them, but then they said
    they're working on things. If they see queries, it'll be time to call my
    ISP.


    >> The strange packets are no longer coming in and in any case, I don't have the resources right now to hook up a Linux box with a more recent kernel to see what would happen.
    >>

    > Well, at least things did a bit improve, didn't they :-) ?
    >


    The glass is either half full or half empty. It's just that I like
    to get at the bottom of things, both problems and glasses. I hate
    problems that disappear unsolved, almost as much as I hate glasses that
    disappear unfinished .

    But yes, we're making progress and that's a Good Thing indeed.

    Luc Pardon
    _______________________________________________
    questions mailing list
    questions@lists.ntp.isc.org
    https://lists.ntp.isc.org/mailman/listinfo/questions


  14. Re: recvfrom(0.0.0.0) fd=51: Connection refused

    xntp@skopos.be (Luc Pardon) writes:

    > Frank Kardel wrote:
    >> You are not NATting anything ? A broken NAT config/device could give this too if other systems from your network do queries that get mapped
    >> to your primary system - but that's just a guess. Just like forged send IP would be. Maybe you could double check at your outgoing link
    >> (inner and outer interface) for correlations like that.

    >
    > None of the internal systems should query outside servers. And even if they did, they should not have started doing that all of a sudden a week or so ago. Never say never, though, so I double-checked already, in various ways. I'm pretty sure it's not coming from behind my back.

    ok.

    >
    > What I don't control is the ADSL router in front of me, though. If my friendly ISP decided last week that it would be nice to sync it to that belbone server, and if they forward the replies right through to the network behind, then that might be the cause.
    >
    > In fact, there is an indication that this might be what's going on. Here is a tcpdump of one such reply:
    >
    > > 19:59:19.083130 ntp1.belbone.be.ntp > adsl-gida.ntp: v1 server strat 2 poll 0 prec -20 (DF) [tos 0x10]

    >
    > Note that it says "v1"... That's not in reply to an (x)ntp request.

    very old version indeed (sntp?).

    >
    > If it is indeed the router, the master of time at belbone would see requests coming in from over here (this is why I double-checked they're not mine ). I haven't heard back from them, but then they said they're working on things. If they see queries, it'll be time to call my ISP.
    >

    This is probably beyond the point where I can help.

    >
    >>> The strange packets are no longer coming in and in any case, I don't have the resources right now to hook up a Linux box with a more recent kernel to see what would happen.
    >>>

    >> Well, at least things did a bit improve, didn't they :-) ?
    >>

    >
    > The glass is either half full or half empty. It's just that I like to get at the bottom of things, both problems and glasses. I hate problems that disappear unsolved, almost as much as I hate glasses that disappear unfinished .
    >
    > But yes, we're making progress and that's a Good Thing indeed.


    Well I hope you get to the bottom of the paket source and find full glasses :-)

    >
    > Luc Pardon


    Frank

  15. Re: recvfrom(0.0.0.0) fd=51: Connection refused

    xntp@skopos.be (Luc Pardon) writes:

    > FWIW, ECONNREFUSED is listed in man (2) recvfrom on one Linux
    >system with a 2.4.20 kernel and on another one with a 2.6.17 kernel.


    And it's also in the Solaris manual. I seem to remember hacking
    a SunOS 3.x driver (really replacing ip_icmp.c with the BSD version)
    in order for it to work on SunOS 3.x; it worked in SunOS 4.x.

    Casper
    --
    Expressed in this posting are my opinions. They are in no way related
    to opinions held by my employer, Sun Microsystems.
    Statements on Sun products included here are not gospel and may
    be fiction rather than truth.

+ Reply to Thread