ppp Warning: Sending empty PAP authname!

From: Matthias Teege <matthias-dbsdq(at)mteege.de>
Date: Sat, 28 Jun 2003 19:48:34 +0200

Moin,

ich habe ein Problem bei der Konfiguration einer ppp Einwahl. Die
Einwahl läuft normal ab. Allerdings schlägt die Authentifizierung
fehl. Der Server meldet "Warning: Sending empty PAP authname!". Es
gibt ein paar Hinweise bei google aber ich habe, soweit ich das
beurteilen kann, Benutzername und Passwort gesetzt und der Rest ist
nicht wirklich hilfreich.

Vielleicht hat hier jemand einen Vorschlag. Hier meine Konfiguration
und die Logdateien.

Der Server, auf dem eingewählt werden soll läuft unter FreeBSD
4.7-STABLE. Auf ihm ist mgetty mit Auto-PPP installiert.

Die ppp.conf ist relativ einfach (glaube ich) und sieht wie folgt aus:

default:
 set log Phase Chat LCP IPCP CCP tun command

pap:
  enable pap
  enable proxy
  enable passwdauth

Außerdem habe ich die Datei ppp-pap-dialin mit folgendem Inhalt
angelegt:

#!/bin/sh
exec /usr/sbin/ppp -direct pap$IDENT

Auf dem Klienten läuft ein 4.8 STABLE und die ppp.conf sieht so aus:

default:
 set log Phase Chat LCP IPCP CCP tun command
 ident user-ppp VERSION (built COMPILATIONDATE)

 set device /dev/cuaa0

 set speed 115200
 set dial "ABORT BUSY ABORT NO\\sCARRIER TIMEOUT 5 \
           \"\" AT OK-AT-OK ATE1Q0 OK \\dATDT\\T TIMEOUT 40 CONNECT"
 set timeout 180 # 3 minute idle timer (the default)
 enable dns # request DNS info (for resolv.conf)

mteege:
 enable pap
 set phone 0123456789
 set authname "pppuser"
 set authkey "pppasswd"

Die Logdatei auf dem Server sieht wie folgt aus:

Jun 28 19:34:48 bullet ppp[12863]: Phase: Using interface: tun1
Jun 28 19:34:48 bullet ppp[12863]: Phase: deflink: Created in closed state
Jun 28 19:34:48 bullet ppp[12863]: tun1: Command: pap: enable pap
Jun 28 19:34:48 bullet ppp[12863]: tun1: Command: pap: enable proxy
Jun 28 19:34:48 bullet ppp[12863]: tun1: Command: pap: enable passwdauth
Jun 28 19:34:48 bullet ppp[12863]: tun1: Phase: PPP Started (direct mode).
Jun 28 19:34:48 bullet ppp[12863]: tun1: Phase: bundle: Establish
Jun 28 19:34:48 bullet ppp[12863]: tun1: Phase: deflink: closed -> opening
Jun 28 19:34:48 bullet ppp[12863]: tun1: Phase: deflink: Connected!
Jun 28 19:34:48 bullet ppp[12863]: tun1: Phase: deflink: opening -> carrier
Jun 28 19:34:49 bullet ppp[12863]: tun1: Phase: deflink: /dev/cuaa0: CD detected
Jun 28 19:34:49 bullet ppp[12863]: tun1: Phase: deflink: carrier -> lcp
Jun 28 19:34:49 bullet ppp[12863]: tun1: LCP: FSM: Using "deflink" as a transport
Jun 28 19:34:49 bullet ppp[12863]: tun1: LCP: deflink: State change Initial --> Closed
Jun 28 19:34:49 bullet ppp[12863]: tun1: LCP: deflink: State change Closed --> Stopped
Jun 28 19:34:49 bullet ppp[12863]: tun1: LCP: deflink: RecvConfigReq(9) state = Stopped
Jun 28 19:34:49 bullet ppp[12863]: tun1: LCP: ACFCOMP[2]
Jun 28 19:34:49 bullet ppp[12863]: tun1: LCP: PROTOCOMP[2]
Jun 28 19:34:49 bullet ppp[12863]: tun1: LCP: ACCMAP[6] 0x00000000
Jun 28 19:34:49 bullet ppp[12863]: tun1: LCP: MRU[4] 1500
Jun 28 19:34:49 bullet ppp[12863]: tun1: LCP: MAGICNUM[6] 0x9049ce49
Jun 28 19:34:49 bullet ppp[12863]: tun1: LCP: AUTHPROTO[4] 0xc023 (PAP)
Jun 28 19:34:49 bullet ppp[12863]: tun1: LCP: deflink: SendConfigReq(1) state = Stopped
Jun 28 19:34:49 bullet ppp[12863]: tun1: LCP: ACFCOMP[2]
Jun 28 19:34:49 bullet ppp[12863]: tun1: LCP: PROTOCOMP[2]
Jun 28 19:34:49 bullet ppp[12863]: tun1: LCP: ACCMAP[6] 0x00000000
Jun 28 19:34:49 bullet ppp[12863]: tun1: LCP: MRU[4] 1500
Jun 28 19:34:49 bullet ppp[12863]: tun1: LCP: MRU[4] 1500
Jun 28 19:34:49 bullet ppp[12863]: tun1: LCP: MAGICNUM[6] 0x8ad1e2a6
Jun 28 19:34:49 bullet ppp[12863]: tun1: LCP: AUTHPROTO[4] 0xc023 (PAP)
Jun 28 19:34:49 bullet ppp[12863]: tun1: LCP: deflink: SendConfigAck(9) state = Stopped
Jun 28 19:34:49 bullet ppp[12863]: tun1: LCP: ACFCOMP[2]
Jun 28 19:34:49 bullet ppp[12863]: tun1: LCP: PROTOCOMP[2]
Jun 28 19:34:49 bullet ppp[12863]: tun1: LCP: ACCMAP[6] 0x00000000
Jun 28 19:34:49 bullet ppp[12863]: tun1: LCP: MRU[4] 1500
Jun 28 19:34:49 bullet ppp[12863]: tun1: LCP: MAGICNUM[6] 0x9049ce49
Jun 28 19:34:49 bullet ppp[12863]: tun1: LCP: AUTHPROTO[4] 0xc023 (PAP)
Jun 28 19:34:49 bullet ppp[12863]: tun1: LCP: deflink: LayerStart
Jun 28 19:34:49 bullet ppp[12863]: tun1: LCP: deflink: State change Stopped --> Ack-Sent
Jun 28 19:34:50 bullet ppp[12863]: tun1: LCP: deflink: RecvConfigAck(1) state = Ack-Sent
Jun 28 19:34:50 bullet ppp[12863]: tun1: LCP: ACFCOMP[2]
Jun 28 19:34:50 bullet ppp[12863]: tun1: LCP: PROTOCOMP[2]
Jun 28 19:34:50 bullet ppp[12863]: tun1: LCP: ACCMAP[6] 0x00000000
Jun 28 19:34:50 bullet ppp[12863]: tun1: LCP: MRU[4] 1500
Jun 28 19:34:50 bullet ppp[12863]: tun1: LCP: MAGICNUM[6] 0x8ad1e2a6
Jun 28 19:34:50 bullet ppp[12863]: tun1: LCP: AUTHPROTO[4] 0xc023 (PAP)
Jun 28 19:34:50 bullet ppp[12863]: tun1: LCP: deflink: State change Ack-Sent --> Opened
Jun 28 19:34:50 bullet ppp[12863]: tun1: LCP: deflink: LayerUp
Jun 28 19:34:50 bullet ppp[12863]: tun1: Phase: bundle: Authenticate
Jun 28 19:34:50 bullet ppp[12863]: tun1: Phase: deflink: his = PAP, mine = PAP
Jun 28 19:34:50 bullet ppp[12863]: tun1: Phase: Pap Output: ********
Jun 28 19:34:50 bullet ppp[12863]: tun1: Warning: Sending empty PAP authname!
Jun 28 19:34:50 bullet ppp[12863]: tun1: LCP: deflink: RecvIdent(4) state = Opened
Jun 28 19:34:50 bullet ppp[12863]: tun1: LCP: MAGICNUM 9049ce49
Jun 28 19:34:50 bullet ppp[12863]: tun1: LCP: TEXT user-ppp 3.1 (built Jun 17 2003)
Jun 28 19:34:50 bullet ppp[12863]: tun1: Phase: Pap Input: REQUEST (pppuser)
Jun 28 19:34:50 bullet ppp[12863]: tun1: Phase: Pap Output: FAILURE
Jun 28 19:34:50 bullet ppp[12863]: tun1: LCP: deflink: LayerDown
Jun 28 19:34:50 bullet ppp[12863]: tun1: LCP: deflink: SendTerminateReq(2) state = Opened
Jun 28 19:34:50 bullet ppp[12863]: tun1: LCP: deflink: State change Opened --> Closing
Jun 28 19:34:51 bullet ppp[12863]: tun1: Phase: Pap Input: FAILURE (Login incorrect)
Jun 28 19:34:51 bullet ppp[12863]: tun1: LCP: deflink: RecvTerminateReq(10) state = Closing
Jun 28 19:34:51 bullet ppp[12863]: tun1: LCP: deflink: SendTerminateAck(10) state = Closing
Jun 28 19:34:51 bullet ppp[12863]: tun1: LCP: deflink: RecvTerminateAck(2) state = Closing
Jun 28 19:34:51 bullet ppp[12863]: tun1: LCP: deflink: LayerFinish
Jun 28 19:34:51 bullet ppp[12863]: tun1: LCP: deflink: State change Closing --> Closed
Jun 28 19:34:51 bullet ppp[12863]: tun1: LCP: deflink: State change Closed --> Initial
Jun 28 19:34:51 bullet ppp[12863]: tun1: Phase: deflink: Disconnected!
Jun 28 19:34:51 bullet ppp[12863]: tun1: Phase: deflink: Connect time: 3 secs: 305 octets in, 188 octets out
Jun 28 19:34:51 bullet ppp[12863]: tun1: Phase: deflink: 23 packets in, 6 packets out
Jun 28 19:34:51 bullet ppp[12863]: tun1: Phase: total 164 bytes/sec, peak 138 bytes/sec on Sat Jun 28 19:34:50 2003
Jun 28 19:34:51 bullet ppp[12870]: tun1: Phase: deflink: lcp -> closed
Jun 28 19:34:51 bullet ppp[12870]: tun1: Phase: bundle: Dead
Jun 28 19:34:51 bullet ppp[12870]: tun1: Phase: PPP Terminated (normal).

Der Klient meldet das hier:

Jun 28 18:38:03 jbook ppp[245]: tun0: Command: /dev/tty: dial
Jun 28 18:38:03 jbook ppp[245]: tun0: Phase: bundle: Establish
Jun 28 18:38:03 jbook ppp[245]: tun0: Phase: deflink: closed -> opening
Jun 28 18:38:03 jbook ppp[245]: tun0: Phase: deflink: Connected!
Jun 28 18:38:03 jbook ppp[245]: tun0: Phase: deflink: opening -> dial
Jun 28 18:38:03 jbook ppp[245]: tun0: Chat: Phone: 0123456789
Jun 28 18:38:03 jbook ppp[245]: tun0: Chat: deflink: Dial attempt 1 of 1
Jun 28 18:38:03 jbook ppp[245]: tun0: Chat: Send: AT^M
Jun 28 18:38:03 jbook ppp[245]: tun0: Chat: Expect(5): OK
Jun 28 18:38:03 jbook ppp[245]: tun0: Chat: Received: AT^M^M
Jun 28 18:38:03 jbook ppp[245]: tun0: Chat: Received: OK^M
Jun 28 18:38:03 jbook ppp[245]: tun0: Chat: Send: ATE1Q0^M
Jun 28 18:38:03 jbook ppp[245]: tun0: Chat: Expect(5): OK
Jun 28 18:38:03 jbook ppp[245]: tun0: Chat: Received: ATE1Q0^M^M
Jun 28 18:38:03 jbook ppp[245]: tun0: Chat: Received: OK^M
Jun 28 18:38:03 jbook ppp[245]: tun0: Chat: Send: ATDT0123456789^M
Jun 28 18:38:05 jbook ppp[245]: tun0: Chat: Expect(40): CONNECT
Jun 28 18:38:25 jbook ppp[245]: tun0: Chat: Received: ATDT0123456789^M^M
Jun 28 18:38:25 jbook ppp[245]: tun0: Chat: Received: CONNECT 9600/RLP^M
Jun 28 18:38:25 jbook ppp[245]: tun0: Phase: deflink: dial -> carrier
Jun 28 18:38:26 jbook ppp[245]: tun0: Phase: deflink: /dev/cuaa0: CD detected
Jun 28 18:38:26 jbook ppp[245]: tun0: Phase: deflink: carrier -> login
Jun 28 18:38:27 jbook ppp[245]: tun0: Phase: deflink: login -> lcp
Jun 28 18:38:27 jbook ppp[245]: tun0: LCP: FSM: Using "deflink" as a transport
Jun 28 18:38:27 jbook ppp[245]: tun0: LCP: deflink: State change Initial --> Closed
Jun 28 18:38:27 jbook ppp[245]: tun0: LCP: deflink: State change Closed --> Stopped
Jun 28 18:38:28 jbook ppp[245]: tun0: LCP: deflink: LayerStart
Jun 28 18:38:28 jbook ppp[245]: tun0: LCP: deflink: SendConfigReq(9) state = Stopped
Jun 28 18:38:28 jbook ppp[245]: tun0: LCP: ACFCOMP[2]
Jun 28 18:38:28 jbook ppp[245]: tun0: LCP: PROTOCOMP[2]
Jun 28 18:38:28 jbook ppp[245]: tun0: LCP: ACCMAP[6] 0x00000000
Jun 28 18:38:28 jbook ppp[245]: tun0: LCP: MRU[4] 1500
Jun 28 18:38:28 jbook ppp[245]: tun0: LCP: MAGICNUM[6] 0x9049ce49
Jun 28 18:38:28 jbook ppp[245]: tun0: LCP: AUTHPROTO[4] 0xc023 (PAP)
Jun 28 18:38:28 jbook ppp[245]: tun0: LCP: deflink: State change Stopped --> Req-Sent
Jun 28 18:38:28 jbook ppp[245]: tun0: LCP: deflink: RecvConfigReq(1) state = Req-Sent
Jun 28 18:38:28 jbook ppp[245]: tun0: LCP: ACFCOMP[2]
Jun 28 18:38:28 jbook ppp[245]: tun0: LCP: PROTOCOMP[2]
Jun 28 18:38:28 jbook ppp[245]: tun0: LCP: ACCMAP[6] 0x00000000
Jun 28 18:38:28 jbook ppp[245]: tun0: LCP: MRU[4] 1500
Jun 28 18:38:28 jbook ppp[245]: tun0: LCP: MAGICNUM[6] 0x8ad1e2a6
Jun 28 18:38:28 jbook ppp[245]: tun0: LCP: AUTHPROTO[4] 0xc023 (PAP)
Jun 28 18:38:28 jbook ppp[245]: tun0: LCP: deflink: SendConfigAck(1) state = Req-Sent
Jun 28 18:38:28 jbook ppp[245]: tun0: LCP: ACFCOMP[2]
Jun 28 18:38:28 jbook ppp[245]: tun0: LCP: PROTOCOMP[2]
Jun 28 18:38:28 jbook ppp[245]: tun0: LCP: ACCMAP[6] 0x00000000
Jun 28 18:38:28 jbook ppp[245]: tun0: LCP: MRU[4] 1500
Jun 28 18:38:28 jbook ppp[245]: tun0: LCP: MAGICNUM[6] 0x8ad1e2a6
Jun 28 18:38:28 jbook ppp[245]: tun0: LCP: AUTHPROTO[4] 0xc023 (PAP)
Jun 28 18:38:28 jbook ppp[245]: tun0: LCP: deflink: State change Req-Sent --> Ack-Sent
Jun 28 18:38:28 jbook ppp[245]: tun0: LCP: deflink: RecvConfigAck(9) state = Ack-Sent
Jun 28 18:38:28 jbook ppp[245]: tun0: LCP: ACFCOMP[2]
Jun 28 18:38:28 jbook ppp[245]: tun0: LCP: PROTOCOMP[2]
Jun 28 18:38:28 jbook ppp[245]: tun0: LCP: ACCMAP[6] 0x00000000
Jun 28 18:38:28 jbook ppp[245]: tun0: LCP: MRU[4] 1500
Jun 28 18:38:28 jbook ppp[245]: tun0: LCP: MAGICNUM[6] 0x9049ce49
Jun 28 18:38:28 jbook ppp[245]: tun0: LCP: AUTHPROTO[4] 0xc023 (PAP)
Jun 28 18:38:28 jbook ppp[245]: tun0: LCP: deflink: State change Ack-Sent --> Opened
Jun 28 18:38:28 jbook ppp[245]: tun0: LCP: deflink: LayerUp
Jun 28 18:38:28 jbook ppp[245]: tun0: LCP: deflink: SendIdent(4) state = Opened
Jun 28 18:38:28 jbook ppp[245]: tun0: LCP: MAGICNUM 9049ce49
Jun 28 18:38:28 jbook ppp[245]: tun0: LCP: TEXT user-ppp 3.1 (built Jun 17 2003)
Jun 28 18:38:28 jbook ppp[245]: tun0: Phase: bundle: Authenticate
Jun 28 18:38:28 jbook ppp[245]: tun0: Phase: deflink: his = PAP, mine = PAP
Jun 28 18:38:28 jbook ppp[245]: tun0: Phase: Pap Output: pppuser ********
Jun 28 18:38:29 jbook ppp[245]: tun0: Phase: Pap Input: REQUEST ()
Jun 28 18:38:29 jbook ppp[245]: tun0: Phase: Pap Output: FAILURE
Jun 28 18:38:29 jbook ppp[245]: tun0: LCP: deflink: LayerDown
Jun 28 18:38:29 jbook ppp[245]: tun0: LCP: deflink: SendTerminateReq(10) state = Opened
Jun 28 18:38:29 jbook ppp[245]: tun0: LCP: deflink: State change Opened --> Closing
Jun 28 18:38:29 jbook ppp[245]: tun0: Phase: Pap Input: FAILURE (Login incorrect)
Jun 28 18:38:29 jbook ppp[245]: tun0: LCP: deflink: RecvTerminateReq(2) state = Closing
Jun 28 18:38:29 jbook ppp[245]: tun0: LCP: deflink: SendTerminateAck(2) state = Closing
Jun 28 18:38:30 jbook ppp[245]: tun0: LCP: deflink: RecvTerminateAck(10) state = Closing
Jun 28 18:38:30 jbook ppp[245]: tun0: LCP: deflink: LayerFinish
Jun 28 18:38:30 jbook ppp[245]: tun0: LCP: deflink: State change Closing --> Closed
Jun 28 18:38:30 jbook ppp[245]: tun0: LCP: deflink: State change Closed --> Initial
Jun 28 18:38:30 jbook ppp[245]: tun0: Phase: deflink: Disconnected!
Jun 28 18:38:30 jbook ppp[245]: tun0: Phase: deflink: lcp -> logout
Jun 28 18:38:30 jbook ppp[245]: tun0: Phase: deflink: logout -> hangup
Jun 28 18:38:30 jbook ppp[245]: tun0: Phase: deflink: Disconnected!
Jun 28 18:38:30 jbook ppp[245]: tun0: Phase: deflink: Connect time: 27 secs: 225 octets in, 252 octets out
Jun 28 18:38:30 jbook ppp[245]: tun0: Phase: deflink: 92 packets in, 40 packets out
Jun 28 18:38:30 jbook ppp[245]: tun0: Phase: total 17 bytes/sec, peak 91 bytes/sec on Sat Jun 28 18:38:30 2003
Jun 28 18:38:30 jbook ppp[245]: tun0: Phase: deflink: hangup -> closed
Jun 28 18:38:30 jbook ppp[245]: tun0: Phase: bundle: Dead
Jun 28 18:39:55 jbook ppp[245]: tun0: Command: /dev/tty: quit
Jun 28 18:39:55 jbook ppp[245]: tun0: Phase: PPP Terminated (normal).

Vielen Dank
Matthias

-- 
Matthias Teege -- http://www.mteege.de
make world not war
PGP-Key auf Anfrage
To Unsubscribe: send mail to majordomo(at)de.FreeBSD.org
with "unsubscribe de-bsd-questions" in the body of the message
Received on Sat 28 Jun 2003 - 19:50:18 CEST

search this site