Kitz Forum

Broadband Related => FTTC and FTTP Issues => Topic started by: markg33 on October 12, 2015, 09:39:51 PM

Title: BT HH5A losing PPPoE but DSL stays up.
Post by: markg33 on October 12, 2015, 09:39:51 PM
I posted this on the BT forum about this issue.

Basically the HH5 loses the PPPoE connection but the DSL stays up.

The HH5 will display an orange power light but there will be no orange broadband light - Neither flashing or static.

The weird thing is when I try to go to a website there will be a page pop up say - It appears your Home Hub is having a problem connecting to the internet and the broadband light is flashing. Or something along those lines. I follow the page where it asks if I am using DSL or WAN. I choose DSL, Then the next page says it is attempting to reconnect the broadband and the PPPoE is up and running again.

I am on Infinity 2 by the way. I noticed my noise margin dropping too and my maximum data rate getting slower. Also my line attenuation seems to go up or down. I think it is because I have been resetting the HH5 after I get everything working again.

Here is my post on the BT forum as I posted links to different ISPs having similar issues over the years and the like. The latest one was from Zen on September 23rd, my issue first happened on September 25th -

https://community.bt.com/t5/BT-Infinity-Speed-Connection/PPPoE-Keeps-getting-lost/td-p/1544797 (https://community.bt.com/t5/BT-Infinity-Speed-Connection/PPPoE-Keeps-getting-lost/td-p/1544797)

I have very limited knowledge on this particular issue but all I know is it is not right. From my little research it seems this points to BTs side. Or perhaps my HH5 is at fault. My data rate on the HH5 still stays at 20000/79995 despite all of this happening.

This was copied from my HH5 event logs/from my thread on the BT forum. I got this exact same message on the 25th. -

17:26:56, 12 Oct.   (19425.560000) PPPoE is down after 322 minutes uptime [Disabled] <<WHY DOES THIS ALWAYS GET DISABLED?
17:26:52, 12 Oct.   (19421.110000) PPP LCP Send Termination Request [User request]

Help would be appreciated,
Thanks.
Mark.
Title: Re: BT HH5A losing PPPoE but DSL stays up.
Post by: Dray on October 12, 2015, 09:52:34 PM
You can rule out the HH5 by using a modem with another router instead, if you have one.

Have you tried a factory reset of the HH5?
Title: Re: BT HH5A losing PPPoE but DSL stays up.
Post by: markg33 on October 12, 2015, 10:21:25 PM
I unfortunately do not have another router to try just the HH5 itself.

I did try my Openreach ECI modem with the HH5 but the HH5 still stayed orange even when restarting the Hub. But all the lights on the modem were green and operational.

I did not try a factory reset yet. I do not have a pin or pen to press into the recess button on the back. Looking through the HH5 manager it says I can factory reset it via this. Would it work doing it through that?

Title: Re: BT HH5A losing PPPoE but DSL stays up.
Post by: burakkucat on October 12, 2015, 10:22:12 PM
Welcome to the Kitz forum.

This was copied from my HH5 event logs/from my thread on the BT forum. I got this exact same message on the 25th. -

17:26:56, 12 Oct.   (19425.560000) PPPoE is down after 322 minutes uptime [Disabled] <<WHY DOES THIS ALWAYS GET DISABLED?
17:26:52, 12 Oct.   (19421.110000) PPP LCP Send Termination Request [User request]

Looking at those two lines we see that there is a link control protocol (LCP) termination request sent by the modem/router (logged at 17:26:52) and four seconds later (at 17:26:56) we see that the PPP server takes down the current PPPoE session as a direct result of the prior LCP termination request.

I performed a quick Google search of the Kitz site and came up with this list (https://www.google.com/search?q=LCP+site%3Akitz.co.uk&ie=utf-8&oe=utf-8). Of all the entries in that list, this one (http://forum.kitz.co.uk/index.php?topic=14457.55;wap2) matches what you have observed. (And I see that a certain old black cat even posted to that thread!  ::)  ) Here is the opening post of the thread (http://forum.kitz.co.uk/index.php/topic,14457.0.html) and here is the actual post (http://forum.kitz.co.uk/index.php/topic,14457.msg271366.html#msg271366) found by the above Google search. Please have read through that thread and see if it helps . . .  :-\
Title: Re: BT HH5A losing PPPoE but DSL stays up.
Post by: burakkucat on October 12, 2015, 10:30:26 PM
I did not try a factory reset yet. I do not have a pin or pen to press into the recess button on the back. Looking through the HH5 manager it says I can factory reset it via this. Would it work doing it through that?

Remove the patch cable that connects the HH5 to the line (xDSL port to the filter (centralised or micro)) and use an opened up paper clip or something similar to press and hold the recessed reset button for, at least, ten seconds. All the LEDs should go out / come on / flash / etc. Wait a few minutes and then reconnect the HH5 to the line by reinserting the patch cable.

I strongly suspect that your problem is being caused by the HH5.  :-X
Title: Re: BT HH5A losing PPPoE but DSL stays up.
Post by: markg33 on October 12, 2015, 10:30:46 PM
Thank you very much also for the reply.

I am just very confused on this matter, I am such a newbie on why this is happening. I decided to use kitz for advice as I find on the BT forum there is not very useful replies. I usually get ignored for whatever reason.

But I will have a look at this thank you. I just cannot figure out why my PPPoE gets disabled and never comes back until I use that page that pops up.  ???

I will try this also with the HH5 and see if that helps. Again thank you. I do have a feeling it is the HH5 itself.
Title: Re: BT HH5A losing PPPoE but DSL stays up.
Post by: burakkucat on October 12, 2015, 10:37:43 PM
I just cannot figure out why my PPPoE gets disabled and never comes back until I use that page that pops up.  ???

The PPPoE session is taken down by the server, "at the other end of the link", as a result of an instruction (the LCP termination request) being sent to the server by the client (the HH5) "at your end of the link".

Quote
I do have a feeling it is the HH5 itself.

That is also my conclusion.  :(
Title: Re: BT HH5A losing PPPoE but DSL stays up.
Post by: markg33 on October 12, 2015, 10:44:17 PM
I understand how this works now, thanks for the explanation.

I wish I could buy a more reliable router or VDSL2 compatible one but financially I am not in the luxurious position to buy anything.

I will do all this when all the folks are asleep in bed, I suffer from insomnia so any oddities I experience first hand.

I may try connecting the HH5 to my ECI modem in future if it continues. Or try getting a new HH5 sent out to me. :)

Title: Re: BT HH5A losing PPPoE but DSL stays up.
Post by: markg33 on October 13, 2015, 12:18:38 AM
I did not try a factory reset yet. I do not have a pin or pen to press into the recess button on the back. Looking through the HH5 manager it says I can factory reset it via this. Would it work doing it through that?

Remove the patch cable that connects the HH5 to the line (xDSL port to the filter (centralised or micro)) and use an opened up paper clip or something similar to press and hold the recessed reset button for, at least, ten seconds. All the LEDs should go out / come on / flash / etc. Wait a few minutes and then reconnect the HH5 to the line by reinserting the patch cable.

I strongly suspect that your problem is being caused by the HH5.  :-X

I hope I did this correctly - I removed the dsl cable from the back of the Hub, and obviously it light up orange with a flashing red b light. I found a pen and pushed it in the recess button until it turned green indicating it was doing the factory reset.
And I waited until it eventually went orange again with the flashing red b indicating it was complete. So I put the dsl cable back into the Hub.
I noticed it was much faster this time around connecting and getting the blue power light. Hopefully that is a good sign already.

Also I did this without turning off or powering down the Hub first. You do not mention needing to do this so I assume I did it right with it all powered on with what I did above.

I guess the next step will be to monitor this now.

I should have mentioned I am in contact with a BT moderator from the BT forum, do you think it would be worth mentioning this to him?

Anyway time to pass the time with my insomnia wonderful lol.  ::)

HH5 stats -

Code: [Select]
1. Product name: BT Home Hub
2. Serial number: +068343+NQ42338353
3. Firmware version: Software version 4.7.5.1.83.8.204.1.11 (Type A) Last updated 04/07/15
4. Board version: BT Hub 5A
5. DSL uptime: 0 days, 00:51:52
6. Data rate: 20000 / 79995
7. Maximum data rate: 32837 / 99370
8. Noise margin: 15.2 / 11.0
9. Line attenuation: 7.2 / 10.6
10. Signal attenuation: 7.1 / 10.6
11. Data sent/received: 3.6 MB / 151.7 MB
12. Broadband username: bthomehub@btbroadband.com

Event log after factory reset and dsl reconnected, read from bottom to top (Sorry it is a large chunk.) -

Code: [Select]
Time and date Message
00:23:39, 13 Oct. ( 2358.040000) Admin login successful by 192.168.1.70 on HTTP
00:23:22, 13 Oct. ( 2341.600000) New GUI session from IP 192.168.1.70
00:04:45, 13 Oct. ( 1224.410000) Lease for IP 192.168.1.70 issued for host User-​PC (MAC 68:a3:c4:7d:7c:dc). Lease duration: 30240 min
00:04:45, 13 Oct. ( 1224.410000) Device connected: Hostname: User-​PC IP: 192.168.1.70 MAC: 68:a3:c4:7d:7c:dc Lease time: 30240 min. Link rate: 138.1 Mbps
00:04:45, 13 Oct. ( 1224.290000) Lease requested
00:04:44, 13 Oct. ( 1222.860000) New GUI session from IP 192.168.1.70
00:04:41, 13 Oct. ( 1220.460000) Lease requested
00:04:41, 13 Oct. ath00: STA 68:a3:c4:7d:7c:dc IEEE 802.11: Client associated
00:04:37, 13 Oct. IN: BLOCK [16] Remote administration (TCP [91.236.74.164]:50681-​>[81.129.25.139]:22 on ppp3)
00:04:19, 13 Oct. ath00: STA 68:a3:c4:7d:7c:dc IEEE 802.11: Client disassociated
00:04:14, 13 Oct. ath00: STA 68:a3:c4:7d:7c:dc IEEE 802.11: Client associated
00:04:11, 13 Oct. ath00: STA 68:a3:c4:7d:7c:dc IEEE 802.11: Client disassociated
00:04:06, 13 Oct. ath00: STA 68:a3:c4:7d:7c:dc IEEE 802.11: Client associated
00:03:37, 13 Oct. ath00: STA 68:a3:c4:7d:7c:dc IEEE 802.11: Client disassociated
00:03:32, 13 Oct. ath00: STA 68:a3:c4:7d:7c:dc IEEE 802.11: Client associated
00:02:28, 13 Oct. ath00: STA 68:a3:c4:7d:7c:dc IEEE 802.11: Client disassociated
00:02:23, 13 Oct. ath00: STA 68:a3:c4:7d:7c:dc IEEE 802.11: Client associated
00:01:20, 13 Oct. ath00: STA 68:a3:c4:7d:7c:dc IEEE 802.11: Client disassociated
00:01:15, 13 Oct. ath00: STA 68:a3:c4:7d:7c:dc IEEE 802.11: Client associated
00:00:24, 13 Oct. OUT: BLOCK [7] ICMP replay (ICMP type 3 code 1 81.129.25.139-​>2.18.72.89 on ppp3)
00:00:22, 13 Oct. BLOCKED 2 more packets (because of ICMP replay)
00:00:21, 13 Oct. OUT: BLOCK [7] ICMP replay (ICMP type 3 code 1 81.129.25.139-​>2.18.72.89 on ppp3)
00:00:12, 13 Oct. ath00: STA 68:a3:c4:7d:7c:dc IEEE 802.11: Client disassociated
00:00:07, 13 Oct. ath00: STA 68:a3:c4:7d:7c:dc IEEE 802.11: Client associated
23:59:34, 12 Oct. ( 912.810000) Device disconnected: Hostname: jills IP: 192.168.1.74 MAC: 08:62:66:1d:43:13
23:59:34, 12 Oct. ( 912.810000) Wire Lan Port 4 down
23:59:03, 12 Oct. ath00: STA 68:a3:c4:7d:7c:dc IEEE 802.11: Client disassociated
23:58:58, 12 Oct. ath00: STA 68:a3:c4:7d:7c:dc IEEE 802.11: Client associated
23:58:34, 12 Oct. ( 852.810000) New GUI session from IP 192.168.1.74
23:58:33, 12 Oct. ( 851.910000) Admin login successful by 192.168.1.74 on HTTP
23:57:55, 12 Oct. ath00: STA 68:a3:c4:7d:7c:dc IEEE 802.11: Client disassociated
23:57:50, 12 Oct. ath00: STA 68:a3:c4:7d:7c:dc IEEE 802.11: Client associated
23:57:17, 12 Oct. ( 776.360000) Admin login FAILED by 192.168.1.74 on HTTP
23:56:47, 12 Oct. ath00: STA 68:a3:c4:7d:7c:dc IEEE 802.11: Client disassociated
23:56:42, 12 Oct. ath00: STA 68:a3:c4:7d:7c:dc IEEE 802.11: Client associated
23:55:38, 12 Oct. ath00: STA 68:a3:c4:7d:7c:dc IEEE 802.11: Client disassociated
23:55:33, 12 Oct. ath00: STA 68:a3:c4:7d:7c:dc IEEE 802.11: Client associated
23:54:30, 12 Oct. ath00: STA 68:a3:c4:7d:7c:dc IEEE 802.11: Client disassociated
23:54:25, 12 Oct. ath00: STA 68:a3:c4:7d:7c:dc IEEE 802.11: Client associated
23:53:37, 12 Oct. ( 556.200000) UPnP was enabled via GUI
23:53:22, 12 Oct. ath00: STA 68:a3:c4:7d:7c:dc IEEE 802.11: Client disassociated
23:53:17, 12 Oct. ath00: STA 68:a3:c4:7d:7c:dc IEEE 802.11: Client associated
23:53:01, 12 Oct. ( 520.080000) Lease for IP 192.168.1.64 issued for host android-​348811d06ebf1a5 (MAC c4:3a:be:fd:22:21). Lease duration: 1440 min
23:53:01, 12 Oct. ( 520.080000) Device connected: Hostname: android-​348811d06ebf1a5 IP: 192.168.1.64 MAC: c4:3a:be:fd:22:21 Lease time: 1440 min. Link rate: 52.8 Mbps
23:53:01, 12 Oct. ( 520.020000) Lease requested
23:52:57, 12 Oct. ( 516.150000) Lease requested
23:52:56, 12 Oct. ath00: STA c4:3a:be:fd:22:21 IEEE 802.11: Client associated
23:52:13, 12 Oct. ath00: STA 68:a3:c4:7d:7c:dc IEEE 802.11: Client disassociated
23:52:08, 12 Oct. ath00: STA 68:a3:c4:7d:7c:dc IEEE 802.11: Client associated
23:51:52, 12 Oct. ( 451.430000) WPA2 mode selected
23:51:52, 12 Oct. ( 451.430000) WPS disabled
23:51:34, 12 Oct. ( 433.090000) WiFi Down, GUI Disabled
23:51:11, 12 Oct. ( 410.240000) Wireless SSID was changed to BTHub5-​NGWK5
23:51:05, 12 Oct. ath10: STA 68:a3:c4:7d:7c:dc IEEE 802.11: Client disassociated
23:51:00, 12 Oct. ath10: STA 68:a3:c4:7d:7c:dc IEEE 802.11: Client associated
23:50:07, 12 Oct. ( 346.270000) WPA2 mode selected
23:50:04, 12 Oct. ( 343.560000) WPA2 mode selected
23:49:57, 12 Oct. ath10: STA 68:a3:c4:7d:7c:dc IEEE 802.11: Client disassociated
23:49:52, 12 Oct. ath10: STA 68:a3:c4:7d:7c:dc IEEE 802.11: Client associated
23:48:43, 12 Oct. IN: BLOCK [15] Default policy (TCP [111.248.9.187]:9814-​>[81.129.25.139]:56762 on ppp3)
23:48:48, 12 Oct. ath10: STA 68:a3:c4:7d:7c:dc IEEE 802.11: Client disassociated
23:48:43, 12 Oct. ath10: STA 68:a3:c4:7d:7c:dc IEEE 802.11: Client associated
23:48:40, 12 Oct. IN: BLOCK [15] Default policy (TCP [216.58.210.14]:443-​>[81.129.25.139]:52683 on ppp3)
23:48:29, 12 Oct. ( 248.440000) Admin login successful by 192.168.1.74 on HTTP
23:48:27, 12 Oct. BLOCKED 1 more packets (because of Packet invalid in connection)
23:48:26, 12 Oct. OUT: BLOCK [9] Packet invalid in connection (Packet not in tcp window: TCP [192.168.1.74]:52577-​>[161.69.165.58]:443 on ppp3)
23:48:25, 12 Oct. OUT: BLOCK [65] First packet is Invalid (Packet not in tcp window: TCP [192.168.1.74]:52577-​>[161.69.165.58]:443 on ppp3)
23:48:09, 12 Oct. BLOCKED 1 more packets (because of Default policy)
23:48:08, 12 Oct. OUT: BLOCK [15] Default policy (First packet in connection is not a SYN packet: TCP [192.168.1.74]:52646-​>[216.58.210.3]:443 on ppp3)
23:48:00, 12 Oct. ( 219.050000) New GUI session from IP 192.168.1.74
23:47:59, 12 Oct. BLOCKED 1 more packets (because of Default policy)
23:47:58, 12 Oct. OUT: BLOCK [15] Default policy (First packet in connection is not a SYN packet: TCP [192.168.1.74]:52626-​>[216.58.210.74]:443 on ppp3)
23:47:42, 12 Oct. ( 201.360000) Lease for IP 192.168.1.74 issued for host jills (MAC 08:62:66:1d:43:13). Lease duration: 1440 min
23:47:42, 12 Oct. ( 201.360000) Device connected: Hostname: jills IP: 192.168.1.74 MAC: 08:62:66:1d:43:13 Lease time: 1440 min. Link rate: 1000.0 Mbps
23:47:42, 12 Oct. ( 201.260000) Lease requested
23:47:40, 12 Oct. ath10: STA 68:a3:c4:7d:7c:dc IEEE 802.11: Client disassociated
23:47:35, 12 Oct. ath10: STA 68:a3:c4:7d:7c:dc IEEE 802.11: Client associated
23:47:34, 12 Oct. ( 193.120000) Host Unknown-​08-​62-​66-​1d-​43-​13 (MAC 08:62:66:1d:43:13) using IP 192.168.1.74 detected on interface eth0, port 3
23:47:33, 12 Oct. IN: BLOCK [15] Default policy (TCP [66.193.112.93]:443-​>[81.129.25.139]:47780 on ppp3)
23:47:33, 12 Oct. ( 192.050000) CWMP: session completed successfully
23:47:33, 12 Oct. ( 192.390000) Lease requested
23:47:29, 12 Oct. ( 188.540000) CWMP: HTTP authentication success from https://pbthdm.bt.mo
23:47:28, 12 Oct. ( 187.150000) CWMP: Server URL: https://pbthdm.bt.mo; Connecting as user: ACS username
23:47:28, 12 Oct. ( 187.150000) CWMP: Session start now. Event code(s): '6 CONNECTION REQUEST'
23:47:28, 12 Oct. ( 186.850000) CWMP: Initializing transaction for event code 6 CONNECTION REQUEST
23:47:28, 12 Oct. ( 187.390000) Lease requested
23:47:27, 12 Oct. IN: BLOCK [15] Default policy (TCP [66.193.112.93]:443-​>[81.129.25.139]:40186 on ppp3)
23:47:27, 12 Oct. ( 185.910000) CWMP: session completed successfully
23:47:26, 12 Oct. BLOCKED 2 more packets (because of Default policy)
23:47:26, 12 Oct. ( 185.730000) CWMP: HTTP authentication success from https://pbthdm.bt.mo
23:47:25, 12 Oct. IN: BLOCK [15] Default policy (TCP [66.193.112.93]:443-​>[81.129.25.139]:58366 on ppp3)
23:47:25, 12 Oct. ( 184.610000) CWMP: Server URL: https://pbthdm.bt.mo; Connecting as user: ACS username
23:47:25, 12 Oct. ( 184.610000) CWMP: Session start now. Event code(s): '6 CONNECTION REQUEST'
23:47:25, 12 Oct. ( 184.310000) CWMP: session completed successfully
23:47:25, 12 Oct. ( 184.620000) Wire Lan Port 4 up
23:47:24, 12 Oct. ( 183.570000) CWMP: HTTP authentication success from https://pbthdm.bt.mo
23:47:23, 12 Oct. ( 182.110000) CWMP: Initializing transaction for event code 6 CONNECTION REQUEST
23:47:23, 12 Oct. ( 182.090000) CWMP: Server URL: https://pbthdm.bt.mo; Connecting as user: ACS username
23:47:23, 12 Oct. ( 182.080000) CWMP: Session start now. Event code(s): '6 CONNECTION REQUEST'
23:47:22, 12 Oct. ( 181.790000) CWMP: Initializing transaction for event code 6 CONNECTION REQUEST
23:47:22, 12 Oct. ( 181.620000) Wire Lan Port 4 down
23:47:21, 12 Oct. IN: BLOCK [15] Default policy (TCP [66.193.112.93]:443-​>[81.129.25.139]:55068 on ppp3)
23:47:20, 12 Oct. ( 179.760000) CWMP: session completed successfully
23:47:20, 12 Oct. ( 179.570000) CWMP: HTTP authentication success from https://pbthdm.bt.mo
23:47:19, 12 Oct. IN: BLOCK [15] Default policy (TCP [66.193.112.93]:443-​>[81.129.25.139]:51800 on ppp3)
23:47:19, 12 Oct. ( 178.610000) CWMP: Server URL: https://pbthdm.bt.mo; Connecting as user: ACS username
23:47:19, 12 Oct. ( 178.600000) CWMP: Session start now. Event code(s): '6 CONNECTION REQUEST'
23:47:19, 12 Oct. ( 178.310000) CWMP: session completed successfully
23:47:16, 12 Oct. ( 175.520000) Wire Lan Port 4 up
23:47:09, 12 Oct. ( 167.900000) CWMP: Set Parameter by TR069 Success
23:47:07, 12 Oct. ( 166.540000) CWMP: Set Parameter by TR069 Success
23:47:07, 12 Oct. ( 166.340000) CWMP: HTTP authentication success from https://pbthdm.bt.mo
23:47:06, 12 Oct. ( 164.930000) CWMP: Initializing transaction for event code 6 CONNECTION REQUEST
23:47:06, 12 Oct. ( 164.920000) CWMP: Initializing transaction for event code 6 CONNECTION REQUEST
23:47:06, 12 Oct. ( 164.890000) CWMP: Server URL: https://pbthdm.bt.mo; Connecting as user: ACS username
23:47:06, 12 Oct. ( 164.890000) CWMP: Session start now. Event code(s): '6 CONNECTION REQUEST'
23:47:05, 12 Oct. ( 164.590000) CWMP: Initializing transaction for event code 6 CONNECTION REQUEST
23:47:04, 12 Oct. IN: BLOCK [15] Default policy (TCP [66.193.112.93]:443-​>[81.129.25.139]:43884 on ppp3)
23:47:04, 12 Oct. ( 162.930000) CWMP: session completed successfully
23:47:03, 12 Oct. ( 162.740000) CWMP: HTTP authentication success from https://pbthdm.bt.mo
23:47:02, 12 Oct. IN: BLOCK [15] Default policy (TCP [66.193.112.94]:443-​>[81.129.25.139]:56818 on ppp3)
23:47:02, 12 Oct. ( 160.910000) CWMP: Server URL: https://pbthdm.bt.mo; Connecting as user: ACS username
23:47:02, 12 Oct. ( 160.900000) CWMP: Session start now. Event code(s): '0 BOOTSTRAP'
23:47:01, 12 Oct. ( 160.610000) CWMP: session completed successfully
23:47:00, 12 Oct. ( 159.230000) CWMP: Initializing transaction for event code 0 BOOTSTRAP
23:47:00, 12 Oct. ( 159.100000) CWMP: Set Parameter by TR069 Success
23:47:00, 12 Oct. ( 158.850000) CWMP: HTTP authentication success from https://pbthdmw.bt.mo
23:46:58, 12 Oct. IN: BLOCK [15] Default policy (TCP [76.20.63.45]:1596-​>[81.129.25.139]:7889 on ppp3)
23:46:58, 12 Oct. ( 157.420000) CWMP: Server URL: https://pbthdmw.bt.mo; Connecting as user: Default username
23:46:58, 12 Oct. ( 157.410000) CWMP: Session start now. Event code(s): '6 CONNECTION REQUEST'
23:46:58, 12 Oct. ( 157.120000) CWMP: Initializing transaction for event code 6 CONNECTION REQUEST
23:46:57, 12 Oct. IN: BLOCK [15] Default policy (TCP [76.20.63.45]:1594-​>[81.129.25.139]:7889 on ppp3)
23:46:54, 12 Oct. IN: BLOCK [15] Default policy (TCP [66.193.112.94]:443-​>[81.129.25.139]:52525 on ppp3)
23:46:54, 12 Oct. ( 153.240000) CWMP: session completed successfully
23:46:53, 12 Oct. ( 151.840000) CWMP: Set Parameter by TR069 Success
23:46:52, 12 Oct. ( 151.580000) CWMP: HTTP authentication success from https://pbthdmw.bt.mo
23:46:37, 12 Oct. IN: BLOCK [15] Default policy (TCP [111.248.9.187]:8766-​>[81.129.25.139]:56762 on ppp3)
23:46:32, 12 Oct. ath10: STA 68:a3:c4:7d:7c:dc IEEE 802.11: Client disassociated
23:46:16, 12 Oct. ( 128.800000) NTP synchronization success!
23:46:14, 12 Oct. ath10: STA 68:a3:c4:7d:7c:dc IEEE 802.11: Client associated
23:46:13, 12 Oct. ( 125.510000) CWMP: Server URL: https://pbthdmw.bt.mo; Connecting as user: Default username
23:46:13, 12 Oct. ( 125.500000) CWMP: Session start now. Event code(s): '0 BOOTSTRAP,4 VALUE CHANGE'
23:46:12, 12 Oct. ( 125.220000) NTP synchronization start
23:46:11, 12 Oct. ( 123.790000) WAN operating mode is VDSL
23:46:09, 12 Oct. ( 122.440000) PPP IPCP Receive Configuration ACK
23:46:09, 12 Oct. ( 122.440000) PPP IPCP Send Configuration Request
23:46:09, 12 Oct. ( 122.430000) PPP IPCP Receive Configuration NAK
23:46:09, 12 Oct. ( 122.430000) PPP IPCP Send Configuration ACK
23:46:09, 12 Oct. ( 122.430000) PPP IPCP Receive Configuration Request
23:46:09, 12 Oct. ( 122.430000) PPP IPCP Send Configuration Request
23:46:08, 12 Oct. ( 121.240000) PPPoE is up -​ Down Rate=79995000Kbps, Up Rate=20000000Kbps; SNR Margin Down=11.1dB, Up=15.2dB
23:46:08, 12 Oct. ( 121.220000) CHAP authentication successful
23:46:08, 12 Oct. ( 121.070000) CHAP Receive Challenge
23:46:08, 12 Oct. ( 121.070000) Starting CHAP authentication with peer
23:46:08, 12 Oct. ( 121.070000) PPP LCP Receive Configuration ACK
23:46:08, 12 Oct. ( 121.060000) PPP LCP Send Configuration Request
23:46:08, 12 Oct. ( 121.060000) PPP LCP Receive Configuration Reject
23:46:08, 12 Oct. ( 121.060000) PPP LCP Send Configuration ACK
23:46:08, 12 Oct. ( 121.060000) PPP LCP Receive Configuration Request
23:46:08, 12 Oct. ( 121.060000) PPP LCP Send Configuration Request
23:46:06, 12 Oct. OUT: BLOCK [15] Default policy (ICMP Packet is not a request packet: ICMPv6 type 143 code 0 fe80:0000:0000:0000:42f2:01ff:fe54:dc2b-​>ff02:0000:0000:0000:0000:0000:0000:0016 on ptm0)
23:45:59, 12 Oct. BLOCKED 1 more packets (because of Default policy)
23:45:59, 12 Oct. OUT: BLOCK [15] Default policy (ICMP Packet is not a request packet: ICMPv6 type 143 code 0 fe80:0000:0000:0000:42f2:01ff:fe54:dc2b-​>ff02:0000:0000:0000:0000:0000:0000:0016 on ptm0)
23:45:56, 12 Oct. ( 109.280000) PTM over DSL is up
23:45:41, 12 Oct. ( 94.340000) CWMP: Initializing transaction for event code 4 VALUE CHANGE
23:45:36, 12 Oct. ( 88.660000) CWMP: session closed due to error: No response
23:45:36, 12 Oct. ( 88.640000) CWMP: Server URL: https://pbthdmw.bt.mo; Connecting as user: Default username
23:45:36, 12 Oct. ( 88.640000) CWMP: Session start now. Event code(s): '0 BOOTSTRAP,4 VALUE CHANGE'
23:45:09, 12 Oct. ath10: STA 68:a3:c4:7d:7c:dc IEEE 802.11: Client disassociated
23:45:05, 12 Oct. ( 57.710000) CWMP: session closed due to error: No response
23:45:05, 12 Oct. ath10: STA 68:a3:c4:7d:7c:dc IEEE 802.11: Client associated
23:45:00, 12 Oct. ( 52.950000) Reset button pressed
23:44:57, 12 Oct. STP Alert: Port eth0 leaving blocking state.
23:44:52, 12 Oct. ( 45.030000) CWMP: Server URL: https://pbthdmw.bt.mo; Connecting as user: Default username
23:44:52, 12 Oct. ( 45.020000) CWMP: Session start now. Event code(s): '0 BOOTSTRAP,4 VALUE CHANGE'
23:44:52, 12 Oct. ( 44.680000) CWMP: Initializing transaction for event code 0 BOOTSTRAP
23:44:47, 12 Oct. ( 40.230000) WiFi auto selected channel 48
23:44:47, 12 Oct. ( 40.230000) 36-​93::40-​92::44-​92::48-​92::52-​92::56-​92::60-​91::64-​91::100-​93::104-​93::108-​94::112-​95::116-​94::120-​94::124-​95::128-​96
23:44:47, 12 Oct. ( 40.220000) 5 GHz Wireless: Rescan, Reason: 'Power-​up'
23:44:47, 12 Oct. ( 40.220000) WiFi auto selected channel 1
23:44:47, 12 Oct. ( 40.220000) 1-​95::2-​95::3-​94::4-​93::5-​94::6-​94::7-​96::8-​95::9-​95::10-​96::11-​96::12-​96::13-​97
23:44:47, 12 Oct. ( 40.220000) 2.4 GHz Wireless: Rescan, Reason: 'Power-​up'
23:44:46, 12 Oct. ( 38.680000) WAN Auto-​sensing running.
23:44:42, 12 Oct. ( 34.560000) System up, firmware version: 4.7.5.1.83.8.204.1.11 (Type A)
23:44:33, 12 Oct. ( 25.710000) WPA2 mode selected
23:44:33, 12 Oct. ( 25.710000) WPS enabled
23:44:31, 12 Oct. ( 23.650000) WPA2 mode selected
23:44:31, 12 Oct. ( 23.640000) WPS enabled
23:44:22, 12 Oct. ( 14.690000) System start
23:43:55, 12 Oct. (19562.310000) The system is going DOWN for reboot.

[Moderator edited to correct the broken formatting code.]
Title: Re: BT HH5A losing PPPoE but DSL stays up.
Post by: burakkucat on October 13, 2015, 01:08:42 AM
I hope I did this correctly - I removed the dsl cable from the back of the Hub, and obviously it light up orange with a flashing red b light. I found a pen and pushed it in the recess button until it turned green indicating it was doing the factory reset.
And I waited until it eventually went orange again with the flashing red b indicating it was complete. So I put the dsl cable back into the Hub.
I noticed it was much faster this time around connecting and getting the blue power light. Hopefully that is a good sign already.

Also I did this without turning off or powering down the Hub first. You do not mention needing to do this so I assume I did it right with it all powered on with what I did above.

That was just "purrfect".  ;)  You assumed correctly and performed the task exactly as I would have done.

Quote
I guess the next step will be to monitor this now.

Yes, precisely.

Quote
I should have mentioned I am in contact with a BT moderator from the BT forum, do you think it would be worth mentioning this to him?

Most definitely. I would suggest that you also provide a link to this thread (which is http://forum.kitz.co.uk/index.php/topic,16308.0.html).

I have quickly looked through the logs that you provided and did not notice anything untoward. At present it all looks good. I'm sure other Kitizens will also be taking a look and if anything seems suspicious they will comment.
Title: Re: BT HH5A losing PPPoE but DSL stays up.
Post by: markg33 on October 13, 2015, 01:18:16 AM
Thank you very much burakkucat for being patient with me. You seem very supportive especially with someone like me who is learning the ins and outs about these things.

I am glad I followed your instructions correctly.  ;D

So I will keep an eye on it now, good thing I do not really sleep as I can see if it goes well through the night lol.

Also I shall link the moderator from BT to this forum and perhaps me and him and perhaps other parts of BT can learn from this oddity I have experienced. ;)

Good to see everything is looking good thus far, stats wise and from the event log - Fingers crossed!

If you are still around and awake, what does a factory reset do exactly? From my understanding it puts everything back into its original state on the Hub side. I guess this will have some bearing on the other side of things such as the Infinity cabinet, exchange and the like.
Title: Re: BT HH5A losing PPPoE but DSL stays up.
Post by: burakkucat on October 13, 2015, 01:44:24 AM
If you are still around and awake,

Just about to depart for the sleepy-spot.

Quote
what does a factory reset do exactly? From my understanding it put everything back into its original state on the Hub side.

Yes, correct. The BT HH5, just like all other modem/routers, contains an embedded computer. All modern day computers use an operating system and that operating system needs to be configured to do the appropriate tasks. The software and configuration code exists in an entity termed the firmware. On the HH5, the firmware can be remotely upgraded by the BT systems "pushing" newer firmware onto the device. Those persons who are well experienced with upgrading the firmware of modem/routers will have a "feeling" for when a factory reset may be beneficial. In your case, I suspect that newer firmware image has been "pushed" onto the HH5 and a factory reset will ensure that it operates exactly as designed. Think of it as a "just in case" action.

Quote
I guess this will have some bearing on the other side of things such as the Infinity cabinet, exchange and like.

In the broadest terms, yes. The modem part of the HH5 communicates with the equipment in the green street-cabinet. The router part of the HH5 establishes the higher level protocols with remote servers . . . one such protocol is the point to point protocol over Ethernet (PPPoE). And it was PPPoE which was being terminated as a result of the HH5 sending a link control protocol (LCP) termination request.
Title: Re: BT HH5A losing PPPoE but DSL stays up.
Post by: markg33 on October 13, 2015, 02:02:18 AM
Brilliant a very big thank you for putting things in such an easy to understand perspective!  :D

I guess that is why it looked like the HH5 connected up faster this time around after following your instructions.

I shall leave you be for now as some can actually get sleep, unlike me.  ::)

Once you are up and about later or maybe another member could help me identify what cabinet I am on. I know the HH5 firmware .11 supports G.INP but I am not sure if my cabinet is Huawei or ECI.

I know there is a website where you can find out which cabinet you are connected on.
All I know is I am on cabinet 18 but do not know if it is an ECI or Huawei cabinet, I never pass it despite being close to it somewhere lol.

Anyway take care for now.  :)

Title: Re: BT HH5A losing PPPoE but DSL stays up.
Post by: Dray on October 13, 2015, 08:19:07 AM
I think you're on an ECI cabinet, given the speed you're getting on the HH5A. But it's very easy to find out either by looking up your exchange here https://www.telecom-tariffs.co.uk/codelook.htm or just by confirming your exchange or locality or postcode and I'll look it up for you.
Detailed instructions here http://www.kitz.co.uk/adsl/cabinet-lookup.htm
Title: Re: BT HH5A losing PPPoE but DSL stays up.
Post by: markg33 on October 13, 2015, 10:00:54 AM
I think I may be doing something wrong as it will not show a vendor I am on which is odd.

I looked up on SamKnows and I am connected to the NESU exchange. Cabinet 18 as I previously stated. I hope that is enough to go by. :)

Hopefully you have better luck than me Dray.
Title: Re: BT HH5A losing PPPoE but DSL stays up.
Post by: Dray on October 13, 2015, 10:11:48 AM
Yes, that's an ECI cab so no G.INP
Title: Re: BT HH5A losing PPPoE but DSL stays up.
Post by: markg33 on October 13, 2015, 10:24:55 AM
That is not good is it?

I have seen the Huawei vs ECI thing on many forums. Well at least the HH5A pretty much matches the cabinet. I know equipment matching with the cabinet is not a big thing anymore but as the HH5A is my only choice I guess it is better. Just guessing.

Thank you for confirming this for me Dray, for whatever reason I feel disappointed that it is ECI.  :-\

At the other place I lived it was Huawei and I was in the first trial for G.INP or the MK1 phase as it is called. I saw a speed increase and lower pings but I was on Infinity 1 then as I could not get Infinity 2 speeds.

So here I get max Infinity 2 speeds but no G.INP because ECI is not too good.  :P

Anyhow sorry for going off track about my original post about the PPPoE. I am still keeping an eye on it. Everything has been up for 10+ hours now since the factory reset.

Title: Re: BT HH5A losing PPPoE but DSL stays up.
Post by: Dray on October 13, 2015, 10:41:55 AM
I remember you had some line issues at your last place, plus some equipment problems and I sent one or two PMs to the mods to try and persuade them to give you a new device.

You connection speeds look fine, as you say your HH5A matches the ECI cabinet so you will probably be on fastpath if you don't have too many errors or disconnections on your line.

If you were on a Huawei cab with a matching modem you would probably have G.INP on your downstream as I think it's unlikely to get fastpath if G.INP is available. Of course since Openreach changed to G.INP mk2, it's rare to get G.INP on the upstream and more likely to get fastpath.

I don't think the HH5A supports G.INP on Huawei.
Title: Re: BT HH5A losing PPPoE but DSL stays up.
Post by: markg33 on October 13, 2015, 11:28:21 AM
I did have line issues yes at my last place and also equipment problems. It was such a farce!

You tried to do that? :)
Wow well thanks a lot for trying - Small world isn't it?  ;D

I think I may be on fastpath due to the fact I never get any latency higher than 20ms even on the weekends or peak time. Even my wireless displays excellent results on wireless N.

Just a comparison. In my last place I could not use the HH5 by itself for more than 2-3 days max and then it would reboot. So I needed my ECI modem for stability, which held up for 14 days then rebooted.

In the place I live now it seems the HH5 is fit for use (Apart from the PPPoE oddities of course.) - It was up for 8 days until the 25th September when the first PPPoE issue started. Then yesterday it happened twice.

It seems thus far the factory reset has made the Hub a bit more responsive. Still keeping my eye on it.  ;)

I suffered from the slower speeds and higher latency then when G.INP was introduced nationwide. But when I was put in the trial my speeds came back with even better upload and lower latency. I for some reason seen a better result using ECI stuff.

I think the HH5A does support it just when the firmware .11 was released it was after the MK2 phase so the full potential of the firmware was not utilised, which is a shame.

Stats from the Hub -
1. Product name:   BT Home Hub
2. Serial number:   +068343+NQ42338353
3. Firmware version:   Software version 4.7.5.1.83.8.204.1.11 (Type A) Last updated 04/07/15
4. Board version:   BT Hub 5A
5. DSL uptime:   0 days, 12:05:28
6. Data rate:   20000 / 79995
7. Maximum data rate:   32847 / 99326
8. Noise margin:   15.2 / 11.0
9. Line attenuation:   7.2 / 10.6
10. Signal attenuation:   7.1 / 10.6
11. Data sent/received:   131.1 MB / 3.3 GB
12. Broadband username:   bthomehub@btbroadband.com

Umm...no idea what this is about, from the event logs -

11:29:34, 13 Oct.   IN: BLOCK [16] Remote administration (TCP [125.64.94.200]:58960-​>[81.129.25.139]:80 on ppp3)
10:41:40, 13 Oct.   IN: BLOCK [16] Remote administration (TCP [74.82.47.18]:55113-​>[81.129.25.139]:443 on ppp3)
10:24:53, 13 Oct.   IN: BLOCK [16] Remote administration (ICMP type 8 code 0 98.89.5.104-​>81.129.25.139 on ppp3)

Looks like BT is having a look.

It has been happening since last night according to the logs.
Title: Re: BT HH5A losing PPPoE but DSL stays up.
Post by: markg33 on October 13, 2015, 01:40:37 PM
I lost connection briefly but it came up automatically instead of me needing to manually use that page like yesterday to get the PPPoE to work, so this is a start.

I have a feeling this happened because of these remote admin logs in my HH5 which is very odd. Please read from bottom to top.

Time and date   Message
13:27:04, 13 Oct.   IN: BLOCK [16] Remote administration (TCP [46.148.16.98]:57486-​>[86.180.213.89]:22 on ppp3)
13:18:06, 13 Oct.   (48825.290000) CWMP: session completed successfully
13:18:06, 13 Oct.   (48825.090000) CWMP: HTTP authentication success from https://pbthdm.bt.mo
13:17:58, 13 Oct.   (48817.250000) CWMP: Server URL: https://pbthdm.bt.mo; Connecting as user: ACS username
13:17:58, 13 Oct.   (48817.240000) CWMP: Session start now. Event code(s): '4 VALUE CHANGE'
13:17:56, 13 Oct.   (48815.300000) WAN operating mode is VDSL
13:17:56, 13 Oct.   (48815.300000) Last WAN operating mode was VDSL
13:17:55, 13 Oct.   (48813.930000) PPP IPCP Receive Configuration ACK
13:17:55, 13 Oct.   (48813.930000) PPP IPCP Send Configuration Request
13:17:55, 13 Oct.   (48813.920000) PPP IPCP Receive Configuration NAK
13:17:55, 13 Oct.   (48813.920000) PPP IPCP Send Configuration ACK
13:17:55, 13 Oct.   (48813.920000) PPP IPCP Receive Configuration Request
13:17:55, 13 Oct.   (48813.920000) PPP IPCP Send Configuration Request
13:17:53, 13 Oct.   (48812.710000) PPPoE is up -​ Down Rate=79995000Kbps, Up Rate=20000000Kbps; SNR Margin Down=11.1dB, Up=15.3dB
13:17:53, 13 Oct.   (48812.690000) CHAP authentication successful
13:17:53, 13 Oct.   (48812.560000) CHAP Receive Challenge
13:17:53, 13 Oct.   (48812.560000) Starting CHAP authentication with peer
13:17:53, 13 Oct.   (48812.560000) PPP LCP Receive Configuration ACK
13:17:53, 13 Oct.   (48812.560000) PPP LCP Send Configuration Request
13:17:53, 13 Oct.   (48812.560000) PPP LCP Receive Configuration Reject
13:17:53, 13 Oct.   (48812.560000) PPP LCP Send Configuration ACK
13:17:53, 13 Oct.   (48812.560000) PPP LCP Receive Configuration Request
13:17:53, 13 Oct.   (48812.560000) PPP LCP Send Configuration Request
13:17:42, 13 Oct.   (48801.080000) Admin login successful by 192.168.1.70 on HTTP
13:17:04, 13 Oct.   (48763.090000) PTM over DSL is up
13:16:59, 13 Oct.   (48758.540000) CWMP: session closed due to error: No response
13:16:59, 13 Oct.   (48758.440000) CWMP: Server URL: https://pbthdm.bt.mo; Connecting as user: ACS username
13:16:59, 13 Oct.   (48758.430000) CWMP: Session start now. Event code(s): '4 VALUE CHANGE'
13:16:29, 13 Oct.   (48728.020000) CWMP: session closed due to error: No response
13:16:28, 13 Oct.   (48727.790000) CWMP: Server URL: https://pbthdm.bt.mo; Connecting as user: ACS username
13:16:28, 13 Oct.   (48727.780000) CWMP: Session start now. Event code(s): '4 VALUE CHANGE'
13:16:28, 13 Oct.   (48727.410000) CWMP: Initializing transaction for event code 4 VALUE CHANGE
13:16:26, 13 Oct.   (48725.110000) PTM over DSL is down after 810 minutes uptime
13:16:26, 13 Oct.   (48725.100000) PPPoE is down after 810 minutes uptime [Waiting for Underlying Connection (WAN Ethernet 2 -​ Down)]
13:16:23, 13 Oct.   (48722.300000) PPP LCP Send Termination Request [User request]
13:15:36, 13 Oct.   IN: BLOCK [16] Remote administration (TCP [193.104.41.53]:50641-​>[81.129.25.139]:22 on ppp3)

My noise margins have increased a little. Perhaps this is a good sign?

1. Product name:   BT Home Hub
2. Serial number:   +068343+NQ42338353
3. Firmware version:   Software version 4.7.5.1.83.8.204.1.11 (Type A) Last updated 04/07/15
4. Board version:   BT Hub 5A
5. DSL uptime:   0 days, 00:22:38
6. Data rate:   20000 / 79995
7. Maximum data rate:   33028 / 99507
8. Noise margin:   15.5 / 11.1
9. Line attenuation:   7.2 / 10.6
10. Signal attenuation:   7.1 / 10.6

This what my Infinity 2 looked like on the day of install -

1. Product name:   BT Home Hub
2. Serial number:   +068343+NQ42338353
3. Firmware version:   Software version 4.7.5.1.83.8.204.1.11 (Type A) Last updated 04/07/15
4. Board version:   BT Hub 5A
5. DSL uptime:   0 days, 00:11:15
6. Data rate:   20000 / 79995
7. Maximum data rate:   34193 / 102735
8. Noise margin:   15.6 / 12.0
9. Line attenuation:   7.5 / 10.6
10. Signal attenuation:   7.4 / 10.6
11. Data sent/received:   0.2 MB / 0.1 MB
12. Broadband username:   
bthomehub@btbroadband.com
Title: Re: BT HH5A losing PPPoE but DSL stays up.
Post by: Dray on October 13, 2015, 02:48:50 PM
Looks like the standard reboot for HH5 which no-one knows why it happens.

The noise margins vary all the time anyway so nothing suspicious there.
Title: Re: BT HH5A losing PPPoE but DSL stays up.
Post by: markg33 on October 13, 2015, 03:01:52 PM
Hi Dray,
Thanks for your input again. Yeah it is looking like it is just the HH5 being the HH5.

But what was happening with just the PPPoE dropping and the DSL staying up is something I have never had before with the HH5. The reboot I got today was the first time I got a "regular" reboot.

The past three times were it just dropping the PPPoE and not the DSL. And it was fine from 16th until the 25th September then the PPPoE weirdness happened again twice yesterday.

Usually the mystery reboot takes down the DSL with the PPPoE and automatically comes back quickly. The 25th and yesterday was completely opposite. And still not sure why, I will put it down to Hub. But also could have been something exchange side like the PPP authentication, radius server etc being at fault.

I was happy that the usual reboot happened as I did not need to manually connect the PPPoE via that darn page.  :lol:

The only thing I can think of with the HH5 in general is it is losing its echo requests and timing out the PPP sessions and needing to re-establish the PPP session to continue.

Just my limited knowledge guessing here lol.