PPP Problem (Timeout LCP ConfReq)
Hi all,
I'm stuck with a problem related to ppp that is similar to the one already
brought up here by Ashby Gochenour's (see his post
http://lists.debian.org/debian-user-0007/msg00157.html in July).
Unfortunately, no solution working for me was given in the thread.
Short description of the problem:
---------------------------------
* Config:
- Debian GNU/Linux 2.2r0 _Potato_ Official i386
- Linux Kernel 2.4.0-test9
- PPP compiled as modules (ppp_generic.o, ppp_async.o)
that kerneld inserts successfuly
- ppp_2.3.11-1.4.deb
- pppconfig_2.0.5.deb
* Problem:
I configured the scripts with pppconfig. I use PAP and chat. pppd calls
the ISP, establishes a serial connection and dies with a LCP timeout after
having failed to send out ConfReqs. It seems to be a specific problem to
the above mentioned configuration as my SuSE 6.1 box (Linux 2.2.10,
pppd 2.3.5) works fine with the same ISP (i.e. it sends out the LCP
ConfReq and receives one shortly afterwards). I tried to use the SuSE
scripts on Debian, but pppd died with 'alarm'.
Any help is very appreciated!
Cheers,
Mike
PS: Long description of the problem:
------------------------------------
* Output of /var/log/ppp.log:
Oct 19 13:03:46 calypso pppd[219]: pppd 2.3.11 started by croon, uid 1000
Oct 19 13:03:47 calypso chat[220]: abort on (BUSY)
Oct 19 13:03:47 calypso chat[220]: abort on (NO CARRIER)
Oct 19 13:03:47 calypso chat[220]: abort on (VOICE)
Oct 19 13:03:47 calypso chat[220]: abort on (NO DIALTONE)
Oct 19 13:03:47 calypso chat[220]: abort on (NO DIAL TONE)
Oct 19 13:03:47 calypso chat[220]: abort on (NO ANSWER)
Oct 19 13:03:47 calypso chat[220]: send (ATZ^M)
Oct 19 13:03:47 calypso chat[220]: expect (OK)
Oct 19 13:04:06 calypso chat[220]: ATZ^M^M
Oct 19 13:04:06 calypso chat[220]: OK
Oct 19 13:04:06 calypso chat[220]: -- got it
Oct 19 13:04:06 calypso chat[220]: send (ATDT<deleted>^M)
Oct 19 13:04:06 calypso chat[220]: expect (CONNECT)
Oct 19 13:04:06 calypso chat[220]: ^M
Oct 19 13:04:46 calypso chat[220]: ATDT<deleted>^M
Oct 19 13:04:46 calypso chat[220]: CONNECT
Oct 19 13:04:46 calypso chat[220]: -- got it
Oct 19 13:04:46 calypso chat[220]: send (\d)
Oct 19 13:04:47 calypso pppd[219]: Serial connection established.
Oct 19 13:04:47 calypso pppd[219]: Using interface ppp0
Oct 19 13:04:47 calypso pppd[219]: Connect: ppp0 <--> /dev/ttyS1
Oct 19 13:04:48 calypso pppd[219]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0xb6080482> <pcomp> <accomp>]
Oct 19 13:05:15 calypso last message repeated 9 times
Oct 19 13:05:18 calypso pppd[219]: LCP: timeout sending Config-Requests
Oct 19 13:05:18 calypso pppd[219]: Connection terminated.
Oct 19 13:05:19 calypso pppd[219]: Exit.
* Here's /etc/ppp/peers/provider:
# This optionfile was generated by pppconfig 2.0.5.
#
#
hide-password
noauth
connect "/usr/sbin/chat -v -f /etc/chatscripts/provider"
debug
/dev/ttyS1
115200
defaultroute
noipdefault
user <deleted>
remotename provider
ipparam provider
* Here's /etc/chatscripts/provider:
# This chatfile was generated by pppconfig 2.0.5.
# Please do not delete any of the comments. Pppconfig needs them.
#
# ispauth PAP
# abortstring
ABORT BUSY ABORT 'NO CARRIER' ABORT VOICE ABORT 'NO DIALTONE' ABORT 'NO DIAL TONE' ABORT 'NO ANSWER'
# modeminit
'' ATZ
# ispnumber
OK-AT-OK ATDT<deleted>
# ispconnect
CONNECT \d\c
# prelogin
# ispname
# isppassword
# postlogin
# end of pppconfig stuff
Now, here's how pppd on my SuSE box gets the same job done:
------------------------------------------------------------
* First, some extracts from /var/log/messages:
Oct 15 22:27:38 mortisha kernel: CSLIP: code copyright 1989 Regents of the University of California
Oct 15 22:27:38 mortisha kernel: PPP: version 2.3.7 (demand dialling)
Oct 15 22:27:38 mortisha kernel: PPP line discipline registered.
Oct 15 22:27:38 mortisha kernel: registered device ppp0
Oct 15 22:27:38 mortisha pppd[723]: pppd 2.3.5 started by croon, uid 1001
Oct 15 22:27:39 mortisha chat[725]: timeout set to 30 seconds
Oct 15 22:27:39 mortisha chat[725]: abort on (NO CARRIER)
Oct 15 22:27:39 mortisha chat[725]: abort on (BUSY)
Oct 15 22:27:39 mortisha chat[725]: abort on (NO DIALTONE)
Oct 15 22:27:39 mortisha chat[725]: abort on (ERROR)
Oct 15 22:27:39 mortisha chat[725]: send (+++ATZ^M)
Oct 15 22:27:40 mortisha chat[725]: expect (OK)
Oct 15 22:27:40 mortisha chat[725]: ATZ^M^M
Oct 15 22:27:40 mortisha chat[725]: OK
Oct 15 22:27:40 mortisha chat[725]: -- got it
Oct 15 22:27:40 mortisha chat[725]: send (ATDT<deleted>^M)
Oct 15 22:27:40 mortisha chat[725]: expect (CONNECT)
Oct 15 22:27:40 mortisha chat[725]: ^M
Oct 15 22:28:08 mortisha chat[725]: ATDT<deleted>^M^M
Oct 15 22:28:08 mortisha pppd[723]: Serial connection established.
Oct 15 22:28:08 mortisha chat[725]: CONNECT
Oct 15 22:28:08 mortisha chat[725]: -- got it
Oct 15 22:28:09 mortisha kernel: ppp_ioctl: set dbg flags to 10000
Oct 15 22:28:09 mortisha kernel: ppp_ioctl: set flags to 10000
Oct 15 22:28:09 mortisha kernel: ppp_tty_ioctl: set xasyncmap
Oct 15 22:28:09 mortisha kernel: ppp_tty_ioctl: set xmit asyncmap ffffffff
Oct 15 22:28:09 mortisha kernel: ppp_ioctl: set flags to 10000
Oct 15 22:28:09 mortisha kernel: ppp_ioctl: set mru to 5dc
Oct 15 22:28:09 mortisha pppd[723]: Using interface ppp0
Oct 15 22:28:09 mortisha pppd[723]: Connect: ppp0 <--> /dev/modem
Oct 15 22:28:09 mortisha pppd[723]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x327b8cf3> <pcomp> <accomp>]
Oct 15 22:28:09 mortisha kernel: ppp_tty_ioctl: set rcv asyncmap ffffffff
Oct 15 22:28:09 mortisha kernel: ppp_ioctl: set flags to 10000
Oct 15 22:28:09 mortisha kernel: ppp: tossing frame (e0)
Oct 15 22:28:09 mortisha pppd[723]: rcvd [LCP ConfReq id=0x1 < 00 04 00 00> <mru 1524> <asyncmap 0xa0000> <auth pap> <pcomp> <accomp> < 11 04 05 f4> < 13 09 03 00 c0 7b 81 b3 93>]
Oct 15 22:28:09 mortisha pppd[723]: sent [LCP ConfRej id=0x1 < 00 04 00 00> < 11 04 05 f4> < 13 09 03 00 c0 7b 81 b3 93>]
Oct 15 22:28:09 mortisha pppd[723]: rcvd [LCP ConfAck id=0x1 <asyncmap 0x0> <magic 0x327b8cf3> <pcomp> <accomp>]
Oct 15 22:28:09 mortisha kernel: ppp_tty_ioctl: set xmit asyncmap a0000
Oct 15 22:28:09 mortisha kernel: ppp_ioctl: set flags to f010003
Oct 15 22:28:09 mortisha kernel: ppp_ioctl: set mru to 5dc
Oct 15 22:28:09 mortisha kernel: ppp_tty_ioctl: set rcv asyncmap 0
Oct 15 22:28:09 mortisha kernel: ppp_ioctl: set flags to f010003
Oct 15 22:28:09 mortisha pppd[723]: rcvd [LCP ConfReq id=0x2 <mru 1524> <asyncmap 0xa0000> <auth pap> <pcomp> <accomp>]
Oct 15 22:28:09 mortisha pppd[723]: sent [LCP ConfAck id=0x2 <mru 1524> <asyncmap 0xa0000> <auth pap> <pcomp> <accomp>]
Oct 15 22:28:09 mortisha pppd[723]: sent [PAP AuthReq id=0x1 user="<deleted>" password="<deleted>"]
Oct 15 22:28:09 mortisha kernel: ppp_proto_ccp rcvd=1 code=1 flags=f010003
Oct 15 22:28:09 mortisha kernel: ppp_ioctl: set flags to f010043
Oct 15 22:28:09 mortisha pppd[723]: rcvd [PAP AuthAck id=0x1 ""]
Oct 15 22:28:09 mortisha pppd[723]: Remote message:
Oct 15 22:28:09 mortisha pppd[723]: sent [IPCP ConfReq id=0x1 <addr 0.0.0.0> <compress VJ 0f 01>]
Oct 15 22:28:09 mortisha kernel: PPP BSD Compression module registered
Oct 15 22:28:09 mortisha kernel: PPP Deflate Compression module registered
Oct 15 22:28:09 mortisha kernel: ppp_proto_ccp rcvd=0 code=1 flags=f010043
Oct 15 22:28:09 mortisha kernel: ppp_proto_ccp rcvd=0 code=4 flags=f010043
Oct 15 22:28:09 mortisha pppd[723]: sent [CCP ConfReq id=0x1 <deflate 15> <deflate(old#) 15> <bsd v1 15>]
Oct 15 22:28:09 mortisha pppd[723]: rcvd [CCP ConfReq id=0x1 < 11 06 00 01 01 03>]
Oct 15 22:28:09 mortisha pppd[723]: sent [CCP ConfRej id=0x1 < 11 06 00 01 01 03>]
Oct 15 22:28:09 mortisha pppd[723]: rcvd [IPCP ConfReq id=0x1 <compress VJ 0f 01> <addr <deleted>>]
Oct 15 22:28:09 mortisha pppd[723]: sent [IPCP ConfAck id=0x1 <compress VJ 0f 01> <addr <deleted>>]
Oct 15 22:28:09 mortisha pppd[723]: rcvd [IPCP ConfNak id=0x1 <addr <deleted>>]
Oct 15 22:28:09 mortisha pppd[723]: sent [IPCP ConfReq id=0x2 <addr <deleted>> <compress VJ 0f 01>]
Oct 15 22:28:09 mortisha kernel: ppp_proto_ccp rcvd=1 code=4 flags=f010043
Oct 15 22:28:09 mortisha kernel: ppp_proto_ccp rcvd=0 code=1 flags=f010043
Oct 15 22:28:09 mortisha kernel: ppp_ioctl: set maxcid to 16
Oct 15 22:28:09 mortisha kernel: ppp_ioctl: set flags to f010047
Oct 15 22:28:09 mortisha kernel: ppp: set np 0 to 0
Oct 15 22:28:09 mortisha pppd[723]: rcvd [CCP ConfRej id=0x1 <deflate 15> <deflate(old#) 15> <bsd v1 15>]
Oct 15 22:28:09 mortisha pppd[723]: sent [CCP ConfReq id=0x2]
Oct 15 22:28:09 mortisha pppd[723]: rcvd [IPCP ConfAck id=0x2 <addr <deleted>> <compress VJ 0f 01>]
Oct 15 22:28:09 mortisha pppd[723]: local IP address <deleted>
Oct 15 22:28:09 mortisha pppd[723]: remote IP address <deleted>
Oct 15 22:28:10 mortisha kernel: ppp_proto_ccp rcvd=1 code=4 flags=f010047
Oct 15 22:28:10 mortisha pppd[723]: rcvd [CCP ConfRej id=0x2]
* Now the corresponding /etc/ppp/options:
name <deleted>
noipdefault
defaultroute
debug
kdebug 1
noauth
crtscts
lock
modem
asyncmap 0
nodetach
noipx
/dev/modem
115200
connect "/usr/sbin/chat -v -f /etc/ppp/chat-public"
* And the corresponding /etc/ppp/chat-public:
TIMEOUT 30
ABORT "NO CARRIER"
ABORT BUSY
ABORT "NO DIALTONE"
ABORT ERROR
"" +++ATZ
OK ATDT<deleted>
CONNECT
Reply to: