In this case PPPoE session logs from both the BT end and the router.
Like I said and the point seems to have been missed somehow, it's even there in the logs, the PPPoE session is dropping not the VDSL line.
Hi - apologies but I don't know what that means.
I created manually the log files to show only the PPPoE - there is no option to select VDSL on my BT router.
Also, why do the router logs for UPNP/DNS show a change of date to 01 JAN.
00:01:49, 01 Jan.
BR_LAN:UPnP functionality has been activated
00:01:49, 01 Jan.
BR_LAN:UPnP functionality has been deactivated (manually)
00:00:55, 01 Jan.
BR_LAN:UPnP functionality has been activated
The Hub might not have picked up the time from the NTP server, or just kept the logs relative to the default time from when the hub was switched on.
You can get a good idea if the VDSL line droped from the technical info, I have no idea if the recent BT smart hubs reset the Connection uptime on DSL, PPPOE or both. if the time exceeds the last PPPoE drop is safe to assume that the DSL up time exceeds the PPPoE session.
The normal reason for a PPPoE session to drop is the DSL line dropping out or erroring.
would it help if I posted all the router info from the time of the drop out, instead of only the PPPoE which is what I filtered on?
Router Stats?
11:12:51, 25 May.
dsl:VDSL Link Down: duration was 1007 seconds
@Hangerheadwrote:All I get is a pre recorded msg. This number does nor accept income calls.
Just to check you dialled: 17070? You should get "this circuit is defined as (will read out your landline number) , welcome to your Openreach line test facilities" - followed by a list of options. Can you re-dial and check it again?
That number worked - a little bit noisy which is part of previous complaint to BT - gets resolved temporrily and then worsens.
logs for 2 separate dropouts.
11:13:01, 25 May.
wl1:A WiFi device <0C:47:C9:53:13:07> has successfully connected to SSID (Device/WiFi/SSIDs/SSID[WL_PRIV2G])
11:13:00, 25 May.
wl1:Device <0C:47:C9:53:13:07> was disconnected on SSID (Device/WiFi/SSIDs/SSID[WL_PRIV2G])
11:12:58, 25 May.
wl1:(1/6) Channel Hopping initiated/Manually initiated
11:12:55, 25 May.
:VLAN VLAN_DATA disconnected
11:12:55, 25 May.
:Connection to the Internet has been terminated.(Reboot,Reconfiguration,forced termination)
11:12:54, 25 May.
BR_LAN:The LAN DHCPv6 Server is active
11:12:53, 25 May.
ppp1:Connection to the Internet has been terminated.(Reboot,Reconfiguration,forced termination)
11:12:53, 25 May.
ppp1:The DYN ROUTE [81.139.56.100/32 gw 172.16.14.188] is deleted
11:12:53, 25 May.
ppp1:The DYN ROUTE [81.139.57.100/32 gw 172.16.14.188] is deleted
11:12:53, 25 May.
BR_LAN:The LAN DHCPv6 Server is inactive
11:12:52, 25 May.
BR_LAN:The LAN DHCPv6 Server is active
11:12:52, 25 May.
BR_LAN:LAN Router Advertisement Setting Updated : M_flag = 0, O_flag = 1
11:12:52, 25 May.
BR_LAN:The LAN DHCPv6 Server is inactive
11:12:52, 25 May.
ppp1:The WAN DHCPv6 Client Process has successfully been terminated on Vlan 36
11:12:52, 25 May.
BR_LAN:The LAN DHCPv6 Server is active
11:12:52, 25 May.
BR_LAN:The LAN DHCPv6 Server is inactive
11:12:51, 25 May.
BR_LAN: Allocated prefix = fdaa:bbcc:ddee::/64 (valid time = 4293967296 / preferred time = 4293967296)
11:12:51, 25 May.
BR_LAN: Revoked prefix = 2a00:23c6:7487:fb00::/64 (valid time = 2026291200 / preferred time = 2026291200)
11:12:51, 25 May.
ppp1: Revoked prefix = 2a00:23c6:7487:fb01::/64 (valid time = 2026291200 / preferred time = 2026291200)
11:12:51, 25 May.
ppp1: Revoked prefix = 2a00:23c6:7487:fb00::/56 (valid time = 2026291200 / preferred time = 2026291200)
11:12:51, 25 May.
dsl:VDSL Link Down: duration was 1007 seconds
10:56:51, 25 May.
wl1:A WiFi device <A8:DB:03:B1:30:26> has successfully connected to SSID (Device/WiFi/SSIDs/SSID[WL_PRIV2G])
10:56:50, 25 May.
wl0:Device <A8:DB:03:B1:30:26> was disconnected on SSID (Device/WiFi/SSIDs/SSID[WL_PRIV5G])
10:56:49, 25 May.
wl1:Device <A8:DB:03:B1:30:26> was disconnected on SSID (Device/WiFi/SSIDs/SSID[WL_PRIV2G])
10:56:49, 25 May.
wl1:IGMP group 224.0.1.187 on interface wl1 ended by 192.168.1.206
10:56:48, 25 May.
:WAN DHCPv6 Client Prefix : 2a00:23c6:7487:fb00::/56 (valid time = 315360000 / preferred time = 315360000)
10:56:46, 25 May.
BR_LAN:LAN Router Advertisement Setting Updated : M_flag = 0, O_flag = 1
10:56:46, 25 May.
BR_LAN:The LAN DHCPv6 Server is active
10:56:46, 25 May.
BR_LAN: Allocated prefix = fdaa:bbcc:ddee::/64 (valid time = 4293967296 / preferred time = 4293967296)
10:56:46, 25 May.
BR_LAN: Allocated prefix = 2a00:23c6:7487:fb00::/64 (valid time = 2026291200 / preferred time = 2026291200)
10:56:46, 25 May.
BR_LAN: Allocated address = 2a00:23c6:7487:fb00:2620:c7ff:fe66:7c89 (valid time = 2026291200 / preferred time = 2026291200)
10:56:46, 25 May.
BR_LAN: Allocated prefix = 2a00:23c6:7487:fb00::/64 (valid time = 2026291200 / preferred time = 2026291200)
10:56:46, 25 May.
ppp1: Allocated prefix = 2a00:23c6:7487:fb01::/64 (valid time = 2026291200 / preferred time = 2026291200)
10:56:46, 25 May.
ppp1: Allocated prefix = 2a00:23c6:7487:fb00::/56 (valid time = 2026291200 / preferred time = 2026291200)
10:56:46, 25 May.
ppp1: Allocated address = 2a00:23c6:7487:fb01:2620:c7ff:fe66:7c87 (valid time = 2026291200 / preferred time = 2026291200)
10:56:46, 25 May.
ppp1: Allocated prefix = 2a00:23c6:7487:fb01::/64 (valid time = 2026291200 / preferred time = 2026291200)
10:56:46, 25 May.
BR_LAN:The LAN DHCPv6 Server is inactive
10:56:46, 25 May.
ppp1:The WAN DHCPv6 Client Process has successfully been launched on Vlan 36
10:56:45, 25 May.
BR_LAN:LAN Router Advertisement Setting Updated : M_flag = 0, O_flag = 1
10:56:45, 25 May.
BR_LAN:The LAN DHCPv6 Server is active
10:56:45, 25 May.
ppp1: Allocated prefix = 2a00:23c6:7487:fb01::/64 (valid time = 2026291200 / preferred time = 2026291200)
10:56:45, 25 May.
ppp1: Allocated prefix = 2a00:23c6:7487:fb00::/56 (valid time = 2026291200 / preferred time = 2026291200)
10:56:45, 25 May.
ppp1: Allocated address = 2a00:23c6:7487:fb01:2620:c7ff:fe66:7c87 (valid time = 2026291200 / preferred time = 2026291200)
10:56:45, 25 May.
ppp1: Allocated prefix = 2a00:23c6:7487:fb01::/64 (valid time = 2026291200 / preferred time = 2026291200)
10:56:45, 25 May.
BR_LAN: Allocated prefix = fdaa:bbcc:ddee::/64 (valid time = 4293967296 / preferred time = 4293967296)
10:56:45, 25 May.
BR_LAN: Allocated prefix = 2a00:23c6:7487:fb00::/64 (valid time = 2026291200 / preferred time = 2026291200)
10:56:45, 25 May.
BR_LAN: Allocated address = 2a00:23c6:7487:fb00:2620:c7ff:fe66:7c89 (valid time = 2026291200 / preferred time = 2026291200)
10:56:45, 25 May.
BR_LAN: Allocated prefix = 2a00:23c6:7487:fb00::/64 (valid time = 2026291200 / preferred time = 2026291200)
10:56:45, 25 May.
BR_LAN: Allocated prefix = fdaa:bbcc:ddee::/64 (valid time = 4293967296 / preferred time = 4293967296)
10:56:45, 25 May.
BR_LAN: Allocated prefix = 2a00:23c6:7487:fb00::/64 (valid time = 2026291200 / preferred time = 2026291200)
10:56:45, 25 May.
BR_LAN: Allocated address = 2a00:23c6:7487:fb00:2620:c7ff:fe66:7c89 (valid time = 2026291200 / preferred time = 2026291200)
10:56:45, 25 May.
BR_LAN: Allocated prefix = 2a00:23c6:7487:fb00::/64 (valid time = 2026291200 / preferred time = 2026291200)
10:56:45, 25 May.
BR_LAN: Allocated prefix = fdaa:bbcc:ddee::/64 (valid time = 4293967296 / preferred time = 4293967296)
10:56:45, 25 May.
BR_LAN: Allocated prefix = 2a00:23c6:7487:fb00::/64 (valid time = 2026291200 / preferred time = 2026291200)
10:56:45, 25 May.
BR_LAN: Allocated address = 2a00:23c6:7487:fb00:2620:c7ff:fe66:7c89 (valid time = 2026291200 / preferred time = 2026291200)
10:56:45, 25 May.
BR_LAN: Allocated prefix = 2a00:23c6:7487:fb00::/64 (valid time = 2026291200 / preferred time = 2026291200)
10:56:45, 25 May.
BR_LAN:The LAN DHCPv6 Server is inactive
10:56:45, 25 May.
ppp1:WAN DHCPv6 Mode : Statefull
10:56:44, 25 May.
BR_LAN:LAN Router Advertisement Setting Updated : M_flag = 0, O_flag = 1
10:56:44, 25 May.
BR_LAN:The LAN DHCPv6 Server is active
10:56:44, 25 May.
BR_LAN:The LAN DHCPv6 Server is inactive
10:56:44, 25 May.
BR_LAN: Allocated prefix = fdaa:bbcc:ddee::/64 (valid time = 4293967296 / preferred time = 4293967296)
10:56:44, 25 May.
BR_LAN: Allocated prefix = 2a00:23c6:7487:fb00::/64 (valid time = 240000000 / preferred time = 0)
10:56:43, 25 May.
ppp1: Allocated prefix = 2a00:23c6:7487:fb01::/64 (valid time = 240000000 / preferred time = 0)
10:56:43, 25 May.
ppp1: Allocated prefix = 2a00:23c6:7487:fb00::/56 (valid time = 2026291200 / preferred time = 2026291200)
10:56:43, 25 May.
ppp1: Allocated prefix = 2a00:23c6:7487:fb00::/56 (valid time = 2026291200 / preferred time = 2026291200)
10:56:43, 25 May.
:WAN DHCPv6 Client Prefix : 2a00:23c6:7487:fb00::/56 (valid time = 315360000 / preferred time = 315360000)
10:56:43, 25 May.
ppp1:The WAN DHCPv6 Client Process has successfully been terminated on Vlan 36
10:56:43, 25 May.
BR_LAN:The LAN DHCPv6 Server is active
10:56:43, 25 May.
wl0:A WiFi device <A8:DB:03:B1:30:26> has successfully connected to SSID (Device/WiFi/SSIDs/SSID[WL_PRIV5G])
10:56:42, 25 May.
BR_LAN: Allocated prefix = fdaa:bbcc:ddee::/64 (valid time = 4293967296 / preferred time = 4293967296)
10:56:42, 25 May.
BR_LAN: Allocated prefix = 2a00:23c6:7487:fb00::/64 (valid time = 240000000 / preferred time = 0)
10:56:42, 25 May.
BR_LAN: Allocated address = 2a00:23c6:7487:fb00:2620:c7ff:fe66:7c89 (valid time = 2026291200 / preferred time = 2026291200)
10:56:42, 25 May.
BR_LAN: Allocated prefix = 2a00:23c6:7487:fb00::/64 (valid time = 2026291200 / preferred time = 2026291200)
10:56:41, 25 May.
BR_LAN:The LAN DHCPv6 Server is inactive
10:56:41, 25 May.
BR_LAN: Allocated prefix = fdaa:bbcc:ddee::/64 (valid time = 4293967296 / preferred time = 4293967296)
10:56:41, 25 May.
BR_LAN: Allocated prefix = 2a00:23c6:7487:fb00::/64 (valid time = 240000000 / preferred time = 0)
10:56:41, 25 May.
ppp1: Allocated prefix = 2a00:23c6:7487:fb01::/64 (valid time = 240000000 / preferred time = 0)
10:56:41, 25 May.
ppp1: Allocated prefix = 2a00:23c6:7487:fb00::/56 (valid time = 240000000 / preferred time = 0)
10:56:41, 25 May.
ppp1: Allocated prefix = 2a00:23c6:7487:fb00::/56 (valid time = 240000000 / preferred time = 0)
10:56:41, 25 May.
ppp1:WAN Router Discovery Setting Updated : M_flag = 1, O_flag = 0
10:56:41, 25 May.
BR_LAN:LAN Router Advertisement Setting Updated : M_flag = 0, O_flag = 1
10:56:41, 25 May.
BR_LAN:The LAN DHCPv6 Server is active
10:56:40, 25 May.
BR_LAN:The LAN DHCPv6 Server is inactive
10:56:39, 25 May.
:WAN: SENSING AUTO VDSL
10:56:39, 25 May.
BR_LAN:The LAN DHCPv6 Server is active
10:56:39, 25 May.
ppp1:The WAN DHCPv6 Client Process has successfully been launched on Vlan 36
10:56:39, 25 May.
ppp1:New DYN ROUTE is added [81.139.56.100/32 gw 172.16.14.188]
10:56:39, 25 May.
ppp1:New DYN ROUTE is added [81.139.57.100/32 gw 172.16.14.188]
10:56:39, 25 May.
wl1:IGMP join received for group 224.0.1.187 on interface wl1
10:56:39, 25 May.
ppp1:PPP: PPP INFO 81.139.57.100,81.139.56.100
10:56:39, 25 May.
BR_LAN:The LAN DHCPv6 Server is inactive
10:56:39, 25 May.
BR_LAN: Allocated prefix = fdaa:bbcc:ddee::/64 (valid time = 4293967296 / preferred time = 4293967296)
10:56:39, 25 May.
BR_LAN: Allocated prefix = 2a00:23c6:7487:fb00::/64 (valid time = 2026291200 / preferred time = 2026291200)
10:56:38, 25 May.
ppp1: Allocated prefix = 2a00:23c6:7487:fb01::/64 (valid time = 2026291200 / preferred time = 2026291200)
10:56:38, 25 May.
ppp1: Allocated prefix = 2a00:23c6:7487:fb00::/56 (valid time = 2026291200 / preferred time = 2026291200)
10:56:38, 25 May.
ppp1:PPP: PPP INFO
10:56:38, 25 May.
ppp:PPP: IPCP_NAK
10:56:38, 25 May.
ppp:PPP: CHAP_SUCCESS
10:56:38, 25 May.
ppp:PPP: CHAP_RESPONSE
10:56:38, 25 May.
ppp:PPP: LCP_GOOD_ACK
10:56:38, 25 May.
ppp:PPP: LCP_REQUEST
10:56:38, 25 May.
:PPPoE error: timeout
10:56:22, 25 May.
:PPPoE error: timeout
10:56:14, 25 May.
:PPPoE error: timeout
10:56:10, 25 May.
:PPPoE error: timeout
10:56:09, 25 May.
wl1:IGMP join received for group 224.0.1.187 on interface wl1
10:56:09, 25 May.
wl1:IGMP group 224.0.1.187 on interface wl1 started by 192.168.1.206
10:56:09, 25 May.
wl1:IGMP group 224.0.1.187 on interface wl1 by 192.168.1.206 requested
10:56:05, 25 May.
ptm0.101:VLAN VLAN_DATA connected
10:56:05, 25 May.
:connection ATM_TV disconnected.[ERROR_USER_DISCONNECT]
10:56:05, 25 May.
:connection ATM_DATA disconnected.[ERROR_USER_DISCONNECT]
10:56:05, 25 May.
dsl:VDSL link Up: Down Rate=74239Kbps, Up Rate=17000Kbps, SNR Margin Down=0.00dB, SNR Margin Up=6.00dB
10:55:43, 25 May.
wl0:IGMP group 224.0.1.187 on interface wl0 ended by 192.168.1.240
10:55:43, 25 May.
:VLAN VLAN_DATA disconnected
10:55:43, 25 May.
:Connection to the Internet has been terminated.(Reboot,Reconfiguration,forced termination)
10:55:42, 25 May.
BR_LAN:The LAN DHCPv6 Server is active
10:55:42, 25 May.
:Connection to the Internet has been terminated.(Reboot,Reconfiguration,forced termination)
10:55:41, 25 May.
ppp1:The DYN ROUTE [81.139.57.100/32 gw 172.16.14.188] is deleted
10:55:41, 25 May.
ppp1:The DYN ROUTE [81.139.56.100/32 gw 172.16.14.188] is deleted
10:55:41, 25 May.
BR_LAN:The LAN DHCPv6 Server is inactive
10:55:40, 25 May.
BR_LAN:The LAN DHCPv6 Server is active
10:55:40, 25 May.
BR_LAN:LAN Router Advertisement Setting Updated : M_flag = 0, O_flag = 1
10:55:40, 25 May.
BR_LAN:The LAN DHCPv6 Server is inactive
10:55:40, 25 May.
ppp1:The WAN DHCPv6 Client Process has successfully been terminated on Vlan 36
10:55:40, 25 May.
BR_LAN:The LAN DHCPv6 Server is active
10:55:40, 25 May.
BR_LAN:The LAN DHCPv6 Server is inactive
10:55:40, 25 May.
BR_LAN: Allocated prefix = fdaa:bbcc:ddee::/64 (valid time = 4293967296 / preferred time = 4293967296)
10:55:40, 25 May.
BR_LAN: Revoked prefix = 2a00:23c6:7487:fb00::/64 (valid time = 2026291200 / preferred time = 2026291200)
10:55:39, 25 May.
ppp1: Revoked prefix = 2a00:23c6:7487:fb01::/64 (valid time = 2026291200 / preferred time = 2026291200)
10:55:39, 25 May.
ppp1: Revoked prefix = 2a00:23c6:7487:fb00::/56 (valid time = 2026291200 / preferred time = 2026291200)
10:55:39, 25 May.
dsl:VDSL Link Down: duration was 482 seconds
10:55:33, 25 May.
wl0:Device <D0:C5:F3:0C:5A:32> was disconnected on SSID (Device/WiFi/SSIDs/SSID[WL_PRIV5G])
10:54:34, 25 May.
wl1:IGMP join received for group 224.0.1.187 on interface wl1
10:54:34, 25 May.
wl1:IGMP group 224.0.1.187 on interface wl1 started by 192.168.1.206
10:54:34, 25 May.
wl1:IGMP group 224.0.1.187 on interface wl1 by 192.168.1.206 requested
10:53:37, 25 May.
wl0:Device <38:53:9C:90:B2:C8> was disconnected on SSID (Device/WiFi/SSIDs/SSID[WL_PRIV5G])
10:53:34, 25 May.
wl0:Device <A8:DB:03:B1:30:26> was disconnected on SSID (Device/WiFi/SSIDs/SSID[WL_PRIV5G])
Router Stats:
(NOISE Margin looks high?)
BT Hub 6A
+084316+xxxxx
SG4B1000E020
27-Mar-2020
1.0
1.115.0
1 Days, 0 Hours 57 Minutes 33 Seconds
17.00 Mbps / 49.00 Mbps
29464 / 78027
14.1 dB / 13.8 dB
21 dB
13.4 dB / 21 dB
0/38
G_993_2_ANNEX_B
Fast Path
9 GB Uploaded / 24 GB Downloaded
bthomehub@btbroadband.com
Active
xxxxx
Smart (Channel 1)
xxxx
Smart (Channel 36)
WPA2 (Recommended)
Mode 1
On
xxxx
-
7.33.1