What is my BT HH 5 up to at night?

joeyjojo · 6 Apr 2016 at 10:38

I've noticed in the logs each evening lines like these (sensitive lines removed, reverse chronological order). CWMP seems to be a remote management protocol. Anyone know what BT is up to poking around our routers at night?

The only reason I checked the logs is the connection seems to be flaky on mornings after. A reboot gets it back to normal.

Last night:

00:20:34, 06 Apr. CWMP: HDM socket closed successfully.
00:20:34, 06 Apr. CWMP: HTTP authentication success from pbthdm.x.x.x
00:20:33, 06 Apr. CWMP: HDM socket opened successfully.
00:20:32, 06 Apr. CWMP: session completed successfully
00:20:31, 06 Apr. CWMP: HDM socket closed successfully.
00:20:31, 06 Apr. CWMP: HTTP authentication success from pbthdm.x.x.x
00:20:30, 06 Apr. CWMP: HDM socket opened successfully.
00:20:30, 06 Apr. CWMP: HDM socket opened successfully.
00:20:29, 06 Apr. 5G WiFi scan(Reason:boot)
00:20:26, 06 Apr. CWMP: Server URL: https://pbthdm.x.x.x; Connecting as user: ACS username
00:20:26, 06 Apr. CWMP: Session start now, server: pbthdm.x.x.x, Event code:
00:20:25, 06 Apr. CWMP: Initializing transaction for event code 1 BOOT
00:20:06, 06 Apr. NTP synchronization success
00:20:04, 06 Apr. 5G WiFi auto selected channel 44 Bandwidth:80M(Reason:boot)
00:19:56, 06 Apr. 5G WiFi scan(Reason:boot)
00:19:55, 06 Apr. 2.4G WiFi auto selected channel 1 Bandwidth:20M(Reason:boot)
00:19:51, 06 Apr. NTP synchronization start
00:19:49, 06 Apr. WAN connection PTM connected
00:19:49, 06 Apr. PPP IPCP Receive Configuration ACK
00:19:49, 06 Apr. PPP IPCP Send Configuration Request
00:19:49, 06 Apr. 2.4G WiFi scan(Reason:boot)
00:19:49, 06 Apr. PPP IPCP Receive Configuration NAK
00:19:49, 06 Apr. PPP IPCP Send Configuration ACK
00:19:48, 06 Apr. PPP IPCP Receive Configuration Request
00:19:48, 06 Apr. PPP IPCP Send Configuration Request
00:19:48, 06 Apr. PPP CHAP Receive success : authentication successful
00:19:48, 06 Apr. PPP CHAP Receive Challenge
00:19:47, 06 Apr. PPP LCP Receive Configuration ACK
00:19:47, 06 Apr. PPP LCP Send Configuration ACK
00:19:47, 06 Apr. PPP LCP Receive Configuration Request
00:19:47, 06 Apr. PPP LCP Send Configuration Request
00:19:37, 06 Apr. 2.4G WiFi auto selected channel 1 Bandwidth:20M(Reason:boot)
00:19:33, 06 Apr. 2.4G WiFi scan(Reason:boot)
00:19:33, 06 Apr. 5G WiFi auto selected channel 36 Bandwidth:80M(Reason:boot)
00:19:26, 06 Apr. 5G WiFi scan(Reason:boot)
00:19:20, 06 Apr. DSL Link Up: Down Rate=40000Kbps, Up Rate=9999Kbps; SNR Margin Down=19.9dB, Up=22.6dB
00:19:15, 06 Apr. Booting firmware v0.07.05.0A13-BT (Thu Oct 15 14:28:46 2015)
00:19:15, 06 Apr. System start Button press (PowerButton)
00:19:08, 06 Apr. 5G WiFi auto selected channel 44 Bandwidth:80M(Reason:boot)
00:19:01, 06 Apr. 5G WiFi scan(Reason:boot)
00:18:58, 06 Apr. System up
00:18:54, 06 Apr. Wire Lan Port 2 up
00:18:43, 06 Apr. 2.4G WPS feature disabled
00:18:43, 06 Apr. 2.4G WPA2 mode selected
00:18:43, 06 Apr. 2.4G WiFi UP
00:18:43, 06 Apr. 5G WPS feature disabled
00:18:43, 06 Apr. 5G WPA2 mode selected
00:18:43, 06 Apr. 5G WiFi UP
00:18:41, 06 Apr. IPv6 Service: DHCP Server stop
00:18:41, 06 Apr. IPv6 Service: RA Server stop

Two nights ago:

02:56:52, 04 Apr. CWMP: HDM socket closed successfully.
02:56:52, 04 Apr. CWMP: HTTP authentication success from pbthdm.x.x.x
02:56:52, 04 Apr. CWMP: HDM socket opened successfully.
02:56:51, 04 Apr. CWMP: session completed successfully
02:56:51, 04 Apr. CWMP: HDM socket closed successfully.
02:56:51, 04 Apr. CWMP: HTTP authentication success from pbthdm.x.x.x
02:56:51, 04 Apr. CWMP: HDM socket opened successfully.
02:56:51, 04 Apr. CWMP: HDM socket opened successfully.
02:56:50, 04 Apr. 2.4G WiFi auto selected channel 1 Bandwidth:20M(Reason:boot)
02:56:49, 04 Apr. CWMP: Server URL: https://pbthdm.x.x.x; Connecting as user: ACS username
02:56:49, 04 Apr. CWMP: Session start now, server: pbthdm.x.x.x, Event code:
02:56:49, 04 Apr. CWMP: Initializing transaction for event code 4 VALUE CHANGE
02:56:46, 04 Apr. 2.4G WiFi scan(Reason:boot)
02:56:46, 04 Apr. 5G WiFi auto selected channel 36 Bandwidth:80M(Reason:boot)
02:56:39, 04 Apr. 5G WiFi scan(Reason:boot)
02:56:38, 04 Apr. CWMP: HDM socket closed successfully.
02:56:38, 04 Apr. CWMP: HTTP authentication success from pbthdm.x.x.x
02:56:37, 04 Apr. CWMP: HDM socket opened successfully.
02:56:37, 04 Apr. CWMP: session completed successfully
02:56:37, 04 Apr. CWMP: HDM socket closed successfully.
02:56:37, 04 Apr. CWMP: HTTP authentication success from pbthdm.x.x.x
02:56:36, 04 Apr. CWMP: HDM socket opened successfully.
02:56:36, 04 Apr. CWMP: HDM socket opened successfully.
02:56:33, 04 Apr. CWMP: Server URL: https://pbthdm.x.x.x; Connecting as user: ACS username
02:56:33, 04 Apr. CWMP: Session start now, server: pbthdm.x.x.x, Event code:
02:56:32, 04 Apr. CWMP: Initializing transaction for event code 1 BOOT
02:56:29, 04 Apr. Receive a DHCP request
02:56:10, 04 Apr. NTP synchronization success
02:56:07, 04 Apr. 5G WiFi auto selected channel 36 Bandwidth:80M(Reason:boot)
02:56:01, 04 Apr. 5G WiFi scan(Reason:boot)
02:56:00, 04 Apr. 2.4G WiFi auto selected channel 1 Bandwidth:20M(Reason:boot)
02:55:56, 04 Apr. NTP synchronization start
02:55:54, 04 Apr. 2.4G WiFi scan(Reason:boot)
02:55:54, 04 Apr. WAN connection PTM connected
02:55:53, 04 Apr. PPP IPCP Receive Configuration ACK
02:55:53, 04 Apr. PPP IPCP Send Configuration Request
02:55:53, 04 Apr. PPP IPCP Receive Configuration NAK
02:55:53, 04 Apr. PPP IPCP Send Configuration ACK
02:55:52, 04 Apr. PPP IPCP Receive Configuration Request
02:55:52, 04 Apr. PPP IPCP Send Configuration Request
02:55:52, 04 Apr. PPP CHAP Receive success : authentication successful
02:55:51, 04 Apr. PPP CHAP Receive Challenge
02:55:51, 04 Apr. PPP LCP Receive Configuration ACK
02:55:51, 04 Apr. PPP LCP Send Configuration ACK
02:55:50, 04 Apr. PPP LCP Receive Configuration Request
02:55:50, 04 Apr. PPP LCP Send Configuration Request
02:55:41, 04 Apr. 2.4G WiFi auto selected channel 1 Bandwidth:20M(Reason:boot)
02:55:37, 04 Apr. 2.4G WiFi scan(Reason:boot)
02:55:37, 04 Apr. 5G WiFi auto selected channel 36 Bandwidth:80M(Reason:boot)
02:55:30, 04 Apr. 5G WiFi scan(Reason:boot)
02:55:25, 04 Apr. DSL Link Up: Down Rate=40000Kbps, Up Rate=9999Kbps; SNR Margin Down=20.1dB, Up=22.6dB
02:55:20, 04 Apr. Booting firmware v0.07.05.0A13-BT (Thu Oct 15 14:28:46 2015)
02:55:20, 04 Apr. System start Button press (PowerButton)
02:55:14, 04 Apr. 5G WiFi auto selected channel 36 Bandwidth:80M(Reason:boot)
02:55:07, 04 Apr. 5G WiFi scan(Reason:boot)
02:55:04, 04 Apr. System up
02:54:59, 04 Apr. Wire Lan Port 2 up
02:54:49, 04 Apr. 2.4G WPS feature disabled
02:54:49, 04 Apr. 2.4G WPA2 mode selected
02:54:49, 04 Apr. 2.4G WiFi UP
02:54:48, 04 Apr. 5G WPS feature disabled
02:54:48, 04 Apr. 5G WPA2 mode selected
02:54:48, 04 Apr. 5G WiFi UP
02:54:47, 04 Apr. IPv6 Service: DHCP Server stop
02:54:47, 04 Apr. IPv6 Service: RA Server stop
02:48:07, 04 Apr. CWMP: HDM socket closed successfully.
02:48:07, 04 Apr. CWMP: HTTP authentication success from pbthdm.x.x.x
02:48:07, 04 Apr. CWMP: HDM socket opened successfully.
02:48:07, 04 Apr. CWMP: session completed successfully
02:48:07, 04 Apr. CWMP: HDM socket closed successfully.
02:48:07, 04 Apr. CWMP: HTTP authentication success from pbthdm.x.x.x
02:48:06, 04 Apr. CWMP: HDM socket opened successfully.
02:48:06, 04 Apr. CWMP: HDM socket opened successfully.
02:48:05, 04 Apr. CWMP: Server URL: https://pbthdm.x.x.x; Connecting as user: ACS username
02:48:05, 04 Apr. CWMP: Session start now, server: pbthdm.x.x.x, Event code:
02:48:05, 04 Apr. CWMP: Initializing transaction for event code 4 VALUE CHANGE
02:47:28, 04 Apr. NTP synchronization success
02:47:14, 04 Apr. NTP synchronization start
02:47:12, 04 Apr. WAN connection PTM connected
02:47:12, 04 Apr. PPP IPCP Receive Configuration ACK
02:47:12, 04 Apr. PPP IPCP Send Configuration Request
02:47:11, 04 Apr. PPP IPCP Receive Configuration NAK
02:47:11, 04 Apr. PPP IPCP Send Configuration ACK
02:47:11, 04 Apr. PPP IPCP Receive Configuration Request
02:47:11, 04 Apr. PPP IPCP Send Configuration Request
02:47:11, 04 Apr. PPP CHAP Receive success : authentication successful
02:47:11, 04 Apr. PPP CHAP Receive Challenge
02:47:10, 04 Apr. PPP LCP Receive Configuration ACK
02:47:10, 04 Apr. PPP LCP Send Configuration ACK
02:47:10, 04 Apr. PPP LCP Receive Configuration Request
02:47:10, 04 Apr. PPP LCP Send Configuration Request

Caged · 6 Apr 2016 at 11:17

Did your hub come from BT? The firmware is newer than the latest published on their website (http://bt.custhelp.com/app/answers/...check-the-firmware-version-on-my-bt-home-hub?) and the same as my BT trial version.

Either this firmware has been released now and the site hasn't been updated, or you've ended up with a trial hub for some reason.

joeyjojo · 6 Apr 2016 at 13:01

Thanks Caged, that's strange. It came from BT. Order was placed on 16/07/15. I haven't opted in to any testing.

davieg · 6 Apr 2016 at 19:00

That firmware for HH5 type B has been out since before christmas last year they've just not bothered updating that site,so its not some trial firmware. Dunno what BT mess around with tbh on the logs mine seems to have less interaction with BT after opting out of the BT free wifi hotspot jobby but still some daft o clock times they seem to have a play around in there.

TheMadDutchDude · 6 Apr 2016 at 19:13

I think they typically try to force an update on the device around 1AM, which is why it usually resets itself. Bar that, I've no idea. Mine used to reset fairly often as well, but it has been on for weeks now with no change. I'll take a look at the connection logs to see if I've got the same remote access going on, as it may be automated and not physically one of their "engineers" at work.

joeyjojo · 7 Apr 2016 at 08:45

Thanks both.

davieg said:
That firmware for HH5 type B has been out since before christmas last year they've just not bothered updating that site,so its not some trial firmware. Dunno what BT mess around with tbh on the logs mine seems to have less interaction with BT after opting out of the BT free wifi hotspot jobby but still some daft o clock times they seem to have a play around in there.

I opted out of BT Wi-fi at the beginning and it shows "not active" on the control panel.

TheMadDutchDude said:
I think they typically try to force an update on the device around 1AM, which is why it usually resets itself. Bar that, I've no idea. Mine used to reset fairly often as well, but it has been on for weeks now with no change. I'll take a look at the connection logs to see if I've got the same remote access going on, as it may be automated and not physically one of their "engineers" at work.

It's a bit annoying as I run stuff that expects 100% uptime. At least it's only for a couple of minutes.