Billion 8800AXL - R2 - IPv6 now failing!

[andruec]

So in the early hours of this morning my router dropped IPV6. IPv4 was unaffected. I've contacted my ISP and their response is:

'Does the router show anything in the log? We can see the IPv4 session remained up throughout but had made a request for IPv6 at 02:53 this morning'

Unfortunately by the time I got home the log had discarded entries from that time. However what I can see in the log is loads of:

May 10 03:14:08 daemon warn radvd[20656]: received RA from <censored by me>

With the occasional:

May 10 07:02:48 daemon warn radvd[20656]: received RS from

And IPv6 is still down.

[andruec]

Okay. I've disconnected and reconnected (and got an IPv6) so here's the log:

May 10 19:26:49 daemon notice syslog: pppd:Terminating connection due to link down.
May 10 19:26:49 daemon crit syslog: Clear IP addresses. PPP connection DOWN.
May 10 19:26:49 daemon crit syslog: Clear IP addresses. Connection DOWN.
May 10 19:26:49 daemon info radvd[20656]: attempting to reread config file
May 10 19:26:49 daemon notice syslog: pppd:Couldn't increase MTU to 1500.
May 10 19:26:49 daemon err syslog: pppd:Couldn't increase MRU to 1500
May 10 19:26:49 daemon notice syslog: pppd:Connection terminated.
May 10 19:26:49 daemon notice syslog: pppd:Connect time 1233.5 minutes.
May 10 19:26:49 daemon notice syslog: pppd:Sent 21389031 bytes, received 56803202 bytes.
May 10 19:26:49 daemon info radvd[20656]: resuming normal operation
May 10 19:26:49 daemon warn radvd[20656]: received RA from <censored by me 1>
May 10 19:26:49 daemon info radvd[20656]: attempting to reread config file
May 10 19:26:49 daemon info radvd[20656]: resuming normal operation
May 10 19:26:49 daemon warn radvd[20656]: received RA from <censored by me 1>
May 10 19:26:49 daemon notice syslog: pppd:Doing disconnect
May 10 19:26:57 daemon notice syslog: PPP: Start to connect ...
May 10 19:26:57 daemon crit syslog: session disconnect pppoe.oldsession=10e878a7a1bc/041c
May 10 19:27:01 daemon crit syslog: PPP server detected.
May 10 19:27:01 daemon crit syslog: PPP session established.
May 10 19:27:01 daemon info radvd[20656]: attempting to reread config file
May 10 19:27:01 kern warn kernel: netdev path : ppp2.1 ->
May 10 19:27:01 kern info kernel: eth4.1
May 10 19:27:01 kern info kernel: ->
May 10 19:27:01 kern info kernel: eth4
May 10 19:27:01 daemon notice syslog: pppd:Using interface ppp2.1
May 10 19:27:01 daemon notice syslog: pppd:Connect: ppp2.1 <--> eth4.1
May 10 19:27:01 daemon notice syslog: pppd:Couldn't increase MTU to 1500.
May 10 19:27:01 daemon err syslog: pppd:Couldn't increase MRU to 1500
May 10 19:27:01 daemon info radvd[20656]: resuming normal operation
May 10 19:27:01 daemon warn radvd[20656]: received RA from <censored by me 1>
May 10 19:27:01 daemon err syslog: pppd:Couldn't increase MRU to 1500
May 10 19:27:01 daemon crit syslog: PPP LCP UP.
May 10 19:27:02 daemon notice syslog: pppd:Couldn't increase MTU to 1500.
May 10 19:27:02 daemon err syslog: pppd:Couldn't increase MRU to 1500
May 10 19:27:02 daemon err syslog: pppd:Couldn't increase MRU to 1500
May 10 19:27:02 daemon crit syslog: PPP LCP UP.
May 10 19:27:02 daemon info radvd[20656]: attempting to reread config file
May 10 19:27:02 daemon notice syslog: pppd:local LL address fe80::8dc3:9ad8:c61e:e965
May 10 19:27:02 daemon notice syslog: pppd:remote LL address fe80::0227:e3ff:fe77:b100
May 10 19:27:02 daemon info radvd[20656]: resuming normal operation
May 10 19:27:02 daemon warn radvd[20656]: received RA from <censored by me 1>
May 10 19:27:02 daemon notice syslog: pppd:local IP address <censored by me 2>
May 10 19:27:02 daemon notice syslog: pppd:remote IP address 212.69.63.36
May 10 19:27:02 daemon notice syslog: pppd:primary DNS address 212.69.40.23
May 10 19:27:02 daemon notice syslog: pppd:secondary DNS address 212.69.36.23
May 10 19:27:02 daemon crit syslog: Received valid IP address from server. Connection UP.
May 10 19:27:02 daemon info syslog: Hop limit : 64
May 10 19:27:02 daemon info syslog: Stateful address conf. : No
May 10 19:27:02 daemon info syslog: Stateful other conf. : No
May 10 19:27:02 daemon info syslog: Router preference : medium
May 10 19:27:02 daemon info syslog: Router lifetime : 1800 seconds
May 10 19:27:02 daemon info syslog: Reachable time : 0 milliseconds
May 10 19:27:02 daemon info syslog: Retransmit time : 0 milliseconds
May 10 19:27:02 daemon info syslog: Prefix : <censored by me>::/64
May 10 19:27:02 daemon info syslog: Valid time : 2592000 seconds
May 10 19:27:02 daemon info syslog: Pref. time : 604800 seconds
May 10 19:27:12 daemon info syslog: Hop limit : 64
May 10 19:27:12 daemon info syslog: Stateful address conf. : No
May 10 19:27:12 daemon info syslog: Stateful other conf. : No
May 10 19:27:12 daemon info syslog: Router preference : medium
May 10 19:27:12 daemon info syslog: Router lifetime : 1800 seconds
May 10 19:27:12 daemon info syslog: Reachable time : 0 milliseconds
May 10 19:27:12 daemon info syslog: Retransmit time : 0 milliseconds
May 10 19:27:12 daemon info syslog: Prefix : <censored by me>::/64
May 10 19:27:12 daemon info syslog: Valid time : 2592000 seconds
May 10 19:27:12 daemon info syslog: Pref. time : 604800 seconds
May 10 19:27:13 daemon info syslog: dhcp6c restart..
May 10 19:27:18 daemon warn radvd[20656]: received RA from <censored by me 1>
May 10 19:27:26 daemon warn radvd[20656]: poll error: Interrupted system call
May 10 19:27:26 daemon warn radvd[20656]: Exiting, sigterm received.
May 10 19:27:27 daemon info radvd[25163]: version 1.8 started
May 10 19:27:27 daemon warn radvd[25163]: received RA from <censored by me 1>
May 10 19:27:28 daemon warn radvd[25163]: poll error: Interrupted system call
May 10 19:27:28 daemon warn radvd[25163]: Exiting, sigterm received.
May 10 19:27:29 daemon info radvd[25220]: version 1.8 started
May 10 19:27:29 daemon warn radvd[25220]: received RA from <censored by me 1>
May 10 19:27:29 daemon warn radvd[25220]: poll error: Interrupted system call
May 10 19:27:29 daemon warn radvd[25220]: Exiting, sigterm received.
May 10 19:27:30 daemon info radvd[25235]: version 1.8 started
May 10 19:27:30 daemon warn radvd[25235]: received RA from <censored by me 1>
May 10 19:27:30 daemon warn radvd[25235]: poll error: Interrupted system call
May 10 19:27:30 daemon warn radvd[25235]: Exiting, sigterm received.
May 10 19:27:31 daemon info radvd[25261]: version 1.8 started
May 10 19:27:31 daemon warn radvd[25261]: received RA from <censored by me 1>
May 10 19:27:32 daemon warn radvd[25261]: poll error: Interrupted system call
May 10 19:27:32 daemon warn radvd[25261]: Exiting, sigterm received.
May 10 19:27:33 daemon info radvd[25287]: version 1.8 started
May 10 19:27:33 daemon warn radvd[25287]: received RA from <censored by me 1>
May 10 19:27:49 daemon warn radvd[25287]: received RA from <censored by me 1>
May 10 19:28:05 daemon warn radvd[25287]: received RA from <censored by me 1>
May 10 19:28:21 daemon warn radvd[25287]: received RA from <censored by me 1>

[billion_fan]

Okay. I've disconnected and reconnected (and got an IPv6) so here's the log:

May 10 19:26:49 daemon notice syslog: pppd:Terminating connection due to link down.
May 10 19:26:49 daemon crit syslog: Clear IP addresses. PPP connection DOWN.
May 10 19:26:49 daemon crit syslog: Clear IP addresses. Connection DOWN.
May 10 19:26:49 daemon info radvd[20656]: attempting to reread config file
May 10 19:26:49 daemon notice syslog: pppd:Couldn't increase MTU to 1500.
May 10 19:26:49 daemon err syslog: pppd:Couldn't increase MRU to 1500
May 10 19:26:49 daemon notice syslog: pppd:Connection terminated.
May 10 19:26:49 daemon notice syslog: pppd:Connect time 1233.5 minutes.
May 10 19:26:49 daemon notice syslog: pppd:Sent 21389031 bytes, received 56803202 bytes.
May 10 19:26:49 daemon info radvd[20656]: resuming normal operation
May 10 19:26:49 daemon warn radvd[20656]: received RA from <censored by me 1>
May 10 19:26:49 daemon info radvd[20656]: attempting to reread config file
May 10 19:26:49 daemon info radvd[20656]: resuming normal operation
May 10 19:26:49 daemon warn radvd[20656]: received RA from <censored by me 1>
May 10 19:26:49 daemon notice syslog: pppd:Doing disconnect
May 10 19:26:57 daemon notice syslog: PPP: Start to connect ...
May 10 19:26:57 daemon crit syslog: session disconnect pppoe.oldsession=10e878a7a1bc/041c
May 10 19:27:01 daemon crit syslog: PPP server detected.
May 10 19:27:01 daemon crit syslog: PPP session established.
May 10 19:27:01 daemon info radvd[20656]: attempting to reread config file
May 10 19:27:01 kern warn kernel: netdev path : ppp2.1 ->
May 10 19:27:01 kern info kernel: eth4.1
May 10 19:27:01 kern info kernel: ->
May 10 19:27:01 kern info kernel: eth4
May 10 19:27:01 daemon notice syslog: pppd:Using interface ppp2.1
May 10 19:27:01 daemon notice syslog: pppd:Connect: ppp2.1 <--> eth4.1
May 10 19:27:01 daemon notice syslog: pppd:Couldn't increase MTU to 1500.
May 10 19:27:01 daemon err syslog: pppd:Couldn't increase MRU to 1500
May 10 19:27:01 daemon info radvd[20656]: resuming normal operation
May 10 19:27:01 daemon warn radvd[20656]: received RA from <censored by me 1>
May 10 19:27:01 daemon err syslog: pppd:Couldn't increase MRU to 1500
May 10 19:27:01 daemon crit syslog: PPP LCP UP.
May 10 19:27:02 daemon notice syslog: pppd:Couldn't increase MTU to 1500.
May 10 19:27:02 daemon err syslog: pppd:Couldn't increase MRU to 1500
May 10 19:27:02 daemon err syslog: pppd:Couldn't increase MRU to 1500
May 10 19:27:02 daemon crit syslog: PPP LCP UP.
May 10 19:27:02 daemon info radvd[20656]: attempting to reread config file
May 10 19:27:02 daemon notice syslog: pppd:local LL address fe80::8dc3:9ad8:c61e:e965
May 10 19:27:02 daemon notice syslog: pppd:remote LL address fe80::0227:e3ff:fe77:b100
May 10 19:27:02 daemon info radvd[20656]: resuming normal operation
May 10 19:27:02 daemon warn radvd[20656]: received RA from <censored by me 1>
May 10 19:27:02 daemon notice syslog: pppd:local IP address <censored by me 2>
May 10 19:27:02 daemon notice syslog: pppd:remote IP address 212.69.63.36
May 10 19:27:02 daemon notice syslog: pppd:primary DNS address 212.69.40.23
May 10 19:27:02 daemon notice syslog: pppd:secondary DNS address 212.69.36.23
May 10 19:27:02 daemon crit syslog: Received valid IP address from server. Connection UP.
May 10 19:27:02 daemon info syslog: Hop limit : 64
May 10 19:27:02 daemon info syslog: Stateful address conf. : No
May 10 19:27:02 daemon info syslog: Stateful other conf. : No
May 10 19:27:02 daemon info syslog: Router preference : medium
May 10 19:27:02 daemon info syslog: Router lifetime : 1800 seconds
May 10 19:27:02 daemon info syslog: Reachable time : 0 milliseconds
May 10 19:27:02 daemon info syslog: Retransmit time : 0 milliseconds
May 10 19:27:02 daemon info syslog: Prefix : <censored by me>::/64
May 10 19:27:02 daemon info syslog: Valid time : 2592000 seconds
May 10 19:27:02 daemon info syslog: Pref. time : 604800 seconds
May 10 19:27:12 daemon info syslog: Hop limit : 64
May 10 19:27:12 daemon info syslog: Stateful address conf. : No
May 10 19:27:12 daemon info syslog: Stateful other conf. : No
May 10 19:27:12 daemon info syslog: Router preference : medium
May 10 19:27:12 daemon info syslog: Router lifetime : 1800 seconds
May 10 19:27:12 daemon info syslog: Reachable time : 0 milliseconds
May 10 19:27:12 daemon info syslog: Retransmit time : 0 milliseconds
May 10 19:27:12 daemon info syslog: Prefix : <censored by me>::/64
May 10 19:27:12 daemon info syslog: Valid time : 2592000 seconds
May 10 19:27:12 daemon info syslog: Pref. time : 604800 seconds
May 10 19:27:13 daemon info syslog: dhcp6c restart..
May 10 19:27:18 daemon warn radvd[20656]: received RA from <censored by me 1>
May 10 19:27:26 daemon warn radvd[20656]: poll error: Interrupted system call
May 10 19:27:26 daemon warn radvd[20656]: Exiting, sigterm received.
May 10 19:27:27 daemon info radvd[25163]: version 1.8 started
May 10 19:27:27 daemon warn radvd[25163]: received RA from <censored by me 1>
May 10 19:27:28 daemon warn radvd[25163]: poll error: Interrupted system call
May 10 19:27:28 daemon warn radvd[25163]: Exiting, sigterm received.
May 10 19:27:29 daemon info radvd[25220]: version 1.8 started
May 10 19:27:29 daemon warn radvd[25220]: received RA from <censored by me 1>
May 10 19:27:29 daemon warn radvd[25220]: poll error: Interrupted system call
May 10 19:27:29 daemon warn radvd[25220]: Exiting, sigterm received.
May 10 19:27:30 daemon info radvd[25235]: version 1.8 started
May 10 19:27:30 daemon warn radvd[25235]: received RA from <censored by me 1>
May 10 19:27:30 daemon warn radvd[25235]: poll error: Interrupted system call
May 10 19:27:30 daemon warn radvd[25235]: Exiting, sigterm received.
May 10 19:27:31 daemon info radvd[25261]: version 1.8 started
May 10 19:27:31 daemon warn radvd[25261]: received RA from <censored by me 1>
May 10 19:27:32 daemon warn radvd[25261]: poll error: Interrupted system call
May 10 19:27:32 daemon warn radvd[25261]: Exiting, sigterm received.
May 10 19:27:33 daemon info radvd[25287]: version 1.8 started
May 10 19:27:33 daemon warn radvd[25287]: received RA from <censored by me 1>
May 10 19:27:49 daemon warn radvd[25287]: received RA from <censored by me 1>
May 10 19:28:05 daemon warn radvd[25287]: received RA from <censored by me 1>
May 10 19:28:21 daemon warn radvd[25287]: received RA from <censored by me 1>

It looks fine to me

[andruec]

Okay. Well I've adjusted the logging to be less verbose and hopefully will eventually be able to post more information. For what it's worth my ISP's latest comment is:

'Does the router have a DHCPv6 lease time you can set? Most routers we see, the routers send renew requests each hour but for your connection we only see 3 or 4 requests a day'. Also when the connection dropped at 0257 yesterday they say that a request for an IPv6 address was seen and a response sent.

So it seems like the router either ignored the response or in attempting to update the connection it failed.

Hopefully next time we'll have more information but I still find it very odd that when this happens it always happens at the same time (2am UTC) :-/

The router doesn't have any kind of housekeeping configured for that time, does it?

[billion_fan]

Okay. Well I've adjusted the logging to be less verbose and hopefully will eventually be able to post more information. For what it's worth my ISP's latest comment is:

'Does the router have a DHCPv6 lease time you can set? Most routers we see, the routers send renew requests each hour but for your connection we only see 3 or 4 requests a day'. Also when the connection dropped at 0257 yesterday they say that a request for an IPv6 address was seen and a response sent.

So it seems like the router either ignored the response or in attempting to update the connection it failed.

Hopefully next time we'll have more information but I still find it very odd that when this happens it always happens at the same time (2am UTC) :-/

The router doesn't have any kind of housekeeping configured for that time, does it?

Not that I am aware, like your ISP stated, the request was made by the router, we will no more once we can have a look at the logs

Also I assume you are on latest version of firmware (not the test firmware)

I will put a unit up on test with our ISP Zen and report back on Monday

[andruec]

Yes, I'm on 2.52.d10 (downloaded from http://www.billion.uk.com/esupport/inde ... ion-252d10 ).

It's also odd that the 8800NL R2 was doing the same thing (although most of the time that router crashed completely) which was why I replaced it. That router was running slightly old firmware - something released around December 2016 I think. I hadn't updated it because there was a warning about having to do a factory reset and I didn't want the hassle. I decided it was easier to get another router so I could compare config pages side by side.

[billion_fan]

Yes, I'm on 2.52.d10 (downloaded from http://www.billion.uk.com/esupport/inde ... ion-252d10 ).

It's also odd that the 8800NL R2 was doing the same thing (although most of the time that router crashed completely) which was why I replaced it. That router was running slightly old firmware - something released around December 2016 I think. I hadn't updated it because there was a warning about having to do a factory reset and I didn't want the hassle. I decided it was easier to get another router so I could compare config pages side by side.

IDnet should be able to investigate, as 8800NL R2 is a official router they sell, the 8800AXL R2 has almost the same firmware

I'll report back my results on Monday, just to confirm

[billion_fan]

Yes, I'm on 2.52.d10 (downloaded from http://www.billion.uk.com/esupport/inde ... ion-252d10 ).

It's also odd that the 8800NL R2 was doing the same thing (although most of the time that router crashed completely) which was why I replaced it. That router was running slightly old firmware - something released around December 2016 I think. I hadn't updated it because there was a warning about having to do a factory reset and I didn't want the hassle. I decided it was easier to get another router so I could compare config pages side by side.

IDnet should be able to investigate, as 8800NL R2 is a official router they sell, the 8800AXL R2 has almost the same firmware

I'll report back my results on Monday, just to confirm

No problem with my unit 2 days 22 hours up and the router still have a IPv6 address assigned

[andruec]

Not yet with mine after the previous fail. With the old router it seemed to happen every month or so. Next time it happens I will hopefully have the logs. At present I'd lose them if this router crashes like the old one did but as part of a server rebuild I'm setting up a Syslog server so hopefully if I can get the router logging to that at least some of the entries will survive.