Connection dropping 'on the hour'

[#1]

Reset. fingers crossed

[#2]

What could be the reasons for the router dropping sync with the cabinet? I have just experienced another connection being dropped although not on the hour but as is usual no issues during the daytime when I'm working from home.

[#3]

Hi @bobpullen,

Thanks for taking the time to investigate.

However I'm not sure your graph shows what i'm experiencing at home as I had a disconnection on the 10th and 11th as shown at the top of the thread. Also note that I have not had a disconnection I'm aware of (or the router logs show) since the 12th when I did a factory reset (via the GUI) on the router - i'm going to monitor this for a couple of weeks though.

Perhaps something cached on the router that shouldn't have been there?

One of the PlusNet staff that I spoke to said my router was rather old and a new design was on its way, is that right?

[#4]

---

@prosser99 wrote:

However I'm not sure your graph shows what i'm experiencing at home as I had a disconnection on the 10th and 11th as shown at the top of the thread.

The graph is missing data, which is why there's a break in the horizontal blue/purple lines.

Here's another view, showing physical sync drops on the 10th and 11th:-

I've no news to share about a newer router at the moment.

[#5]

---

@bobpullen wrote:

---

@Townman wrote:
I doubt that there will be any quick answers here. This looks like a loss of the PPP session without the loss of xDSL.

---

Not the case. @prosser99's router is dropping sync with the cabinet as can be seen below (grey bars). The PPP references in the router logs are likely a consequence of the underlying DSL connection dropping:-

---

The part of the router logs shared by the OP do not indicate that the xDSL session is down - if it was, would one expect to see that reported in the log?

If xDSL was down, does it seem logical (reasonable) that the router should none-the-less attempt to send a PPP LCP Session Termination request ... over a non-existent xDSL service?

If xDSL were down, what might make the events occur regularly on the hour as perceived by the OP?

Are there session management events which happen on a timed basis within the network which might give rise to what has been reported?  Note that I owe you a report on something I have observed happening on my service at 18:00 each day...

[#6]

---

@Townman wrote:

---

@bobpullen wrote:

---

@Townman wrote:
I doubt that there will be any quick answers here. This looks like a loss of the PPP session without the loss of xDSL.

---

Not the case. @prosser99's router is dropping sync with the cabinet as can be seen below (grey bars). The PPP references in the router logs are likely a consequence of the underlying DSL connection dropping:-

---

The part of the router logs shared by the OP do not indicate that the xDSL session is down - if it was, would one expect to see that reported in the log?

If xDSL was down, does it seem logical (reasonable) that the router should none-the-less attempt to send a PPP LCP Session Termination request ... over a non-existent xDSL service?

If xDSL were down, what might make the events occur regularly on the hour as perceived by the OP?

Are there session management events which happen on a timed basis within the network which might give rise to what has been reported?  Note that I owe you a report on something I have observed happening on my service at 18:00 each day...

---

Emphasis in bold. You're not seeing the entire story, only an excerpt. 

From the logs in message 8, here's the wider picture:-

wan            Jul 11 19:00:10 2020 (618485.680000) PPP LCP Send Termination Request [User request]
wan            Jul 11 19:00:13 2020 (618488.830000) PPPoE is down after 1376 minutes uptime [Waiting for Underlying Connection (WAN Ethernet 7 - Down)]
wan            Jul 11 19:00:13 2020 (618488.860000) PTM over DSL is down after 1377 minutes uptime
tr069          Jul 11 19:00:15 2020 (618490.980000) CWMP: Initializing transaction for event code 4 VALUE CHANGE
tr069          Jul 11 19:00:16 2020 (618491.320000) CWMP: Session start now. Event code(s): '4 VALUE CHANGE'
tr069          Jul 11 19:00:16 2020 (618491.330000) CWMP: Server URL: https://dbtpnhdm.bt.mo; Connecting as user: ACS username
tr069          Jul 11 19:00:16 2020 (618491.350000) CWMP: session closed due to error: Could not resolve host
tr069          Jul 11 19:00:46 2020 (618521.700000) CWMP: Session start now. Event code(s): '4 VALUE CHANGE'
tr069          Jul 11 19:00:46 2020 (618521.710000) CWMP: Server URL: https://dbtpnhdm.bt.mo; Connecting as user: ACS username
tr069          Jul 11 19:00:46 2020 (618521.730000) CWMP: session closed due to error: Could not resolve host
wan            Jul 11 19:03:56 2020 (618712.030000) PTM over DSL is up
wan            Jul 11 19:04:48 2020 (618763.990000) PPP LCP Send Configuration Request
wan            Jul 11 19:04:48 2020 (618764.000000) PPP LCP Receive Configuration Request
wan            Jul 11 19:04:48 2020 (618764.000000) PPP LCP Send Configuration ACK
wan            Jul 11 19:04:48 2020 (618764.000000) PPP LCP Receive Configuration Reject
wan            Jul 11 19:04:48 2020 (618764.010000) PPP LCP Send Configuration Request
wan            Jul 11 19:04:48 2020 (618764.010000) PPP LCP Receive Configuration ACK
wan            Jul 11 19:04:48 2020 (618764.020000) Starting CHAP authentication with peer
wan            Jul 11 19:04:48 2020 (618764.020000) CHAP Receive Challenge
wan            Jul 11 19:04:48 2020 (618764.070000) CHAP authentication successful
wan            Jul 11 19:04:48 2020 (618764.090000) PPPoE is up - Down Rate=39950Kbps, Up Rate=7565Kbps; SNR Margin Down=11.8dB, Up=6.0dB

The 'PTM over DSL' entries refer to the the xDSL handshake and the PPPoE entry with the sync rates is a clear indicator that sync has been lost (and subsequently regained).

And just for good measure, here are the PPP logs:-

Session Started	| Session Ended
05:03 09/Jul/2020	21:01 10/Jul/2020
01:15 07/Jul/2020	04:58 09/Jul/2020
12:36 12/Jul/2020	12:51 12/Jul/2020
12:55 12/Jul/2020	12:56 12/Jul/2020
21:23 11/Jul/2020	12:29 12/Jul/2020
20:04 11/Jul/2020	21:19 11/Jul/2020
21:03 10/Jul/2020	20:01 11/Jul/2020
12:56 12/Jul/2020	N/A

I'd question that anything is happening 'on the hour'

In terms of network activity, there is a TR069 inform at 24 hour intervals, or whenever the connection is interrupted and then restored.

[#7]

Hi,

Not sure what you mean by "I'd question that anything is happening 'on the hour'"?

Still no issues i'm aware of since the factory reset on Sunday ... will continue to monitor.

[#8]

@prosser99 the drops prior to Sunday (seen in the second column of the last set of data in my last post) are not all timestamped on the hour.

Glad to hear things are better though.

[#9]

Hi @bobpullen, I've just taken this from the WAN filter of the router event logs, searching on Termination Request to locate issues:

It looks like we had a drop last night at very nearly 01:00 (correcting for the clock).

The 12th July can be ignored as that was when I was fiddling with the router (factory reset and restarted it a couple of times).  

So over 1/2 of them are just about on the hour and the ones that we notice as it interrupts streaming a film etc certainly were.

23:57:20, 15 Jul. (302724.800000) PPP LCP Send Termination Request [User request]
*11:56:29, 12 Jul. ( 278.960000) PPP LCP Send Termination Request [User request]
*11:51:17, 12 Jul. ( 1101.690000) PPP LCP Send Termination Request [User request]
*11:28:58, 12 Jul. (677813.380000) PPP LCP Send Termination Request [User request]
20:18:27, 11 Jul. (623182.800000) PPP LCP Send Termination Request [User request]
19:00:10, 11 Jul. (618485.680000) PPP LCP Send Termination Request [User request]
20:00:21, 10 Jul. (535698.530000) PPP LCP Send Termination Request [User request]
03:57:44, 09 Jul. (391543.840000) PPP LCP Send Termination Request [User request]
00:11:48, 07 Jul. (205190.930000) PPP LCP Send Termination Request [User request]
23:59:23, 04 Jul. (31649.210000) PPP LCP Send Termination Request [User request]
21:00:00, 04 Jul. (20886.110000) PPP LCP Send Termination Request [User request]

Will continue to monitor, many thanks all.

[#10]

Anything you can think of locally in/around your house that happens around these times?

Lights being switched on/off? Heating? Other electrical equipment? 

You can see there are downstream error spikes on the line around the time the connection drops:-

[#11]

This is a very interesting graph, I don't suppose there's any way I could access this data is there, to help diagnose? Perhaps it's in the router logs and I could extract and filter it?

So your graph shows last Saturday with issues most clearly from 20:00 which coincides with our dropout while streaming a film - at exactly 20:00:10.

It would probably be too light to be putting on house lights at this point and as we were all sitting in the living room there would not have been anybody turning things on and off.

Our heating has not been on for months but the boiler will no doubt be heating water - but of course it does this every day and will be turning on at random times during day and night so doesn’t match the pattern. But I will, as a test, turn the heating on and off several times and see if the line stays up to be sure.

So no, I can’t think of anything out of the ordinary that doesn’t happen every day.

There is also nothing out of the ordinary I’m aware of nearby, outside the house. We are in a detached house too, so no neighbours the other side of the wall.

Perhaps more likely at the exchange or cabinet maybe?

[#12]

No, it not the boiler - turned on and off several times with no issues.

[#13]

My router just crashed at 21:00hrs exactly. It's happened a few times before now at that time and if Sonos is playing or we are watching BBC iPlayer we always check the time when it crashes. Our boiler is off by then so can't think what else it could be.

Is it time for a new router?

[#14]

@Fred_Scuttle

Situation on your line is quite different. On every test I can find in history of this ticket there is some interference

From most recent test:

Interference Pattern Regular Interference Observed on Week Days

Service Impact Retrains Observed

Interference Duration Longest Occurrence From00:00to00:15

Interference  Location Customer Premise

Here is graph of your connection

I have placed order to change stability option on your line, this should be completed by Wednesday. Ticket is still with our faults team so they will retest your line shortly.

Please accept apologies for this inconvenience.

[#15]

Oops. dropped again, 5 days like almost clockwork(router timestamp still 1 hour behind)

19:33:21, 18 Jul.	(358311.790000) PTM over DSL is up
19:33:15, 18 Jul.	(358305.810000) CWMP: session closed due to error: Could not resolve host
19:33:15, 18 Jul.	(358305.750000) CWMP: Server URL: https://dbtpnhdm.bt.mo; Connecting as user: ACS username
19:33:15, 18 Jul.	(358305.740000) CWMP: Session start now. Event code(s): '4 VALUE CHANGE'
19:32:45, 18 Jul.	(358275.400000) CWMP: session closed due to error: Could not resolve host
19:32:44, 18 Jul.	(358275.340000) CWMP: Server URL: https://dbtpnhdm.bt.mo; Connecting as user: ACS username
19:32:44, 18 Jul.	(358275.330000) CWMP: Session start now. Event code(s): '4 VALUE CHANGE'
19:32:44, 18 Jul.	(358274.990000) CWMP: Initializing transaction for event code 4 VALUE CHANGE
19:32:42, 18 Jul.	(358272.470000) PTM over DSL is down after 5969 minutes uptime
19:32:42, 18 Jul.	(358272.470000) PPPoE is down after 5968 minutes uptime [Waiting for Underlying Connection (WAN Ethernet 7 -​ Down)]
19:32:39, 18 Jul.	(358269.550000) PPP LCP Send Termination Request [User request]