PPP connection problem with Motorola cell phone as USB modem

Discussion:

(too old to reply)

JBorch

2009-07-13 06:02:50 UTC

I am trying to use my cell phone as a modem to connect to the T-Mobile
network. I have successfully connected on Windows XP but can't seem
to connect with my PowerBook running OS 10.4.11. It seems to be an
authentication problem. The remote server does not require
authentication and I leave both the username and password blank on
both XP and OS X. XP connects fine, but OS X doesn't. Can anybody
help me?

Here are the logs from both XP and OS X.

XP Modem Log:

07-12-2009 21:42:54.855 - File: C:\WINDOWS\system32\tapisrv.dll,
Version 5.1.2600
07-12-2009 21:42:54.855 - File: C:\WINDOWS\system32\unimdm.tsp,
Version 5.1.2600
07-12-2009 21:42:54.855 - File: C:\WINDOWS\system32\unimdmat.dll,
Version 5.1.2600
07-12-2009 21:42:54.855 - File: C:\WINDOWS\system32\uniplat.dll,
Version 5.1.2600
07-12-2009 21:42:54.855 - File: C:\WINDOWS\system32\drivers\modem.sys,
Version 5.1.2600
07-12-2009 21:42:54.855 - File: C:\WINDOWS\system32\modemui.dll,
Version 5.1.2600
07-12-2009 21:42:54.855 - File: C:\WINDOWS\system32\mdminst.dll,
Version 5.1.2600
07-12-2009 21:42:54.855 - Modem type: Motorola USB Modem
07-12-2009 21:42:54.855 - Modem inf path: oem27.inf
07-12-2009 21:42:54.855 - Modem inf section: USBMOTOROLA_COMMON
07-12-2009 21:42:54.855 - Matching hardware ID: usb\vid_22b8&pid_6422
07-12-2009 21:42:54.870 - 921600,8,N,1, ctsfl=0, rtsctl=1
07-12-2009 21:42:54.870 - Initializing modem.
07-12-2009 21:42:54.870 - CD is high while initializing modem.
07-12-2009 21:42:54.886 - Send: ATE0<cr>
07-12-2009 21:42:54.886 - Recv: ATE0<cr>
07-12-2009 21:42:54.886 - Command Echo
07-12-2009 21:42:54.886 - Recv: <cr><lf>OK<cr><lf>
07-12-2009 21:42:54.886 - Interpreted response: OK
07-12-2009 21:42:54.902 - Send: ATS7=60<cr>
07-12-2009 21:42:54.902 - Recv: <cr><lf>OK<cr><lf>
07-12-2009 21:42:54.902 - Interpreted response: OK
07-12-2009 21:42:54.902 - Sending user initialization commands.
07-12-2009 21:42:54.917 - Send: at
+cgdcont=1,"IP","wap.voicestream.com"<cr>
07-12-2009 21:42:54.949 - Recv: <cr><lf>OK<cr><lf>
07-12-2009 21:42:54.949 - Interpreted response: OK
07-12-2009 21:42:54.949 - Waiting for a call.
07-12-2009 21:42:54.964 - Send: ATS0=0<cr>
07-12-2009 21:42:54.964 - Recv: <cr><lf>OK<cr><lf>
07-12-2009 21:42:54.964 - Interpreted response: OK
07-12-2009 21:42:54.980 - 921600,8,N,1, ctsfl=1, rtsctl=2
07-12-2009 21:42:54.980 - Initializing modem.
07-12-2009 21:42:54.980 - CD is high while initializing modem.
07-12-2009 21:42:54.995 - Send: ATE0<cr>
07-12-2009 21:42:54.995 - Recv: <cr><lf>OK<cr><lf>
07-12-2009 21:42:54.995 - Interpreted response: OK
07-12-2009 21:42:55.011 - Send: ATS7=60<cr>
07-12-2009 21:42:55.011 - Recv: <cr><lf>OK<cr><lf>
07-12-2009 21:42:55.011 - Interpreted response: OK
07-12-2009 21:42:55.011 - Sending user initialization commands.
07-12-2009 21:42:55.027 - Send: at
+cgdcont=1,"IP","wap.voicestream.com"<cr>
07-12-2009 21:42:55.074 - Recv: <cr><lf>OK<cr><lf>
07-12-2009 21:42:55.074 - Interpreted response: OK
07-12-2009 21:42:55.074 - Dialing.
07-12-2009 21:42:55.074 - Send: ATD*###<cr>
07-12-2009 21:42:55.089 - Recv: <cr><lf>CONNECT<cr><lf>
07-12-2009 21:42:55.089 - Interpreted response: Connect
07-12-2009 21:42:55.089 - Connection established at 921600bps.
07-12-2009 21:42:55.089 - Error-control off or unknown.
07-12-2009 21:42:55.089 - Data compression off or unknown.
07-12-2009 21:43:25.089 - Read: Total: 69917, Per/Sec: 2329, Written:
Total: 21174, Per/Sec: 703
07-12-2009 21:43:44.745 - Hanging up the modem.
07-12-2009 21:43:44.745 - Hardware hangup by lowering DTR.
07-12-2009 21:43:54.745 - A timeout has expired waiting to comm event
to occour.
07-12-2009 21:43:54.745 - WARNING: After lowering DTR to hangup, the
modem did not drop CD with in 10 seconds, Attempting software hangup.
07-12-2009 21:43:54.745 - Send: +++

OS X ppp log:

===== Monday, July 13, 2009 12:00:05 AM US/Mountain =====
Mon Jul 13 00:00:13 2009 : CCLWrite : AT\13
Mon Jul 13 00:00:13 2009 : CCLMatched : OK\13\10
Mon Jul 13 00:00:13 2009 : CCLWrite : AT&FE0V1&C1S0=0\13
Mon Jul 13 00:00:13 2009 : CCLMatched : OK\13\10
Mon Jul 13 00:00:15 2009 : CCLWrite : AT
+CGDCONT=1,"IP","wap.voicestream.com",,0,0\13
Mon Jul 13 00:00:15 2009 : CCLMatched : OK\13\10
Mon Jul 13 00:00:15 2009 : Making GPRS connection
Mon Jul 13 00:00:15 2009 : CCLWrite : ATD*99#\13
Mon Jul 13 00:00:15 2009 : CCLMatched : CONNECT
Mon Jul 13 00:00:19 2009 : Serial connection established.
Mon Jul 13 00:00:20 2009 : using link 0
Mon Jul 13 00:00:20 2009 : Using interface ppp0
Mon Jul 13 00:00:20 2009 : Connect: ppp0 <--> /dev/cu.usbmodem5B21
Mon Jul 13 00:00:21 2009 : sent [LCP ConfReq id=0x1 <asyncmap 0x0>
<magic 0x41c13706> <pcomp> <accomp>]
Mon Jul 13 00:00:21 2009 : rcvd [LCP ConfReq id=0x1 <asyncmap 0x0>
<auth pap> <magic 0x428f8488> <pcomp> <accomp>]
Mon Jul 13 00:00:21 2009 : No auth is possible
Mon Jul 13 00:00:21 2009 : lcp_reqci: returning CONFREJ.
Mon Jul 13 00:00:21 2009 : sent [LCP ConfRej id=0x1 <auth pap>]
Mon Jul 13 00:00:21 2009 : rcvd [LCP ConfAck id=0x1 <asyncmap 0x0>
<magic 0x41c13706> <pcomp> <accomp>]
Mon Jul 13 00:00:21 2009 : rcvd [LCP ConfReq id=0x2 <asyncmap 0x0>
<magic 0x428f8488> <pcomp> <accomp>]
Mon Jul 13 00:00:21 2009 : lcp_reqci: returning CONFACK.
Mon Jul 13 00:00:21 2009 : sent [LCP ConfAck id=0x2 <asyncmap 0x0>
<magic 0x428f8488> <pcomp> <accomp>]
Mon Jul 13 00:00:21 2009 : sent [IPCP ConfReq id=0x1 <compress VJ 0f
01> <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns3 0.0.0.0>]
Mon Jul 13 00:00:21 2009 : sent [IPV6CP ConfReq id=0x1 <addr
fe80::020d:93ff:feb4:f4d4>]
Mon Jul 13 00:00:21 2009 : rcvd [LCP TermReq id=0x3 "peer refused to
authenticate"]
Mon Jul 13 00:00:21 2009 : LCP terminated by peer (peer refused to
authenticate)
Mon Jul 13 00:00:21 2009 : sent [LCP TermAck id=0x3]
Mon Jul 13 00:00:24 2009 : Connection terminated.
Mon Jul 13 00:00:25 2009 : CCLWrite : +++
Mon Jul 13 00:00:28 2009 : CCLWrite : ATH0\13
Mon Jul 13 00:00:28 2009 : CCLMatched : OK\13\10
Mon Jul 13 00:00:29 2009 : CCLWrite : AT&F\13
Mon Jul 13 00:00:30 2009 : CCLMatched : OK\13\10
Mon Jul 13 00:00:30 2009 : Serial link disconnected.

Anssi Saari

2009-07-13 14:17:25 UTC

Permalink

Post by JBorch
I am trying to use my cell phone as a modem to connect to the T-Mobile
network. I have successfully connected on Windows XP but can't seem
to connect with my PowerBook running OS 10.4.11. It seems to be an
authentication problem. The remote server does not require
authentication and I leave both the username and password blank on
both XP and OS X. XP connects fine, but OS X doesn't. Can anybody
help me?

Perhaps you just need to provide some username and password, no matter
what? A very old lesson from a Palm VX...

JBorch

2009-07-13 14:32:15 UTC

Permalink

Post by Anssi Saari

Perhaps you just need to provide some username and password, no matter
what? A very old lesson from a Palm VX...

I've tried that too. If I enter a username and password it
authenticates but then immediately disconnects. And I can connect
fine in XP without a username and password which makes me think it is
something about the way OS X is handling the PPP handshake.

Here is the PPP log from XP:

[604] 08:25:58:962: PPPEMSG_Start recvd, d=,
hPort=5,callback=0,mask=83034a,IfType=-1
[3980] 08:25:58:962: Line up event occurred on port 5
[3980] 08:25:58:962: Local identification = MSRAS-0-JBORCHERT
[3980] 08:25:58:962: PortName: COM6
[3980] 08:25:58:962: Starting PPP on link with
IfType=0xffffffff,IPIf=0xffffffff,IPXIf=0xffffffff
[3980] 08:25:58:962: RasGetBuffer returned 5ed4020 for SendBuf
[3980] 08:25:58:962: FsmInit called for protocol = c021, port = 5
[3980] 08:25:58:962: ConfigInfo = 83034a
[3980] 08:25:58:962: APs available = 5e
[3980] 08:25:58:962: FsmReset called for protocol = c021, port = 5
[3980] 08:25:58:962: Inserting port in bucket # 0
[3980] 08:25:58:962: Inserting bundle in bucket # 1
[3980] 08:25:58:962: FsmOpen event received for protocol c021 on port
5
[3980] 08:25:58:962: FsmThisLayerStarted called for protocol = c021,
port = 5
[3980] 08:25:58:962: FsmUp event received for protocol c021 on port 5
[3980] 08:25:58:962: <PPP packet sent at 07/13/2009 14:25:58:962
[3980] 08:25:58:962: <Protocol = LCP, Type = Configure-Req, Length =
0x19, Id = 0x0, Port = 5
[3980] 08:25:58:962: <C0 21 01 00 00 17 02 06 00 00 00 00 05 06 55 17
|.!............U.|
[3980] 08:25:58:962: <3C 64 07 02 08 02 0D 03 06 00 00 00 00 00 00 00 |
<d..............|
[3980] 08:25:58:962:
[3980] 08:25:58:962: InsertInTimerQ called
portid=0,Id=0,Protocol=c021,EventType=0,fAuth=0
[3980] 08:25:58:962: InsertInTimerQ called
portid=0,Id=0,Protocol=0,EventType=3,fAuth=0
[3980] 08:26:00:977: Recv timeout event received for
portid=0,Id=0,Protocol=c021,fAuth=0
[3980] 08:26:00:977: NotifyCaller(hPort=5, dwMsgId=9)
[3980] 08:26:00:977: <PPP packet sent at 07/13/2009 14:26:00:977
[3980] 08:26:00:977: <Protocol = LCP, Type = Configure-Req, Length =
0x19, Id = 0x1, Port = 5
[3980] 08:26:00:977: <C0 21 01 01 00 17 02 06 00 00 00 00 05 06 55 17
|.!............U.|
[3980] 08:26:00:977: <3C 64 07 02 08 02 0D 03 06 00 00 00 00 00 00 00 |
<d..............|
[3980] 08:26:00:977:
[3980] 08:26:00:977: InsertInTimerQ called
portid=0,Id=1,Protocol=c021,EventType=0,fAuth=0
[2572] 08:26:00:993: Packet received (26 bytes) for hPort 5
[3980] 08:26:00:993: >PPP packet received at 07/13/2009 14:26:00:993
[3980] 08:26:00:993: >Protocol = LCP, Type = Configure-Req, Length =
0x1a, Id = 0x1, Port = 5
[3980] 08:26:00:993: >C0 21 01 01 00 18 02 06 00 00 00 00 03 04 C0 23
|.!.............#|
[3980] 08:26:00:993: >05 06 59 E8 97 F5 07 02 08 02 00 00 00 00 00 00
|..Y.............|
[3980] 08:26:00:993:
[3980] 08:26:00:993: <PPP packet sent at 07/13/2009 14:26:00:993
[3980] 08:26:00:993: <Protocol = LCP, Type = Configure-Ack, Length =
0x1a, Id = 0x1, Port = 5
[3980] 08:26:00:993: <C0 21 02 01 00 18 02 06 00 00 00 00 03 04 C0 23
|.!.............#|
[3980] 08:26:00:993: <05 06 59 E8 97 F5 07 02 08 02 00 00 00 00 00 00
|..Y.............|
[3980] 08:26:00:993:
[2572] 08:26:00:993: Packet received (9 bytes) for hPort 5
[3980] 08:26:00:993: >PPP packet received at 07/13/2009 14:26:00:993
[3980] 08:26:00:993: >Protocol = LCP, Type = Configure-Reject, Length
= 0x9, Id = 0x1, Port = 5
[3980] 08:26:00:993: >C0 21 04 01 00 07 0D 03 06 00 00 00 00 00 00 00
|.!..............|
[3980] 08:26:00:993:
[3980] 08:26:00:993: RemoveFromTimerQ called
portid=0,Id=1,Protocol=c021,EventType=0,fAuth=0
[3980] 08:26:00:993: <PPP packet sent at 07/13/2009 14:26:00:993
[3980] 08:26:00:993: <Protocol = LCP, Type = Configure-Req, Length =
0x16, Id = 0x2, Port = 5
[3980] 08:26:00:993: <C0 21 01 02 00 14 02 06 00 00 00 00 05 06 55 17
|.!............U.|
[3980] 08:26:00:993: <3C 64 07 02 08 02 00 00 00 00 00 00 00 00 00 00 |
<d..............|
[3980] 08:26:00:993:
[3980] 08:26:00:993: InsertInTimerQ called
portid=0,Id=2,Protocol=c021,EventType=0,fAuth=0
[2572] 08:26:00:993: Packet received (22 bytes) for hPort 5
[3980] 08:26:00:993: >PPP packet received at 07/13/2009 14:26:00:993
[3980] 08:26:00:993: >Protocol = LCP, Type = Configure-Ack, Length =
0x16, Id = 0x2, Port = 5
[3980] 08:26:00:993: >C0 21 02 02 00 14 02 06 00 00 00 00 05 06 55 17
|.!............U.|
[3980] 08:26:00:993: >3C 64 07 02 08 02 00 00 00 00 00 00 00 00 00 00 |
<d..............|
[3980] 08:26:00:993:
[3980] 08:26:00:993: RemoveFromTimerQ called
portid=0,Id=2,Protocol=c021,EventType=0,fAuth=0
[3980] 08:26:00:993: FsmThisLayerUp called for protocol = c021, port =
5
[3980] 08:26:00:993: LCP Local Options-------------
[3980] 08:26:00:993:
MRU=1500,ACCM=0,Auth=0,MagicNumber=1427586148,PFC=ON,ACFC=ON
[3980] 08:26:00:993: Recv Framing =
PPP,SSHF=OFF,MRRU=1500,LinkDiscrim=0,BAP=OFF
[3980] 08:26:00:993: LCP Remote Options-------------
[3980] 08:26:00:993:
MRU=1500,ACCM=0,Auth=c023,MagicNumber=1508415477,PFC=ON,ACFC=ON
[3980] 08:26:00:993: Send Framing =
PPP,SSHF=OFF,MRRU=1500,LinkDiscrim=0
[3980] 08:26:00:993: LCP Configured successfully
[3980] 08:26:00:993: <PPP packet sent at 07/13/2009 14:26:00:993
[3980] 08:26:00:993: <Protocol = LCP, Type = Identification, Length =
0x14, Id = 0x3, Port = 5
[3980] 08:26:00:993: <C0 21 0C 03 00 12 55 17 3C 64 4D 53 52 41 53 56
|.!....U.<dMSRASV|
[3980] 08:26:00:993: <35 2E 31 30 00 00 00 00 00 00 00 00 00 00 00 00 |
5.10............|
[3980] 08:26:00:993:
[3980] 08:26:00:993: <PPP packet sent at 07/13/2009 14:26:00:993
[3980] 08:26:00:993: <Protocol = LCP, Type = Identification, Length =
0x1b, Id = 0x4, Port = 5
[3980] 08:26:00:993: <C0 21 0C 04 00 19 55 17 3C 64 4D 53 52 41 53 2D
|.!....U.<dMSRAS-|
[3980] 08:26:00:993: <30 2D 4A 42 4F 52 43 48 45 52 54 00 00 00 00 00 |
0-JBORCHERT.....|
[3980] 08:26:00:993:
[3980] 08:26:00:993: Authenticating phase started
[3980] 08:26:01:009: Calling APWork in APStart
[3980] 08:26:01:009: <PPP packet sent at 07/13/2009 14:26:01:009
[3980] 08:26:01:009: <Protocol = PAP, Type = Protocol specific, Length
= 0x8, Id = 0x0, Port = 5
[3980] 08:26:01:009:
[3980] 08:26:01:009: InsertInTimerQ called
portid=0,Id=0,Protocol=c023,EventType=0,fAuth=0
[2572] 08:26:01:009: Packet received (24 bytes) for hPort 5
[2572] 08:26:01:009: Packet received (31 bytes) for hPort 5
[3980] 08:26:01:009: >PPP packet received at 07/13/2009 14:26:01:009
[3980] 08:26:01:009: >Protocol = LCP, Type = Code-Reject, Length =
0x18, Id = 0x2, Port = 5
[3980] 08:26:01:009: >C0 21 07 02 00 16 0C 03 00 12 55 17 3C 64 4D 53
|.!........U.<dMS|
[3980] 08:26:01:009: >52 41 53 56 35 2E 31 30 00 00 00 00 00 00 00 00 |
RASV5.10........|
[3980] 08:26:01:009:
[3980] 08:26:01:009: PPP Code Reject rcvd, rejected Code = 12
[3980] 08:26:01:009: >PPP packet received at 07/13/2009 14:26:01:009
[3980] 08:26:01:009: >Protocol = LCP, Type = Code-Reject, Length =
0x1f, Id = 0x3, Port = 5
[3980] 08:26:01:009: >C0 21 07 03 00 1D 0C 04 00 19 55 17 3C 64 4D 53
|.!........U.<dMS|
[3980] 08:26:01:009: >52 41 53 2D 30 2D 4A 42 4F 52 43 48 45 52 54 00 |
RAS-0-JBORCHERT.|
[3980] 08:26:01:009:
[3980] 08:26:01:009: PPP Code Reject rcvd, rejected Code = 12
[2572] 08:26:01:025: Packet received (7 bytes) for hPort 5
[3980] 08:26:01:025: >PPP packet received at 07/13/2009 14:26:01:025
[3980] 08:26:01:025: >Protocol = PAP, Type = Protocol specific, Length
= 0x7, Id = 0x0, Port = 5
[3980] 08:26:01:025:
[3980] 08:26:01:025: RemoveFromTimerQ called
portid=0,Id=0,Protocol=c023,EventType=0,fAuth=0
[3980] 08:26:01:025: FsmThisLayerUp called for protocol = c023, port =
5
[3980] 08:26:01:025: NotifyCaller(hPort=5, dwMsgId=17)
[3980] 08:26:01:025: NotifyCaller(hPort=5, dwMsgId=3)
[3980] 08:26:01:025: Will not initialize CP 8029
[3980] 08:26:01:025: Will not initialize CP 802b
[3980] 08:26:01:025: FsmInit called for protocol = 80fd, port = 5
[3980] 08:26:01:025: FsmReset called for protocol = 80fd, port = 5
[3980] 08:26:01:025: FsmInit called for protocol = 8021, port = 5
[3980] 08:26:01:025: FsmReset called for protocol = 8021, port = 5
[3980] 08:26:01:025: FsmOpen event received for protocol 80fd on port
5
[3980] 08:26:01:025: FsmThisLayerStarted called for protocol = 80fd,
port = 5
[3980] 08:26:01:025: FsmUp event received for protocol 80fd on port 5
[3980] 08:26:01:025: <PPP packet sent at 07/13/2009 14:26:01:025
[3980] 08:26:01:025: <Protocol = CCP, Type = Configure-Req, Length =
0xc, Id = 0x5, Port = 5
[3980] 08:26:01:025: <80 FD 01 05 00 0A 12 06 00 00 00 01 00 00 00 00
|................|
[3980] 08:26:01:025:
[3980] 08:26:01:025: InsertInTimerQ called
portid=0,Id=5,Protocol=80fd,EventType=0,fAuth=0
[3980] 08:26:01:025: FsmOpen event received for protocol 8021 on port
5
[3980] 08:26:01:025: FsmThisLayerStarted called for protocol = 8021,
port = 5
[3980] 08:26:01:025: FsmUp event received for protocol 8021 on port 5
[3980] 08:26:01:025: <PPP packet sent at 07/13/2009 14:26:01:025
[3980] 08:26:01:025: <Protocol = IPCP, Type = Configure-Req, Length =
0x2a, Id = 0x6, Port = 5
[3980] 08:26:01:025: <80 21 01 06 00 28 02 06 00 2D 0F 01 03 06 00 00
|.!...(...-......|
[3980] 08:26:01:025: <00 00 81 06 00 00 00 00 82 06 00 00 00 00 83 06
|................|
[3980] 08:26:01:025: <00 00 00 00 84 06 00 00 00 00 00 00 00 00 00 00
|................|
[3980] 08:26:01:025:
[3980] 08:26:01:025: InsertInTimerQ called
portid=0,Id=6,Protocol=8021,EventType=0,fAuth=0
[2572] 08:26:01:072: Packet received (18 bytes) for hPort 5
[3980] 08:26:01:072: >PPP packet received at 07/13/2009 14:26:01:072
[3980] 08:26:01:072: >Protocol = IPCP, Type = Configure-Req, Length =
0x12, Id = 0x1, Port = 5
[3980] 08:26:01:072: >80 21 01 01 00 10 02 06 00 2D 0F 01 03 06 A9 FE
|.!.......-......|
[3980] 08:26:01:072: >00 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00
|................|
[3980] 08:26:01:072:
[3980] 08:26:01:072: <PPP packet sent at 07/13/2009 14:26:01:072
[3980] 08:26:01:072: <Protocol = IPCP, Type = Configure-Ack, Length =
0x12, Id = 0x1, Port = 5
[3980] 08:26:01:072: <80 21 02 01 00 10 02 06 00 2D 0F 01 03 06 A9 FE
|.!.......-......|
[3980] 08:26:01:072: <00 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00
|................|
[3980] 08:26:01:072:
[2572] 08:26:01:119: Packet received (6 bytes) for hPort 5
[3980] 08:26:01:119: >PPP packet received at 07/13/2009 14:26:01:119
[3980] 08:26:01:119: >Protocol = CCP, Type = Configure-Req, Length =
0x6, Id = 0x1, Port = 5
[3980] 08:26:01:119: >80 FD 01 01 00 04 00 00 00 00 00 00 00 00 00 00
|................|
[3980] 08:26:01:119:
[3980] 08:26:01:119: <PPP packet sent at 07/13/2009 14:26:01:119
[3980] 08:26:01:119: <Protocol = CCP, Type = Configure-Ack, Length =
0x6, Id = 0x1, Port = 5
[3980] 08:26:01:119: <80 FD 02 01 00 04 00 00 00 00 00 00 00 00 00 00
|................|
[3980] 08:26:01:119:
[2572] 08:26:01:119: Packet received (12 bytes) for hPort 5
[3980] 08:26:01:119: >PPP packet received at 07/13/2009 14:26:01:119
[3980] 08:26:01:119: >Protocol = CCP, Type = Configure-Reject, Length
= 0xc, Id = 0x5, Port = 5
[3980] 08:26:01:119: >80 FD 04 05 00 0A 12 06 00 00 00 01 00 00 00 00
|................|
[3980] 08:26:01:119:
[3980] 08:26:01:119: The control protocol for 80fd on port 5 returned
error 732
[3980] 08:26:01:119: FsmClose event received for protocol 80fd on port
5
[3980] 08:26:01:119: RemoveFromTimerQ called
portid=0,Id=5,Protocol=80fd,EventType=0,fAuth=0
[3980] 08:26:01:119: <PPP packet sent at 07/13/2009 14:26:01:119
[3980] 08:26:01:119: <Protocol = CCP, Type = Terminate-Req, Length =
0x12, Id = 0x7, Port = 5
[3980] 08:26:01:119: <80 FD 05 07 00 10 55 17 3C 64 00 3C CD 74 00 00
|......U.<d.<.t..|
[3980] 08:26:01:119: <02 DC 00 00 00 00 00 00 00 00 00 00 00 00 00 00
|................|
[3980] 08:26:01:119:
[3980] 08:26:01:119: InsertInTimerQ called
portid=0,Id=7,Protocol=80fd,EventType=0,fAuth=0
[3980] 08:26:04:000: Recv timeout event received for
portid=0,Id=7,Protocol=80fd,fAuth=0
[3980] 08:26:04:000: <PPP packet sent at 07/13/2009 14:26:04:000
[3980] 08:26:04:000: <Protocol = CCP, Type = Terminate-Req, Length =
0x12, Id = 0x8, Port = 5
[3980] 08:26:04:000: <80 FD 05 08 00 10 55 17 3C 64 00 3C CD 74 00 00
|......U.<d.<.t..|
[3980] 08:26:04:000: <02 DC 00 00 00 00 00 00 00 00 00 00 00 00 00 00
|................|
[3980] 08:26:04:000:
[3980] 08:26:04:000: InsertInTimerQ called
portid=0,Id=8,Protocol=80fd,EventType=0,fAuth=0
[3980] 08:26:04:000: Recv timeout event received for
portid=0,Id=6,Protocol=8021,fAuth=0
[3980] 08:26:04:000: <PPP packet sent at 07/13/2009 14:26:04:000
[3980] 08:26:04:000: <Protocol = IPCP, Type = Configure-Req, Length =
0x2a, Id = 0x9, Port = 5
[3980] 08:26:04:000: <80 21 01 09 00 28 02 06 00 2D 0F 01 03 06 00 00
|.!...(...-......|
[3980] 08:26:04:000: <00 00 81 06 00 00 00 00 82 06 00 00 00 00 83 06
|................|
[3980] 08:26:04:000: <00 00 00 00 84 06 00 00 00 00 00 00 00 00 00 00
|................|
[3980] 08:26:04:000:
[3980] 08:26:04:000: InsertInTimerQ called
portid=0,Id=9,Protocol=8021,EventType=0,fAuth=0
[2572] 08:26:06:834: Packet received (18 bytes) for hPort 5
[3980] 08:26:06:834: >PPP packet received at 07/13/2009 14:26:06:834
[3980] 08:26:06:834: >Protocol = IPCP, Type = Configure-Reject, Length
= 0x12, Id = 0x6, Port = 5
[3980] 08:26:06:834: >80 21 04 06 00 10 82 06 00 00 00 00 84 06 00 00
|.!..............|
[3980] 08:26:06:834: >00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
|................|
[3980] 08:26:06:834:
[3980] 08:26:06:834: Config Nak/Rej on port 5 silently discarded.
Invalid Id
[2572] 08:26:06:834: Packet received (18 bytes) for hPort 5
[3980] 08:26:06:834: >PPP packet received at 07/13/2009 14:26:06:834
[3980] 08:26:06:834: >Protocol = IPCP, Type = Configure-Req, Length =
0x12, Id = 0x1, Port = 5
[3980] 08:26:06:834: >80 21 01 01 00 10 02 06 00 2D 0F 01 03 06 A9 FE
|.!.......-......|
[3980] 08:26:06:834: >00 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00
|................|
[3980] 08:26:06:834:
[3980] 08:26:06:834: <PPP packet sent at 07/13/2009 14:26:06:834
[3980] 08:26:06:834: <Protocol = IPCP, Type = Configure-Ack, Length =
0x12, Id = 0x1, Port = 5
[3980] 08:26:06:834: <80 21 02 01 00 10 02 06 00 2D 0F 01 03 06 A9 FE
|.!.......-......|
[3980] 08:26:06:834: <00 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00
|................|
[3980] 08:26:06:834:
[2572] 08:26:06:834: Packet received (6 bytes) for hPort 5
[3980] 08:26:06:834: >PPP packet received at 07/13/2009 14:26:06:834
[3980] 08:26:06:834: >Protocol = CCP, Type = Configure-Req, Length =
0x6, Id = 0x1, Port = 5
[3980] 08:26:06:834: >80 FD 01 01 00 04 00 00 00 00 00 00 00 00 00 00
|................|
[3980] 08:26:06:834:
[2572] 08:26:06:834: Packet received (6 bytes) for hPort 5
[3980] 08:26:06:834: >PPP packet received at 07/13/2009 14:26:06:834
[3980] 08:26:06:834: >Protocol = CCP, Type = Terminate-Ack, Length =
0x6, Id = 0x7, Port = 5
[3980] 08:26:06:834: >80 FD 06 07 00 04 00 00 00 00 00 00 00 00 00 00
|................|
[3980] 08:26:06:834:
[3980] 08:26:06:834: Term Ack with on port 5 silently discarded.
Invalid Id
[2572] 08:26:06:849: Packet received (6 bytes) for hPort 5
[3980] 08:26:06:849: >PPP packet received at 07/13/2009 14:26:06:849
[3980] 08:26:06:849: >Protocol = CCP, Type = Terminate-Ack, Length =
0x6, Id = 0x8, Port = 5
[3980] 08:26:06:849: >80 FD 06 08 00 04 00 00 00 00 00 00 00 00 00 00
|................|
[3980] 08:26:06:849:
[3980] 08:26:06:849: RemoveFromTimerQ called
portid=0,Id=8,Protocol=80fd,EventType=0,fAuth=0
[3980] 08:26:06:849: FsmThisLayerFinished called for protocol = 80fd,
port = 5
[2572] 08:26:06:849: Packet received (18 bytes) for hPort 5
[3980] 08:26:06:849: >PPP packet received at 07/13/2009 14:26:06:849
[3980] 08:26:06:849: >Protocol = IPCP, Type = Configure-Reject, Length
= 0x12, Id = 0x9, Port = 5
[3980] 08:26:06:849: >80 21 04 09 00 10 82 06 00 00 00 00 84 06 00 00
|.!..............|
[3980] 08:26:06:849: >00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
|................|
[3980] 08:26:06:849:
[3980] 08:26:06:849: RemoveFromTimerQ called
portid=0,Id=9,Protocol=8021,EventType=0,fAuth=0
[3980] 08:26:06:849: <PPP packet sent at 07/13/2009 14:26:06:849
[3980] 08:26:06:849: <Protocol = IPCP, Type = Configure-Req, Length =
0x1e, Id = 0xa, Port = 5
[3980] 08:26:06:849: <80 21 01 0A 00 1C 02 06 00 2D 0F 01 03 06 00 00
|.!.......-......|
[3980] 08:26:06:849: <00 00 81 06 00 00 00 00 83 06 00 00 00 00 00 00
|................|
[3980] 08:26:06:849:
[3980] 08:26:06:849: InsertInTimerQ called
portid=0,Id=10,Protocol=8021,EventType=0,fAuth=0
[2572] 08:26:06:865: Packet received (24 bytes) for hPort 5
[3980] 08:26:06:865: >PPP packet received at 07/13/2009 14:26:06:865
[3980] 08:26:06:865: >Protocol = IPCP, Type = Configure-Nak, Length =
0x18, Id = 0xa, Port = 5
[3980] 08:26:06:865: >80 21 03 0A 00 16 03 06 19 C0 EF 9F 81 06 0A B1
|.!..............|
[3980] 08:26:06:865: >00 22 83 06 0A A3 8C F2 00 00 00 00 00 00 00 00
|."..............|
[3980] 08:26:06:865:
[3980] 08:26:06:865: RemoveFromTimerQ called
portid=0,Id=10,Protocol=8021,EventType=0,fAuth=0
[3980] 08:26:06:865: <PPP packet sent at 07/13/2009 14:26:06:865
[3980] 08:26:06:865: <Protocol = IPCP, Type = Configure-Req, Length =
0x1e, Id = 0xb, Port = 5
[3980] 08:26:06:865: <80 21 01 0B 00 1C 02 06 00 2D 0F 01 03 06 19 C0
|.!.......-......|
[3980] 08:26:06:865: <EF 9F 81 06 0A B1 00 22 83 06 0A A3 8C F2 00 00
|......."........|
[3980] 08:26:06:865:
[3980] 08:26:06:865: InsertInTimerQ called
portid=0,Id=11,Protocol=8021,EventType=0,fAuth=0
[2572] 08:26:06:865: Packet received (30 bytes) for hPort 5
[3980] 08:26:06:865: >PPP packet received at 07/13/2009 14:26:06:865
[3980] 08:26:06:865: >Protocol = IPCP, Type = Configure-Ack, Length =
0x1e, Id = 0xb, Port = 5
[3980] 08:26:06:865: >80 21 02 0B 00 1C 02 06 00 2D 0F 01 03 06 19 C0
|.!.......-......|
[3980] 08:26:06:865: >EF 9F 81 06 0A B1 00 22 83 06 0A A3 8C F2 00 00
|......."........|
[3980] 08:26:06:865:
[3980] 08:26:06:865: RemoveFromTimerQ called
portid=0,Id=11,Protocol=8021,EventType=0,fAuth=0
[3980] 08:26:06:865: FsmThisLayerUp called for protocol = 8021, port =
5
[3980] 08:26:06:990: Notifying IPCP of projection notification
[3980] 08:26:06:990: RemoveFromTimerQ called
portid=0,Id=0,Protocol=0,EventType=3,fAuth=0
[3980] 08:26:06:990: NotifyCaller(hPort=5, dwMsgId=4)
[3980] 08:26:06:990: NotifyCaller(hPort=5, dwMsgId=0)
[3980] 08:26:07:021: Inserting autodisconnect in timer q for port=5,
sec=1200
[3980] 08:26:07:021: RemoveFromTimerQ called
portid=0,Id=0,Protocol=0,EventType=1,fAuth=0
[3980] 08:26:07:021: InsertInTimerQ called
portid=0,Id=0,Protocol=0,EventType=1,fAuth=0
[2572] 08:26:09:818: Packet received (6 bytes) for hPort 5
[3980] 08:26:09:818: >PPP packet received at 07/13/2009 14:26:09:818
[3980] 08:26:09:818: >Protocol = CCP, Type = Configure-Req, Length =
0x6, Id = 0x1, Port = 5
[3980] 08:26:09:818: >80 FD 01 01 00 04 00 00 00 00 00 00 00 00 00 00
|................|
[3980] 08:26:09:818:
[3980] 08:26:09:818: <PPP packet sent at 07/13/2009 14:26:09:818
[3980] 08:26:09:818: <Protocol = CCP, Type = Terminate-Ack, Length =
0x6, Id = 0x1, Port = 5
[3980] 08:26:09:818: <80 FD 06 01 00 04 00 00 00 00 00 00 00 00 00 00
|................|
[3980] 08:26:09:818:
[2572] 08:26:09:833: Packet received (31 bytes) for hPort 5
[3980] 08:26:09:833: >PPP packet received at 07/13/2009 14:26:09:833
[3980] 08:26:09:833: >Protocol = CCP, Type = Terminate-Req, Length =
0x1f, Id = 0x2, Port = 5
[3980] 08:26:09:833: >80 FD 05 02 00 1D 4E 6F 20 63 6F 6D 70 72 65 73
|......No compres|
[3980] 08:26:09:833: >73 69 6F 6E 20 6E 65 67 6F 74 69 61 74 65 64 00 |
sion negotiated.|
[3980] 08:26:09:833:
[3980] 08:26:09:833: RemoveFromTimerQ called
portid=0,Id=8,Protocol=80fd,EventType=0,fAuth=0
[3980] 08:26:09:833: <PPP packet sent at 07/13/2009 14:26:09:833
[3980] 08:26:09:833: <Protocol = CCP, Type = Terminate-Ack, Length =
0x1f, Id = 0x2, Port = 5
[3980] 08:26:09:833: <80 FD 06 02 00 1D 4E 6F 20 63 6F 6D 70 72 65 73
|......No compres|
[3980] 08:26:09:833: <73 69 6F 6E 20 6E 65 67 6F 74 69 61 74 65 64 00 |
sion negotiated.|
[3980] 08:26:09:833:
[3980] 08:26:09:833: FsmThisLayerFinished called for protocol = 80fd,
port = 5
[3980] 08:26:09:833: RemoveFromTimerQ called
portid=0,Id=0,Protocol=0,EventType=3,fAuth=0
[3980] 08:26:09:833: AreAnyNCPsActive result=1)
[3980] 08:26:09:833: NotifyCaller(hPort=5, dwMsgId=4)
[3980] 08:26:09:833: NotifyCaller(hPort=5, dwMsgId=0)
[3980] 08:26:09:833: Inserting autodisconnect in timer q for port=5,
sec=1200
[3980] 08:26:09:833: RemoveFromTimerQ called
portid=0,Id=0,Protocol=0,EventType=1,fAuth=0
[3980] 08:26:09:833: InsertInTimerQ called
portid=0,Id=0,Protocol=0,EventType=1,fAuth=0

Anssi Saari

2009-07-13 16:09:50 UTC

Permalink

Post by JBorch

Post by Anssi Saari
Perhaps you just need to provide some username and password, no matter
what? A very old lesson from a Palm VX...

I've tried that too. If I enter a username and password it
authenticates but then immediately disconnects.

For what reason? In the one you provided it was clear that your Mac
refused to authenticate:

Mon Jul 13 00:00:21 2009 : rcvd [LCP ConfReq id=0x1 <asyncmap 0x0> <auth pap> <magic 0x428f8488> <pcomp> <accomp>]
Mon Jul 13 00:00:21 2009 : No auth is possible
Mon Jul 13 00:00:21 2009 : lcp_reqci: returning CONFREJ.
Mon Jul 13 00:00:21 2009 : sent [LCP ConfRej id=0x1 <auth pap>]

Here it is, received request to authenticate with PAP. You reject.

Mon Jul 13 00:00:21 2009 : rcvd [LCP TermReq id=0x3 "peer refused to authenticate"]
Mon Jul 13 00:00:21 2009 : LCP terminated by peer (peer refused to authenticate)
Mon Jul 13 00:00:21 2009 : sent [LCP TermAck id=0x3]

And as a result the connection is terminated.

So the interesting question is what the ppp log looks like on the Mac
if you do provide a username and password. As for the XP log, I can't
make heads or tails out of it.

JBorch

2009-07-13 18:31:31 UTC

Permalink

Post by Anssi Saari

Post by Anssi Saari
Perhaps you just need to provide some username and password, no matter
what? A very old lesson from a Palm VX...

I've tried that too. If I enter a username and password it
authenticates but then immediately disconnects.

For what reason? In the one you provided it was clear that your Mac
Mon Jul 13 00:00:21 2009 : rcvd [LCP ConfReq id=0x1 <asyncmap 0x0> <auth pap> <magic 0x428f8488> <pcomp> <accomp>]
Mon Jul 13 00:00:21 2009 : No auth is possible
Mon Jul 13 00:00:21 2009 : lcp_reqci: returning CONFREJ.
Mon Jul 13 00:00:21 2009 : sent [LCP ConfRej id=0x1 <auth pap>]
Here it is, received request to authenticate with PAP. You reject.
Mon Jul 13 00:00:21 2009 : rcvd [LCP TermReq id=0x3 "peer refused to authenticate"]
Mon Jul 13 00:00:21 2009 : LCP terminated by peer (peer refused to authenticate)
Mon Jul 13 00:00:21 2009 : sent [LCP TermAck id=0x3]
And as a result the connection is terminated.
So the interesting question is what the ppp log looks like on the Mac
if you do provide a username and password. As for the XP log, I can't
make heads or tails out of it.

Here is the OS X log with a dummy username and password. It
authenticates fine but then terminates due to "No network protocols
running"

===== Monday, July 13, 2009 12:23:50 PM US/Mountain =====
Mon Jul 13 12:23:52 2009 : Terminating on signal 15.
Mon Jul 13 12:23:54 2009 : CCLWrite : AT\13
Mon Jul 13 12:23:54 2009 : CCLMatched : OK\13\10
Mon Jul 13 12:23:54 2009 : CCLWrite : AT&FE0V1&C1S0=0\13
Mon Jul 13 12:23:54 2009 : CCLMatched : OK\13\10
Mon Jul 13 12:23:56 2009 : CCLWrite : AT
+CGDCONT=1,"IP","wap.voicestream.com",,0,0\13
Mon Jul 13 12:23:57 2009 : CCLMatched : OK\13\10
Mon Jul 13 12:23:57 2009 : Making GPRS connection
Mon Jul 13 12:23:57 2009 : CCLWrite : ATD*99#\13
Mon Jul 13 12:23:57 2009 : CCLMatched : CONNECT
Mon Jul 13 12:24:01 2009 : Serial connection established.
Mon Jul 13 12:24:01 2009 : using link 0
Mon Jul 13 12:24:01 2009 : Using interface ppp0
Mon Jul 13 12:24:01 2009 : Connect: ppp0 <--> /dev/cu.usbmodem5B21
Mon Jul 13 12:24:02 2009 : sent [LCP ConfReq id=0x1 <asyncmap 0x0>
<magic 0x4e03c5f2> <pcomp> <accomp>]
Mon Jul 13 12:24:02 2009 : rcvd [LCP ConfReq id=0x1 <asyncmap 0x0>
<auth pap> <magic 0xe7e5f8c4> <pcomp> <accomp>]
Mon Jul 13 12:24:02 2009 : lcp_reqci: returning CONFACK.
Mon Jul 13 12:24:02 2009 : sent [LCP ConfAck id=0x1 <asyncmap 0x0>
<auth pap> <magic 0xe7e5f8c4> <pcomp> <accomp>]
Mon Jul 13 12:24:02 2009 : rcvd [LCP ConfAck id=0x1 <asyncmap 0x0>
<magic 0x4e03c5f2> <pcomp> <accomp>]
Mon Jul 13 12:24:02 2009 : sent [PAP AuthReq id=0x1 user="guest"
password=<hidden>]
Mon Jul 13 12:24:02 2009 : rcvd [PAP AuthAck id=0x1 ""]
Mon Jul 13 12:24:02 2009 : PAP authentication succeeded
Mon Jul 13 12:24:02 2009 : sent [IPCP ConfReq id=0x1 <compress VJ 0f
01> <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns3 0.0.0.0>]
Mon Jul 13 12:24:02 2009 : sent [IPV6CP ConfReq id=0x1 <addr
fe80::020d:93ff:feb4:f4d4>]
Mon Jul 13 12:24:02 2009 : rcvd [IPCP ConfReq id=0x1 <compress VJ 0f
01> <addr 169.254.0.1>]
Mon Jul 13 12:24:02 2009 : ipcp: returning Configure-ACK
Mon Jul 13 12:24:02 2009 : sent [IPCP ConfAck id=0x1 <compress VJ 0f
01> <addr 169.254.0.1>]
Mon Jul 13 12:24:05 2009 : sent [IPCP ConfReq id=0x1 <compress VJ 0f
01> <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns3 0.0.0.0>]
Mon Jul 13 12:24:05 2009 : sent [IPV6CP ConfReq id=0x1 <addr
fe80::020d:93ff:feb4:f4d4>]
Mon Jul 13 12:24:08 2009 : sent [IPCP ConfReq id=0x1 <compress VJ 0f
01> <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns3 0.0.0.0>]
Mon Jul 13 12:24:08 2009 : sent [IPV6CP ConfReq id=0x1 <addr
fe80::020d:93ff:feb4:f4d4>]
Mon Jul 13 12:24:08 2009 : rcvd [IPCP ConfNak id=0x1 <addr 25.194.9.1>
<ms-dns1 10.177.0.34> <ms-dns3 10.163.140.242>]
Mon Jul 13 12:24:08 2009 : sent [IPCP ConfReq id=0x2 <compress VJ 0f
01> <addr 25.194.9.1> <ms-dns1 10.177.0.34> <ms-dns3 10.163.140.242>]
Mon Jul 13 12:24:08 2009 : rcvd [LCP ProtRej id=0x2 80 57 01 01 00 0e
01 0a 02 0d 93 ff fe b4 f4 d4]
Mon Jul 13 12:24:08 2009 : rcvd [IPCP ConfReq id=0x1 <compress VJ 0f
01> <addr 169.254.0.1>]
Mon Jul 13 12:24:08 2009 : ipcp: returning Configure-ACK
Mon Jul 13 12:24:08 2009 : sent [IPCP ConfAck id=0x1 <compress VJ 0f
01> <addr 169.254.0.1>]
Mon Jul 13 12:24:08 2009 : rcvd [LCP ProtRej id=0x3 80 57 01 01 00 0e
01 0a 02 0d 93 ff fe b4 f4 d4]
Mon Jul 13 12:24:08 2009 : sent [LCP TermReq id=0x2 "No network
protocols running"]
Mon Jul 13 12:24:08 2009 : rcvd [LCP ProtRej id=0x4 80 57 01 01 00 0e
01 0a 02 0d 93 ff fe b4 f4 d4]
Mon Jul 13 12:24:08 2009 : Protocol-Reject discarded: LCP in state 4
Mon Jul 13 12:24:08 2009 : rcvd [IPCP ConfNak id=0x1 <addr 25.194.9.1>
<ms-dns1 10.177.0.34> <ms-dns3 10.163.140.242>]
Mon Jul 13 12:24:08 2009 : rcvd [IPCP ConfNak id=0x1 <addr 25.194.9.1>
<ms-dns1 10.177.0.34> <ms-dns3 10.163.140.242>]
Mon Jul 13 12:24:08 2009 : rcvd [IPCP ConfAck id=0x2 <compress VJ 0f
01> <addr 25.194.9.1> <ms-dns1 10.177.0.34> <ms-dns3 10.163.140.242>]
Mon Jul 13 12:24:08 2009 : rcvd [LCP TermAck id=0x2]
Mon Jul 13 12:24:08 2009 : Connection terminated.
Mon Jul 13 12:24:10 2009 : CCLWrite : +++
Mon Jul 13 12:24:13 2009 : CCLWrite : ATH0\13
Mon Jul 13 12:24:13 2009 : CCLMatched : NO CARRIER\13\10
Mon Jul 13 12:24:14 2009 : CCLWrite : AT&F\13
Mon Jul 13 12:24:14 2009 : CCLMatched : OK\13\10
Mon Jul 13 12:24:14 2009 : Serial link disconnected.

Anssi Saari

2009-07-14 06:07:33 UTC

Permalink

Post by JBorch
Here is the OS X log with a dummy username and password. It
authenticates fine but then terminates due to "No network protocols
running"

I'll have to guess again, but it looks like IPv6 causes the problem
now so turn it off. Conventional wisdom is to turn off TCP header
compression with phones too, but apparently your phone supports so
probably it's not a problem.

JBorch

2009-07-14 14:40:57 UTC

Permalink

Post by Anssi Saari

Here is the OS X log with a dummy username and password. It
authenticates fine but then terminates due to "No network protocols
running"

I figured that out last night. Thanks for the help. With a dummy
username and password and IPv6 turned off it connected just fine. Is
that a buggy implementation of PPP? Shouldn't it continue on it's
merry way with other protocols if IPv6 is rejected? It's as if my
computer said "Fine, I'll take may ball and go home then!" after IPv6
was rejected. I don't know much about PPP but from what I've read in
the last few days it seems that it is common for protocols that aren't
available on the remote peer to be rejected and that the local peer
should just continue with another protocol.

Moe Trin

2009-07-14 19:46:51 UTC

Permalink

On Mon, 13 Jul 2009, in the Usenet newsgroup comp.protocols.ppp, in article

As for the XP log, I can't make heads or tails out of it.

You must remember that microsoft means to scare away any technical
questions by dumping a ton of bullshit on anyone who asks. Consequently
you need to look carefully at the crap in the logs.

))[2572] 08:26:00:993: Packet received (26 bytes) for hPort 5
))[3980] 08:26:00:993: >PPP packet received at 07/13/2009 14:26:00:993
))[3980] 08:26:00:993: >Protocol = LCP, Type = Configure-Req, Length =
))0x1a, Id = 0x1, Port = 5
))[3980] 08:26:00:993: >C0 21 01 01 00 18 02 06 00 00 00 00 03 04 C0 23

Right there. C021 01 is an LCP ConfReq and the 03 04 C023 is a request
for PAP authentication. See RFC1661 section 6.2. So the peer is asking
for PAP.

)[3980] 08:26:00:993: <PPP packet sent at 07/13/2009 14:26:00:993
)[3980] 08:26:00:993: <Protocol = LCP, Type = Configure-Ack, Length =
)0x1a, Id = 0x1, Port = 5
)[3980] 08:26:00:993: <C0 21 02 01 00 18 02 06 00 00 00 00 03 04 C0 23

And here is this box sending an LCP ConfAcq for this.

))[3980] 08:26:00:993: LCP Remote Options-------------
))[3980] 08:26:00:993:
))MRU=1500,ACCM=0,Auth=c023,MagicNumber=1508415477,PFC=ON,ACFC=ON

It also shows up here (Auth=c023 - peer wants PAP)

)[3980] 08:26:00:993: LCP Local Options-------------
)[3980] 08:26:00:993:
)MRU=1500,ACCM=0,Auth=0,MagicNumber=1427586148,PFC=ON,ACFC=ON

and not here (Auth=0 - peer doesn't have to authenticate to me)

)[3980] 08:26:00:993: Authenticating phase started
)[3980] 08:26:01:009: Calling APWork in APStart
)[3980] 08:26:01:009: <PPP packet sent at 07/13/2009 14:26:01:009
)[3980] 08:26:01:009: <Protocol = PAP, Type = Protocol specific, Length
)= 0x8, Id = 0x0, Port = 5

and here.

Old guy