Technology Development

http://www.modemsite.com/56k/ppp.asp

Windows 2000 and XP:
Win2k Pro and all versions of XP require using a command prompt to enable logging. Open a command prompt with Start->Run and type in cmd

From the command prompt, type:

netsh
ras
set tracing PPP enable
exit

After you enable logging, all PPP activity is logged to a file named ppp.log in the folder Tracing located in the Windows folder.

To disable PPP logging, use the command sequence above, except replace enable with disable.

What the logs look like & what they reveal:

Here's a portion of a PPP log from WinMe calling a network (AOL/ANS) doing authentication in PPP:

04-20-2002 08:27:56.17 - Microsoft Dial Up Adapter log opened.
04-20-2002 08:27:56.17 - Server type is PPP (Point to Point Protocol).
04-20-2002 08:27:56.17 - FSA : Adding Control Protocol 80fd (CCP) to control protocol chain.
04-20-2002 08:27:56.17 - FSA : Protocol not bound - skipping control protocol 803f (NBFCP).
04-20-2002 08:27:56.17 - FSA : Adding Control Protocol 8021 (IPCP) to control protocol chain.
04-20-2002 08:27:56.17 - FSA : Protocol not bound - skipping control protocol 802b (IPXCP).
04-20-2002 08:27:56.17 - FSA : Adding Control Protocol c029 (CallbackCP) to control protocol chain.
04-20-2002 08:27:56.17 - FSA : Adding Control Protocol c027 (no description) to control protocol chain.
04-20-2002 08:27:56.17 - FSA : Adding Control Protocol c023 (PAP) to control protocol chain.
04-20-2002 08:27:56.17 - FSA : Adding Control Protocol c223 (CHAP) to control protocol chain.
04-20-2002 08:27:56.17 - FSA : Adding Control Protocol c021 (LCP) to control protocol chain.
04-20-2002 08:27:56.17 - LCP : Callback negotiation enabled.
04-20-2002 08:27:56.17 - LCP : Layer started.
04-20-2002 08:27:56.17 - PPP : Transmitting Control Packet of length: 25
04-20-2002 08:27:56.17 - Data 0000: c0 20 01 01 00 14 02 06 | .!.....
...
04-20-2002 08:27:56.32 - PPP : Received Control Packet of length: 25
...
04-20-2002 08:27:56.32 - LCP : Received and accepted ACCM of a0000.
04-20-2002 08:27:56.32 - LCP : Naking possibly loopback magic number.
04-20-2002 08:27:56.32 - PPP : Transmitting Control Packet of length: 12
...
04-20-2002 08:27:56.44 - LCP : Loopback! Peer nak'd with our nak of peer's magic number!
04-20-2002 08:27:56.44 - LCP : Peer requests use of magic number xxxx0b.
04-20-2002 08:27:56.44 - PPP : Transmitting Control Packet of length: 25
...
04-20-2002 08:27:56.58 - LCP : Received and accepted ACCM of a0000.
04-20-2002 08:27:56.58 - LCP : Naking possibly loopback magic number.
04-20-2002 08:27:56.58 - PPP : Transmitting Control Packet of length: 12
...
04-20-2002 08:27:58.94 - LCP : Received and accepted ACCM of a0000.
04-20-2002 08:27:58.94 - LCP : Received and accepted authentication protocol c223 (CHAP).
04-20-2002 08:27:58.94 - LCP : Received and accepted magic number xxxxxxx0.
04-20-2002 08:27:58.94 - LCP : Received and accepted protocol field compression option.
04-20-2002 08:27:58.94 - LCP : Received and accepted address+control field compression option.
...
04-20-2002 08:28:00.68 - LCP : Received configure reject for callback control protocol option.
...
04-20-2002 08:28:00.94 - LCP : Received and accepted protocol field compression option.
04-20-2002 08:28:00.94 - LCP : Received and accepted address+control field compression option.
...
04-20-2002 08:28:00.94 - LCP : Layer up.
04-20-2002 08:28:00.94 - CHAP : Layer started.
04-20-2002 08:28:03.58 - PPP : Received Control Packet of length: 31
...
04-20-2002 08:28:03.58 - PPP : Transmitting Control Packet of length: 48
04-20-2002 08:28:03.58 - Data 0000: xx xx xx xx xx xx xx xx | .#.....~
(you may see your UserID in data during authentication here)
...
04-20-2002 08:28:03.90 - CHAP : Login was successful.
04-20-2002 08:28:03.90 - CHAP : Layer up.
04-20-2002 08:28:03.90 - IPCP : Layer started.
04-20-2002 08:28:03.90 - IPCP : IP address is 0.
04-20-2002 08:28:03.90 - CCP : Layer started.
04-20-2002 08:28:03.90 - PPP : Transmitting Control Packet of length: 42
...
04-20-2002 08:28:04.18 - FSA : Received protocol reject for control protocol 80fd.
04-20-2002 08:28:04.18 - CCP : Layer finished.
04-20-2002 08:28:04.42 - PPP : Received Control Packet of length: 24
...
04-20-2002 08:28:04.42 - IPCP : Changing IP address from 0 to xxxxxxxx.
04-20-2002 08:28:04.42 - IPCP : Accepting primary DNS xxxxxx21.
04-20-2002 08:28:04.42 - IPCP : Accepting backup DNS xxxxxx22.
04-20-2002 08:28:04.42 - PPP : Transmitting Control Packet of length: 24
...
04-20-2002 08:28:05.85 - IPCP : Layer up.
04-20-2002 08:28:05.85 - FSA : Last control protocol is up.
04-20-2002 08:29:52.36 - Remote access driver is shutting down.
04-20-2002 08:29:52.36 - CRC Errors 0
04-20-2002 08:29:52.36 - Timeout Errors 0
04-20-2002 08:29:52.36 - Alignment Errors 0
04-20-2002 08:29:52.36 - Overrun Errors 0
04-20-2002 08:29:52.36 - Framing Errors 0
04-20-2002 08:29:52.36 - Buffer Overrun Errors 0
04-20-2002 08:29:52.36 - Incomplete Packets 0
04-20-2002 08:29:52.36 - Bytes Received 69017
04-20-2002 08:29:52.36 - Bytes Transmittted 13862
04-20-2002 08:29:52.36 - Frames Received 163
04-20-2002 08:29:52.36 - Frames Transmitted 175
04-20-2002 08:29:52.36 - LCP : Layer down.
04-20-2002 08:29:52.36 - CHAP : Layer down.
04-20-2002 08:29:52.36 - IPCP : Layer down.
04-20-2002 08:29:52.37 - CCP : Layer started.
04-20-2002 08:29:52.37 - PPP : Transmitting Control Packet of length: 6
...
04-20-2002 08:29:52.62 - LCP : Received terminate acknowledgement.
04-20-2002 08:29:52.62 - LCP : Layer finished.
04-20-2002 08:29:52.62 - Microsoft Dial Up Adapter log closed.

Here's a portion of a PPP log from WindowsXP calling the same number, and failing with a DUNS ERROR 737:

[2584] 10:23:06:809: PPPEMSG_Start recvd, d=, hPort=6,callback=0,mask=11111a,IfType=-1
[1160] 10:23:06:809: Line up event occurred on port 6
[1160] 10:23:06:809: Local identification = MSRAS-1-NAME
...
[1160] 10:23:07:390: The control protocol for c021, returned error 737
[1160] 10:23:07:390: while making a configure result on port 6
[1160] 10:23:07:390: FsmClose event received for protocol c021 on port 6
[1160] 10:23:07:390: RemoveFromTimerQ called portid=6,Id=2,Protocol=c021,EventType=0,fAuth=0
[1160] 10:23:07:390: FsmThisLayerDown called for protocol = c021, port = 6
[1160] 10:23:07:390: RemoveFromTimerQ called portid=6,Id=0,Protocol=c029,EventType=0,fAuth=0
[1160] 10:23:07:390: [1160] 10:23:07:390: ...
[2584] 10:23:07:500: PppStop

[2584] 10:23:07:500: PPPEMSG_Stop recvd

[1160] 10:23:07:500: FsmClose event received for protocol c021 on port 6
[1160] 10:23:07:500: RemoveFromTimerQ called portid=6,Id=3,Protocol=c021,EventType=0,fAuth=0
[1160] 10:23:07:500: FsmThisLayerFinished called for protocol = c021, port = 6
[1160] 10:23:07:500: NotifyCaller(hPort=6, dwMsgId=10)
[1036] 10:23:08:481: PPPEMSG_LineDown recvd, hPort=6

[1160] 10:23:08:511: Line down event occurred on port 6
[1160] 10:23:08:792: FsmDown event received for protocol c021 on port 6
[1160] 10:23:08:792: RemoveFromTimerQ called portid=6,Id=3,Protocol=c021,EventType=0,fAuth=0
[1160] 10:23:08:792: FsmReset called for protocol = c021, port = 6
[1160] 10:23:08:792: RemoveFromTimerQ called portid=6,Id=0,Protocol=0,EventType=3,fAuth=0
[1160] 10:23:08:792: RemoveFromTimerQ called portid=6,Id=0,Protocol=0,EventType=7,fAuth=0
[1160] 10:23:08:792: RemoveFromTimerQ called portid=6,Id=0,Protocol=0,EventType=2,fAuth=0
[1160] 10:23:08:792: RemoveFromTimerQ called portid=6,Id=0,Protocol=0,EventType=1,fAuth=0
[1160] 10:23:08:792: RemoveFromTimerQ called portid=6,Id=0,Protocol=c029,EventType=0,fAuth=0
[1160] 10:23:08:792: LcpEnd
[1160] 10:23:08:792: Post line down event occurred on port 6
[1160] 10:23:08:792: NotifyCaller(hPort=6, dwMsgId=23)