Very Computer

by **richard maye** » Mon, 22 Jun 1998 04:00:00

I have installed Redhat 5.1 on a Satellite Pro 420CDT laptop and on
another machine (not laptop). I can run ppp fine on the other machine,
but when I use the same scripts (pap-secrets, etc.) on the laptop, pppd
fails. I can connect using minicom and I eventually tried the other
machine's external modem that works on the other machine with the same
failing results on the laptop, so I do not think that the modem causes
the problem. I run
***
pppd -detach modem crtscts defaultroute debug kdebug 7 /dev/modem 115200
connect 'chat -v -f chatfilename'
***
and I included the kernel debug messages below. It seems to me that pppd
is timing out sending config requests, and this is strange because from
the other machine I can connect to the same ISP without any problem. The
ISP has autoprotocoldetect running. As you can see the debug stuff
contains the line
*** ppp: frame with bad fcs, excess = b01c ***
but I do not know the significance of that.

I would really appreciate it if somebody could please help me out
because I'm stuck. I even tried an earlier version of pppd with the same
result so I really don't know what is going on.

-Thank you,

-Richard Mayer

********************* debug messages
**********************************************
Jun 21 12:27:52 localhost kernel: CSLIP: code copyright 1989 Regents of
the University of California
Jun 21 12:27:52 localhost kernel: PPP: version 2.2.0 (dynamic channel
allocation)
Jun 21 12:27:52 localhost kernel: PPP Dynamic channel allocation code
copyright 1995 Caldera, Inc.
Jun 21 12:27:52 localhost kernel: PPP line discipline registered.
Jun 21 12:27:52 localhost kernel: registered device ppp0
Jun 21 12:27:52 localhost pppd[341]: pppd 2.3.3 started by root, uid 0
Jun 21 12:27:54 localhost chat[345]: abort on (BUSY)
Jun 21 12:27:54 localhost chat[345]: abort on (ERROR)
Jun 21 12:27:54 localhost chat[345]: abort on (NO CARRIER)
Jun 21 12:27:54 localhost chat[345]: abort on (NO DIALTONE)
Jun 21 12:27:54 localhost chat[345]: abort on (Invalid Login)
Jun 21 12:27:54 localhost chat[345]: abort on (Login incorrect)
Jun 21 12:27:54 localhost chat[345]: send (ATZ^M)
Jun 21 12:27:54 localhost chat[345]: expect (OK)
Jun 21 12:27:54 localhost chat[345]: ATZ^M^M
Jun 21 12:27:54 localhost chat[345]: OK
Jun 21 12:27:54 localhost chat[345]: -- got it
Jun 21 12:27:54 localhost chat[345]: send (ATDT5453700^M)
Jun 21 12:27:54 localhost chat[345]: expect (CONNECT)
Jun 21 12:27:54 localhost chat[345]: ^M
Jun 21 12:28:11 localhost chat[345]: ATDT5453700^M^M
Jun 21 12:28:11 localhost pppd[341]: Serial connection established.
Jun 21 12:28:11 localhost chat[345]: CONNECT
Jun 21 12:28:11 localhost chat[345]: -- got it
Jun 21 12:28:11 localhost chat[345]: send (^M)
Jun 21 12:28:12 localhost kernel: ppp_tty_ioctl: set flags to 70000
Jun 21 12:28:12 localhost kernel: ppp_tty_ioctl: get flags: addr
bffffbb4 flags 0
Jun 21 12:28:12 localhost kernel: ppp_tty_ioctl: set flags to 70000
Jun 21 12:28:12 localhost kernel: ppp_tty_ioctl: set xasyncmap
Jun 21 12:28:12 localhost kernel: ppp_tty_ioctl: set xmit asyncmap
ffffffff
Jun 21 12:28:12 localhost kernel: ppp_tty_ioctl: get flags: addr
bffffb4c flags 0
Jun 21 12:28:12 localhost kernel: ppp_tty_ioctl: set flags to 70000
Jun 21 12:28:12 localhost kernel: ppp_tty_ioctl: set mru to 5dc
Jun 21 12:28:12 localhost kernel: ppp_tty_ioctl: set rcv asyncmap
ffffffff
Jun 21 12:28:12 localhost kernel: ppp_tty_ioctl: get flags: addr
bffffb60 flags 0
Jun 21 12:28:12 localhost kernel: ppp_tty_ioctl: set flags to 70000
Jun 21 12:28:12 localhost pppd[341]: Using interface ppp0
Jun 21 12:28:12 localhost pppd[341]: Connect: ppp0 <--> /dev/modem
Jun 21 12:28:12 localhost pppd[341]: sent [LCP ConfReq id=0x1 <magic
0xffff08b1> <pcomp> <accomp>]
Jun 21 12:28:12 localhost kernel: ppp: write frame, count = 18
Jun 21 12:28:12 localhost kernel: FF 03 C0 21 01 01 00 0E ...!....
Jun 21 12:28:12 localhost kernel: 05 06 FF FF 08 B1 07 02 ........
Jun 21 12:28:12 localhost kernel: 08 02 ..
Jun 21 12:28:12 localhost kernel: ppp_dev_xmit_lower: fcs is f891
Jun 21 12:28:12 localhost kernel: ppp_dev_xmit: writing 34 chars
Jun 21 12:28:15 localhost pppd[341]: sent [LCP ConfReq id=0x1 <magic
0xffff08b1> <pcomp> <accomp>]
Jun 21 12:28:15 localhost kernel: ppp: write frame, count = 18
Jun 21 12:28:15 localhost kernel: FF 03 C0 21 01 01 00 0E ...!....
Jun 21 12:28:15 localhost kernel: 05 06 FF FF 08 B1 07 02 ........
Jun 21 12:28:15 localhost kernel: 08 02 ..
Jun 21 12:28:15 localhost kernel: ppp_dev_xmit_lower: fcs is f891
Jun 21 12:28:15 localhost kernel: ppp_dev_xmit: writing 34 chars
Jun 21 12:28:15 localhost kernel: ppp_tty_read: called buf=08063e50
nr=1504
Jun 21 12:28:15 localhost kernel: ppp_tty_read: no data (EAGAIN)
Jun 21 12:28:15 localhost kernel: ppp: receive frame, count = 28
Jun 21 12:28:15 localhost kernel: FF 03 C0 21 01 01 00 18 ...!....
Jun 21 12:28:15 localhost kernel: 02 06 00 00 00 00 03 04 ........
Jun 21 12:28:15 localhost kernel: C0 23 05 06 07 0A D2 03 .#......
Jun 21 12:28:15 localhost kernel: 07 02 08 02 ....
Jun 21 12:28:15 localhost kernel: ppp: successfully queued 26 bytes,
flags = f070000
Jun 21 12:28:15 localhost kernel: ppp: successfully queued 26 bytes,
flags = f070000
Jun 21 12:28:15 localhost kernel: ppp_tty_read: called buf=08063e50
nr=1504
Jun 21 12:28:15 localhost kernel: ppp_tty_read: len = 26
Jun 21 12:28:15 localhost kernel: ppp_tty_read: passing 28 bytes up
Jun 21 12:28:15 localhost kernel: ppp: write frame, count = 12
Jun 21 12:28:15 localhost kernel: FF 03 C0 21 04 01 00 08 ...!....
Jun 21 12:28:15 localhost kernel: 03 04 C0 23 ...#
Jun 21 12:28:15 localhost kernel: ppp_dev_xmit_lower: fcs is d42c
Jun 21 12:28:15 localhost kernel: ppp_dev_xmit: writing 23 chars
Jun 21 12:28:15 localhost kernel: ppp: receive frame, count = 18
Jun 21 12:28:15 localhost kernel: FF 03 C0 21 02 01 00 0E ...!....
Jun 21 12:28:15 localhost kernel: 05 06 FF FF 08 B1 07 02 ........
Jun 21 12:28:15 localhost pppd[341]: rcvd [LCP ConfReq id=0x1 <asyncmap
0x0> <auth pap> <magic 0x70ad203> <pcomp> <accomp>]
Jun 21 12:28:15 localhost pppd[341]: sent [LCP ConfRej id=0x1 <auth
pap>]
Jun 21 12:28:15 localhost pppd[341]: rcvd [LCP ConfAck id=0x1 <magic
0xffff08b1> <pcomp> <accomp>]
Jun 21 12:28:15 localhost pppd[341]: rcvd [LCP TermAck id=0x0]
Jun 21 12:28:15 localhost kernel: 08 02 ..
Jun 21 12:28:15 localhost kernel: ppp: successfully queued 16 bytes,
flags = f070000
Jun 21 12:28:15 localhost kernel: ppp: successfully queued 16 bytes,
flags = f070000
Jun 21 12:28:15 localhost kernel: ppp_tty_read: called buf=08063e50
nr=1504
Jun 21 12:28:15 localhost kernel: ppp_tty_read: len = 16
Jun 21 12:28:15 localhost kernel: ppp_tty_read: passing 18 bytes up
Jun 21 12:28:15 localhost kernel: ppp: frame with bad fcs, excess = b01c

Jun 21 12:28:15 localhost kernel: ppp: frame with bad fcs, excess = b01c

Jun 21 12:28:15 localhost kernel: ppp: receive frame, count = 8
Jun 21 12:28:15 localhost kernel: FF 03 C0 21 06 00 00 04 ...!....
Jun 21 12:28:15 localhost kernel: ppp: successfully queued 6 bytes,
flags = f070000
Jun 21 12:28:15 localhost kernel: ppp: successfully queued 6 bytes,
flags = f070000
Jun 21 12:28:15 localhost kernel: ppp_tty_read: called buf=08063e50
nr=1504
Jun 21 12:28:15 localhost kernel: ppp_tty_read: len = 6
Jun 21 12:28:15 localhost kernel: ppp_tty_read: passing 8 bytes up
Jun 21 12:28:18 localhost pppd[341]: sent [LCP ConfReq id=0x1 <magic
0xffff08b1> <pcomp> <accomp>]
Jun 21 12:28:18 localhost kernel: ppp: write frame, count = 18
Jun 21 12:28:18 localhost kernel: FF 03 C0 21 01 01 00 0E ...!....
Jun 21 12:28:18 localhost kernel: 05 06 FF FF 08 B1 07 02 ........
Jun 21 12:28:18 localhost kernel: 08 02 ..
Jun 21 12:28:18 localhost kernel: ppp_dev_xmit_lower: fcs is f891
Jun 21 12:28:18 localhost kernel: ppp_dev_xmit: writing 34 chars
Jun 21 12:28:18 localhost kernel: ppp_tty_read: called buf=08063e50
nr=1504
Jun 21 12:28:18 localhost kernel: ppp_tty_read: no data (EAGAIN)
Jun 21 12:28:21 localhost pppd[341]: sent [LCP ConfReq id=0x1 <magic
0xffff08b1> <pcomp> <accomp>]
Jun 21 12:28:21 localhost kernel: ppp: write frame, count = 18
Jun 21 12:28:21 localhost kernel: FF 03 C0 21 01 01 00 0E ...!....
Jun 21 12:28:21 localhost kernel: 05 06 FF FF 08 B1 07 02 ........
Jun 21 12:28:21 localhost kernel: 08 02 ..
Jun 21 12:28:21 localhost kernel: ppp_dev_xmit_lower: fcs is f891
Jun 21 12:28:21 localhost kernel: ppp_dev_xmit: writing 34 chars
Jun 21 12:28:21 localhost kernel: ppp_tty_read: called buf=08063e50
nr=1504
Jun 21 12:28:21 localhost kernel: ppp_tty_read: no data (EAGAIN)
Jun 21 12:28:24 localhost pppd[341]: sent [LCP ConfReq id=0x1 <magic
0xffff08b1> <pcomp> <accomp>]
Jun 21 12:28:24 localhost kernel: ppp: write frame, count = 18
Jun 21 12:28:24 localhost kernel: FF 03 C0 21 01 01 00 0E ...!....
Jun 21 12:28:24 localhost kernel: 05 06 FF FF 08 B1 07 02 ........
Jun 21 12:28:24 localhost kernel: 08 02 ..
Jun 21 12:28:24 localhost kernel: ppp_dev_xmit_lower: fcs is f891
Jun 21 12:28:24 localhost kernel: ppp_dev_xmit: writing 34 chars
Jun 21 12:28:24 localhost kernel: ppp_tty_read: called buf=08063e50
nr=1504
Jun 21 12:28:24 localhost kernel: ppp_tty_read: no data (EAGAIN)
Jun 21 12:28:27 localhost kernel: ppp: channel ppp0 closing.
Jun 21 12:28:27 localhost kernel: ppp: channel ppp0 closing.
Jun 21 12:28:27 localhost pppd[341]: Modem hangup
Jun 21 12:28:27 localhost pppd[341]: Connection terminated.
Jun 21 12:28:28 localhost pppd[341]: Exit.
Jun 21 12:29:51 localhost kernel: PPP: ppp line discipline successfully
unregistered

*********************end debug messages*******************************

by **Clifford Ki** » Tue, 23 Jun 1998 04:00:00

Fools rush in where gurus fear to tread.

I can't provide much, just observations about some things that you have
likely already made.

The message

ppp: frame with bad fcs, excess = b01c

is from the ppp kernel code, it means that the code has found something
that it regards as an error in incoming data. These occur after the ISP
has apparently given up.

This doesn't seem too surprising since the messages indicate a decided lack
of communication between the linux pppd and the ISP equivalent. See below.

One thing stands out, namely that the linux pppd does not request pap
authentication, which could be default behavior, and rejects the <pap auth>
in the ISP configuration request.

Sorry but that's about all. Hope a guru comes along and enlightens both
of us.

===

>I have installed Redhat 5.1 on a Satellite Pro 420CDT laptop and on
>another machine (not laptop). I can run ppp fine on the other machine,
>but when I use the same scripts (pap-secrets, etc.) on the laptop, pppd
>fails. I can connect using minicom and I eventually tried the other
>machine's external modem that works on the other machine with the same
>failing results on the laptop, so I do not think that the modem causes
>the problem. I run
>***
>pppd -detach modem crtscts defaultroute debug kdebug 7 /dev/modem 115200
>connect 'chat -v -f chatfilename'
>***
>and I included the kernel debug messages below. It seems to me that pppd
>is timing out sending config requests, and this is strange because from
>the other machine I can connect to the same ISP without any problem. The
>ISP has autoprotocoldetect running. As you can see the debug stuff
>contains the line
>*** ppp: frame with bad fcs, excess = b01c ***
>but I do not know the significance of that.
>I would really appreciate it if somebody could please help me out
>because I'm stuck. I even tried an earlier version of pppd with the same
>result so I really don't know what is going on.
>-Thank you,
>-Richard Mayer
>********************* debug messages
>**********************************************
>Jun 21 12:27:52 localhost kernel: CSLIP: code copyright 1989 Regents of
>the University of California
>Jun 21 12:27:52 localhost kernel: PPP: version 2.2.0 (dynamic channel
>allocation)
>Jun 21 12:27:52 localhost kernel: PPP Dynamic channel allocation code
>copyright 1995 Caldera, Inc.
>Jun 21 12:27:52 localhost kernel: PPP line discipline registered.
>Jun 21 12:27:52 localhost kernel: registered device ppp0
>Jun 21 12:27:52 localhost pppd[341]: pppd 2.3.3 started by root, uid 0
>Jun 21 12:27:54 localhost chat[345]: abort on (BUSY)
>Jun 21 12:27:54 localhost chat[345]: abort on (ERROR)
>Jun 21 12:27:54 localhost chat[345]: abort on (NO CARRIER)
>Jun 21 12:27:54 localhost chat[345]: abort on (NO DIALTONE)
>Jun 21 12:27:54 localhost chat[345]: abort on (Invalid Login)
>Jun 21 12:27:54 localhost chat[345]: abort on (Login incorrect)
>Jun 21 12:27:54 localhost chat[345]: send (ATZ^M)
>Jun 21 12:27:54 localhost chat[345]: expect (OK)
>Jun 21 12:27:54 localhost chat[345]: ATZ^M^M
>Jun 21 12:27:54 localhost chat[345]: OK
>Jun 21 12:27:54 localhost chat[345]: -- got it
>Jun 21 12:27:54 localhost chat[345]: send (ATDT5453700^M)
>Jun 21 12:27:54 localhost chat[345]: expect (CONNECT)
>Jun 21 12:27:54 localhost chat[345]: ^M
>Jun 21 12:28:11 localhost chat[345]: ATDT5453700^M^M
>Jun 21 12:28:11 localhost pppd[341]: Serial connection established.
>Jun 21 12:28:11 localhost chat[345]: CONNECT
>Jun 21 12:28:11 localhost chat[345]: -- got it
>Jun 21 12:28:11 localhost chat[345]: send (^M)

[snip]

Quote:>Jun 21 12:28:12 localhost pppd[341]: Using interface ppp0
>Jun 21 12:28:12 localhost pppd[341]: Connect: ppp0 <--> /dev/modem
>Jun 21 12:28:12 localhost pppd[341]: sent [LCP ConfReq id=0x1 <magic
>0xffff08b1> <pcomp> <accomp>] |

Configuration request by linux pppd ---------------
[snip]

Quote:>Jun 21 12:28:15 localhost pppd[341]: sent [LCP ConfReq id=0x1 <magic
>0xffff08b1> <pcomp> <accomp>] |

Repeated configuration request by linux pppd ------
[snip]

Quote:>Jun 21 12:28:15 localhost pppd[341]: rcvd [LCP ConfReq id=0x1 <asyncmap
>0x0> <auth pap> <magic 0x70ad203> <pcomp> <accomp>] |

Configuration request from ISP received by linux pppd -

Quote:>Jun 21 12:28:15 localhost pppd[341]: sent [LCP ConfRej id=0x1 <auth
>pap>] |

<auth pap> in ISP configuration request rejected by linux pppd

Quote:>Jun 21 12:28:15 localhost pppd[341]: rcvd [LCP ConfAck id=0x1 <magic
>0xffff08b1> <pcomp> <accomp>] |

Linux configuration request acknowledged by ISP ---

Quote:>Jun 21 12:28:15 localhost pppd[341]: rcvd [LCP TermAck id=0x0]

Termination acknowledgement by ISP but no prior termination request by
linux pppd
{snip]

Quote:>Jun 21 12:28:15 localhost kernel: ppp: frame with bad fcs, excess = b01c

Here is the CRC error from the kernel code----------------

Quote:>Jun 21 12:28:15 localhost kernel: ppp: frame with bad fcs, excess = b01c

And again ..............................------------------
[snip]

Quote:>Jun 21 12:28:18 localhost pppd[341]: sent [LCP ConfReq id=0x1 <magic

Linux pppd trucks on but ISP has quit.

Quote:>Jun 21 12:28:21 localhost pppd[341]: sent [LCP ConfReq id=0x1 <magic
>0xffff08b1> <pcomp> <accomp>]

Linux pppd still trying.

Quote:>Jun 21 12:28:24 localhost pppd[341]: sent [LCP ConfReq id=0x1 <magic

And yet again.

Quote:>0xffff08b1> <pcomp> <accomp>]
>Jun 21 12:28:24 localhost kernel: ppp: write frame, count = 18
>Jun 21 12:28:24 localhost kernel: FF 03 C0 21 01 01 00 0E ...!....
>Jun 21 12:28:24 localhost kernel: 05 06 FF FF 08 B1 07 02 ........
>Jun 21 12:28:24 localhost kernel: 08 02 ..
>Jun 21 12:28:24 localhost kernel: ppp_dev_xmit_lower: fcs is f891
>Jun 21 12:28:24 localhost kernel: ppp_dev_xmit: writing 34 chars
>Jun 21 12:28:24 localhost kernel: ppp_tty_read: called buf=08063e50
>nr=1504
>Jun 21 12:28:24 localhost kernel: ppp_tty_read: no data (EAGAIN)
>Jun 21 12:28:27 localhost kernel: ppp: channel ppp0 closing.
>Jun 21 12:28:27 localhost kernel: ppp: channel ppp0 closing.

Kernel gives up.

Quote:>Jun 21 12:28:27 localhost pppd[341]: Modem hangup
>Jun 21 12:28:27 localhost pppd[341]: Connection terminated.
>Jun 21 12:28:28 localhost pppd[341]: Exit.
>Jun 21 12:29:51 localhost kernel: PPP: ppp line discipline successfully
>unregistered
>*********************end debug messages*******************************

--
Clifford Kite Not a guru. (tm)

Very Computer

Strange pppd problem, can a kernel guru please help !!!

Strange pppd problem, can a kernel guru please help !!!

Strange pppd problem, can a kernel guru please help !!!