cancel
Showing results for 
Show  only  | Search instead for 
Did you mean: 
preston55
Aspiring Contributor
2,256 Views
Message 1 of 10

HH5 can't connect. Curious logs. Any ideas?

We've had infinity 2 since jan 20, and it's been reliable until today. The HH5 line state says connected for a minute or two in "advanced settings", but other settings say that it's disconnected, which is correct as it's not working and it seems not to be able to get beyond trying to establish a PPP connection. The fault reporter on the BT site shows no fault with the line. Luckily we also have a WIMAX Internet connection from another provider.

 

Is this a typical Infinity experience? From reading it seems that service problems are common, and is it something that should "sort itself out" so to speak, or should we be logging a fault at this point? 

 

Example logs are below. Not sure if the https://pbthdm.bt.mo connections are coming into the router from BT or the router connecting out. Also seems it is getting an IP briefly but then goes dead. Once it sets the date via NTP it's also an hour forward for some reason. 

 

As the log also showed a blocked incoming request probing for an open squid proxy from an IP in Poland at 22:08:20, 12 Feb (which was actually 21:08 as the router is setting its time at UTC+1), it must have been online briefly. 

 

 

22:08:27, 12 Feb.( 160.600000) NTP synchronization success!
  
01:01:28, 26 Sep.( 103.750000) Port forwarding rule added via UPnP/TR064. Protocol: TCP, external ports: any-​>29649, internal ports: 29649, internal client: 192.168.1.72
01:01:24, 26 Sep.OUT: BLOCK [15] Default policy (ICMP Packet is not a request packet: ICMPv6 type 143 code 0 fe80:0000:0000:0000:ca91:f9ff:fe88:8f65-​>ff02:0000:0000:0000:0000:0000:0000:0016 on ptm0)
01:01:20, 26 Sep.BLOCKED 1 more packets (because of Default policy)
01:01:20, 26 Sep.OUT: BLOCK [15] Default policy (ICMP Packet is not a request packet: ICMPv6 type 143 code 0 fe80:0000:0000:0000:ca91:f9ff:fe88:8f65-​>ff02:0000:0000:0000:0000:0000:0000:0016 on ptm0)
01:01:20, 26 Sep.OUT: BLOCK [71] Non-​routable IPv6 address (ICMPv6 type 143 code 0 0000:0000:0000:0000:0000:0000:0000:0000-​>ff02:0000:0000:0000:0000:0000:0000:0016 on ptm0)
01:01:22, 26 Sep.OUT: BLOCK [15] Default policy (ICMP Packet is not a request packet: ICMPv6 type 143 code 0 fe80:0000:0000:0000:ca91:f9ff:fe88:8f65-​>ff02:0000:0000:0000:0000:0000:0000:0016 on ptm0)
01:01:22, 26 Sep.OUT: BLOCK [15] Default policy (ICMP Packet is not a request packet: ICMPv6 type 143 code 0 fe80:0000:0000:0000:ca91:f9ff:fe88:8f65-​>ff02:0000:0000:0000:0000:0000:0000:0016 on ptm0.101)
01:01:18, 26 Sep.OUT: BLOCK [15] Default policy (ICMP Packet is not a request packet: ICMPv6 type 143 code 0 fe80:0000:0000:0000:ca91:f9ff:fe88:8f65-​>ff02:0000:0000:0000:0000:0000:0000:0016 on ptm0)
22:08:20, 12 Feb.IN: BLOCK [15] Default policy (TCP [91.238.134.51]:56655-​>[86.178.15.163]:3128 on ppp3)
01:01:05, 26 Sep.( 81.540000) CWMP: session closed due to error: No response
01:01:05, 26 Sep.( 81.520000) CWMP: Server URL: https://pbthdm.bt.mo; Connecting as user: ACS username
01:01:05, 26 Sep.( 81.510000) CWMP: Session start now. Event code(s): '1 BOOT,4 VALUE CHANGE'
01:00:35, 26 Sep.( 51.250000) CWMP: session closed due to error: No response
01:00:25, 26 Sep.( 40.740000) CWMP: Server URL: https://pbthdm.bt.mo; Connecting as user: ACS username
01:00:25, 26 Sep.( 40.730000) CWMP: Session start now. Event code(s): '1 BOOT,4 VALUE CHANGE'
01:00:24, 26 Sep.( 40.270000) CWMP: Initializing transaction for event code 1 BOOT
01:01:02, 26 Sep.( 78.440000) CWMP: session closed due to error: No response
01:01:02, 26 Sep.( 78.420000) CWMP: Server URL: https://pbthdm.bt.mo; Connecting as user: ACS username
01:01:02, 26 Sep.( 78.410000) CWMP: Session start now. Event code(s): '1 BOOT,4 VALUE CHANGE'
01:00:32, 26 Sep.( 48.120000) CWMP: session closed due to error: No response
01:00:24, 26 Sep.( 40.300000) CWMP: Server URL: https://pbthdm.bt.mo; Connecting as user: ACS username
01:00:24, 26 Sep.( 40.290000) CWMP: Session start now. Event code(s): '1 BOOT,4 VALUE CHANGE'
01:00:24, 26 Sep.( 39.670000) CWMP: Initializing transaction for event code 1 BOOT
01:01:02, 26 Sep.( 78.610000) CWMP: session closed due to error: No response
  
22:08:18, 12 Feb.

( 151.400000) NTP synchronization start

 

 

 

22:08:15, 12 Feb.( 147.650000) Updating NoIP service with IP 86.178.15.163 for host xxx

01:01:16, 26 Sep.( 91.630000) PTM over DSL is up
01:00:20, 26 Sep.( 35.650000) WAN Auto-​sensing running.
01:02:10, 26 Sep.( 146.420000) PPP LCP Send Termination Request [User request]
01:01:15, 26 Sep.( 90.680000) PTM over DSL is up
01:00:19, 26 Sep.( 35.610000) WAN Auto-​sensing running.
01:01:16, 26 Sep.( 91.740000) PTM over DSL is up
01:00:19, 26 Sep.( 35.600000) WAN Auto-​sensing running.
01:01:16, 26 Sep.( 92.550000) PTM over DSL is up
01:00:19, 26 Sep.( 35.510000) WAN Auto-​sensing running.
01:02:12, 26 Sep.( 147.750000) PPP LCP Send Termination Request [User request]
01:01:16, 26 Sep.( 91.740000) PTM over DSL is up
01:00:19, 26 Sep.( 35.590000) WAN Auto-​sensing running.
01:02:11, 26 Sep.( 147.000000) PPP LCP Send Termination Request [User request]
01:02:10, 26 Sep.( 146.530000) PPP LCP Send Configuration Request
01:01:13, 26 Sep.( 89.380000) PTM over DSL is up
01:00:19, 26 Sep.( 35.550000) WAN Auto-​sensing running.
01:01:14, 26 Sep.( 90.110000) PTM over DSL is up
01:00:19, 26 Sep.( 35.080000) WAN Auto-​sensing running.
21:08:45, 12 Feb.( 162.950000) PPP LCP Send Termination Request [User request]
22:08:15, 12 Feb.( 147.930000) WAN operating mode is VDSL
22:08:15, 12 Feb.( 147.930000) Last WAN operating mode was VDSL
22:08:13, 12 Feb.( 146.440000) Updating NoIP service with IP 86.178.15.163 for host xxx

22:08:13, 12 Feb.( 146.430000) PPP IPCP Receive Configuration ACK
22:08:13, 12 Feb.( 146.420000) PPP IPCP Send Configuration Request
22:08:13, 12 Feb.( 146.410000) PPP IPCP Receive Configuration NAK
22:08:13, 12 Feb.( 146.410000) PPP IPCP Send Configuration ACK
22:08:13, 12 Feb.( 146.410000) PPP IPCP Receive Configuration Request
22:08:13, 12 Feb.( 146.400000) PPP IPCP Send Configuration Request
22:08:12, 12 Feb.( 145.250000) PPPoE is up -​ Down Rate=79995000Kbps, Up Rate=19999000Kbps; SNR Margin Down=9.7dB, Up=15.3dB
22:08:12, 12 Feb.( 145.230000) CHAP authentication successful
22:08:12, 12 Feb.( 145.170000) CHAP Receive Challenge
22:08:12, 12 Feb.( 145.170000) Starting CHAP authentication with peer
22:08:12, 12 Feb.( 145.170000) PPP LCP Receive Configuration ACK
22:08:12, 12 Feb.( 145.160000) PPP LCP Send Configuration Request
22:08:12, 12 Feb.( 145.160000) PPP LCP Receive Configuration Reject
22:08:12, 12 Feb.( 145.160000) PPP LCP Send Configuration ACK
22:08:12, 12 Feb.( 145.160000) PPP LCP Receive Configuration Request
22:08:12, 12 Feb.( 145.150000) PPP LCP Send Configuration Request
22:07:37, 12 Feb.( 110.060000) Port forwarding rule added via UPnP/TR064. Protocol: UDP, external ports: any-​>29649, internal ports: 29649, internal client: 192.168.1.72
22:07:35, 12 Feb.

( 108.480000) No response from server

 

 

0 Ratings
9 REPLIES 9
ray_dorset
Distinguished Guru
2,236 Views
Message 2 of 10

Re: HH5 can't connect. Curious logs. Any ideas?

Can you post your line stats from the HH5 please? These are in Troubleshooting/Helpdesk on the web interface at http://192.168.1.254

Lines 1-13 will be enough

_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
If you found this post helpful, please click on the star on the left
If not, I'll try again 🙂
0 Ratings
preston55
Aspiring Contributor
2,228 Views
Message 3 of 10

Re: HH5 can't connect. Curious logs. Any ideas?

Hi Ray,

 

Many thanks for replying. I just got off the phone with a BT support tech, who determined that the router was resetting itself and had me reset to factory settings via the switch at the back. This worked and the hub is stable. The last f/w update was 25th, and it's been working fine since then until today. Any ideas why it could have needed a factory reset now?

 

There was also odd behaviour during the issue where it would sometimes say that the admin password was incorrect, which it wasn't, and that a firmware update was ready to install. I'm assuming that the router hadn't been hacked, though wondering.

 

1. Product name:BT Home Hub
2. Serial number:+068543+NQ43931414
3. Firmware version:Software version 4.7.5.1.83.8.204 (Type A) Last updated 25/01/15
4. Board version:BT Hub 5A
5. DSL uptime:0 days, 00:16:28
6. Data rate:19999 / 79995
7. Maximum data rate:33954 / 92562
8. Noise margin:15.3 / 9.4
9. Line attenuation:12.5 / 10.9
10. Signal attenuation:12.6 / 11.1
11. Data sent/received:0.6 MB / 0.6 MB
12. Broadband username:bthomehub@btbroadband.com
13. BT Wi-fi:Yes
0 Ratings
ray_dorset
Distinguished Guru
2,223 Views
Message 4 of 10

Re: HH5 can't connect. Curious logs. Any ideas?

Don't know sorry, but I know a factory reset often fixes problems.

 

Excellent stats btw 🙂

_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
If you found this post helpful, please click on the star on the left
If not, I'll try again 🙂
0 Ratings
john46
Distinguished Sage
2,218 Views
Message 5 of 10

Re: HH5 can't connect. Curious logs. Any ideas?

most likely the hub config file has been corrupted when the hub restarted after the update
0 Ratings
ray_dorset
Distinguished Guru
2,217 Views
Message 6 of 10

Re: HH5 can't connect. Curious logs. Any ideas?

What's the hub config file?
Is it viewable?
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
If you found this post helpful, please click on the star on the left
If not, I'll try again 🙂
0 Ratings
john46
Distinguished Sage
2,214 Views
Message 7 of 10

Re: HH5 can't connect. Curious logs. Any ideas?

0 Ratings
preston55
Aspiring Contributor
2,163 Views
Message 8 of 10

Re: HH5 can't connect. Curious logs. Any ideas?

Hi Ray,

 

Thanks, and the stats were good until this evening. A speedtest was slower than previously, and checking they are now as follows. While the theorhetical rate has improved since last night, over 20Mb has been lopped off the received profile so that it's below 60. I know there's a training period, though we're past that based on the install date. Any ideas?

 

1. Product name:BT Home Hub
2. Serial number:+068543+NQ43931414
3. Firmware version:Software version 4.7.5.1.83.8.204 (Type A) Last updated 25/01/15
4. Board version:BT Hub 5A
5. DSL uptime:0 days, 00:09:39
6. Data rate:19997 / 59033
7. Maximum data rate:35159 / 95027
8. Noise margin:13.1 / 10.7
9. Line attenuation:12.7 / 11.1
10. Signal attenuation:13.0 / 11.4
0 Ratings
ray_dorset
Distinguished Guru
2,129 Views
Message 9 of 10

Re: HH5 can't connect. Curious logs. Any ideas?

That's very strange. I suggest you leave it 24 hours and then I suggest you try a factory reset of the hub


http://bt.custhelp.com/app/answers/detail/a_id/11386/~/how-do-i-reset-my-bt-home-hub-to-its-factory-...

_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
If you found this post helpful, please click on the star on the left
If not, I'll try again 🙂
0 Ratings
preston55
Aspiring Contributor
2,115 Views
Message 10 of 10

Re: HH5 can't connect. Curious logs. Any ideas?

Will do. That was the fix for the constant reboots when starting the thread, which is an issue someone else just posted here too. After the factory reset thursday night the speed was excellent, getting about 75Mb to a range of servers with speedtest.net going through a vigor wireless router that's connected to the HH5, and I've not seen the data rate showing below 79 before last night.

 

0 Ratings