Help, CWMP: session closed due to error: Could not resolve host

[Owain]

Hi there

Since about late April early May, i have experienced quite consistent dropouts. After consulting BT on the phone, did a line test Engineer came out  replaced the line connecting to thew house. But the Issue persisted. I have hard reset the Modem twice to no avail also tried using an 3rd Party Modem this has not worked either. I did for a while think this could have been a power supply issue causing de-sinc but that turned out not to be the case as for possible interference i have attempted to isolate any device that could have done so and been unsuccessful. So im asking if anyone can help, I'll leave the logs from the last drop out. This one was fairly short but they can be much longer this is why the reboot process is also showing up ion this particular log.

14:37:08, 26 Jun. ( 1449.800000) Lease for IP 192.168.1.67 renewed by host DESKTOP-​FVK7AF3 (MAC 10:c3:7b:cc:87:02). Lease duration: 1440 min
14:37:08, 26 Jun. ( 1449.800000) Device connected: Hostname: DESKTOP-​FVK7AF3 IP: 192.168.1.67 MAC: 10:c3:7b:cc:87:02 Lease time: 1440 min. Link rate: 39.0 Mbps
14:37:08, 26 Jun. ( 1449.620000) Lease requested
14:37:08, 26 Jun. ath00: STA 10:c3:7b:cc:87:02 IEEE 802.11: Client associated
14:37:06, 26 Jun. ( 1448.080000) CWMP: session completed successfully
14:37:06, 26 Jun. ( 1447.790000) CWMP: HTTP authentication success from https://pbthdm.bt.mo
14:37:06, 26 Jun. IN: BLOCK [16] Remote administration (TCP [196.52.43.60]:62082-​>[165.120.112.120]:8080 on ppp3)
14:37:04, 26 Jun. ( 1446.140000) CWMP: Server URL: https://pbthdm.bt.mo; Connecting as user: ACS username
14:37:04, 26 Jun. ( 1446.130000) CWMP: Session start now. Event code(s): '6 CONNECTION REQUEST,4 VALUE CHANGE'
14:37:04, 26 Jun. ( 1445.430000) CWMP: Initializing transaction for event code 6 CONNECTION REQUEST
14:36:56, 26 Jun. OUT: BLOCK [65] First packet is Invalid (Packet not in tcp window: TCP [192.168.1.68]:36299-​>[45.57.41.1]:443 on ppp3)
14:36:56, 26 Jun. BLOCKED 1 more packets (because of First packet is Invalid)
14:36:55, 26 Jun. OUT: BLOCK [65] First packet is Invalid (Packet not in tcp window: TCP [192.168.1.68]:41446-​>[45.57.0.151]:443 on ppp3)
14:36:34, 26 Jun. BLOCKED 1 more packets (because of First packet is Invalid)
14:36:33, 26 Jun. OUT: BLOCK [65] First packet is Invalid (Invalid tcp flags for current tcp state: TCP [192.168.1.64]:51229-​>[104.244.43.131]:443 on ppp3)
14:36:30, 26 Jun. ( 1411.920000) Lease for IP 192.168.1.73 renewed by host Cath-​PC (MAC e4:d5:3d:16:05:e8). Lease duration: 1440 min
14:36:30, 26 Jun. ( 1411.920000) Device connected: Hostname: Cath-​PC IP: 192.168.1.73 MAC: e4:d5:3d:16:05:e8 Lease time: 1440 min. Link rate: 42.9 Mbps
14:36:30, 26 Jun. ( 1411.790000) Lease requested
14:36:30, 26 Jun. ath00: STA e4:d5:3d:16:05:e8 IEEE 802.11: Client associated
14:36:29, 26 Jun. ath00: STA e4:d5:3d:16:05:e8 IEEE 802.11: Client disassociated
14:36:29, 26 Jun. ath00: STA e4:d5:3d:16:05:e8 IEEE 802.11: WiFi registration failed
14:36:20, 26 Jun. ( 1401.580000) CWMP: session completed successfully
14:36:19, 26 Jun. ( 1401.380000) CWMP: HTTP authentication success from https://pbthdm.bt.mo
14:36:18, 26 Jun. OUT: BLOCK [65] First packet is Invalid (Invalid tcp flags for current tcp state: TCP [192.168.1.64]:51238-​>[151.101.62.219]:443 on ppp3)
14:36:18, 26 Jun. ath00: STA e4:d5:3d:16:05:e8 IEEE 802.11: Client associated
14:36:16, 26 Jun. OUT: BLOCK [65] First packet is Invalid (Invalid tcp flags for current tcp state: TCP [192.168.1.64]:51236-​>[199.232.58.219]:443 on ppp3)
14:36:16, 26 Jun. ath00: STA e4:d5:3d:16:05:e8 IEEE 802.11: Client disassociated
14:36:16, 26 Jun. ath00: STA e4:d5:3d:16:05:e8 IEEE 802.11: Client associated
14:36:16, 26 Jun. ath00: STA e4:d5:3d:16:05:e8 IEEE 802.11: Client disassociated
14:36:16, 26 Jun. ath00: STA e4:d5:3d:16:05:e8 IEEE 802.11: Client associated
14:36:15, 26 Jun. BLOCKED 1 more packets (because of First packet is Invalid)
14:36:13, 26 Jun. OUT: BLOCK [65] First packet is Invalid (Invalid tcp flags for current tcp state: TCP [192.168.1.64]:51216-​>[104.244.42.129]:443 on ppp3)
14:36:12, 26 Jun. OUT: BLOCK [65] First packet is Invalid (Invalid tcp flags for current tcp state: TCP [192.168.1.64]:51235-​>[151.101.17.7]:443 on ppp3)
14:36:12, 26 Jun. ath00: STA e4:d5:3d:16:05:e8 IEEE 802.11: Client disassociated
14:36:06, 26 Jun. ( 1387.560000) CWMP: Server URL: https://pbthdm.bt.mo; Connecting as user: ACS username
14:36:06, 26 Jun. ( 1387.550000) CWMP: Session start now. Event code(s): '4 VALUE CHANGE'
14:36:04, 26 Jun. ( 1385.860000) WAN operating mode is VDSL
14:36:04, 26 Jun. ( 1385.860000) Last WAN operating mode was VDSL
14:36:03, 26 Jun. ( 1384.470000) PPP IPCP Receive Configuration ACK
14:36:03, 26 Jun. ( 1384.450000) PPP IPCP Send Configuration Request
14:36:03, 26 Jun. ( 1384.440000) PPP IPCP Receive Configuration NAK
14:36:03, 26 Jun. ( 1384.440000) PPP IPCP Send Configuration ACK
14:36:03, 26 Jun. ( 1384.430000) PPP IPCP Receive Configuration Request
14:36:03, 26 Jun. ( 1384.430000) PPP IPCP Send Configuration Request
14:36:01, 26 Jun. ( 1383.210000) PPPoE is up -​ Down Rate=45857Kbps, Up Rate=498Kbps; SNR Margin Down=6.0dB, Up=7.0dB
14:36:01, 26 Jun. ( 1383.200000) CHAP authentication successful
14:36:01, 26 Jun. ( 1383.140000) CHAP Receive Challenge
14:36:01, 26 Jun. ( 1383.140000) Starting CHAP authentication with peer
14:36:01, 26 Jun. ( 1383.130000) PPP LCP Receive Configuration ACK
14:36:01, 26 Jun. ( 1383.120000) PPP LCP Send Configuration Request
14:36:01, 26 Jun. ( 1383.110000) PPP LCP Receive Configuration Reject
14:36:01, 26 Jun. ( 1383.100000) PPP LCP Send Configuration ACK
14:36:01, 26 Jun. ( 1383.100000) PPP LCP Receive Configuration Request
14:36:01, 26 Jun. ( 1383.100000) PPP LCP Send Configuration Request
14:35:44, 26 Jun. ( 1365.730000) Device disconnected: Hostname: Rachels-​iPhone IP: 192.168.1.69 MAC: 50:bc:96:5b:1b:5c
14:35:43, 26 Jun. ath10: STA 50:bc:96:5b:1b:5c IEEE 802.11: Client disassociated
14:35:11, 26 Jun. ( 1333.070000) PTM over DSL is up
14:33:10, 26 Jun. ( 1212.100000) CWMP: session closed due to error: Could not resolve host
14:33:10, 26 Jun. ( 1212.070000) CWMP: Server URL: https://pbthdm.bt.mo; Connecting as user: ACS username
14:33:10, 26 Jun. ( 1212.060000) CWMP: Session start now. Event code(s): '4 VALUE CHANGE'
14:32:40, 26 Jun. ( 1181.530000) CWMP: session closed due to error: Could not resolve host
14:32:38, 26 Jun. ( 1180.000000) CWMP: Server URL: https://pbthdm.bt.mo; Connecting as user: ACS username
14:32:38, 26 Jun. ( 1179.990000) CWMP: Session start now. Event code(s): '4 VALUE CHANGE'
14:32:38, 26 Jun. ( 1179.460000) CWMP: Initializing transaction for event code 4 VALUE CHANGE
14:32:36, 26 Jun. ( 1177.680000) PTM over DSL is down after 16 minutes uptime
14:32:36, 26 Jun. ( 1177.670000) PPPoE is down after 15 minutes uptime [Waiting for Underlying Connection (WAN Ethernet 7 -​ Down)]
14:32:32, 26 Jun. ( 1173.810000) PPP LCP Send Termination Request [User request]
14:30:42, 26 Jun. BLOCKED 3 more packets (because of Remote administration)
14:30:42, 26 Jun. IN: BLOCK [16] Remote administration (TCP [5.62.48.120]:54116-​>[165.120.112.7]:8080 on ppp3)
14:30:40, 26 Jun. BLOCKED 4 more packets (because of Remote administration)
14:30:39, 26 Jun. BLOCKED 3 more packets (because of Remote administration)
14:30:39, 26 Jun. IN: BLOCK [16] Remote administration (TCP [5.62.48.120]:33670-​>[165.120.112.7]:22 on ppp3)

Thanks

[imjolly]

please can you post the stats from your router (if hub enter 192.168.1.254 in your browser) and if  HH5 then go to troubleshooting then helpdesk and if HH6/SH2 then advanced settings then technical log information . 

Have you tried the quiet line test? - dial 17070 option 2 - should hear nothing - best done with a corded phone. if cordless phone you may hear a 'dull hum' which is normal

are you using the test socket with a filter to eliminate your internal wiring as causing a problem and see if that stabilises your line

enter your phone number and post results  remember to delete number   https://www.broadbandchecker.btwholesale.com/#/ADSL

Someone may then be able to offer help/assistance/suggestions to your problem

[Owain]

Hi Imjolly

thanks for the quick reply

Heres the HH5 details

1. Product name:	BT Home Hub
2. Serial number:	+068543+NQ60531829
3. Firmware version:	Software version 4.7.5.1.83.8.264 (Type A) Last updated 01/03/19
4. Board version:	BT Hub 5A
5. DSL uptime:	0 days, 01:05:03
6. Data rate:	498 / 45857
7. Maximum data rate:	466 / 71145
8. Noise margin:	6.9 / 12.8
9. Line attenuation:	7.4 / 11.6
10. Signal attenuation:	12.3 / 12.2
11. Data sent/received:	54.0 MB / 4.3 GB
12. Broadband username:	bthomehub@btbroadband.com
13. BT Wi-fi:	Yes
14. 2.4 GHz Wireless network/SSID:	BTHub5-9K6K
15. 2.4 GHz Wireless connections:	Enabled (802.11 b/g/n (up to 144 Mb/s))
16. 2.4 GHz Wireless security:	WPA2
17. 2.4 GHz Wireless channel:	Automatic (Smart Wireless)
18. 5 GHz Wireless network/SSID:	BTHub5-9K6K
19. 5 GHz Wireless connections:	Enabled (802.11 a/n/ac (up to 1300 Mb/s))
20. 5 GHz Wireless security:	WPA2
21. 5 GHz Wireless channel:	Automatic (Smart Wireless)
22. Firewall:	Default
23. MAC Address:	90:72:82:80:52:a8
24. Modulation:	G.993.2 Annex B
25. Software variant:	AA
26. Boot loader:	1.0.0

[Owain]

And also the results from the Avialibilty Checker

As for the line, I have already performed the quiet line test and, also used the test socket in the past. The engineer replaced both with a brand new wiring up to the pole and a new socket.

Thanks

[imjolly]

If you are on fibre 2 then your speeds are terrible and the result of the continual drops in connection.  Have you turned of smart setup in hub manager?

other information will help

[Owain]

Im on fibre 1, i accept being in West Wales my internet speeds wont be top draw.

Prior to the last time io did a factory reset which i did this morning I had disabled Smart setup  a while back.

I have been digging hard for a sopolution to this issue for a month or two. It seems its a very vague one. Sin one back in 2014 the IP address was mentioned as a possible cause, There was also possibly a firmware fault in the HH5. Having tried trhe 3rd party hub the latter seems not to be the case. We have hads storms recently and around the time connections began initially dropping so i thought possibly some damage may have been caused but this issue seems isolated to my house. What then complicates the issue is that open reach had been out around the same time the issue began installing more fibre features. So as you can see im finding this difficult to pin down other than the log entries

[imjolly]

There is something causing drops in connection so first place to start is to make sure no line noise and if ok then to move connection to test socket with a filter

if you are on fibre 1 then looking at dslchecker results you had an 80mb connection yesterday before you did a factory reset