Solved: Re: BT Homehub6 Failing to connect via Openreach F...

kefabean101 · ‎14-09-2018

Hello all,

I'm hoping someone has experienced something similar - and managed to resolve it!

After 5 years of waiting(!) we've just had FTTP installed, but unfortunately it's been a nightmare installation. After about 8 engineer visits, 5 attempts to splice the fibre finally we have a solid green 'PON' light on the ONT fibre modem.

The issue now is that after connecting the ONT modem to the BT Homehub6 via the red WAN port, the router fails to connect and constantly goes in to the green 'booting' state before occasionally going 'amber' indicating no internet connection. While this is happening, wifi from the router is intermittent and the the management page on http://192.168.1.254 is unresponsive. I've also tried a couple of Homehub5 routers that have a WAN port but these don't connect either.

I connected my Draytek 2130n router that supports PPPoE so that I can get some debug logs. It looks like I am getting authentication errors as follows:

Jan 1 04:48:31    notice    local4    pppd[7858]: Connection terminated.
Jan 1 04:48:31    debug    local4    pppd[7858]: rcvd [LCP TermAck id=0x2]
Jan 1 04:48:31    debug    local4    pppd[7858]: sent [LCP TermAck id=0xd1]
Jan 1 04:48:31    debug    local4    pppd[7858]: rcvd [LCP TermReq id=0xd1]
Jan 1 04:48:31    debug    local4    pppd[7858]: sent [LCP TermReq id=0x2 "Failed to authenticate ourselves to peer"]
Jan 1 04:48:31    err    local4    pppd[7858]: CHAP authentication failed
Jan 1 04:48:31    info    local4    pppd[7858]: CHAP authentication failed: CHAP authentication failure
Jan 1 04:48:31    debug    local4    pppd[7858]: rcvd [CHAP Failure id=0x1 "CHAP authentication failure"]
Jan 1 04:48:31    debug    local4    pppd[7858]: rcvd [LCP EchoRep id=0x0 magic=0x5d5acbd7]
Jan 1 04:48:31    debug    local4    pppd[7858]: sent [CHAP Response id=0x1 <2768253b7dac7e34757f7a5615213f92>, name = "bthomehub@btbroadband.com"]
Jan 1 04:48:31    debug    local4    pppd[7858]: rcvd [CHAP Challenge id=0x1 <cfbaf4163e1adc4dcca1f50dc054b8e5c4be3f2521212d24aad9f831693943b8f4394fb2d2ab009fccf5ad8ecae5f38fa43434c6d461ea7f>, name = "acc-aln2.dk"]
Jan 1 04:48:31    debug    local4    pppd[7858]: sent [LCP EchoReq id=0x0 magic=0x71ab7e58]
Jan 1 04:48:31    debug    local4    pppd[7858]: rcvd [LCP ConfAck id=0x1 <mru 1492> <magic 0x71ab7e58>]
Jan 1 04:48:31    debug    local4    pppd[7858]: sent [LCP ConfAck id=0xd0 <mru 1492> <auth chap MD5> <magic 0x5d5acbd7>]
Jan 1 04:48:31    debug    local4    pppd[7858]: rcvd [LCP ConfReq id=0xd0 <mru 1492> <auth chap MD5> <magic 0x5d5acbd7>]
Jan 1 04:48:31    debug    local4    pppd[7858]: sent [LCP ConfReq id=0x1 <mru 1492> <magic 0x71ab7e58>]
Jan 1 04:48:31    notice    local4    pppd[7858]: Connect: ppp0 <--> eth1.101

There seems to be some device (name = "acc-aln2.dk") that is responding (from a google search this seems to be a BT device), but I'm seeing PPPoE authentication errors. This could be just some configuration issue with the Draytek, although it might explain why none of the BT Homehubs are able to connect either. (My understanding is that 'bthomehub@btbroadband.com' should be used as the username, with <blank>, 'BT', or 'bt' as the password - I've tried all combinations)

Needless to say, I'm raising a support request via the BT Fault process in parallel, but I'd be eternally grateful if anyone has had a similar issue and is able to shed some light on the problem. I'm worried this could fall between the BT/Openreach cracks and take ages to resolve.

Starwire2000 · ‎14-09-2018

It could potentially be an issue with the Profile Build.

I’d imagine they’ll want to send an Openreach Engineer out to do some checks with their Support Desk. There’s tests they can do to check if the issues at Openreaches end or if it’s at BT’s end.

kefabean101 · ‎14-09-2018

Funny you should say that, they did have to do a 'profile rebuild' today while the engineer was here, after the line wouldn't initially activate (eg. PON wouldn't go solid green). Not sure what a 'rebuild' means (took about 30 minutes for the guy at the other end of the phone to complete).

I do wonder whether something has got in to a stale config state somewhere in the depths of the BT systems. Question is what!?!?

pippincp · ‎14-09-2018

Give the FTTP team a ring tomorrow. 0800 587 4787

Unfotunately the Mods here can't deal with FTTP issues.

kefabean101 · ‎14-09-2018

Thanks pippincp - definitely will. Now I'm not 100% sure it is an FTTP issue. This evening, I isolated the router with no WAN connection and it seems to reboot continually now also, going from green, to flashing purple to solid purple and back to green (over a 5 min period or so).

Have tried a factory reset, but no luck. Perhaps maybe a faulty router (although doesn't explain why the other routers are unable to connect).

kefabean101 · ‎14-09-2018

After a bit more digging, I'm thinking I may be the lucky recipient of both a faulty router and a mis-configured line. I reconnected an old Homehub 5 noticed that the error light (a red 'b') specifically means username/password error.

I connected it up to the ONT modem via the WAN port and went through the wizard to activate the WAN. Still no luck. However on digging through the event log, I can see that I am getting similar errors as with the Draytek router:

01:33:50, 11 Apr.	( 2030.670000) PPP LCP Send Termination Request [Failed to authenticate ourselves to peer]
01:33:50, 11 Apr.	( 2030.670000) CHAP authentication failed
01:33:50, 11 Apr.	( 2030.660000) CHAP Receive Challenge
01:33:50, 11 Apr.	( 2030.660000) Starting CHAP authentication with peer
01:33:50, 11 Apr.	( 2030.650000) PPP LCP Receive Configuration ACK
01:33:50, 11 Apr.	( 2030.650000) PPP LCP Send Configuration Request
01:33:50, 11 Apr.	( 2030.650000) PPP LCP Receive Configuration Reject
01:33:50, 11 Apr.	( 2030.650000) PPP LCP Send Configuration ACK
01:33:50, 11 Apr.	( 2030.640000) PPP LCP Receive Configuration Request
01:33:50, 11 Apr.	( 2030.640000) PPP LCP Send Configuration Request

I'm assuming that username 'bthomehub@btbroadband.com' and no password are the correct authentication credentials. If anyone can advise otherwise that would be greatly appreciated?!

Starwire2000 · ‎15-09-2018

Just remembered it. Something I’ve only done twice in all the years I’ve been doing FTTP so it’s easily forgotten.

The Engineer needs to speak to the Second Line Support and they will do something called a CTH Test. This is where Openreach can emulate an ISP’s PPPoE Session. If it works then that proves the issue is with BT and not Openreach.

Last time I came across it turns out the ISP then had to completely cease the FTTP Service and basically start from scratch.

Good luck................

kefabean101 · ‎15-09-2018

Hi Starwire2000, thanks so much for this info - sounds like it could be invaluable.

Do you know if it's possible to run the CTH test without an engineer present? I'm wondering whether I can get the ball rolling before my next engineer appointment.

Crikey, a cease and replace sounds quite dramatic - fingers crossed this is reasonably straightforward. I'm assuming it requires a new ONT modem to be installed as I believe it is 'locked' to the customer once activated.

(I also have a replacement router arriving in the next day or so, to rule out this as an issue.)

I'll keep the post updated with further developments!

Thanks again,

Dan.

pippincp · ‎15-09-2018

IIRC the ONT is locked to the premises not the customer.

kefabean101 · ‎15-09-2018

Hi @pippincp - makes total sense!

@Starwire2000amazingly the replacement router just arrived. So immediately plugged it in. Goes green then amber as before (seems stable at amber this time). I immediately connected to wifi, browsed to the admin interface (http://192.168.1.254) and looked at the event log. Exactly the same error as before (see below) so I think I can safely rule out this as a router issue.

I've called BT to try to log a fault this morning but unfortunately as the installation 'close' process has not yet been completed by Openreach I am unable to do so. Unfortunately it looks like this won't happen until Monday 😞

Now I am certain it is a problem with the account/profile setup configuration, if there is anyone that has experienced anything similar and can shed any light on it then I will be eternally grateful.

   00:06:14, 01 Jan.    :PPPoE connection could not be established. Login failed but there was no detailed information delivered by the radius server.
   00:06:13, 01 Jan.    ppp:PPP: CHAP_FAILURE
   00:06:13, 01 Jan.    ppp:PPP: CHAP_RESPONSE
   00:06:13, 01 Jan.    ppp:PPP: LCP_GOOD_ACK
   00:06:13, 01 Jan.    ppp:PPP: LCP_REQUEST
   00:05:43, 01 Jan.    :PPPoE connection could not be established. Login failed but there was no detailed information delivered by the radius server.
   00:05:42, 01 Jan.    ppp:PPP: CHAP_FAILURE
   00:05:42, 01 Jan.    ppp:PPP: CHAP_RESPONSE
   00:05:42, 01 Jan.    ppp:PPP: LCP_GOOD_ACK
   00:05:42, 01 Jan.    ppp:PPP: LCP_REQUEST
   00:05:11, 01 Jan.    :PPPoE connection could not be established. Login failed but there was no detailed information delivered by the radius server.
   00:05:10, 01 Jan.    ppp:PPP: CHAP_FAILURE
   00:05:10, 01 Jan.    ppp:PPP: CHAP_RESPONSE
   00:05:10, 01 Jan.    ppp:PPP: LCP_GOOD_ACK
   00:05:10, 01 Jan.    ppp:PPP: LCP_REQUEST
   00:04:40, 01 Jan.    :PPPoE connection could not be established. Login failed but there was no detailed information delivered by the radius server.
   00:04:39, 01 Jan.    ppp:PPP: CHAP_FAILURE
   00:04:39, 01 Jan.    ppp:PPP: CHAP_RESPONSE
   00:04:39, 01 Jan.    ppp:PPP: LCP_GOOD_ACK
   00:04:39, 01 Jan.    ppp:PPP: LCP_REQUEST
   00:04:09, 01 Jan.    :PPPoE connection could not be established. Login failed but there was no detailed information delivered by the radius server.
   00:04:08, 01 Jan.    ppp:PPP: CHAP_FAILURE
   00:04:08, 01 Jan.    ppp:PPP: CHAP_RESPONSE
   00:04:08, 01 Jan.    ppp:PPP: LCP_GOOD_ACK
   00:04:08, 01 Jan.    ppp:PPP: LCP_REQUEST
   00:04:02, 01 Jan.    :HTTP UserAdmin login from 192.168.1.64 successfully
   00:03:37, 01 Jan.    :PPPoE connection could not be established. Login failed but there was no detailed information delivered by the radius server.
   00:03:36, 01 Jan.    ppp:PPP: CHAP_FAILURE
   00:03:36, 01 Jan.    ppp:PPP: CHAP_RESPONSE
   00:03:36, 01 Jan.    ppp:PPP: LCP_GOOD_ACK
   00:03:36, 01 Jan.    ppp:PPP: LCP_REQUEST
   00:03:31, 01 Jan.    :HTTP UserBasic login from 192.168.1.64 successfully
   00:03:06, 01 Jan.    :PPPoE connection could not be established. Login failed but there was no detailed information delivered by the radius server.
   00:03:05, 01 Jan.    ppp:PPP: CHAP_FAILURE
   00:03:05, 01 Jan.    ppp:PPP: CHAP_RESPONSE
   00:03:05, 01 Jan.    ppp:PPP: LCP_GOOD_ACK
   00:03:05, 01 Jan.    ppp:PPP: LCP_REQUEST
   00:02:44, 01 Jan.    :HTTP UserBasic login from 192.168.1.64 successfully
   00:02:35, 01 Jan.    BR_LAN:A redirect rule is added for the device (id:1)
   00:02:35, 01 Jan.    BR_LAN:The OIE is supported for the device (id:1)
   00:02:35, 01 Jan.    BR_LAN:The DHCP options that are offered by the device (id:1): DiscoverOptions: 53,55,57,61,51,12 | DiscoverOption55: 1,121,3,6,15,119,252,95,44,46 | RequestOptions: 53,55,57,61,50,54,12 | RequestOption55: 1,121,3,6,15,119,252,95,44,46 | HostName: kefabean101MBP | VendorId:
   00:02:35, 01 Jan.    :DHCP Confirmation of Request
   00:02:35, 01 Jan.    :PPPoE connection could not be established. Login failed but there was no detailed information delivered by the radius server.
   00:02:31, 01 Jan.    ppp:PPP: CHAP_FAILURE
   00:02:31, 01 Jan.    ppp:PPP: CHAP_RESPONSE
   00:02:31, 01 Jan.    ppp:PPP: LCP_GOOD_ACK
   00:02:31, 01 Jan.    ppp:PPP: LCP_REQUEST
   00:02:27, 01 Jan.    BR_LAN:New device (id:1) connecting on the LAN was detected
   00:02:27, 01 Jan.    wl0:A WiFi device <8C:85:90:18:80:46> has successfully connected to SSID (Device/WiFi/SSIDs/SSID[WL_PRIV5G])
   00:01:59, 01 Jan.    :PPPoE connection could not be established. Login failed but there was no detailed information delivered by the radius server.
   00:01:58, 01 Jan.    ppp:PPP: CHAP_FAILURE
   00:01:58, 01 Jan.    ppp:PPP: CHAP_RESPONSE
   00:01:58, 01 Jan.    ppp:PPP: LCP_GOOD_ACK
   00:01:58, 01 Jan.    ppp:PPP: LCP_REQUEST
   00:01:28, 01 Jan.    :PPPoE connection could not be established. Login failed but there was no detailed information delivered by the radius server.
   00:01:25, 01 Jan.    ppp:PPP: CHAP_FAILURE
   00:01:25, 01 Jan.    ppp:PPP: CHAP_RESPONSE
   00:01:25, 01 Jan.    ppp:PPP: LCP_GOOD_ACK
   00:01:25, 01 Jan.    ppp:PPP: LCP_REQUEST
   00:01:07, 01 Jan.    wl0:(44/36) Channel Hopping initiated/Manually initiated
   00:01:07, 01 Jan.    wl1:(11/6) Channel Hopping initiated/Manually initiated
   00:00:56, 01 Jan.    BR_LAN:The LAN DHCPv6 Server is active
   00:00:54, 01 Jan.    BR_LAN:The LAN DHCPv6 Server is inactive
   00:00:54, 01 Jan.    :PPPoE connection could not be established. Login failed but there was no detailed information delivered by the radius server.
   00:00:52, 01 Jan.    BR_LAN:UPnP functionality has been activated
   00:00:51, 01 Jan.    ppp:PPP: CHAP_FAILURE
   00:00:51, 01 Jan.    ppp:PPP: CHAP_RESPONSE
   00:00:51, 01 Jan.    ppp:PPP: LCP_GOOD_ACK
   00:00:51, 01 Jan.    ppp:PPP: LCP_REQUEST
   00:00:50, 01 Jan.    BR_LAN:The LAN DHCPv6 Server is active
   00:00:49, 01 Jan.    eth0.0:VLAN VLAN_FTTH_DATA connected
   00:00:49, 01 Jan.    BR_LAN:The LAN DHCPv6 Server is inactive
   00:00:49, 01 Jan.    eth0:WAN Ethernet connectivity has been established
   00:00:40, 01 Jan.    :This Rule has been applied successfully: [id:1, InternalClient: , External Ports:(0,0), Internal Ports: (0,0), Protocol: ]
   00:00:40, 01 Jan.    :Updating port mapping rule (1) by UPnP
   00:00:37, 01 Jan.    BR_LAN:The LAN DHCPv6 Server is active
   00:00:37, 01 Jan.    :The LAN DHCP Server is active
   00:00:36, 01 Jan.    BR_LAN: Allocated prefix = fdaa:bbcc:ddee::/64 (valid time = 4293967296 / preferred time = 4293967296)
   00:00:36, 01 Jan.    :DNS name resolution is now active
   00:00:36, 01 Jan.    wl0:WLAN has been deactivated (BTWifi-X) (band : 5GHz).
   00:00:36, 01 Jan.    wl0:WLAN has been deactivated (BTWifi-with-FON) (band : 5GHz).
   00:00:36, 01 Jan.    wl0:WLAN has been activated (BTHub6-CFR9) (band : 5GHz).
   00:00:36, 01 Jan.    wl1:WLAN has been deactivated (BTWifi-X) (band : 2.4GHz).
   00:00:36, 01 Jan.    wl1:WLAN has been deactivated (BTWifi-with-FON) (band : 2.4GHz).
   00:00:36, 01 Jan.    wl1:WLAN has been activated (BTHub6-CFR9) (band : 2.4GHz).
   00:00:34, 01 Jan.    Default:Firewall change to Level: FRWL
   00:00:33, 01 Jan.    wl0:(0/44) Channel Hopping initiated/Manually initiated
   00:00:33, 01 Jan.    wl1:(0/11) Channel Hopping initiated/Manually initiated
   00:00:33, 01 Jan.    :The Modem has successfully powered up

BT Homehub6 Failing to connect via Openreach FTTP modem

Re: BT Homehub6 Failing to connect via Openreach FTTP modem

Re: BT Homehub6 Failing to connect via Openreach FTTP modem

Re: BT Homehub6 Failing to connect via Openreach FTTP modem

Re: BT Homehub6 Failing to connect via Openreach FTTP modem

Re: BT Homehub6 Failing to connect via Openreach FTTP modem

Re: BT Homehub6 Failing to connect via Openreach FTTP modem

Re: BT Homehub6 Failing to connect via Openreach FTTP modem

Re: BT Homehub6 Failing to connect via Openreach FTTP modem

Re: BT Homehub6 Failing to connect via Openreach FTTP modem