[RESOLVED] internet connection problem, ppp log

[wengang]

Hi all.
A couple of days ago my PC started dropping off line by itself for no reason. Before it does, it stops downloading anything, stops loading pages in IE. Then after a while of inactivity, it disconnects. And although I have it set to automatically redial when the line drops, it doesn't. It's a new problem and I have no experience with this.

I'm on Win XP. My connection is an ADSL modem (D-Link) with username and password. I've had it for a couple of years and it has been reliable. The cut off times are not regular, sometimes in just a short while, like maybe half-hour, other times as long as 6 hours (that is the longest I've been able to stay online at one time since it started).

I look at the system event log, but usually it shows nothing happening anywhere in the neighborhood of the time that it goes offline.
But last night when it went offline, there were a few messages leading up to the cut-off, all from source TCPIP:
TCP/IP has reached the security limit imposed on the number of concurrent TCP connect attempts.
I got that message sporadically from 15 minutes to an hour apart leading up to the disconnect. Then at the time it goes offline, just the usual simple message:
The connection to ADSL made by user 100045435443 using device PPPoE4-0 was disconnected.

I read on a couple of sites that I should start a PPP log to track the problem. So I did that. And it is basically sending out packets and checking responses constantly. But beyond that, I don't really know how to read it for helpful information. So I'm posting the the last while before it crashed. If you have experience with this, please let me know if it contains anything that could help me solve the problem:
The section below repeats constantly all night

[160] 03:47:20:125: Packet received (10 bytes) for hPort 5
[396] 03:47:20:125: >PPP packet received at 10/05/2005 19:47:20:125
[396] 03:47:20:125: >Protocol = LCP, Type = Echo-Request, Length = 0xa, Id = 0x50, Port = 5
[396] 03:47:20:125: >C0 21 09 50 00 08 5B 69 40 58 00 00 00 00 00 00 |.!.P..[i@X......|
[396] 03:47:20:125:
[396] 03:47:20:125: <PPP packet sent at 10/05/2005 19:47:20:125
[396] 03:47:20:125: <Protocol = LCP, Type = Echo-Reply, Length = 0xa, Id = 0x50, Port = 5
[396] 03:47:20:125: <C0 21 0A 50 00 08 56 81 37 10 00 00 00 00 00 00 |.!.P..V.7.......|
[396] 03:47:20:125:

Then the next section comes from the point 7 minutes before drop, where my system event log shows that last TCPIP limit error message (above) and up to the final message, where it goes offline:

[160] 03:49:45:203: Packet received (10 bytes) for hPort 5
[396] 03:49:45:203: >PPP packet received at 10/05/2005 19:49:45:203
[396] 03:49:45:203: >Protocol = LCP, Type = Echo-Request, Length = 0xa, Id = 0x53, Port = 5
[396] 03:49:45:203: >C0 21 09 53 00 08 5B 69 40 58 00 00 00 00 00 00 |.!.S..[i@X......|
[396] 03:49:45:203:
[396] 03:49:45:203: <PPP packet sent at 10/05/2005 19:49:45:203
[396] 03:49:45:203: <Protocol = LCP, Type = Echo-Reply, Length = 0xa, Id = 0x53, Port = 5
[396] 03:49:45:203: <C0 21 0A 53 00 08 56 81 37 10 00 00 00 00 00 00 |.!.S..V.7.......|
[396] 03:49:45:203:
[396] 03:54:45:156: Time to check Cps for Activity for port 5
[396] 03:54:45:156: Port 5 inactive for 253 seconds
[396] 03:54:45:156: InsertInTimerQ called portid=0,Id=0,Protocol=0,EventType=7,fAuth=0
[396] 03:55:33:156: Time to check Cps for Activity for port 5
[396] 03:55:33:156: Port 5 inactive for 301 seconds
[396] 03:55:33:156: <PPP packet sent at 10/05/2005 19:55:33:156
[396] 03:55:33:156: <Protocol = LCP, Type = Echo-Request, Length = 0x16, Id = 0xa, Port = 5
[396] 03:55:33:156: <C0 21 09 0A 00 14 56 81 37 10 39 34 61 65 39 30 |.!....V.7.94ae90|
[396] 03:55:33:156: <63 63 33 35 33 31 00 00 00 00 00 00 00 00 00 00 |cc3531..........|
[396] 03:55:33:156:
[396] 03:55:33:156: InsertInTimerQ called portid=0,Id=0,Protocol=0,EventType=7,fAuth=0
[396] 03:56:34:156: Time to check Cps for Activity for port 5
[396] 03:56:34:156: Port 5 inactive for 362 seconds
[396] 03:56:34:156: <PPP packet sent at 10/05/2005 19:56:34:156
[396] 03:56:34:156: <Protocol = LCP, Type = Echo-Request, Length = 0x16, Id = 0xb, Port = 5
[396] 03:56:34:156: <C0 21 09 0B 00 14 56 81 37 10 39 34 61 65 39 30 |.!....V.7.94ae90|
[396] 03:56:34:156: <63 63 33 35 33 31 00 00 00 00 00 00 00 00 00 00 |cc3531..........|
[396] 03:56:34:156:
[396] 03:56:34:156: InsertInTimerQ called portid=0,Id=0,Protocol=0,EventType=7,fAuth=0
[396] 03:57:35:156: Time to check Cps for Activity for port 5
[396] 03:57:35:156: Port 5 inactive for 423 seconds
[396] 03:57:35:156: <PPP packet sent at 10/05/2005 19:57:35:156
[396] 03:57:35:156: <Protocol = LCP, Type = Echo-Request, Length = 0x16, Id = 0xc, Port = 5
[396] 03:57:35:156: <C0 21 09 0C 00 14 56 81 37 10 39 34 61 65 39 30 |.!....V.7.94ae90|
[396] 03:57:35:156: <63 63 33 35 33 31 00 00 00 00 00 00 00 00 00 00 |cc3531..........|
[396] 03:57:35:156:
[396] 03:57:35:156: InsertInTimerQ called portid=0,Id=0,Protocol=0,EventType=7,fAuth=0
[396] 03:58:36:156: Time to check Cps for Activity for port 5
[396] 03:58:36:156: Port 5 inactive for 484 seconds
[396] 03:58:36:156: Missed 3 consecutive echo responses. Disconnecting port 5 due to no echo responses.
[396] 03:58:36:156: FsmClose event received for protocol c021 on port 5
[396] 03:58:36:156: RemoveFromTimerQ called portid=0,Id=3,Protocol=c021,EventType=0,fAuth=0
[396] 03:58:36:156: FsmThisLayerDown called for protocol = c021, port = 5
[396] 03:58:36:156: FsmDown event received for protocol 80fd on port 5
[396] 03:58:36:156: RemoveFromTimerQ called portid=0,Id=6,Protocol=80fd,EventType=0,fAuth=0
[396] 03:58:36:156: FsmThisLayerStarted called for protocol = 80fd, port = 5
[396] 03:58:36:156: FsmReset called for protocol = 80fd, port = 5
[396] 03:58:36:156: FsmDown event received for protocol 8021 on port 5
[396] 03:58:36:156: RemoveFromTimerQ called portid=0,Id=9,Protocol=8021,EventType=0,fAuth=0
[396] 03:58:36:156: FsmThisLayerDown called for protocol = 8021, port = 5
[396] 03:58:36:156: FsmReset called for protocol = 8021, port = 5
[396] 03:58:36:156: RemoveFromTimerQ called portid=0,Id=0,Protocol=c023,EventType=0,fAuth=0
[396] 03:58:36:156: RemoveFromTimerQ called portid=0,Id=0,Protocol=c029,EventType=0,fAuth=0
[396] 03:58:36:156: <PPP packet sent at 10/05/2005 19:58:36:156
[396] 03:58:36:156: <Protocol = LCP, Type = Terminate-Req, Length = 0x12, Id = 0xd, Port = 5
[396] 03:58:36:156: <C0 21 05 0D 00 10 56 81 37 10 00 3C CD 74 00 00 |.!....V.7..<.t..|
[396] 03:58:36:156: <03 9E 00 00 00 00 00 00 00 00 00 00 00 00 00 00 |................|
[396] 03:58:36:156:
[396] 03:58:36:156: InsertInTimerQ called portid=0,Id=13,Protocol=c021,EventType=0,fAuth=0
[396] 03:58:38:156: Recv timeout event received for portid=0,Id=13,Protocol=c021,fAuth=0
[396] 03:58:38:156: <PPP packet sent at 10/05/2005 19:58:38:156
[396] 03:58:38:156: <Protocol = LCP, Type = Terminate-Req, Length = 0x12, Id = 0xe, Port = 5
[396] 03:58:38:156: <C0 21 05 0E 00 10 56 81 37 10 00 3C CD 74 00 00 |.!....V.7..<.t..|
[396] 03:58:38:156: <03 9E 00 00 00 00 00 00 00 00 00 00 00 00 00 00 |................|
[396] 03:58:38:156:
[396] 03:58:38:156: InsertInTimerQ called portid=0,Id=14,Protocol=c021,EventType=0,fAuth=0
[396] 03:58:40:156: Recv timeout event received for portid=0,Id=14,Protocol=c021,fAuth=0
[396] 03:58:40:156: Terminate retry exceeded
[396] 03:58:40:156: FsmThisLayerFinished called for protocol = c021, port = 5
[396] 03:58:40:156: FsmThisLayerFinished called for protocol = 80fd, port = 5: 0
[396] 03:58:40:203: FsmThisLayerFinished called for protocol = 8021, port = 5: 0
[396] 03:58:40:203: NotifyCaller(hPort=5, dwMsgId=10)
[160] 03:58:40:281: PPPEMSG_LineDown recvd, hPort=5

[396] 03:58:40:281: Line down event occurred on port 5
[396] 03:58:40:296: FsmDown event received for protocol c021 on port 5
[396] 03:58:40:296: RemoveFromTimerQ called portid=0,Id=14,Protocol=c021,EventType=0,fAuth=0
[396] 03:58:40:296: FsmReset called for protocol = c021, port = 5
[396] 03:58:40:296: RemoveFromTimerQ called portid=0,Id=0,Protocol=0,EventType=3,fAuth=0
[396] 03:58:40:296: RemoveFromTimerQ called portid=0,Id=0,Protocol=0,EventType=7,fAuth=0
[396] 03:58:40:296: RemoveFromTimerQ called portid=0,Id=0,Protocol=0,EventType=2,fAuth=0
[396] 03:58:40:296: RemoveFromTimerQ called portid=0,Id=0,Protocol=0,EventType=1,fAuth=0
[396] 03:58:40:296: RemoveFromTimerQ called portid=0,Id=0,Protocol=c029,EventType=0,fAuth=0
[396] 03:58:40:296: LcpEnd
[396] 03:58:40:296: Post line down event occurred on port 5
[396] 03:58:40:296: NotifyCaller(hPort=5, dwMsgId=23)

Please let me know if you can interpret the above or if you have any ideas. This msg is too long, so I'm attaching the rest on a txt file.

{text file contents here}

and again, I don't know how to read any of this, so I can't get much out of it.

OK. that's all i have on this.

Anybody?
thanks
Wengang

[dglienna]

I've gotten that error before, but think that it started with instaling SKYPE. It uses your internet connection for other calls, even when after you shut it down.
It could be a virus also, but I'd check that first.

[wengang]

I have a copy of SKYPE at my office but never installed it at home, where the problem is. Maybe another such program. The only thing I installed this week was Google Earth, trial version.

For the moment, I restored my PC back to last week. I'm currently 2.5 hours into my connection (with fingers crossed).

[wengang]

ok.
i haven't really solved it, but the restore appears to have worked. I'm now at 10 hours uninterrupted connection.

thanks all.

[StrangerInBeijing]

Sounds like a problem I had too. Until my gf was clever enough to restart the adsl modem and spend the next two days laughing her @r$e of at me.

[wengang]

my modem doesn't even have any switches. just an in cable out cable and power cable. resetting it is not fixing the problem.
Something else is doing this.
I can restore the pc to any previous restore point before last week and it will be fine again for a day or two. Then it will start again.
my first suspect was windows auto update. since the first time i noticed this problem was just after an autoupdate forced a restart of the pc. So when I restored the pc back before the update, I turned off auto-update. but like i said it happened again anyway. Some sort of virus or spyware maybe that got downloaded and hadn't been activated. Then after the rollback the files are still there, just not active until some kind of behavior executes them. In that case, it would recur no matter what until located and removed.
otherwise, the modem may just be getting old, but then can't see why it straightens out after a restore.
doesn't matter.
as i said in the other thread, I've written an app now to babysit the connection.