From: Rich Kulawiec (rsk@gsp.org)
Date: Wed Mar 26 2003 - 12:04:27 EST
System: Tadpole Sparcbook 3GX running Solaris 2.5.1
PPP version: PPP 2.4.1 (the open-source version) compiled on the
target system with gcc 2.95.2
Modem: 56K PCMCIA modem (known working, see below).
Problem: The entire subsystem (PPP et.al.) is known to work when dialing
ISP #1; in fact, it works like a champ. I believe this indicates that
PPP is installed correctly, that the modem is functioning properly, etc.
However, it does not work when dialing ISP #2; it appears to be having an
issue trying to negotiate PPP options. ISP #2 is using PAP authentication
and so one highly likely cause for this is my error in not setting up
PAP correctly on my side. Another difference is that ISP #1 requires
authentication via a user/password combination, and then starts up PPP,
whereas ISP #2 simply starts PPP on connection. (I believe this is
consistent with how PAP is supposed to be used but I may be wrong about that.)
However, several passes through the PPP docs as well as Celeste's
documentation, plus quite a bit of time trying to debug this by changing
various options, have all failed to produce enlightenment, so I suspect
that I'm overlooking something highly obvious.
I'm invoking pppd via chat (which comes with it) via a command
line which looks like (split here for readability):
/usr/local/bin/pppd debug connect \'/usr/local/bin/chat -v \"\" ATDT123456789
CONNECT \"\"\' /dev/cua/d 57600 defaultroute user USER@RADIUSDOMAIN debug kdebug 7"
BTW: This is the command line used for ISP #2; the one for ISP #1 is slightly
different and includes the arguments to "chat" necessary for authentication.
My /etc/ppp/pap-secrets file looks like this:
USER@RADIUSDOMAIN * MYPASSWORD *
My /etc/ppp/options file looks like this:
noauth
I have enabled debugging in PPP at compile-time and have also modified
syslog.conf appropriately to capture that info. Enclosed below are two
syslog excerpts: the 1st shows a successful connection to ISP #1, the 2nd
shows an unsuccessful connection to ISP #2. If my rather feeble understanding
of PPP is correct, the ConfReq/ConfRej/ConfAck sequences represent negotiation
of various options by both sides of the connection.
-----------------------------------------------------------------------
Successful connection to ISP #1
-----------------------------------------------------------------------
Mar 26 10:56:14 cheech pppd[623]: pppd 2.4.1 started by rsk, uid 1234
Mar 26 10:56:17 cheech chat[629]: send (ATDT0123456789^M)
Mar 26 10:56:17 cheech chat[629]: expect (Login:)
Mar 26 10:56:40 cheech chat[629]: ATDT0123456789^M^M
Mar 26 10:56:40 cheech chat[629]: CONNECT 44000/ARQ/V90/LAPM/V42BIS^M
Mar 26 10:56:40 cheech chat[629]: Login:
Mar 26 10:56:40 cheech chat[629]: -- got it
Mar 26 10:56:40 cheech chat[629]: send (user@XXXXXXXXXXXXXXXX^M)
Mar 26 10:56:41 cheech chat[629]: expect (Password:)
Mar 26 10:56:41 cheech chat[629]: XXXXXXXXXXXXXXXXXXXX^M
Mar 26 10:56:41 cheech chat[629]: Password:
Mar 26 10:56:41 cheech chat[629]: -- got it
Mar 26 10:56:41 cheech chat[629]: send (YYYYYYYYYYYYYYY^M)
Mar 26 10:56:41 cheech pppd[623]: Serial connection established.
Mar 26 10:56:41 cheech unix: ppp0: bad fcs (len=1)
Mar 26 10:56:41 cheech pppd[623]: Using interface ppp0
Mar 26 10:56:41 cheech pppd[623]: Connect: ppp0 <--> /dev/cua/d
Mar 26 10:56:42 cheech pppd[623]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x434af393> <pcomp> <accomp>]
Mar 26 10:56:42 cheech pppd[623]: rcvd 0a 53 74 61 72 74 69 6e 67 20 50 50 50 20
Mar 26 10:56:42 cheech pppd[623]: get_input: Received non-LCP packet when LCP not open.
Mar 26 10:56:42 cheech pppd[623]: rcvd 53 65 73 73 69 6f 6e 20 66 72 6f 6d 20 31
Mar 26 10:56:42 cheech pppd[623]: get_input: Received non-LCP packet when LCP not open.
Mar 26 10:56:42 cheech pppd[623]: rcvd 36 32 2e 33 33 2e 39 34 2e 31 32 30 20 74
Mar 26 10:56:42 cheech pppd[623]: get_input: Received non-LCP packet when LCP not open.
Mar 26 10:56:42 cheech pppd[623]: rcvd 6f 20 31 36 32 2e 33 33 2e 31 36 30 2e 31
Mar 26 10:56:42 cheech pppd[623]: get_input: Received non-LCP packet when LCP not open.
Mar 26 10:56:42 cheech pppd[623]: rcvd 30 39 0d 0a 7e ff 7d 23 c0 21 7d 21 7d 21
Mar 26 10:56:42 cheech pppd[623]: get_input: Received non-LCP packet when LCP not open.
Mar 26 10:56:42 cheech pppd[623]: rcvd 7d 20 7d 39 7d 22 7d 26 7d 20 7d 2a 7d 20
Mar 26 10:56:42 cheech pppd[623]: get_input: Received non-LCP packet when LCP not open.
Mar 26 10:56:42 cheech pppd[623]: rcvd 7d 20 7d 25 7d 26 28 7d 5e c4 7d 37 7d 31
Mar 26 10:56:42 cheech pppd[623]: get_input: Received non-LCP packet when LCP not open.
Mar 26 10:56:42 cheech pppd[623]: rcvd 7d 24 7d 25 dc 7d 33 7d 25 7d 21 99 44 5d
Mar 26 10:56:42 cheech pppd[623]: get_input: Received non-LCP packet when LCP not open.
Mar 26 10:56:42 cheech pppd[623]: rcvd [LCP ConfRej id=0x1 <pcomp> <accomp>]
Mar 26 10:56:42 cheech pppd[623]: Untimeout 0x17ac8:0x4c530.
Mar 26 10:56:42 cheech pppd[623]: sent [LCP ConfReq id=0x2 <asyncmap 0x0> <magic 0x434af393>]
Mar 26 10:56:42 cheech pppd[623]: rcvd [LCP ConfAck id=0x2 <asyncmap 0x0> <magic 0x434af393>]
Mar 26 10:56:43 cheech pppd[623]: rcvd [LCP ConfReq id=0x2 <asyncmap 0xa0000> <magic 0x287ec417> <mrru 1500> <endpoint 13 05 01 99 44>]
Mar 26 10:56:43 cheech pppd[623]: lcp_reqci: returning CONFREJ.
Mar 26 10:56:43 cheech pppd[623]: sent [LCP ConfRej id=0x2 <mrru 1500>]
Mar 26 10:56:43 cheech pppd[623]: rcvd [LCP ConfReq id=0x3 <asyncmap 0xa0000> <magic 0x287ec417> <endpoint 13 05 01 99 44>]
Mar 26 10:56:43 cheech pppd[623]: lcp_reqci: returning CONFACK.
Mar 26 10:56:43 cheech pppd[623]: sent [LCP ConfAck id=0x3 <asyncmap 0xa0000> <magic 0x287ec417> <endpoint 13 05 01 99 44>]
Mar 26 10:56:43 cheech pppd[623]: Untimeout 0x17ac8:0x4c530.
Mar 26 10:56:43 cheech pppd[623]: sent [IPCP ConfReq id=0x1 <addr 192.168.0.78> <compress VJ 0f 01>]
Mar 26 10:56:43 cheech pppd[623]: sent [CCP ConfReq id=0x1 <deflate 15> <deflate(old#) 15> <bsd v1 15>]
Mar 26 10:56:44 cheech pppd[623]: rcvd [IPCP ConfReq id=0x1 <compress VJ 0f 00> <addr 01.02.03.04>]
Mar 26 10:56:44 cheech pppd[623]: ipcp: returning Configure-ACK
Mar 26 10:56:44 cheech pppd[623]: sent [IPCP ConfAck id=0x1 <compress VJ 0f 00> <addr 01.02.03.04>]
Mar 26 10:56:44 cheech pppd[623]: rcvd [LCP ProtRej id=0x4 80 fd 01 01 00 0f 1a 04 78 00 18 04 78 00 15 03 2f]
Mar 26 10:56:44 cheech pppd[623]: Untimeout 0x17ac8:0x4c4f8.
Mar 26 10:56:46 cheech pppd[623]: rcvd [IPCP ConfReq id=0x2 <compress VJ 0f 00> <addr 01.02.03.04>]
Mar 26 10:56:46 cheech pppd[623]: ipcp: returning Configure-ACK
Mar 26 10:56:46 cheech pppd[623]: sent [IPCP ConfAck id=0x2 <compress VJ 0f 00> <addr 01.02.03.04>]
Mar 26 10:56:46 cheech pppd[623]: sent [IPCP ConfReq id=0x1 <addr 01.02.03.04> <compress VJ 0f 01>]
Mar 26 10:56:47 cheech pppd[623]: rcvd [IPCP ConfNak id=0x1 <addr 01.02.03.04> <compress VJ 0f 00>]
Mar 26 10:56:47 cheech pppd[623]: Untimeout 0x17ac8:0x4b3bc.
Mar 26 10:56:47 cheech pppd[623]: sent [IPCP ConfReq id=0x2 <addr 01.02.03.04> <compress VJ 0f 00>]
Mar 26 10:56:47 cheech pppd[623]: rcvd [IPCP ConfAck id=0x2 <addr 01.02.03.04> <compress VJ 0f 00>]
Mar 26 10:56:47 cheech pppd[623]: Untimeout 0x17ac8:0x4b3bc.
Mar 26 10:56:47 cheech pppd[623]: ipcp: up
Mar 26 10:56:47 cheech pppd[623]: local IP address 01.02.03.04
Mar 26 10:56:47 cheech pppd[623]: remote IP address 05.06.07.08
-----------------------------------------------------------------------
Unsuccessful connection to ISP #2
-----------------------------------------------------------------------
Mar 26 11:13:40 cheech unix: ppp/0: debug log enabled
Mar 26 11:13:40 cheech unix: ppp/0: ioctl 7082 count=0
Mar 26 11:13:40 cheech unix: ppp/1: debug log enabled
Mar 26 11:13:40 cheech unix: ppp/1: dlpi prim 0 len=4
Mar 26 11:13:40 cheech pppd[709]: pppd 2.4.1 started by rsk, uid 1234
Mar 26 11:13:43 cheech chat[712]: send (ATDT9876543210^M)
Mar 26 11:13:43 cheech chat[712]: expect (CONNECT)
Mar 26 11:14:11 cheech chat[712]: ATDT9876543210^M^M
Mar 26 11:14:11 cheech chat[712]: CONNECT
Mar 26 11:14:11 cheech chat[712]: -- got it
Mar 26 11:14:11 cheech chat[712]: send (^M)
Mar 26 11:14:11 cheech pppd[709]: Serial connection established.
Mar 26 11:14:11 cheech unix: ppp/0: ioctl 7090 count=4
Mar 26 11:14:11 cheech unix: ppp/0: ioctl 7090 count=4
Mar 26 11:14:11 cheech unix: ppp/0: ioctl 530c count=12
Mar 26 11:14:11 cheech pppd[709]: Using interface ppp0
Mar 26 11:14:11 cheech pppd[709]: Connect: ppp0 <--> /dev/cua/d
Mar 26 11:14:11 cheech unix: ppp/0: ioctl 708a count=32
Mar 26 11:14:11 cheech unix: ppp/0: ioctl 7085 count=4
Mar 26 11:14:11 cheech unix: ppp/0: ioctl 708a count=4
Mar 26 11:14:11 cheech unix: ppp/0: ioctl 7087 count=8
Mar 26 11:14:11 cheech unix: ppp/0: ioctl 7086 count=4
Mar 26 11:14:11 cheech unix: ppp/0: ioctl 708b count=4
Mar 26 11:14:12 cheech unix: ppp/0: ioctl 7087 count=8
Mar 26 11:14:12 cheech pppd[709]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x99e22c89> <pcomp> <accomp>]
Mar 26 11:14:12 cheech unix: ppp/0: uwput M_DATA len=24 flags=13
Mar 26 11:14:15 cheech pppd[709]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x99e22c89> <pcomp> <accomp>]
Mar 26 11:14:15 cheech unix: ppp/0: uwput M_DATA len=24 flags=13
Mar 26 11:14:18 cheech pppd[709]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x99e22c89> <pcomp> <accomp>]
Mar 26 11:14:18 cheech unix: ppp/0: uwput M_DATA len=24 flags=13
Mar 26 11:14:21 cheech pppd[709]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x99e22c89> <pcomp> <accomp>]
Mar 26 11:14:21 cheech unix: ppp/0: uwput M_DATA len=24 flags=13
Mar 26 11:14:24 cheech pppd[709]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x99e22c89> <pcomp> <accomp>]
Mar 26 11:14:24 cheech unix: ppp/0: uwput M_DATA len=24 flags=13
Mar 26 11:14:27 cheech pppd[709]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x99e22c89> <pcomp> <accomp>]
Mar 26 11:14:27 cheech unix: ppp/0: uwput M_DATA len=24 flags=13
Mar 26 11:14:30 cheech pppd[709]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x99e22c89> <pcomp> <accomp>]
Mar 26 11:14:30 cheech unix: ppp/0: uwput M_DATA len=24 flags=13
Mar 26 11:14:33 cheech pppd[709]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x99e22c89> <pcomp> <accomp>]
Mar 26 11:14:33 cheech unix: ppp/0: uwput M_DATA len=24 flags=13
Mar 26 11:14:36 cheech pppd[709]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x99e22c89> <pcomp> <accomp>]
Mar 26 11:14:36 cheech unix: ppp/0: uwput M_DATA len=24 flags=13
Mar 26 11:14:39 cheech pppd[709]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x99e22c89> <pcomp> <accomp>]
Mar 26 11:14:39 cheech unix: ppp/0: uwput M_DATA len=24 flags=13
Mar 26 11:14:42 cheech pppd[709]: LCP: timeout sending Config-Requests
Mar 26 11:14:42 cheech pppd[709]: Connection terminated.
Mar 26 11:14:42 cheech unix: ppp/0: ioctl 708f count=0
Mar 26 11:14:42 cheech unix: ppp/0: ioctl 530d count=12
Mar 26 11:14:42 cheech pppd[709]: Hangup (SIGHUP)
Mar 26 11:14:43 cheech unix: ppp/1: close, flags=11
Mar 26 11:14:43 cheech pppd[709]: Exit.
Mar 26 11:14:43 cheech unix: ppp/0: close, flags=13
Any help in getting this working would be much appreciated, and I'll
of course summarize for the benefit of future readers.
---Rsk
_______________________________________________
sunmanagers mailing list
sunmanagers@sunmanagers.org
http://www.sunmanagers.org/mailman/listinfo/sunmanagers
This archive was generated by hypermail 2.1.7 : Wed Apr 09 2008 - 23:26:04 EDT