Skip site navigation (1)Skip section navigation (2)
Date:      Thu, 2 Nov 2000 23:33:54 -0700
From:      "Robert Goff" <robert@goff.com>
To:        "FreeBSD Questions" <questions@FreeBSD.ORG>
Subject:   User PPP Won't Authenticate (second request)
Message-ID:  <FBEEJKONBLAFDBENBGOFGEFJEDAA.robert@goff.com>

next in thread | raw e-mail | index | archive | help
I have two modems connected to cuaa0 and cuaa1.  User ppp in interactive
mode can talk to both of them.  ppp in auto seems to intialize ok, and can
dial and connect on the first modem.  However, it can't authenticate with
the server, and I can't read the log well enough to determine why.  It looks
like the server is asking for PAP, but after ppp sends the username and
password something seems to go wrong and I don't know what.

I tried it with a unix-style login chat script, but that's definitly wrong.
The server never sends a login: prompt in the clear.  I checked that in
interactive mode too.

Could someone look this over and tell me what you see?  Thanks.  (ppp.conf
is at the bottom)

Oct 27 11:49:44 brittany ppp[228]: Phase: Using interface: tun0
Oct 27 11:49:44 brittany ppp[228]: Phase: deflink: Created in closed state
Oct 27 11:49:44 brittany ppp[228]: tun0: Command: default: set speed 115200
Oct 27 11:49:44 brittany ppp[228]: tun0: Command: default: set dial ABORT
BUSY ABORT NO\sCARRIER ABORT NO\sDIALTONE TIMEOUT 5            "" AT
OK-AT-OK ATE1Q0 OK \dATDT\T TIMEOUT 40 CONNECT
Oct 27 11:49:44 brittany ppp[228]: tun0: Command: fisi_multi_auto: load
fisi_auth
Oct 27 11:49:44 brittany ppp[228]: tun0: Command: fisi_auth: set phone
326-5625
Oct 27 11:49:44 brittany ppp[228]: tun0: Command: fisi_auth: set authname
avalon

Oct 27 11:49:44 brittany ppp[228]: tun0: Command: fisi_auth: set authkey
********
Oct 27 11:49:44 brittany ppp[228]: tun0: Command: fisi_multi_auto: load
multi_auto
Oct 27 11:49:44 brittany ppp[228]: tun0: Command: multi_auto: set reconnect
10 0
Oct 27 11:49:44 brittany ppp[228]: tun0: Command: multi_auto: set mrru 1500
Oct 27 11:49:44 brittany ppp[228]: tun0: Command: multi_auto: set mru 1504
Oct 27 11:49:44 brittany ppp[228]: tun0: Command: multi_auto: set login
Oct 27 11:49:44 brittany ppp[228]: tun0: Command: multi_auto: set timeout
600
Oct 27 11:49:44 brittany ppp[228]: tun0: Command: multi_auto: set ifaddr
10.0.0.1/0 10.0.0.2/0 255.255.255.0 0.0.0.0
Oct 27 11:49:44 brittany ppp[228]: tun0: Command: multi_auto: add default
HISADDR
Oct 27 11:49:44 brittany ppp[228]: tun0: Command: multi_auto: enable dns
Oct 27 11:49:44 brittany ppp[228]: tun0: Command: multi_auto: nat enable yes
Oct 27 11:49:44 brittany ppp[228]: tun0: Command: multi_auto: link deflink
clone 1 2
Oct 27 11:49:44 brittany ppp[228]: tun0: Phase: 1: Cloned in closed state
Oct 27 11:49:44 brittany ppp[228]: tun0: Phase: 2: Cloned in closed state
Oct 27 11:49:44 brittany ppp[228]: tun0: Command: multi_auto: link deflink
remove
Oct 27 11:49:44 brittany ppp[228]: tun0: Command: multi_auto: link * set
mode auto
Oct 27 11:49:44 brittany ppp[229]: tun0: Phase: PPP Started (auto mode).

This to me looks like the auto mode was set up correctly at least to the
point of dialing.

Here's what happened when I tried to open an ftp connection to the outside:

Oct 27 11:49:53 brittany ppp[229]: tun0: Phase: bundle: Establish
Oct 27 11:49:53 brittany ppp[229]: tun0: Phase: 1: closed -> opening
Oct 27 11:49:53 brittany ppp[229]: tun0: Phase: 1: Connected!
Oct 27 11:49:53 brittany ppp[229]: tun0: Phase: 1: opening -> dial
Oct 27 11:49:53 brittany ppp[229]: tun0: Chat: Phone: 326-5625
Oct 27 11:49:53 brittany ppp[229]: tun0: Chat: 1: Dial attempt 1 of 1
Oct 27 11:49:53 brittany ppp[229]: tun0: Chat: Send: AT^M
Oct 27 11:49:53 brittany ppp[229]: tun0: Chat: Expect(5): OK
Oct 27 11:49:53 brittany ppp[229]: tun0: Chat: Received: ^M
Oct 27 11:49:53 brittany ppp[229]: tun0: Chat: Received: OK^M
Oct 27 11:49:53 brittany ppp[229]: tun0: Chat: Send: ATE1Q0^M
Oct 27 11:49:53 brittany ppp[229]: tun0: Chat: Expect(5): OK
Oct 27 11:49:54 brittany ppp[229]: tun0: Chat: Received: ^M
Oct 27 11:49:54 brittany ppp[229]: tun0: Chat: Received: OK^M
Oct 27 11:49:54 brittany ppp[229]: tun0: Chat: Send: ATDT326-5625^M
Oct 27 11:49:56 brittany ppp[229]: tun0: Chat: Expect(40): CONNECT
Oct 27 11:50:26 brittany ppp[229]: tun0: Chat: Received: ATDT326-5625^M^M
Oct 27 11:50:26 brittany ppp[229]: tun0: Chat: Received: CONNECT 31200^M
Oct 27 11:50:26 brittany ppp[229]: tun0: Phase: 1: dial -> carrier
Oct 27 11:50:27 brittany ppp[229]: tun0: Phase: 1: /dev/cuaa0: CD detected
Oct 27 11:50:27 brittany ppp[229]: tun0: Phase: 1: carrier -> login
Oct 27 11:50:27 brittany ppp[229]: tun0: Phase: 1: login -> lcp
Oct 27 11:50:27 brittany ppp[229]: tun0: LCP: FSM: Using "1" as a transport
Oct 27 11:50:27 brittany ppp[229]: tun0: LCP: 1: State change Initial -->
Closed
Oct 27 11:50:27 brittany ppp[229]: tun0: LCP: 1: State change Closed -->
Stopped
Oct 27 11:50:28 brittany ppp[229]: tun0: LCP: 1: LayerStart
Oct 27 11:50:28 brittany ppp[229]: tun0: LCP: 1: SendConfigReq(1) state =
Stopped
Oct 27 11:50:28 brittany ppp[229]: tun0: LCP:  ACFCOMP[2]
Oct 27 11:50:28 brittany ppp[229]: tun0: LCP:  PROTOCOMP[2]
Oct 27 11:50:28 brittany ppp[229]: tun0: LCP:  ACCMAP[6] 0x00000000
Oct 27 11:50:28 brittany ppp[229]: tun0: LCP:  MRU[4] 1500
Oct 27 11:50:28 brittany ppp[229]: tun0: LCP:  MAGICNUM[6] 0x8dfb2a46
Oct 27 11:50:28 brittany ppp[229]: tun0: LCP:  MRRU[4] 1500
Oct 27 11:50:28 brittany ppp[229]: tun0: LCP:  SHORTSEQ[2]
Oct 27 11:50:28 brittany ppp[229]: tun0: LCP: 1: State change Stopped -->
Req-Sent
Oct 27 11:50:28 brittany ppp[229]: tun0: LCP: 1: RecvConfigReq(1) state =
Req-Sent
Oct 27 11:50:28 brittany ppp[229]: tun0: LCP:  MRU[4] 1522
Oct 27 11:50:28 brittany ppp[229]: tun0: LCP:  ACCMAP[6] 0x000a0000
Oct 27 11:50:28 brittany ppp[229]: tun0: LCP:  AUTHPROTO[4] 0xc023 (PAP)
Oct 27 11:50:28 brittany ppp[229]: tun0: LCP:  MAGICNUM[6] 0x2c391edd
Oct 27 11:50:28 brittany ppp[229]: tun0: LCP:  ACFCOMP[2]
Oct 27 11:50:28 brittany ppp[229]: tun0: LCP:  MRRU[4] 1522
Oct 27 11:50:28 brittany ppp[229]: tun0: LCP:  SHORTSEQ[2]
Oct 27 11:50:28 brittany ppp[229]: tun0: LCP:  ENDDISC[9] MAC
00:80:d3:8b:1b:00
Oct 27 11:50:28 brittany ppp[229]: tun0: LCP:  LDBACP[4] 847a
Oct 27 11:50:28 brittany ppp[229]: tun0: LCP: 1: SendConfigRej(1) state =
Req-Sent
Oct 27 11:50:28 brittany ppp[229]: tun0: LCP:  LDBACP[4] 847a
Oct 27 11:50:28 brittany ppp[229]: tun0: LCP: Sending ident magic 8dfb2a46
text
user-ppp 2.27 (built Sep 25 2000)
Oct 27 11:50:28 brittany ppp[229]: tun0: LCP: 1: SendIdent(0) state =
Req-Sent
Oct 27 11:50:28 brittany ppp[229]: tun0: LCP: 1: RecvConfigAck(1) state =
Req-Sent
Oct 27 11:50:28 brittany ppp[229]: tun0: LCP: 1: State change Req-Sent -->
Ack-Rcvd
Oct 27 11:50:28 brittany ppp[229]: tun0: LCP: 1: RecvConfigReq(2) state =
Ack-Rcvd
Oct 27 11:50:28 brittany ppp[229]: tun0: LCP:  MRU[4] 1522
Oct 27 11:50:28 brittany ppp[229]: tun0: LCP:  ACCMAP[6] 0x000a0000
Oct 27 11:50:28 brittany ppp[229]: tun0: LCP:  AUTHPROTO[4] 0xc023 (PAP)
Oct 27 11:50:28 brittany ppp[229]: tun0: LCP:  MAGICNUM[6] 0x2c391edd
Oct 27 11:50:28 brittany ppp[229]: tun0: LCP:  ACFCOMP[2]
Oct 27 11:50:28 brittany ppp[229]: tun0: LCP:  MRRU[4] 1522
Oct 27 11:50:28 brittany ppp[229]: tun0: LCP:  SHORTSEQ[2]
Oct 27 11:50:28 brittany ppp[229]: tun0: LCP:  ENDDISC[9] MAC
00:80:d3:8b:1b:00
Oct 27 11:50:28 brittany ppp[229]: tun0: LCP: 1: SendConfigAck(2) state =
Ack-Rcvd
Oct 27 11:50:28 brittany ppp[229]: tun0: LCP:  MRU[4] 1522
Oct 27 11:50:28 brittany ppp[229]: tun0: LCP:  ACCMAP[6] 0x000a0000
Oct 27 11:50:28 brittany ppp[229]: tun0: LCP:  AUTHPROTO[4] 0xc023 (PAP)
Oct 27 11:50:28 brittany ppp[229]: tun0: LCP:  MAGICNUM[6] 0x2c391edd
Oct 27 11:50:28 brittany ppp[229]: tun0: LCP:  ACFCOMP[2]
Oct 27 11:50:28 brittany ppp[229]: tun0: LCP:  MRRU[4] 1522
Oct 27 11:50:28 brittany ppp[229]: tun0: LCP:  SHORTSEQ[2]
Oct 27 11:50:28 brittany ppp[229]: tun0: LCP:  ENDDISC[9] MAC
00:80:d3:8b:1b:00
Oct 27 11:50:28 brittany ppp[229]: tun0: LCP: 1: State change Ack-Rcvd -->
Opened
Oct 27 11:50:28 brittany ppp[229]: tun0: LCP: 1: LayerUp
Oct 27 11:50:28 brittany ppp[229]: tun0: LCP: Sending ident magic 8dfb2a46
text user-ppp 2.27 (built Sep 25 2000)
Oct 27 11:50:28 brittany ppp[229]: tun0: LCP: 1: SendIdent(1) state = Opened
Oct 27 11:50:28 brittany ppp[229]: tun0: Phase: bundle: Authenticate
Oct 27 11:50:28 brittany ppp[229]: tun0: Phase: 1: his = PAP, mine = none
Oct 27 11:50:28 brittany ppp[229]: tun0: Phase: Pap Output: avalon ********
Oct 27 11:50:32 brittany ppp[229]: tun0: Phase: Pap Output: avalon ********

It looks like here is where the trouble starts:

Oct 27 11:50:32 brittany ppp[229]: tun0: Phase: Pap Input: SUCCESS dropped
(got id 1, not 2)
Oct 27 11:50:32 brittany ppp[229]: tun0: Phase: Unexpected protocol 0x003d
(Multi-Link)
Oct 27 11:50:32 brittany ppp[229]: tun0: LCP: 1: SendProtocolRej(2) state =
Opened
Oct 27 11:50:32 brittany ppp[229]: tun0: Phase: Unexpected protocol 0x003d
(Multi-Link)
Oct 27 11:50:32 brittany ppp[229]: tun0: LCP: 1: SendProtocolRej(2) state =
Opened
Oct 27 11:50:32 brittany ppp[229]: tun0: Phase: Unexpected protocol 0x003d
(Multi-Link)
Oct 27 11:50:32 brittany ppp[229]: tun0: LCP: 1: SendProtocolRej(2) state =
Opened
Oct 27 11:50:32 brittany ppp[229]: tun0: Phase: Unexpected protocol 0x003d
(Multi-Link)
Oct 27 11:50:32 brittany ppp[229]: tun0: LCP: 1: SendProtocolRej(2) state =
Opened
Oct 27 11:50:34 brittany ppp[229]: tun0: Phase: Unexpected protocol 0x003d
(Multi-Link)
Oct 27 11:50:34 brittany ppp[229]: tun0: LCP: 1: SendProtocolRej(2) state =
Opened
Oct 27 11:50:34 brittany ppp[229]: tun0: Phase: Unexpected protocol 0x003d
(Multi-Link)
Oct 27 11:50:34 brittany ppp[229]: tun0: LCP: 1: SendProtocolRej(2) state =
Opened
Oct 27 11:50:34 brittany ppp[229]: tun0: Phase: Unexpected protocol 0x003d
(Multi-Link)
Oct 27 11:50:34 brittany ppp[229]: tun0: LCP: 1: SendProtocolRej(2) state =
Opened
Oct 27 11:50:34 brittany ppp[229]: tun0: Phase: Unexpected protocol 0x003d
(Multi-Link)
Oct 27 11:50:34 brittany ppp[229]: tun0: LCP: 1: SendProtocolRej(2) state =
Opened
Oct 27 11:50:35 brittany ppp[229]: tun0: Phase: Pap Output: avalon ********
Oct 27 11:50:36 brittany ppp[229]: tun0: Phase: Unexpected protocol 0x003d
(Multi-Link)
Oct 27 11:50:36 brittany ppp[229]: tun0: LCP: 1: SendProtocolRej(2) state =
Opened
Oct 27 11:50:36 brittany ppp[229]: tun0: Phase: Unexpected protocol 0x003d
(Multi-Link)
Oct 27 11:50:36 brittany ppp[229]: tun0: LCP: 1: SendProtocolRej(2) state =
Opened
Oct 27 11:50:36 brittany ppp[229]: tun0: Phase: Unexpected protocol 0x003d
(Multi-Link)
Oct 27 11:50:36 brittany ppp[229]: tun0: LCP: 1: SendProtocolRej(2) state =
Opened
Oct 27 11:50:36 brittany ppp[229]: tun0: Phase: Unexpected protocol 0x003d
(Multi-Link)
Oct 27 11:50:36 brittany ppp[229]: tun0: LCP: 1: SendProtocolRej(2) state =
Opened
Oct 27 11:50:38 brittany ppp[229]: tun0: Phase: Auth: No response from
server
Oct 27 11:50:38 brittany ppp[229]: tun0: LCP: 1: LayerDown
Oct 27 11:50:38 brittany ppp[229]: tun0: LCP: 1: SendTerminateReq(2) state =
Opened
Oct 27 11:50:38 brittany ppp[229]: tun0: LCP: 1: State change Opened -->
Closing
Oct 27 11:50:38 brittany ppp[229]: tun0: Phase: Unexpected protocol 0x003d
(Multi-Link)
Oct 27 11:50:38 brittany ppp[229]: tun0: LCP: 1: SendProtocolRej(2) state =
Closing
Oct 27 11:50:38 brittany ppp[229]: tun0: Phase: Unexpected protocol 0x003d
(Multi-Link)
Oct 27 11:50:38 brittany ppp[229]: tun0: LCP: 1: SendProtocolRej(2) state =
Closing
Oct 27 11:50:38 brittany ppp[229]: tun0: Phase: Unexpected protocol 0x003d
(Multi-Link)
Oct 27 11:50:38 brittany ppp[229]: tun0: LCP: 1: SendProtocolRej(2) state =
Closing
Oct 27 11:50:38 brittany ppp[229]: tun0: Phase: Unexpected protocol 0x003d
(Multi-Link)
Oct 27 11:50:38 brittany ppp[229]: tun0: LCP: 1: SendProtocolRej(2) state =
Closing
Oct 27 11:50:38 brittany ppp[229]: tun0: LCP: 1: RecvTerminateAck(2) state =
Closing
Oct 27 11:50:38 brittany ppp[229]: tun0: LCP: 1: LayerFinish
Oct 27 11:50:38 brittany ppp[229]: tun0: LCP: 1: State change Closing -->
Closed
Oct 27 11:50:38 brittany ppp[229]: tun0: LCP: 1: State change Closed -->
Initial
Oct 27 11:50:38 brittany ppp[229]: tun0: Phase: 1: Disconnected!
Oct 27 11:50:38 brittany ppp[229]: tun0: Phase: 1: lcp -> logout
Oct 27 11:50:38 brittany ppp[229]: tun0: Phase: 1: logout -> hangup
Oct 27 11:50:38 brittany ppp[229]: tun0: Phase: 1: Disconnected!
Oct 27 11:50:38 brittany ppp[229]: tun0: Phase: 1: Connect time: 45 secs:
979 octets in, 1620 octets out
Oct 27 11:50:38 brittany ppp[229]: tun0: Phase: 1: : 20 packets in, 25
packets out
Oct 27 11:50:38 brittany ppp[229]: tun0: Phase:  total 57 bytes/sec, peak
308 bytes/sec on Fri Oct 27 11:50:38 2000

This is ppp.conf

#################################################################
# PPP  Sample Configuration File
# Originally written by Toshiharu OHNO
# Simplified 5/14/1999 by wself@cdrom.com
#
# See /usr/share/examples/ppp/ for some examples
#
# $FreeBSD: src/etc/ppp/ppp.conf,v 1.2.2.1 2000/08/18 08:33:02 jhb Exp $
#################################################################

default:
 ident user-ppp VERSION (built COMPILATIONDATE)

 # Ensure that "device" references the correct serial port
 # for your modem. (cuaa0 = COM1, cuaa1 = COM2)
 set device /dev/cuaa0 /dev/cuaa1

 set log Phase Chat LCP IPCP CCP tun command
 set speed 115200
 set dial "ABORT BUSY ABORT NO\\sCARRIER ABORT NO\\sDIALTONE TIMEOUT 5 \
           \"\" AT OK-AT-OK ATE1Q0 OK \\dATDT\\T TIMEOUT 40 CONNECT"

fisi_multi_auto:
 load fisi_auth
 load multi_auto

fisi_auth:
 set phone 326-5625
 set authname avalon
 set authkey tflaa09

# If you want to use PAP or CHAP instead of using a unix-style login
# procedure, do the following.  Note, the peer suggests whether we
# should send PAP or CHAP.  By default, we send whatever we're asked for.
#
multi_auto:
 # Reconnect after loss of carrier, with 10 second delays between each
attempt:
 set reconnect 10 0

 # To enable multilink capabilities, you must specify a MRRU.  1500 is
 # a reasonable value.  To create new links, use the ``clone'' command
 # to duplicate an existing link.  If you already have more than one
 # link, you must specify which link you wish to run the command on via
 # the ``link'' command.
 set mrru 1500
 set mru 1504               # Room for the MP header

# set login "ABORT NO\\sCARRIER TIMEOUT 5 ogin:--ogin: avalon word: \\P"
 set login
 set timeout 600			# 10 minute idle timer
 set ifaddr 10.0.0.1/0 10.0.0.2/0 255.255.255.0 0.0.0.0
 add default HISADDR
 enable dns
 nat enable yes

 # All the examples clone links '1' and '2', and remove 'deflink';
 # I don't know why deflink can't be used.
 link deflink clone 1 2
 link deflink remove
 link * set mode auto

--
What if there were no hypothetical questions?
===============================================
Robert Goff                     robert@goff.com
Technical Writer/Editor, Webmaster 505-564-8959



To Unsubscribe: send mail to majordomo@FreeBSD.org
with "unsubscribe freebsd-questions" in the body of the message




Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?FBEEJKONBLAFDBENBGOFGEFJEDAA.robert>