ntpd kills ppp/pppoe/DSL

Hello Group(s),

I'm building an embedded linux box based on a VIA C3 cpu with
the 2.6.6 kernel. I'm using

ppp-2.4.2b3
rp-pppoe-3.5
ntp-4.2.0

My DSL connection is perfectly functional (stays up for hours,
allows may MB of traffic at DSL max bandwidth), until I start
the ntpd. Immediately the ppp connection is lost. This
is 100% reproducable. Below is an excerpt from my syslog:

router pppd[419]: Terminating on signal 2.
router pppd[419]: Connection terminated.
router pppd[419]: Connect time 25.1 minutes.
router pppd[419]: Sent 105594 bytes, received 408432 bytes.
router pppoe[420]: read (asyncReadFromPPP): Session 4792: Input/output error
router pppoe[420]: Sent PADT
router pppd[419]: Connect time 25.1 minutes.
router pppd[419]: Sent 105594 bytes, received 408432 bytes.
router pppd[419]: Exit.

I have a box with two NICs: eth0 is for IP LAN traffic, and eth1
is used to do PPPoE to the DSL-modem. Here's the output from
"ifconfig -a":

eth0 Link encap:Ethernet HWaddr 00:40:F4:68:00:0B
inet addr:10.1.1.20 Bcast:10.1.1.0 Mask:255.255.255.0
UP BROADCAST RUNNING MULTICAST MTU:1500 Metric:1
RX packets:36131 errors:0 dropped:0 overruns:0 frame:0
TX packets:48288 errors:0 dropped:0 overruns:0 carrier:0
collisions:0 txqueuelen:1000
RX bytes:9995010 (9.5 MiB) TX bytes:41276730 (39.3 MiB)
Interrupt:10 Base address:0x6000

eth1 Link encap:Ethernet HWaddr 00:40:F4:68:00:0A
UP BROADCAST RUNNING MULTICAST MTU:1500 Metric:1
RX packets:38471 errors:0 dropped:0 overruns:0 frame:0
TX packets:15687 errors:0 dropped:0 overruns:0 carrier:0
collisions:0 txqueuelen:1000
RX bytes:40232964 (38.3 MiB) TX bytes:1340210 (1.2 MiB)
Interrupt:11 Base address:0x8000

lo Link encap:Local Loopback
inet addr:127.0.0.1 Mask:255.0.0.0
UP LOOPBACK RUNNING MTU:16436 Metric:1
RX packets:33 errors:0 dropped:0 overruns:0 frame:0
TX packets:33 errors:0 dropped:0 overruns:0 carrier:0
collisions:0 txqueuelen:0
RX bytes:6780 (6.6 kiB) TX bytes:6780 (6.6 kiB)

ppp0 Link encap:Point-Point Protocol
inet addr:84.152.225.213 P-t-P:217.0.116.79 Mask:255.255.255.255
UP POINTOPOINT RUNNING NOARP MULTICAST MTU:1492 Metric:1
RX packets:37239 errors:0 dropped:0 overruns:0 frame:0
TX packets:14523 errors:0 dropped:0 overruns:0 carrier:0
collisions:0 txqueuelen:3
RX bytes:38929959 (37.1 MiB) TX bytes:873210 (852.7 kiB)

My impression is that because ntpd is binding to all interfaces
it can find, it's somehow interfering with PPPoE on eth1. Has
anyone had similar experiences, and possible solved the problem?

At the bottom of this message you will find ntpd debug output
(-d -d -d -v).

cheers,

RU

# ntpd -n -d -d -d -p /var/run/ntpd.pid
ntpd 4.2.0@1.1161-r Sat Jun 11 09:36:55 MDT 2005 (2)
addto_syslog: ntpd 4.2.0@1.1161-r Sat Jun 11 09:36:55 MDT 2005 (2)
addto_syslog: signal_no_reset: signal 13 had flags 4000000
addto_syslog: set_process_priority: Leave priority alone: priority_done is <2>
addto_syslog: precision = 1.000 usec
create_sockets(123)
addto_syslog: no IPv6 interfaces found
address_okay: listen Virtual: 1, IF name: lo, Up Flag: 1
address_okay: listen Virtual: 1, IF name: eth0, Up Flag: 1
address_okay: listen Virtual: 1, IF name: ppp0, Up Flag: 1
bind() fd 4, family 2, port 123, addr 0.0.0.0, flags=8
flags for fd 4: 04002
bind() fd 5, family 2, port 123, addr 127.0.0.1, flags=0
flags for fd 5: 04002
bind() fd 6, family 2, port 123, addr 10.1.1.20, flags=8
flags for fd 6: 04002
bind() fd 7, family 2, port 123, addr 84.152.225.213, flags=0
flags for fd 7: 04002
create_sockets: ninterfaces=4
interface 0: fd=4, bfd=-1, name=wildcard, flags=0x8
sin=0.0.0.0 bcast=0.0.0.0, mask=255.255.255.255
interface 1: fd=5, bfd=-1, name=lo, flags=0x5
sin=127.0.0.1 mask=255.0.0.0
interface 2: fd=6, bfd=-1, name=eth0, flags=0x9
sin=10.1.1.20 bcast=10.1.1.0, mask=255.255.255.0
interface 3: fd=7, bfd=-1, name=ppp0, flags=0x3
sin=84.152.225.213 mask=255.255.255.255
init_io: maxactivefd 7
local_clock: at 0 state 0
getnetnum given 127.0.0.1, got 127.0.0.1
getnetnum given 195.145.119.188, got 195.145.119.188
getnetnum given 255.255.255.255, got 255.255.255.255
getnetnum given 195.145.119.188, got 195.145.119.188
key_expire: at 0
peer_clear: at 0 assoc ID 59588 refid INIT
newpeer: 84.152.225.213->195.145.119.188 mode 3 vers 4 poll 6 10 flags 0x1 0x1 ttl 0 key 00000000
getnetnum given 130.149.17.8, got 130.149.17.8
getnetnum given 255.255.255.255, got 255.255.255.255
getnetnum given 130.149.17.8, got 130.149.17.8
key_expire: at 0
peer_clear: at 0 assoc ID 59589 refid INIT
newpeer: 84.152.225.213->130.149.17.8 mode 3 vers 4 poll 6 10 flags 0x1 0x1 ttl 0 key 00000000
getnetnum given 127.127.1.0, got 127.127.1.0
key_expire: at 0
peer_clear: at 0 assoc ID 59590 refid INIT
newpeer: 127.0.0.1->127.127.1.0 mode 3 vers 4 poll 6 6 flags 0x21 0x1 ttl 0 key 00000000
getnetnum given 127.127.1.0, got 127.127.1.0
addto_syslog: configure: keyword "authenticate" unknown, line ignored
addto_syslog: can't open key file /etc/ntp/keys: No such file or directory
authtrust: keyid 0000ffff life 1
report_event: system event 'event_restart' (0x01) status 'sync_alarm, sync_unspec, 1 event, event_unspec' (0xc010)
addto_syslog: select(): nfound=-1, error: Interrupted system call
MCAST *****sendpkt(fd=7 dst=195.145.119.188, src=84.152.225.213, ttl=0, len=48)
transmit: at 1 84.152.225.213->195.145.119.188 mode 3
poll_update: at 1 195.145.119.188 flags 0001 poll 6 burst 0 last 1 next 65
auth_agekeys: at 1 keys 1 expired 0
timer: refresh ts 0
input_handler: if=3 fd=7 length 48 from c39177bc 195.145.119.188
receive: at 1 84.152.225.213<-195.145.119.188 restrict 1c0
receive: at 1 84.152.225.213<-195.145.119.188 mode 4 code 1
peer 195.145.119.188 event 'event_reach' (0x84) status 'unreach, conf, 1 event, event_reach' (0xa014)
poll_update: at 1 195.145.119.188 flags 0005 poll 6 burst 0 last 1 next 64
clock_filter: n 1 off 0.058284 del 0.026352 dsp 7.937504 jit 0.000001, age 1
addto_syslog: select(): nfound=-1, error: Interrupted system call
MCAST *****sendpkt(fd=7 dst=130.149.17.8, src=84.152.225.213, ttl=0, len=48)
transmit: at 2 84.152.225.213->130.149.17.8 mode 3
poll_update: at 2 130.149.17.8 flags 0001 poll 6 burst 0 last 2 next 68
addto_syslog: select(): nfound=-1, error: Interrupted system call
refclock_transmit: at 3 127.127.1.0
refclock_receive: at 3 127.127.1.0
peer LOCAL(0) event 'event_reach' (0x84) status 'unreach, conf, 1 event, event_reach' (0x8014)
refclock_sample: n 1 offset 0.000000 disp 0.010000 jitter 0.000000
clock_filter: n 1 off 0.000000 del 0.000000 dsp 7.937501 jit 0.000001, age 3
poll_update: at 3 127.127.1.0 flags 0021 poll 6 burst 0 last 3 next 69
addto_syslog: select(): nfound=-1, error: Interrupted system call
addto_syslog: select(): nfound=-1, error: Interrupted system call
addto_syslog: select(): nfound=-1, error: Interrupted system call
addto_syslog: select(): nfound=-1, error: Interrupted system call
addto_syslog: select(): nfound=-1, error: Interrupted system call
addto_syslog: select(): nfound=-1, error: Interrupted system call
addto_syslog: select(): nfound=-1, error: Interrupted system call
addto_syslog: select(): nfound=-1, error: Interrupted system call
addto_syslog: select(): nfound=-1, error: Interrupted system call
addto_syslog: select(): nfound=-1, error: Interrupted system call
addto_syslog: ntpd exiting on signal 2

In article <(E-Mail Removed)>,
"r.u" <(E-Mail Removed)> wrote:

> router pppd[419]: Terminating on signal 2.

> # ntpd -n -d -d -d -p /var/run/ntpd.pid

> addto_syslog: ntpd exiting on signal 2

Signal 2 is SIGINTR, i.e. a console interrupt (typically ^C or DEL).
It is not normally issued by ordinary programs, although it can be.
You have started ntpd in an attached mode. I don't know how you have
started pppd, or what shell you are using.

My guess is that you started pppd in a diagnostic mode, so that it
was still attached to the console, and simply backgrounded it with
&. You are probably using a non-job control shell, so ^C affects
background jobs (it is issued to a process group, when issued by
the terminal driver). You then interrupted your attached ntpd with ^C
causing collateral damage to the also attached pppd.

Your best way of running both diagnostically is to run them in separate
consoles. You can use nohup if it is supported by your configuration.

On Thu, 16 Jun 2005 07:36:17 +0100, David Woolley wrote:

> In article <(E-Mail Removed)>,
> "r.u" <(E-Mail Removed)> wrote:
>
>> router pppd[419]: Terminating on signal 2.
>
>> # ntpd -n -d -d -d -p /var/run/ntpd.pid
>
>> addto_syslog: ntpd exiting on signal 2
>
> Signal 2 is SIGINTR, i.e. a console interrupt (typically ^C or DEL).
> It is not normally issued by ordinary programs, although it can be.
> You have started ntpd in an attached mode. I don't know how you have
> started pppd, or what shell you are using.
>
> My guess is that you started pppd in a diagnostic mode, so that it
> was still attached to the console, and simply backgrounded it with
> &. You are probably using a non-job control shell, so ^C affects
> background jobs (it is issued to a process group, when issued by
> the terminal driver). You then interrupted your attached ntpd with ^C
> causing collateral damage to the also attached pppd.
>
> Your best way of running both diagnostically is to run them in separate
> consoles. You can use nohup if it is supported by your configuration.

Possibly I should have mentioned that I eventually terminated
ntpd using ^C. Indeed, since I used the "-n" flag (don't fork),
it was running in the foreground. In a different window I was
monitoring the ppp connection, and when I saw that the ppp
connection had died, there was no point in continuing to run
ntpd, so I killed it. The point at which ntpd kills my ppp
connection is somewhere much before the termination point.

I included the diagnostic output of ntp because I thought it might
shed some light on it's non-peaceful coexistence with ppp.

cheers,

RU

On Thu, 16 Jun 2005 11:29:56 +0200, "r.u" <(E-Mail Removed)> wrote:
> ntpd, so I killed it. The point at which ntpd kills my ppp
> connection is somewhere much before the termination point.
>
> I included the diagnostic output of ntp because I thought it might
> shed some light on it's non-peaceful coexistence with ppp.

I run ntpd from ip-up script, no problem...

You aware that ntpd barfs if machine time time too far off
'net time? Run ntpdate <time_server> prior to running ntpd
for first time. Will work fine after that.

Normal behaviour Lousy diagnostics though.

--Grant.

On Thu, 16 Jun 2005 07:36:17 +0100, David Woolley wrote:

> In article <(E-Mail Removed)>,
> "r.u" <(E-Mail Removed)> wrote:
>
>> router pppd[419]: Terminating on signal 2.
>
>> # ntpd -n -d -d -d -p /var/run/ntpd.pid
>
>> addto_syslog: ntpd exiting on signal 2
>
> Signal 2 is SIGINTR, i.e. a console interrupt (typically ^C or DEL).
> It is not normally issued by ordinary programs, although it can be.
> You have started ntpd in an attached mode. I don't know how you have
> started pppd, or what shell you are using.
>
> My guess is that you started pppd in a diagnostic mode, so that it
> was still attached to the console, and simply backgrounded it with
> &. You are probably using a non-job control shell, so ^C affects
> background jobs (it is issued to a process group, when issued by
> the terminal driver). You then interrupted your attached ntpd with ^C
> causing collateral damage to the also attached pppd.
>
> Your best way of running both diagnostically is to run them in separate
> consoles. You can use nohup if it is supported by your configuration.

There is a saying in german, "the problem was between the chair and
keyboard". Your analysis was almost entirely correct, except that
I was not running pppd in diagnostic mode. Keyboard interrupts that
I was typing on the same tty where I'd started pppd (using
adsl-start) were somehow being propagated to pppd and killing it.

THERE IS *NO* PROBLEM WITH ntpd. sorry about the confusion.

cheers,

RU