Compare PPP/Modem Logs ...?
DComTalk.com Forum Index DComTalk.com
Discussion of VoIP, VPN, Video Conferencen, DSL and other data commucations.
 
 FAQFAQ   MemberlistMemberlist     RegisterRegister 
 ProfileProfile   Log in to check your private messagesLog in to check your private messages   Log inLog in 
 
Google
 
Web dcomtalk.com
Compare PPP/Modem Logs ...?

 
Post new topic   Reply to topic    DComTalk.com Forum Index -> Modems
Author Message
LoadHawg
Guest
Posted: Fri Jan 14, 2005 10:56 pm    Post subject: Compare PPP/Modem Logs ...? Reply with quote
OK here's a pair of PPP.LOGs.

The first is a short session which didnt' encounter any problems w/ loss of throughput

The second is a slightly longer session (only a couple minutes) in which a few refreshes of say ebay.com quickly induced
a 'no throughput' scenario. The second log also includes the modem.log (not included in teh first).

Note at present I switched to the 'generic 56000 V90' .inf settings but am still using my own custom init string
(AT+MS=V90,,,,40000,48000;+PCW=1;S11=55) so I don't miss any calls. This inf setting file does not display 'errors' in
the DUN window (unlike before) but otherwise still 'dies'. The ATZ commands are back in as I'm no longer grabbing post
call diags. Both calls were manually terminated by me (the second after almost all data stopped coming thru and website
timed out).

Anything I should look for or take notice of in these 2 PPP logs (or the one modem log)?

Next steps? I'm not sure it's worth calling the phone company about the line just yet. And I've duplicated the problem
on 2 different ISPs so not sure if they would be any help.


(The following may be best viewed in a nonproportional font - I widened the margins to 120 to prevent wrapping.)


**************************************************************************************
**************************************************************************************
PPP.LOG - SHORT session, no problems, manually disconnected call:
**************************************************************************************
**************************************************************************************


[568] 11:24:26:217: PPPEMSG_Start recvd, d=, hPort=5,callback=0,mask=83074a,IfType=-1
[888] 11:24:26:217: Line up event occurred on port 5
[888] 11:24:26:227: Local identification = MSRAS-1-P200
[888] 11:24:26:227: PortName: COM1
[888] 11:24:26:227: Starting PPP on link with IfType=0xffffffff,IPIf=0xffffffff,IPXIf=0xffffffff
[888] 11:24:26:227: RasGetBuffer returned 112430 for SendBuf
[888] 11:24:26:227: FsmInit called for protocol = c021, port = 5
[888] 11:24:26:227: ConfigInfo = 83074a
[888] 11:24:26:237: APs available = 5e
[888] 11:24:26:237: FsmReset called for protocol = c021, port = 5
[888] 11:24:26:237: Inserting port in bucket # 0
[888] 11:24:26:237: Inserting bundle in bucket # 0
[888] 11:24:26:237: FsmOpen event received for protocol c021 on port 5
[888] 11:24:26:237: FsmThisLayerStarted called for protocol = c021, port = 5
[888] 11:24:26:237: FsmUp event received for protocol c021 on port 5
[888] 11:24:26:237: <PPP packet sent at 01/14/2005 17:24:26:237
[888] 11:24:26:237: <Protocol = LCP, Type = Configure-Req, Length = 0x26, Id = 0x0, Port = 5
[888] 11:24:26:237: <C0 21 01 00 00 24 02 06 00 00 00 00 05 06 3E AE |.!...$........>.|
[888] 11:24:26:237: <35 D6 07 02 08 02 0D 03 06 11 04 06 4E 13 09 03 |5...........N...|
[888] 11:24:26:237: <00 E0 29 07 D5 50 00 00 00 00 00 00 00 00 00 00 |..)..P..........|
[888] 11:24:26:237:
[888] 11:24:26:237: InsertInTimerQ called portid=8,Id=0,Protocol=c021,EventType=0,fAuth=0
[888] 11:24:26:237: InsertInTimerQ called portid=8,Id=0,Protocol=0,EventType=3,fAuth=0
[712] 11:24:28:160: Packet received (26 bytes) for hPort 5
[888] 11:24:28:160: >PPP packet received at 01/14/2005 17:24:28:160
[888] 11:24:28:160: >Protocol = LCP, Type = Configure-Req, Length = 0x1a, Id = 0x1, Port = 5
[888] 11:24:28:160: >C0 21 01 01 00 18 02 06 00 00 00 00 05 06 45 A2 |.!............E.|
[888] 11:24:28:160: >DA CF 07 02 08 02 03 04 C0 23 00 00 00 00 00 00 |.........#......|
[888] 11:24:28:160:
[888] 11:24:28:160: <PPP packet sent at 01/14/2005 17:24:28:160
[888] 11:24:28:160: <Protocol = LCP, Type = Configure-Ack, Length = 0x1a, Id = 0x1, Port = 5
[888] 11:24:28:160: <C0 21 02 01 00 18 02 06 00 00 00 00 05 06 45 A2 |.!............E.|
[888] 11:24:28:160: <DA CF 07 02 08 02 03 04 C0 23 00 00 00 00 00 00 |.........#......|
[888] 11:24:28:160:
[888] 11:24:28:240: Recv timeout event received for portid=8,Id=0,Protocol=c021,fAuth=0
[888] 11:24:28:240: <PPP packet sent at 01/14/2005 17:24:28:240
[888] 11:24:28:240: <Protocol = LCP, Type = Configure-Req, Length = 0x26, Id = 0x1, Port = 5
[888] 11:24:28:240: <C0 21 01 01 00 24 02 06 00 00 00 00 05 06 3E AE |.!...$........>.|
[888] 11:24:28:240: <35 D6 07 02 08 02 0D 03 06 11 04 06 4E 13 09 03 |5...........N...|
[888] 11:24:28:240: <00 E0 29 07 D5 50 00 00 00 00 00 00 00 00 00 00 |..)..P..........|
[888] 11:24:28:240:
[888] 11:24:28:240: InsertInTimerQ called portid=8,Id=1,Protocol=c021,EventType=0,fAuth=0
[712] 11:24:28:430: Packet received (41 bytes) for hPort 5
[888] 11:24:28:430: >PPP packet received at 01/14/2005 17:24:28:430
[888] 11:24:28:430: >Protocol = LCP, Type = Configure-Req, Length = 0x29, Id = 0x2, Port = 5
[712] 11:24:28:430: Packet received (9 bytes) for hPort 5
[888] 11:24:28:430: >C0 21 01 02 00 27 02 06 00 00 00 00 05 06 45 A2 |.!...'........E.|
[888] 11:24:28:430: >DA CF 07 02 08 02 03 04 C0 23 11 04 06 1C 12 02 |.........#......|
[888] 11:24:28:430: >13 09 03 12 34 56 12 34 56 00 00 00 00 00 00 00 |....4V.4V.......|
[888] 11:24:28:430:
[888] 11:24:28:430: <PPP packet sent at 01/14/2005 17:24:28:430
[888] 11:24:28:430: <Protocol = LCP, Type = Configure-Reject, Length = 0x8, Id = 0x2, Port = 5
[888] 11:24:28:430: <C0 21 04 02 00 06 12 02 00 00 00 00 00 00 00 00 |.!..............|
[888] 11:24:28:430:
[888] 11:24:28:430: >PPP packet received at 01/14/2005 17:24:28:430
[888] 11:24:28:430: >Protocol = LCP, Type = Configure-Reject, Length = 0x9, Id = 0x1, Port = 5
[888] 11:24:28:430: >C0 21 04 01 00 07 0D 03 06 00 00 00 00 00 00 00 |.!..............|
[888] 11:24:28:430:
[888] 11:24:28:440: RemoveFromTimerQ called portid=8,Id=1,Protocol=c021,EventType=0,fAuth=0
[888] 11:24:28:440: <PPP packet sent at 01/14/2005 17:24:28:440
[888] 11:24:28:440: <Protocol = LCP, Type = Configure-Req, Length = 0x23, Id = 0x2, Port = 5
[888] 11:24:28:440: <C0 21 01 02 00 21 02 06 00 00 00 00 05 06 3E AE |.!...!........>.|
[888] 11:24:28:440: <35 D6 07 02 08 02 11 04 06 4E 13 09 03 00 E0 29 |5........N.....)|
[888] 11:24:28:440: <07 D5 50 00 00 00 00 00 00 00 00 00 00 00 00 00 |..P.............|
[888] 11:24:28:440:
[888] 11:24:28:440: InsertInTimerQ called portid=8,Id=2,Protocol=c021,EventType=0,fAuth=0
[712] 11:24:28:540: Packet received (39 bytes) for hPort 5
[888] 11:24:28:540: >PPP packet received at 01/14/2005 17:24:28:540
[888] 11:24:28:540: >Protocol = LCP, Type = Configure-Req, Length = 0x27, Id = 0x3, Port = 5
[888] 11:24:28:540: >C0 21 01 03 00 25 02 06 00 00 00 00 05 06 45 A2 |.!...%........E.|
[888] 11:24:28:540: >DA CF 07 02 08 02 03 04 C0 23 11 04 06 1C 13 09 |.........#......|
[888] 11:24:28:540: >03 12 34 56 12 34 56 00 00 00 00 00 00 00 00 00 |..4V.4V.........|
[888] 11:24:28:540:
[888] 11:24:28:540: <PPP packet sent at 01/14/2005 17:24:28:540
[888] 11:24:28:540: <Protocol = LCP, Type = Configure-Ack, Length = 0x27, Id = 0x3, Port = 5
[888] 11:24:28:540: <C0 21 02 03 00 25 02 06 00 00 00 00 05 06 45 A2 |.!...%........E.|
[888] 11:24:28:540: <DA CF 07 02 08 02 03 04 C0 23 11 04 06 1C 13 09 |.........#......|
[888] 11:24:28:540: <03 12 34 56 12 34 56 00 00 00 00 00 00 00 00 00 |..4V.4V.........|
[888] 11:24:28:540:
[712] 11:24:28:550: Packet received (35 bytes) for hPort 5
[888] 11:24:28:550: >PPP packet received at 01/14/2005 17:24:28:550
[888] 11:24:28:550: >Protocol = LCP, Type = Configure-Ack, Length = 0x23, Id = 0x2, Port = 5
[888] 11:24:28:550: >C0 21 02 02 00 21 02 06 00 00 00 00 05 06 3E AE |.!...!........>.|
[888] 11:24:28:550: >35 D6 07 02 08 02 11 04 06 4E 13 09 03 00 E0 29 |5........N.....)|
[888] 11:24:28:550: >07 D5 50 00 00 00 00 00 00 00 00 00 00 00 00 00 |..P.............|
[888] 11:24:28:550:
[888] 11:24:28:550: RemoveFromTimerQ called portid=8,Id=2,Protocol=c021,EventType=0,fAuth=0
[888] 11:24:28:550: FsmThisLayerUp called for protocol = c021, port = 5
[888] 11:24:28:550: LCP Local Options-------------
[888] 11:24:28:550: MRU=1500,ACCM=0,Auth=0,MagicNumber=1051604438,PFC=ON,ACFC=ON
[888] 11:24:28:550: Recv Framing = PPP Multilink,SSHF=OFF,MRRU=1614,LinkDiscrim=0,BAP=OFF
[888] 11:24:28:550: ED Class = 3, ED Value = 00e02907d5500000000000000000000000000000
[888] 11:24:28:550: LCP Remote Options-------------
[888] 11:24:28:550: MRU=1500,ACCM=0,Auth=c023,MagicNumber=1168300751,PFC=ON,ACFC=ON
[888] 11:24:28:550: Send Framing = PPP Multilink,SSHF=OFF,MRRU=1564,LinkDiscrim=0
[888] 11:24:28:550: ED Class = 3, ED Value = 1234561234560000000000000000000000000000
[888] 11:24:28:550: LCP Configured successfully
[888] 11:24:28:550: <PPP packet sent at 01/14/2005 17:24:28:550
[888] 11:24:28:550: <Protocol = LCP, Type = Identification, Length = 0x14, Id = 0x3, Port = 5
[888] 11:24:28:550: <C0 21 0C 03 00 12 3E AE 35 D6 4D 53 52 41 53 56 |.!....>.5.MSRASV|
[888] 11:24:28:550: <35 2E 30 30 00 00 00 00 00 00 00 00 00 00 00 00 |5.00............|
[888] 11:24:28:550:
[888] 11:24:28:550: <PPP packet sent at 01/14/2005 17:24:28:550
[888] 11:24:28:550: <Protocol = LCP, Type = Identification, Length = 0x16, Id = 0x4, Port = 5
[888] 11:24:28:550: <C0 21 0C 04 00 14 3E AE 35 D6 4D 53 52 41 53 2D |.!....>.5.MSRAS-|
[888] 11:24:28:550: <31 2D 50 32 30 30 00 00 00 00 00 00 00 00 00 00 |1-P200..........|
[888] 11:24:28:550:
[888] 11:24:28:550: Authenticating phase started
[888] 11:24:28:550: <PPP packet sent at 01/14/2005 17:24:28:550
[888] 11:24:28:550: <Protocol = PAP, Type = Protocol specific, Length = 0x13, Id = 0x4, Port = 5
[888] 11:24:28:550:
[888] 11:24:28:560: InsertInTimerQ called portid=8,Id=4,Protocol=c023,EventType=0,fAuth=0
[712] 11:24:28:690: Packet received (22 bytes) for hPort 5
[888] 11:24:28:690: >PPP packet received at 01/14/2005 17:24:28:690
[888] 11:24:28:690: >Protocol = PAP, Type = Protocol specific, Length = 0x16, Id = 0x4, Port = 5
[888] 11:24:28:690:
[888] 11:24:28:690: RemoveFromTimerQ called portid=8,Id=4,Protocol=c023,EventType=0,fAuth=0
[888] 11:24:28:690: FsmThisLayerUp called for protocol = c023, port = 5
[888] 11:24:28:690: NotifyCaller(hPort=5, dwMsgId=17)
[712] 11:24:28:690: Packet received (18 bytes) for hPort 5
[888] 11:24:28:690: NotifyCaller(hPort=5, dwMsgId=3)
[888] 11:24:28:690: Will not initialize CP 8029
[888] 11:24:28:690: FsmInit called for protocol = 80fd, port = 5
[888] 11:24:28:690: FsmReset called for protocol = 80fd, port = 5
[888] 11:24:28:690: FsmInit called for protocol = 8021, port = 5
[888] 11:24:28:690: FsmReset called for protocol = 8021, port = 5
[888] 11:24:28:700: FsmOpen event received for protocol 80fd on port 5
[888] 11:24:28:700: FsmThisLayerStarted called for protocol = 80fd, port = 5
[888] 11:24:28:700: FsmUp event received for protocol 80fd on port 5
[888] 11:24:28:700: <PPP packet sent at 01/14/2005 17:24:28:700
[888] 11:24:28:700: <Protocol = CCP, Type = Configure-Req, Length = 0xc, Id = 0x5, Port = 5
[888] 11:24:28:700: <80 FD 01 05 00 0A 12 06 00 00 00 01 00 00 00 00 |................|
[888] 11:24:28:700:
[888] 11:24:28:700: InsertInTimerQ called portid=8,Id=5,Protocol=80fd,EventType=0,fAuth=0
[888] 11:24:28:700: FsmOpen event received for protocol 8021 on port 5
[888] 11:24:28:700: FsmThisLayerStarted called for protocol = 8021, port = 5
[888] 11:24:28:700: FsmUp event received for protocol 8021 on port 5
[888] 11:24:28:700: <PPP packet sent at 01/14/2005 17:24:28:700
[888] 11:24:28:700: <Protocol = IPCP, Type = Configure-Req, Length = 0x2a, Id = 0x6, Port = 5
[888] 11:24:28:700: <80 21 01 06 00 28 02 06 00 2D 0F 01 03 06 00 00 |.!...(...-......|
[888] 11:24:28:700: <00 00 81 06 00 00 00 00 82 06 00 00 00 00 83 06 |................|
[888] 11:24:28:700: <00 00 00 00 84 06 00 00 00 00 00 00 00 00 00 00 |................|
[888] 11:24:28:700:
[888] 11:24:28:700: InsertInTimerQ called portid=8,Id=6,Protocol=8021,EventType=0,fAuth=0
[888] 11:24:28:700: >PPP packet received at 01/14/2005 17:24:28:700
[888] 11:24:28:700: >Protocol = IPCP, Type = Configure-Req, Length = 0x12, Id = 0x1, Port = 5
[888] 11:24:28:700: >80 21 01 01 00 10 02 06 00 2D 0F 00 03 06 CF 47 |.!.......-.....G|
[888] 11:24:28:700: >14 13 00 00 00 00 00 00 00 00 00 00 00 00 00 00 |................|
[888] 11:24:28:700:
[888] 11:24:28:700: <PPP packet sent at 01/14/2005 17:24:28:700
[888] 11:24:28:700: <Protocol = IPCP, Type = Configure-Ack, Length = 0x12, Id = 0x1, Port = 5
[888] 11:24:28:700: <80 21 02 01 00 10 02 06 00 2D 0F 00 03 06 CF 47 |.!.......-.....G|
[888] 11:24:28:700: <14 13 00 00 00 00 00 00 00 00 00 00 00 00 00 00 |................|
[888] 11:24:28:700:
[712] 11:24:28:811: Packet received (18 bytes) for hPort 5
[888] 11:24:28:811: >PPP packet received at 01/14/2005 17:24:28:811
[888] 11:24:28:811: >Protocol = LCP, Type = Protocol-Reject, Length = 0x12, Id = 0x4, Port = 5
[888] 11:24:28:811: >C0 21 08 04 00 10 80 FD 01 05 00 0A 12 06 00 00 |.!..............|
[888] 11:24:28:811: >00 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 |................|
[888] 11:24:28:811:
[712] 11:24:28:811: Packet received (12 bytes) for hPort 5
[888] 11:24:28:811: PPP Protocol Reject, Protocol = 80fd
[888] 11:24:28:811: RemoveFromTimerQ called portid=8,Id=5,Protocol=80fd,EventType=0,fAuth=0
[888] 11:24:28:811: FsmThisLayerFinished called for protocol = 80fd, port = 5
[888] 11:24:28:811: >PPP packet received at 01/14/2005 17:24:28:811
[888] 11:24:28:811: >Protocol = IPCP, Type = Configure-Reject, Length = 0xc, Id = 0x6, Port = 5
[888] 11:24:28:811: >80 21 04 06 00 0A 84 06 00 00 00 00 00 00 00 00 |.!..............|
[888] 11:24:28:811:
[888] 11:24:28:811: RemoveFromTimerQ called portid=8,Id=6,Protocol=8021,EventType=0,fAuth=0
[888] 11:24:28:811: <PPP packet sent at 01/14/2005 17:24:28:811
[888] 11:24:28:811: <Protocol = IPCP, Type = Configure-Req, Length = 0x24, Id = 0x7, Port = 5
[888] 11:24:28:811: <80 21 01 07 00 22 02 06 00 2D 0F 01 03 06 00 00 |.!..."...-......|
[888] 11:24:28:811: <00 00 81 06 00 00 00 00 82 06 00 00 00 00 83 06 |................|
[888] 11:24:28:811: <00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 |................|
[888] 11:24:28:811:
[888] 11:24:28:821: InsertInTimerQ called portid=8,Id=7,Protocol=8021,EventType=0,fAuth=0
[712] 11:24:30:884: Packet received (18 bytes) for hPort 5
[888] 11:24:30:884: >PPP packet received at 01/14/2005 17:24:30:884
[888] 11:24:30:884: >Protocol = IPCP, Type = Configure-Nak, Length = 0x12, Id = 0x7, Port = 5
[888] 11:24:30:884: >80 21 03 07 00 10 82 06 00 00 00 00 83 06 CC 39 |.!.............9|
[888] 11:24:30:884: >48 03 00 00 00 00 00 00 00 00 00 00 00 00 00 00 |H...............|
[888] 11:24:30:884:
[888] 11:24:30:884: RemoveFromTimerQ called portid=8,Id=7,Protocol=8021,EventType=0,fAuth=0
[888] 11:24:30:884: <PPP packet sent at 01/14/2005 17:24:30:884
[888] 11:24:30:884: <Protocol = IPCP, Type = Configure-Req, Length = 0x24, Id = 0x8, Port = 5
[888] 11:24:30:884: <80 21 01 08 00 22 02 06 00 2D 0F 01 03 06 00 00 |.!..."...-......|
[888] 11:24:30:884: <00 00 81 06 00 00 00 00 82 06 00 00 00 00 83 06 |................|
[888] 11:24:30:884: <CC 39 48 03 00 00 00 00 00 00 00 00 00 00 00 00 |.9H.............|
[888] 11:24:30:884:
[888] 11:24:30:884: InsertInTimerQ called portid=8,Id=8,Protocol=8021,EventType=0,fAuth=0
[712] 11:24:30:984: Packet received (12 bytes) for hPort 5
[888] 11:24:30:984: >PPP packet received at 01/14/2005 17:24:30:984
[888] 11:24:30:984: >Protocol = IPCP, Type = Configure-Reject, Length = 0xc, Id = 0x8, Port = 5
[888] 11:24:30:984: >80 21 04 08 00 0A 82 06 00 00 00 00 00 00 00 00 |.!..............|
[888] 11:24:30:984:
[888] 11:24:30:984: RemoveFromTimerQ called portid=8,Id=8,Protocol=8021,EventType=0,fAuth=0
[888] 11:24:30:984: <PPP packet sent at 01/14/2005 17:24:30:984
[888] 11:24:30:984: <Protocol = IPCP, Type = Configure-Req, Length = 0x1e, Id = 0x9, Port = 5
[888] 11:24:30:984: <80 21 01 09 00 1C 02 06 00 2D 0F 01 03 06 00 00 |.!.......-......|
[888] 11:24:30:984: <00 00 81 06 00 00 00 00 83 06 CC 39 48 03 00 00 |...........9H...|
[888] 11:24:30:984:
[888] 11:24:30:984: InsertInTimerQ called portid=8,Id=9,Protocol=8021,EventType=0,fAuth=0
[712] 11:24:31:074: Packet received (18 bytes) for hPort 5
[888] 11:24:31:074: >PPP packet received at 01/14/2005 17:24:31:074
[888] 11:24:31:074: >Protocol = IPCP, Type = Configure-Nak, Length = 0x12, Id = 0x9, Port = 5
[888] 11:24:31:074: >80 21 03 09 00 10 03 06 CF 47 16 5B 81 06 CC 39 |.!.......G.[...9|
[888] 11:24:31:074: >48 02 00 00 00 00 00 00 00 00 00 00 00 00 00 00 |H...............|
[888] 11:24:31:074:
[888] 11:24:31:074: RemoveFromTimerQ called portid=8,Id=9,Protocol=8021,EventType=0,fAuth=0
[888] 11:24:31:074: <PPP packet sent at 01/14/2005 17:24:31:074
[888] 11:24:31:074: <Protocol = IPCP, Type = Configure-Req, Length = 0x1e, Id = 0xa, Port = 5
[888] 11:24:31:074: <80 21 01 0A 00 1C 02 06 00 2D 0F 01 03 06 CF 47 |.!.......-.....G|
[888] 11:24:31:074: <16 5B 81 06 CC 39 48 02 83 06 CC 39 48 03 00 00 |.[...9H....9H...|
[888] 11:24:31:074:
[888] 11:24:31:074: InsertInTimerQ called portid=8,Id=10,Protocol=8021,EventType=0,fAuth=0
[712] 11:24:31:174: Packet received (30 bytes) for hPort 5
[888] 11:24:31:174: >PPP packet received at 01/14/2005 17:24:31:174
[888] 11:24:31:174: >Protocol = IPCP, Type = Configure-Ack, Length = 0x1e, Id = 0xa, Port = 5
[888] 11:24:31:174: >80 21 02 0A 00 1C 02 06 00 2D 0F 01 03 06 CF 47 |.!.......-.....G|
[888] 11:24:31:174: >16 5B 81 06 CC 39 48 02 83 06 CC 39 48 03 00 00 |.[...9H....9H...|
[888] 11:24:31:174:
[888] 11:24:31:174: RemoveFromTimerQ called portid=8,Id=10,Protocol=8021,EventType=0,fAuth=0
[888] 11:24:31:174: FsmThisLayerUp called for protocol = 8021, port = 5
[888] 11:24:31:755: Notifying IPCP of projection notification
[888] 11:24:31:755: RemoveFromTimerQ called portid=8,Id=0,Protocol=0,EventType=3,fAuth=0
[888] 11:24:31:755: NotifyCaller(hPort=5, dwMsgId=4)
[888] 11:24:31:815: NotifyCaller(hPort=5, dwMsgId=0)
[888] 11:24:31:815: Inserting autodisconnect in timer q for port=5, sec=-1
[888] 11:24:31:815: RemoveFromTimerQ called portid=8,Id=0,Protocol=0,EventType=1,fAuth=0
[888] 11:24:31:815: InsertInTimerQ called portid=8,Id=0,Protocol=0,EventType=1,fAuth=0
[568] 11:25:27:635: PppStop

[568] 11:25:27:635: PPPEMSG_Stop recvd

[888] 11:25:27:996: FsmClose event received for protocol c021 on port 5
[888] 11:25:27:996: RemoveFromTimerQ called portid=8,Id=2,Protocol=c021,EventType=0,fAuth=0
[888] 11:25:27:996: FsmThisLayerDown called for protocol = c021, port = 5
[888] 11:25:27:996: FsmDown event received for protocol 80fd on port 5
[888] 11:25:27:996: RemoveFromTimerQ called portid=8,Id=5,Protocol=80fd,EventType=0,fAuth=0
[888] 11:25:27:996: FsmThisLayerStarted called for protocol = 80fd, port = 5
[888] 11:25:27:996: FsmReset called for protocol = 80fd, port = 5
[888] 11:25:27:996: FsmDown event received for protocol 8021 on port 5
[888] 11:25:27:996: RemoveFromTimerQ called portid=8,Id=10,Protocol=8021,EventType=0,fAuth=0
[888] 11:25:27:996: FsmThisLayerDown called for protocol = 8021, port = 5
[888] 11:25:27:996: FsmReset called for protocol = 8021, port = 5
[888] 11:25:27:996: RemoveFromTimerQ called portid=8,Id=4,Protocol=c023,EventType=0,fAuth=0
[888] 11:25:27:996: RemoveFromTimerQ called portid=8,Id=0,Protocol=c029,EventType=0,fAuth=0
[888] 11:25:27:996: <PPP packet sent at 01/14/2005 17:25:27:996
[888] 11:25:27:996: <Protocol = LCP, Type = Terminate-Req, Length = 0x12, Id = 0xb, Port = 5
[888] 11:25:27:996: <C0 21 05 0B 00 10 3E AE 35 D6 00 3C CD 74 00 00 |.!....>.5..<.t..|
[888] 11:25:27:996: <00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 |................|
[888] 11:25:27:996:
[888] 11:25:27:996: InsertInTimerQ called portid=8,Id=11,Protocol=c021,EventType=0,fAuth=0
[712] 11:25:28:096: Packet received (6 bytes) for hPort 5
[888] 11:25:28:096: >PPP packet received at 01/14/2005 17:25:28:096
[888] 11:25:28:096: >Protocol = LCP, Type = Terminate-Ack, Length = 0x6, Id = 0x5, Port = 5
[888] 11:25:28:096: >C0 21 06 05 00 04 00 00 00 00 00 00 00 00 00 00 |.!..............|
[888] 11:25:28:096:
[888] 11:25:28:096: Term Ack with on port 5 silently discarded. Invalid Id
[888] 11:25:29:999: Recv timeout event received for portid=8,Id=11,Protocol=c021,fAuth=0
[888] 11:25:29:999: <PPP packet sent at 01/14/2005 17:25:29:999
[888] 11:25:29:999: <Protocol = LCP, Type = Terminate-Req, Length = 0x12, Id = 0xc, Port = 5
[888] 11:25:29:999: <C0 21 05 0C 00 10 3E AE 35 D6 00 3C CD 74 00 00 |.!....>.5..<.t..|
[888] 11:25:29:999: <00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 |................|
[888] 11:25:29:999:
[888] 11:25:29:999: InsertInTimerQ called portid=8,Id=12,Protocol=c021,EventType=0,fAuth=0
[888] 11:25:33:003: Recv timeout event received for portid=8,Id=12,Protocol=c021,fAuth=0
[888] 11:25:33:003: Terminate retry exceeded
[888] 11:25:33:003: FsmThisLayerFinished called for protocol = c021, port = 5
[888] 11:25:33:003: FsmThisLayerFinished called for protocol = 80fd, port = 5: 0
[888] 11:25:33:714: FsmThisLayerFinished called for protocol = 8021, port = 5: 0
[888] 11:25:33:714: NotifyCaller(hPort=5, dwMsgId=10)
[712] 11:25:43:829: PPPEMSG_LineDown recvd, hPort=5

[888] 11:25:43:829: Line down event occurred on port 5
[888] 11:25:52:962: FsmDown event received for protocol c021 on port 5
[888] 11:25:52:962: RemoveFromTimerQ called portid=8,Id=12,Protocol=c021,EventType=0,fAuth=0
[888] 11:25:52:962: FsmReset called for protocol = c021, port = 5
[888] 11:25:52:962: RemoveFromTimerQ called portid=8,Id=0,Protocol=0,EventType=3,fAuth=0
[888] 11:25:52:962: RemoveFromTimerQ called portid=8,Id=0,Protocol=0,EventType=1,fAuth=0
[888] 11:25:52:962: RemoveFromTimerQ called portid=8,Id=0,Protocol=c029,EventType=0,fAuth=0
[888] 11:25:52:962: LcpEnd
[888] 11:25:52:962: NotifyCaller(hPort=5, dwMsgId=23)

**************************************************************************************




**************************************************************************************
**************************************************************************************
PPP.LOG - LONGER session, induced no throughput thru refreshes of websites - manually
disconnected when data stopped going thru:
**************************************************************************************
**************************************************************************************


(note this the modem.log for this particular session - the PPP.LOG is below...)

01-14-2005 11:27:22.430 - File: C:\WINNT\system32\unimdm.tsp, Version 5.0.2195 - Retail
01-14-2005 11:27:22.440 - File: C:\WINNT\system32\unimdmat.dll, Version 5.0.2195 - Retail
01-14-2005 11:27:22.440 - File: C:\WINNT\system32\uniplat.dll, Version 5.0.2195 - Retail
01-14-2005 11:27:22.450 - File: C:\WINNT\system32\drivers\modem.sys, Version 5.0.2195 - Retail
01-14-2005 11:27:22.460 - File: C:\WINNT\system32\modemui.dll, Version 5.0.2195 - Retail
01-14-2005 11:27:22.460 - Modem type: Standard 56000 bps V90 Modem
01-14-2005 11:27:22.460 - Modem inf path: mdmusrk1.inf
01-14-2005 11:27:22.460 - Modem inf section: Gen2
01-14-2005 11:27:22.480 - 57600,8,N,1, ctsfl=0, rtsctl=1
01-14-2005 11:27:22.480 - Initializing modem.
01-14-2005 11:27:22.490 - Send: ATZ<cr>
01-14-2005 11:27:22.751 - Recv: <cr><lf>OK<cr><lf>
01-14-2005 11:27:22.751 - Interpreted response: OK
01-14-2005 11:27:22.831 - Send: ATE0V1&C1&D2S0=0<cr>
01-14-2005 11:27:22.851 - Recv: ATE0V1&C1&D2S0=0<cr>
01-14-2005 11:27:22.851 - Command Echo
01-14-2005 11:27:22.871 - Recv: <cr><lf>OK<cr><lf>
01-14-2005 11:27:22.871 - Interpreted response: OK
01-14-2005 11:27:22.881 - Send: ATM1X4<cr>
01-14-2005 11:27:22.911 - Recv: <cr><lf>OK<cr><lf>
01-14-2005 11:27:22.911 - Interpreted response: OK
01-14-2005 11:27:22.931 - Send: AT+MS=V90,,,,40000,48000;+PCW=1;S11=55<cr>
01-14-2005 11:27:22.981 - Recv: <cr><lf>OK<cr><lf>
01-14-2005 11:27:22.981 - Interpreted response: OK
01-14-2005 11:27:22.981 - Waiting for a call.
01-14-2005 11:27:22.991 - Send: ATS0=0<cr>
01-14-2005 11:27:23.031 - Recv: <cr><lf>OK<cr><lf>
01-14-2005 11:27:23.031 - Interpreted response: OK
01-14-2005 11:27:23.031 - 115200,8,N,1, ctsfl=0, rtsctl=1
01-14-2005 11:27:23.031 - Initializing modem.
01-14-2005 11:27:23.041 - Send: ATZ<cr>
01-14-2005 11:27:23.211 - Recv: <cr><lf>OK<cr><lf>
01-14-2005 11:27:23.211 - Interpreted response: OK
01-14-2005 11:27:23.221 - Send: ATE0V1&C1&D2S0=0<cr>
01-14-2005 11:27:23.221 - Recv: ATE0V1&C1&D2S0=0<cr>
01-14-2005 11:27:23.221 - Command Echo
01-14-2005 11:27:23.261 - Recv: <cr><lf>OK<cr><lf>
01-14-2005 11:27:23.261 - Interpreted response: OK
01-14-2005 11:27:23.272 - Send: ATM1X4<cr>
01-14-2005 11:27:23.302 - Recv: <cr><lf>OK<cr><lf>
01-14-2005 11:27:23.302 - Interpreted response: OK
01-14-2005 11:27:23.352 - Send: AT+MS=V90,,,,40000,48000;+PCW=1;S11=55<cr>
01-14-2005 11:27:23.422 - Recv: <cr><lf>OK<cr><lf>
01-14-2005 11:27:23.422 - Interpreted response: OK
01-14-2005 11:27:23.472 - Dialing.
01-14-2005 11:27:23.482 - Send: ATDT##########<cr>
01-14-2005 11:27:49.459 - Recv: <cr><lf>CONNECT 115200<cr><lf>
01-14-2005 11:27:49.459 - Interpreted response: Connect
01-14-2005 11:27:49.459 - Connection established at 115200bps.
01-14-2005 11:27:49.459 - Error-control off or unknown.
01-14-2005 11:27:49.459 - Data compression off or unknown.
01-14-2005 11:28:19.462 - Read: Total: 17186, Per/Sec: 570, Written: Total: 20830, Per/Sec: 691
01-14-2005 11:30:19.465 - Read: Total: 335945, Per/Sec: 2656, Written: Total: 120302, Per/Sec: 828
01-14-2005 11:30:43.009 - Hanging up the modem.
01-14-2005 11:30:43.009 - Hardware hangup by lowering DTR.
01-14-2005 11:30:53.013 - WARNING: After lowering DTR to hangup, the modem did not drop CD with in 10 seconds,
Attempting software hangup.
01-14-2005 11:30:53.013 - Send: +++
01-14-2005 11:31:00.484 - Recv: <cr><lf>OK<cr><lf>
01-14-2005 11:31:00.484 - Interpreted response: OK
01-14-2005 11:31:00.494 - Send: ATH<cr>
01-14-2005 11:31:01.275 - Recv: <cr><lf>OK<cr><lf>
01-14-2005 11:31:01.275 - Interpreted response: OK
01-14-2005 11:31:01.285 - 57600,8,N,1, ctsfl=0, rtsctl=1
01-14-2005 11:31:01.285 - Initializing modem.
01-14-2005 11:31:01.295 - Send: ATZ<cr>
01-14-2005 11:31:01.465 - Recv: <cr><lf>OK<cr><lf>
01-14-2005 11:31:01.465 - Interpreted response: OK
01-14-2005 11:31:01.475 - Send: ATE0V1&C1&D2S0=0<cr>
01-14-2005 11:31:01.475 - Recv: ATE0V1&C1&D2S0=0<cr>
01-14-2005 11:31:01.475 - Command Echo
01-14-2005 11:31:01.515 - Recv: <cr><lf>OK<cr><lf>
01-14-2005 11:31:01.515 - Interpreted response: OK
01-14-2005 11:31:01.525 - Send: ATM1X4<cr>
01-14-2005 11:31:01.565 - Recv: <cr><lf>OK<cr><lf>
01-14-2005 11:31:01.565 - Interpreted response: OK
01-14-2005 11:31:01.575 - Send: AT+MS=V90,,,,40000,48000;+PCW=1;S11=55<cr>
01-14-2005 11:31:01.625 - Recv: <cr><lf>OK<cr><lf>
01-14-2005 11:31:01.625 - Interpreted response: OK
01-14-2005 11:31:01.625 - Waiting for a call.
01-14-2005 11:31:01.636 - Send: ATS0=0<cr>
01-14-2005 11:31:01.676 - Recv: <cr><lf>OK<cr><lf>
01-14-2005 11:31:01.676 - Interpreted response: OK
01-14-2005 11:31:01.686 - Session Statistics:
01-14-2005 11:31:01.686 - Reads : 47 bytes
01-14-2005 11:31:01.686 - Writes: 74 bytes


(end modem.log, begin ppp.log)

[568] 11:27:49:549: PPPEMSG_Start recvd, d=, hPort=5,callback=0,mask=83074a,IfType=-1
[888] 11:27:49:549: Line up event occurred on port 5
[888] 11:27:49:559: Local identification = MSRAS-1-P200
[888] 11:27:49:559: PortName: COM1
[888] 11:27:49:559: Starting PPP on link with IfType=0xffffffff,IPIf=0xffffffff,IPXIf=0xffffffff
[888] 11:27:49:559: RasGetBuffer returned 112430 for SendBuf
[888] 11:27:49:559: FsmInit called for protocol = c021, port = 5
[888] 11:27:49:559: ConfigInfo = 83074a
[888] 11:27:49:559: APs available = 5e
[888] 11:27:49:559: FsmReset called for protocol = c021, port = 5
[888] 11:27:49:559: Inserting port in bucket # 0
[888] 11:27:49:559: Inserting bundle in bucket # 1
[888] 11:27:49:559: FsmOpen event received for protocol c021 on port 5
[888] 11:27:49:559: FsmThisLayerStarted called for protocol = c021, port = 5
[888] 11:27:49:559: FsmUp event received for protocol c021 on port 5
[888] 11:27:49:559: <PPP packet sent at 01/14/2005 17:27:49:559
[888] 11:27:49:559: <Protocol = LCP, Type = Configure-Req, Length = 0x26, Id = 0x0, Port = 5
[888] 11:27:49:559: <C0 21 01 00 00 24 02 06 00 00 00 00 05 06 60 4D |.!...$........`M|
[888] 11:27:49:559: <3D AE 07 02 08 02 0D 03 06 11 04 06 4E 13 09 03 |=...........N...|
[888] 11:27:49:559: <00 E0 29 07 D5 50 00 00 00 00 00 00 00 00 00 00 |..)..P..........|
[888] 11:27:49:559:
[888] 11:27:49:559: InsertInTimerQ called portid=10,Id=0,Protocol=c021,EventType=0,fAuth=0
[888] 11:27:49:559: InsertInTimerQ called portid=10,Id=0,Protocol=0,EventType=3,fAuth=0
[712] 11:27:51:482: Packet received (26 bytes) for hPort 5
[888] 11:27:51:482: >PPP packet received at 01/14/2005 17:27:51:482
[888] 11:27:51:482: >Protocol = LCP, Type = Configure-Req, Length = 0x1a, Id = 0x1, Port = 5
[888] 11:27:51:482: >C0 21 01 01 00 18 02 06 00 00 00 00 05 06 CE 0E |.!..............|
[888] 11:27:51:482: >7A BF 07 02 08 02 03 04 C0 23 00 00 00 00 00 00 |z........#......|
[888] 11:27:51:482:
[888] 11:27:51:482: <PPP packet sent at 01/14/2005 17:27:51:482
[888] 11:27:51:482: <Protocol = LCP, Type = Configure-Ack, Length = 0x1a, Id = 0x1, Port = 5
[888] 11:27:51:482: <C0 21 02 01 00 18 02 06 00 00 00 00 05 06 CE 0E |.!..............|
[888] 11:27:51:482: <7A BF 07 02 08 02 03 04 C0 23 00 00 00 00 00 00 |z........#......|
[888] 11:27:51:482:
[888] 11:27:51:562: Recv timeout event received for portid=10,Id=0,Protocol=c021,fAuth=0
[888] 11:27:51:562: <PPP packet sent at 01/14/2005 17:27:51:562
[888] 11:27:51:562: <Protocol = LCP, Type = Configure-Req, Length = 0x26, Id = 0x1, Port = 5
[888] 11:27:51:562: <C0 21 01 01 00 24 02 06 00 00 00 00 05 06 60 4D |.!...$........`M|
[888] 11:27:51:562: <3D AE 07 02 08 02 0D 03 06 11 04 06 4E 13 09 03 |=...........N...|
[888] 11:27:51:562: <00 E0 29 07 D5 50 00 00 00 00 00 00 00 00 00 00 |..)..P..........|
[888] 11:27:51:562:
[888] 11:27:51:562: InsertInTimerQ called portid=10,Id=1,Protocol=c021,EventType=0,fAuth=0
[712] 11:27:51:672: Packet received (41 bytes) for hPort 5
[888] 11:27:51:672: >PPP packet received at 01/14/2005 17:27:51:672
[888] 11:27:51:672: >Protocol = LCP, Type = Configure-Req, Length = 0x29, Id = 0x2, Port = 5
[888] 11:27:51:672: >C0 21 01 02 00 27 02 06 00 00 00 00 05 06 CE 0E |.!...'..........|
[712] 11:27:51:682: Packet received (9 bytes) for hPort 5
[888] 11:27:51:672: >7A BF 07 02 08 02 03 04 C0 23 11 04 06 1C 12 02 |z........#......|
[888] 11:27:51:672: >13 09 03 12 34 56 12 34 56 00 00 00 00 00 00 00 |....4V.4V.......|
[888] 11:27:51:682:
[888] 11:27:51:682: <PPP packet sent at 01/14/2005 17:27:51:682
[888] 11:27:51:682: <Protocol = LCP, Type = Configure-Reject, Length = 0x8, Id = 0x2, Port = 5
[888] 11:27:51:682: <C0 21 04 02 00 06 12 02 00 00 00 00 00 00 00 00 |.!..............|
[888] 11:27:51:682:
[888] 11:27:51:682: >PPP packet received at 01/14/2005 17:27:51:682
[888] 11:27:51:682: >Protocol = LCP, Type = Configure-Reject, Length = 0x9, Id = 0x1, Port = 5
[888] 11:27:51:682: >C0 21 04 01 00 07 0D 03 06 00 00 00 00 00 00 00 |.!..............|
[888] 11:27:51:682:
[888] 11:27:51:682: RemoveFromTimerQ called portid=10,Id=1,Protocol=c021,EventType=0,fAuth=0
[888] 11:27:51:682: <PPP packet sent at 01/14/2005 17:27:51:682
[888] 11:27:51:682: <Protocol = LCP, Type = Configure-Req, Length = 0x23, Id = 0x2, Port = 5
[888] 11:27:51:682: <C0 21 01 02 00 21 02 06 00 00 00 00 05 06 60 4D |.!...!........`M|
[888] 11:27:51:682: <3D AE 07 02 08 02 11 04 06 4E 13 09 03 00 E0 29 |=........N.....)|
[888] 11:27:51:682: <07 D5 50 00 00 00 00 00 00 00 00 00 00 00 00 00 |..P.............|
[888] 11:27:51:682:
[888] 11:27:51:682: InsertInTimerQ called portid=10,Id=2,Protocol=c021,EventType=0,fAuth=0
[712] 11:27:51:783: Packet received (39 bytes) for hPort 5
[888] 11:27:51:783: >PPP packet received at 01/14/2005 17:27:51:783
[888] 11:27:51:793: >Protocol = LCP, Type = Configure-Req, Length = 0x27, Id = 0x3, Port = 5
[888] 11:27:51:793: >C0 21 01 03 00 25 02 06 00 00 00 00 05 06 CE 0E |.!...%..........|
[888] 11:27:51:793: >7A BF 07 02 08 02 03 04 C0 23 11 04 06 1C 13 09 |z........#......|
[888] 11:27:51:793: >03 12 34 56 12 34 56 00 00 00 00 00 00 00 00 00 |..4V.4V.........|
[888] 11:27:51:793:
[888] 11:27:51:793: <PPP packet sent at 01/14/2005 17:27:51:793
[888] 11:27:51:793: <Protocol = LCP, Type = Configure-Ack, Length = 0x27, Id = 0x3, Port = 5
[888] 11:27:51:793: <C0 21 02 03 00 25 02 06 00 00 00 00 05 06 CE 0E |.!...%..........|
[888] 11:27:51:793: <7A BF 07 02 08 02 03 04 C0 23 11 04 06 1C 13 09 |z........#......|
[888] 11:27:51:793: <03 12 34 56 12 34 56 00 00 00 00 00 00 00 00 00 |..4V.4V.........|
[888] 11:27:51:793:
[712] 11:27:51:793: Packet received (35 bytes) for hPort 5
[888] 11:27:51:793: >PPP packet received at 01/14/2005 17:27:51:793
[888] 11:27:51:793: >Protocol = LCP, Type = Configure-Ack, Length = 0x23, Id = 0x2, Port = 5
[888] 11:27:51:793: >C0 21 02 02 00 21 02 06 00 00 00 00 05 06 60 4D |.!...!........`M|
[888] 11:27:51:793: >3D AE 07 02 08 02 11 04 06 4E 13 09 03 00 E0 29 |=........N.....)|
[888] 11:27:51:793: >07 D5 50 00 00 00 00 00 00 00 00 00 00 00 00 00 |..P.............|
[888] 11:27:51:793:
[888] 11:27:51:793: RemoveFromTimerQ called portid=10,Id=2,Protocol=c021,EventType=0,fAuth=0
[888] 11:27:51:793: FsmThisLayerUp called for protocol = c021, port = 5
[888] 11:27:51:793: LCP Local Options-------------
[888] 11:27:51:793: MRU=1500,ACCM=0,Auth=0,MagicNumber=1615674798,PFC=ON,ACFC=ON
[888] 11:27:51:793: Recv Framing = PPP Multilink,SSHF=OFF,MRRU=1614,LinkDiscrim=0,BAP=OFF
[888] 11:27:51:793: ED Class = 3, ED Value = 00e02907d5500000000000000000000000000000
[888] 11:27:51:793: LCP Remote Options-------------
[888] 11:27:51:793: MRU=1500,ACCM=0,Auth=c023,MagicNumber=-837911873,PFC=ON,ACFC=ON
[888] 11:27:51:793: Send Framing = PPP Multilink,SSHF=OFF,MRRU=1564,LinkDiscrim=0
[888] 11:27:51:793: ED Class = 3, ED Value = 1234561234560000000000000000000000000000
[888] 11:27:51:813: LCP Configured successfully
[888] 11:27:51:813: <PPP packet sent at 01/14/2005 17:27:51:813
[888] 11:27:51:813: <Protocol = LCP, Type = Identification, Length = 0x14, Id = 0x3, Port = 5
[888] 11:27:51:813: <C0 21 0C 03 00 12 60 4D 3D AE 4D 53 52 41 53 56 |.!....`M=.MSRASV|
[888] 11:27:51:813: <35 2E 30 30 00 00 00 00 00 00 00 00 00 00 00 00 |5.00............|
[888] 11:27:51:813:
[888] 11:27:51:813: <PPP packet sent at 01/14/2005 17:27:51:813
[888] 11:27:51:813: <Protocol = LCP, Type = Identification, Length = 0x16, Id = 0x4, Port = 5
[888] 11:27:51:813: <C0 21 0C 04 00 14 60 4D 3D AE 4D 53 52 41 53 2D |.!....`M=.MSRAS-|
[888] 11:27:51:813: <31 2D 50 32 30 30 00 00 00 00 00 00 00 00 00 00 |1-P200..........|
[888] 11:27:51:813:
[888] 11:27:51:813: Authenticating phase started
[888] 11:27:51:813: <PPP packet sent at 01/14/2005 17:27:51:813
[888] 11:27:51:813: <Protocol = PAP, Type = Protocol specific, Length = 0x13, Id = 0x5, Port = 5
[888] 11:27:51:813:
[888] 11:27:51:813: InsertInTimerQ called portid=10,Id=5,Protocol=c023,EventType=0,fAuth=0
[712] 11:27:51:933: Packet received (22 bytes) for hPort 5
[888] 11:27:51:933: >PPP packet received at 01/14/2005 17:27:51:933
[888] 11:27:51:933: >Protocol = PAP, Type = Protocol specific, Length = 0x16, Id = 0x5, Port = 5
[888] 11:27:51:933:
[888] 11:27:51:933: RemoveFromTimerQ called portid=10,Id=5,Protocol=c023,EventType=0,fAuth=0
[888] 11:27:51:933: FsmThisLayerUp called for protocol = c023, port = 5
[888] 11:27:51:933: NotifyCaller(hPort=5, dwMsgId=17)
[888] 11:27:51:933: NotifyCaller(hPort=5, dwMsgId=3)
[888] 11:27:51:933: Will not initialize CP 8029
[888] 11:27:51:933: FsmInit called for protocol = 80fd, port = 5
[888] 11:27:51:933: FsmReset called for protocol = 80fd, port = 5
[888] 11:27:51:933: FsmInit called for protocol = 8021, port = 5
[888] 11:27:51:933: FsmReset called for protocol = 8021, port = 5
[888] 11:27:51:943: FsmOpen event received for protocol 80fd on port 5
[888] 11:27:51:943: FsmThisLayerStarted called for protocol = 80fd, port = 5
[888] 11:27:51:943: FsmUp event received for protocol 80fd on port 5
[888] 11:27:51:943: <PPP packet sent at 01/14/2005 17:27:51:943
[888] 11:27:51:943: <Protocol = CCP, Type = Configure-Req, Length = 0xc, Id = 0x5, Port = 5
[888] 11:27:51:943: <80 FD 01 05 00 0A 12 06 00 00 00 01 00 00 00 00 |................|
[888] 11:27:51:943:
[888] 11:27:51:943: InsertInTimerQ called portid=10,Id=5,Protocol=80fd,EventType=0,fAuth=0
[888] 11:27:51:943: FsmOpen event received for protocol 8021 on port 5
[888] 11:27:51:943: FsmThisLayerStarted called for protocol = 8021, port = 5
[888] 11:27:51:943: FsmUp event received for protocol 8021 on port 5
[888] 11:27:51:943: <PPP packet sent at 01/14/2005 17:27:51:943
[888] 11:27:51:943: <Protocol = IPCP, Type = Configure-Req, Length = 0x2a, Id = 0x6, Port = 5
[888] 11:27:51:943: <80 21 01 06 00 28 02 06 00 2D 0F 01 03 06 00 00 |.!...(...-......|
[888] 11:27:51:943: <00 00 81 06 00 00 00 00 82 06 00 00 00 00 83 06 |................|
[888] 11:27:51:943: <00 00 00 00 84 06 00 00 00 00 00 00 00 00 00 00 |................|
[888] 11:27:51:943:
[888] 11:27:51:943: InsertInTimerQ called portid=10,Id=6,Protocol=8021,EventType=0,fAuth=0
[712] 11:27:51:943: Packet received (18 bytes) for hPort 5
[888] 11:27:51:943: >PPP packet received at 01/14/2005 17:27:51:943
[888] 11:27:51:943: >Protocol = IPCP, Type = Configure-Req, Length = 0x12, Id = 0x1, Port = 5
[888] 11:27:51:943: >80 21 01 01 00 10 02 06 00 2D 0F 00 03 06 CF 47 |.!.......-.....G|
[888] 11:27:51:943: >14 12 00 00 00 00 00 00 00 00 00 00 00 00 00 00 |................|
[888] 11:27:51:943:
[888] 11:27:51:953: <PPP packet sent at 01/14/2005 17:27:51:943
[888] 11:27:51:953: <Protocol = IPCP, Type = Configure-Ack, Length = 0x12, Id = 0x1, Port = 5
[888] 11:27:51:953: <80 21 02 01 00 10 02 06 00 2D 0F 00 03 06 CF 47 |.!.......-.....G|
[888] 11:27:51:953: <14 12 00 00 00 00 00 00 00 00 00 00 00 00 00 00 |................|
[888] 11:27:51:953:
[712] 11:27:52:043: Packet received (18 bytes) for hPort 5
[888] 11:27:52:043: >PPP packet received at 01/14/2005 17:27:52:043
[888] 11:27:52:043: >Protocol = LCP, Type = Protocol-Reject, Length = 0x12, Id = 0x4, Port = 5
[888] 11:27:52:043: >C0 21 08 04 00 10 80 FD 01 05 00 0A 12 06 00 00 |.!..............|
[888] 11:27:52:043: >00 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 |................|
[888] 11:27:52:043:
[888] 11:27:52:043: PPP Protocol Reject, Protocol = 80fd
[888] 11:27:52:043: RemoveFromTimerQ called portid=10,Id=5,Protocol=80fd,EventType=0,fAuth=0
[888] 11:27:52:043: FsmThisLayerFinished called for protocol = 80fd, port = 5
[712] 11:27:52:043: Packet received (12 bytes) for hPort 5
[888] 11:27:52:043: >PPP packet received at 01/14/2005 17:27:52:043
[888] 11:27:52:043: >Protocol = IPCP, Type = Configure-Reject, Length = 0xc, Id = 0x6, Port = 5
[888] 11:27:52:043: >80 21 04 06 00 0A 84 06 00 00 00 00 00 00 00 00 |.!..............|
[888] 11:27:52:043:
[888] 11:27:52:043: RemoveFromTimerQ called portid=10,Id=6,Protocol=8021,EventType=0,fAuth=0
[888] 11:27:52:053: <PPP packet sent at 01/14/2005 17:27:52:043
[888] 11:27:52:053: <Protocol = IPCP, Type = Configure-Req, Length = 0x24, Id = 0x7, Port = 5
[888] 11:27:52:053: <80 21 01 07 00 22 02 06 00 2D 0F 01 03 06 00 00 |.!..."...-......|
[888] 11:27:52:053: <00 00 81 06 00 00 00 00 82 06 00 00 00 00 83 06 |................|
[888] 11:27:52:053: <00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 |................|
[888] 11:27:52:053:
[888] 11:27:52:053: InsertInTimerQ called portid=10,Id=7,Protocol=8021,EventType=0,fAuth=0
[712] 11:27:52:143: Packet received (18 bytes) for hPort 5
[888] 11:27:52:143: >PPP packet received at 01/14/2005 17:27:52:143
[888] 11:27:52:143: >Protocol = IPCP, Type = Configure-Nak, Length = 0x12, Id = 0x7, Port = 5
[888] 11:27:52:143: >80 21 03 07 00 10 82 06 00 00 00 00 83 06 CC 39 |.!.............9|
[888] 11:27:52:143: >48 03 00 00 00 00 00 00 00 00 00 00 00 00 00 00 |H...............|
[888] 11:27:52:143:
[888] 11:27:52:143: RemoveFromTimerQ called portid=10,Id=7,Protocol=8021,EventType=0,fAuth=0
[888] 11:27:52:143: <PPP packet sent at 01/14/2005 17:27:52:143
[888] 11:27:52:143: <Protocol = IPCP, Type = Configure-Req, Length = 0x24, Id = 0x8, Port = 5
[888] 11:27:52:143: <80 21 01 08 00 22 02 06 00 2D 0F 01 03 06 00 00 |.!..."...-......|
[888] 11:27:52:143: <00 00 81 06 00 00 00 00 82 06 00 00 00 00 83 06 |................|
[888] 11:27:52:143: <CC 39 48 03 00 00 00 00 00 00 00 00 00 00 00 00 |.9H.............|
[888] 11:27:52:143:
[888] 11:27:52:143: InsertInTimerQ called portid=10,Id=8,Protocol=8021,EventType=0,fAuth=0
[712] 11:27:52:233: Packet received (12 bytes) for hPort 5
[888] 11:27:52:233: >PPP packet received at 01/14/2005 17:27:52:233
[888] 11:27:52:233: >Protocol = IPCP, Type = Configure-Reject, Length = 0xc, Id = 0x8, Port = 5
[888] 11:27:52:243: >80 21 04 08 00 0A 82 06 00 00 00 00 00 00 00 00 |.!..............|
[888] 11:27:52:243:
[888] 11:27:52:243: RemoveFromTimerQ called portid=10,Id=8,Protocol=8021,EventType=0,fAuth=0
[888] 11:27:52:243: <PPP packet sent at 01/14/2005 17:27:52:243
[888] 11:27:52:243: <Protocol = IPCP, Type = Configure-Req, Length = 0x1e, Id = 0x9, Port = 5
[888] 11:27:52:243: <80 21 01 09 00 1C 02 06 00 2D 0F 01 03 06 00 00 |.!.......-......|
[888] 11:27:52:243: <00 00 81 06 00 00 00 00 83 06 CC 39 48 03 00 00 |...........9H...|
[888] 11:27:52:243:
[888] 11:27:52:243: InsertInTimerQ called portid=10,Id=9,Protocol=8021,EventType=0,fAuth=0
[712] 11:27:52:333: Packet received (18 bytes) for hPort 5
[888] 11:27:52:333: >PPP packet received at 01/14/2005 17:27:52:333
[888] 11:27:52:333: >Protocol = IPCP, Type = Configure-Nak, Length = 0x12, Id = 0x9, Port = 5
[888] 11:27:52:333: >80 21 03 09 00 10 03 06 CF 47 16 09 81 06 CC 39 |.!.......G.....9|
[888] 11:27:52:333: >48 02 00 00 00 00 00 00 00 00 00 00 00 00 00 00 |H...............|
[888] 11:27:52:333:
[888] 11:27:52:333: RemoveFromTimerQ called portid=10,Id=9,Protocol=8021,EventType=0,fAuth=0
[888] 11:27:52:333: <PPP packet sent at 01/14/2005 17:27:52:333
[888] 11:27:52:333: <Protocol = IPCP, Type = Configure-Req, Length = 0x1e, Id = 0xa, Port = 5
[888] 11:27:52:333: <80 21 01 0A 00 1C 02 06 00 2D 0F 01 03 06 CF 47 |.!.......-.....G|
[888] 11:27:52:333: <16 09 81 06 CC 39 48 02 83 06 CC 39 48 03 00 00 |.....9H....9H...|
[888] 11:27:52:333:
[888] 11:27:52:333: InsertInTimerQ called portid=10,Id=10,Protocol=8021,EventType=0,fAuth=0
[712] 11:27:52:433: Packet received (30 bytes) for hPort 5
[888] 11:27:52:433: >PPP packet received at 01/14/2005 17:27:52:433
[888] 11:27:52:433: >Protocol = IPCP, Type = Configure-Ack, Length = 0x1e, Id = 0xa, Port = 5
[888] 11:27:52:433: >80 21 02 0A 00 1C 02 06 00 2D 0F 01 03 06 CF 47 |.!.......-.....G|
[888] 11:27:52:433: >16 09 81 06 CC 39 48 02 83 06 CC 39 48 03 00 00 |.....9H....9H...|
[888] 11:27:52:433:
[888] 11:27:52:433: RemoveFromTimerQ called portid=10,Id=10,Protocol=8021,EventType=0,fAuth=0
[888] 11:27:52:433: FsmThisLayerUp called for protocol = 8021, port = 5
[888] 11:27:53:054: Notifying IPCP of projection notification
[888] 11:27:53:054: RemoveFromTimerQ called portid=10,Id=0,Protocol=0,EventType=3,fAuth=0
[888] 11:27:53:054: NotifyCaller(hPort=5, dwMsgId=4)
[888] 11:27:53:054: NotifyCaller(hPort=5, dwMsgId=0)
[888] 11:27:53:054: Inserting autodisconnect in timer q for port=5, sec=-1
[888] 11:27:53:054: RemoveFromTimerQ called portid=10,Id=0,Protocol=0,EventType=1,fAuth=0
[888] 11:27:53:054: InsertInTimerQ called portid=10,Id=0,Protocol=0,EventType=1,fAuth=0
[568] 11:30:37:180: PppStop

[568] 11:30:37:180: PPPEMSG_Stop recvd

[888] 11:30:37:491: FsmClose event received for protocol c021 on port 5
[888] 11:30:37:491: RemoveFromTimerQ called portid=10,Id=2,Protocol=c021,EventType=0,fAuth=0
[888] 11:30:37:491: FsmThisLayerDown called for protocol = c021, port = 5
[888] 11:30:37:491: FsmDown event received for protocol 80fd on port 5
[888] 11:30:37:491: RemoveFromTimerQ called portid=10,Id=5,Protocol=80fd,EventType=0,fAuth=0
[888] 11:30:37:491: FsmThisLayerStarted called for protocol = 80fd, port = 5
[888] 11:30:37:491: FsmReset called for protocol = 80fd, port = 5
[888] 11:30:37:491: FsmDown event received for protocol 8021 on port 5
[888] 11:30:37:491: RemoveFromTimerQ called portid=10,Id=10,Protocol=8021,EventType=0,fAuth=0
[888] 11:30:37:491: FsmThisLayerDown called for protocol = 8021, port = 5
[888] 11:30:37:491: FsmReset called for protocol = 8021, port = 5
[888] 11:30:37:491: RemoveFromTimerQ called portid=10,Id=5,Protocol=c023,EventType=0,fAuth=0
[888] 11:30:37:491: RemoveFromTimerQ called portid=10,Id=0,Protocol=c029,EventType=0,fAuth=0
[888] 11:30:37:491: <PPP packet sent at 01/14/2005 17:30:37:491
[888] 11:30:37:491: <Protocol = LCP, Type = Terminate-Req, Length = 0x12, Id = 0xb, Port = 5
[888] 11:30:37:491: <C0 21 05 0B 00 10 60 4D 3D AE 00 3C CD 74 00 00 |.!....`M=..<.t..|
[888] 11:30:37:491: <00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 |................|
[888] 11:30:37:491:
[888] 11:30:37:491: InsertInTimerQ called portid=10,Id=11,Protocol=c021,EventType=0,fAuth=0
[712] 11:30:37:641: Packet received (6 bytes) for hPort 5
[888] 11:30:37:641: >PPP packet received at 01/14/2005 17:30:37:641
[888] 11:30:37:641: >Protocol = LCP, Type = Terminate-Ack, Length = 0x6, Id = 0x5, Port = 5
[888] 11:30:37:641: >C0 21 06 05 00 04 00 00 00 00 00 00 00 00 00 00 |.!..............|
[888] 11:30:37:641:
[888] 11:30:37:641: Term Ack with on port 5 silently discarded. Invalid Id
[888] 11:30:39:494: Recv timeout event received for portid=10,Id=11,Protocol=c021,fAuth=0
[888] 11:30:39:494: <PPP packet sent at 01/14/2005 17:30:39:494
[888] 11:30:39:494: <Protocol = LCP, Type = Terminate-Req, Length = 0x12, Id = 0xc, Port = 5
[888] 11:30:39:494: <C0 21 05 0C 00 10 60 4D 3D AE 00 3C CD 74 00 00 |.!....`M=..<.t..|
[888] 11:30:39:494: <00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 |................|
[888] 11:30:39:494:
[888] 11:30:39:494: InsertInTimerQ called portid=10,Id=12,Protocol=c021,EventType=0,fAuth=0
[888] 11:30:42:668: Recv timeout event received for portid=10,Id=12,Protocol=c021,fAuth=0
[888] 11:30:42:668: Terminate retry exceeded
[888] 11:30:42:668: FsmThisLayerFinished called for protocol = c021, port = 5
[888] 11:30:42:668: FsmThisLayerFinished called for protocol = 80fd, port = 5: 0
[888] 11:30:42:909: FsmThisLayerFinished called for protocol = 8021, port = 5: 0
[888] 11:30:42:909: NotifyCaller(hPort=5, dwMsgId=10)
[712] 11:30:53:163: PPPEMSG_LineDown recvd, hPort=5

[888] 11:30:53:163: Line down event occurred on port 5
[888] 11:31:01:716: FsmDown event received for protocol c021 on port 5
[888] 11:31:01:726: RemoveFromTimerQ called portid=10,Id=12,Protocol=c021,EventType=0,fAuth=0
[888] 11:31:01:726: FsmReset called for protocol = c021, port = 5
[888] 11:31:01:726: RemoveFromTimerQ called portid=10,Id=0,Protocol=0,EventType=3,fAuth=0
[888] 11:31:01:726: RemoveFromTimerQ called portid=10,Id=0,Protocol=0,EventType=1,fAuth=0
[888] 11:31:01:726: RemoveFromTimerQ called portid=10,Id=0,Protocol=c029,EventType=0,fAuth=0
[888] 11:31:01:726: LcpEnd
[888] 11:31:01:726: NotifyCaller(hPort=5, dwMsgId=23)


**************************************************************************************
**************************************************************************************
Back to top
Jeroni Paul
Guest
Posted: Sat Jan 15, 2005 6:25 am    Post subject: Re: Compare PPP/Modem Logs ...? Reply with quote
I'll comment some of your results:

01-14-2005 11:27:49.459 - Data compression off or unknown.
01-14-2005 11:28:19.462 - Read: Total: 17186, Per/Sec: 570, Written: Total:
20830, Per/Sec: 691
01-14-2005 11:30:19.465 - Read: Total: 335945, Per/Sec: 2656, Written:
Total: 120302, Per/Sec: 828

This is from the bad modemlog. Every two minutes, the system logs data sent
and received. It is curious that in this instance, the last one shows more
data transferred than the first one, however it didn't take a complete 2
minute interval. Leave some minutes more to see what it says next lines
while it is in a very slow condition. You should see these numbers very low
or 0 if the modem has a problem.
What happens if you download a file? It also uses almost all bandwidth
continuously.

[888] 11:27:53:054: InsertInTimerQ called
portid=10,Id=0,Protocol=0,EventType=1,fAuth=0
[568] 11:30:37:180: PppStop

Notice that the PPP log says nothing in the interval you are connected, so
it is not useful.
Back to top
 
Post new topic   Reply to topic    DComTalk.com Forum Index -> Modems All times are GMT
Page 1 of 1

 
 You cannot post new topics in this forum
You cannot reply to topics in this forum
You cannot edit your posts in this forum
You cannot delete your posts in this forum
You cannot vote in polls in this forum




VoIP Solutions: Telephone Systems Electronics Satellite TV Tech & Gadgets
Powered by phpBB