IPv6 DHCP client has ceased working

ewoodzy · November 1, 2018, 2:02pm

Hello

I have recently run into an issue where IPv6 prefix delegation has ceased working on my router. When I enable the IPv6 DHCP client, the status will remain in “requesting…” for a while before finally changing to “error”.

If I enable logging options that will let me see what is going on, it appears that the router does receive an prefix, but for some reason does not acknowledge it, retries a couple of times, then fails. I even reproduced this on another router with an otherwise default configuration. Below is that configuration and the relevant logging in a single code block. I’ve only scrubbed part of the IPv6 address in the logs.

## ROUTEROS CONFIGURATION ##

# nov/02/2018 00:51:19 by RouterOS 6.43.4
/interface bridge
add admin-mac=CC:2D:E0:7B:46:05 auto-mac=no comment=defconf name=bridge
/interface wireless
set [ find default-name=wlan1 ] band=2ghz-b/g/n channel-width=20/40mhz-Ce \
    disabled=no distance=indoors frequency=auto mode=ap-bridge ssid=\
    MikroTik-7B4607 wireless-protocol=802.11
/interface list
add comment=defconf name=WAN
add comment=defconf name=LAN
/interface wireless security-profiles
set [ find default=yes ] supplicant-identity=MikroTik
/ip pool
add name=default-dhcp ranges=192.168.88.10-192.168.88.254
/ip dhcp-server
add address-pool=default-dhcp disabled=no interface=bridge name=defconf
/interface bridge port
add bridge=bridge comment=defconf interface=ether2
add bridge=bridge comment=defconf interface=wlan1
/ip neighbor discovery-settings
set discover-interface-list=LAN
/interface list member
add comment=defconf interface=bridge list=LAN
add comment=defconf interface=ether1 list=WAN
/ip address
add address=192.168.88.1/24 comment=defconf interface=bridge network=\
    192.168.88.0
/ip dhcp-client
add comment=defconf dhcp-options=hostname,clientid disabled=no interface=ether1
/ip dhcp-server network
add address=192.168.88.0/24 comment=defconf gateway=192.168.88.1
/ip dns
set allow-remote-requests=yes
/ip dns static
add address=192.168.88.1 name=router.lan
/ip firewall filter
add action=accept chain=input comment=\
    "defconf: accept established,related,untracked" connection-state=\
    established,related,untracked
add action=drop chain=input comment="defconf: drop invalid" connection-state=\
    invalid
add action=accept chain=input comment="defconf: accept ICMP" protocol=icmp
add action=drop chain=input comment="defconf: drop all not coming from LAN" \
    in-interface-list=!LAN
add action=accept chain=forward comment="defconf: accept in ipsec policy" \
    ipsec-policy=in,ipsec
add action=accept chain=forward comment="defconf: accept out ipsec policy" \
    ipsec-policy=out,ipsec
add action=fasttrack-connection chain=forward comment="defconf: fasttrack" \
    connection-state=established,related
add action=accept chain=forward comment=\
    "defconf: accept established,related, untracked" connection-state=\
    established,related,untracked
add action=drop chain=forward comment="defconf: drop invalid" connection-state=\
    invalid
add action=drop chain=forward comment=\
    "defconf:  drop all from WAN not DSTNATed" connection-nat-state=!dstnat \
    connection-state=new in-interface-list=WAN
/ip firewall nat
add action=masquerade chain=srcnat comment="defconf: masquerade" ipsec-policy=\
    out,none out-interface-list=WAN
/ipv6 dhcp-client
add add-default-route=yes interface=ether1 pool-name=telstra-pd request=prefix
/ipv6 firewall address-list
add address=::/128 comment="defconf: unspecified address" list=bad_ipv6
add address=::1/128 comment="defconf: lo" list=bad_ipv6
add address=fec0::/10 comment="defconf: site-local" list=bad_ipv6
add address=::ffff:0.0.0.0/96 comment="defconf: ipv4-mapped" list=bad_ipv6
add address=::/96 comment="defconf: ipv4 compat" list=bad_ipv6
add address=100::/64 comment="defconf: discard only " list=bad_ipv6
add address=2001:db8::/32 comment="defconf: documentation" list=bad_ipv6
add address=2001:10::/28 comment="defconf: ORCHID" list=bad_ipv6
add address=3ffe::/16 comment="defconf: 6bone" list=bad_ipv6
add address=::224.0.0.0/100 comment="defconf: other" list=bad_ipv6
add address=::127.0.0.0/104 comment="defconf: other" list=bad_ipv6
add address=::/104 comment="defconf: other" list=bad_ipv6
add address=::255.0.0.0/104 comment="defconf: other" list=bad_ipv6
/ipv6 firewall filter
add action=accept chain=input comment=\
    "defconf: accept established,related,untracked" connection-state=\
    established,related,untracked
add action=drop chain=input comment="defconf: drop invalid" connection-state=\
    invalid
add action=accept chain=input comment="defconf: accept ICMPv6" protocol=icmpv6
add action=accept chain=input comment="defconf: accept UDP traceroute" port=\
    33434-33534 protocol=udp
add action=accept chain=input comment=\
    "defconf: accept DHCPv6-Client prefix delegation." dst-port=546 protocol=\
    udp src-address=fe80::/16
add action=accept chain=input comment="defconf: accept IKE" dst-port=500,4500 \
    protocol=udp
add action=accept chain=input comment="defconf: accept ipsec AH" protocol=\
    ipsec-ah
add action=accept chain=input comment="defconf: accept ipsec ESP" protocol=\
    ipsec-esp
add action=accept chain=input comment=\
    "defconf: accept all that matches ipsec policy" ipsec-policy=in,ipsec
add action=drop chain=input comment=\
    "defconf: drop everything else not coming from LAN" in-interface-list=!LAN
add action=accept chain=forward comment=\
    "defconf: accept established,related,untracked" connection-state=\
    established,related,untracked
add action=drop chain=forward comment="defconf: drop invalid" connection-state=\
    invalid
add action=drop chain=forward comment="defconf: drop packets with bad src ipv6" \
    src-address-list=bad_ipv6
add action=drop chain=forward comment="defconf: drop packets with bad dst ipv6" \
    dst-address-list=bad_ipv6
add action=drop chain=forward comment="defconf: rfc4890 drop hop-limit=1" \
    hop-limit=equal:1 protocol=icmpv6
add action=accept chain=forward comment="defconf: accept ICMPv6" protocol=\
    icmpv6
add action=accept chain=forward comment="defconf: accept HIP" protocol=139
add action=accept chain=forward comment="defconf: accept IKE" dst-port=500,4500 \
    protocol=udp
add action=accept chain=forward comment="defconf: accept ipsec AH" protocol=\
    ipsec-ah
add action=accept chain=forward comment="defconf: accept ipsec ESP" protocol=\
    ipsec-esp
add action=accept chain=forward comment=\
    "defconf: accept all that matches ipsec policy" ipsec-policy=in,ipsec
add action=drop chain=forward comment=\
    "defconf: drop everything else not coming from LAN" in-interface-list=!LAN
/system clock
set time-zone-name=Australia/Melbourne
/system logging
add topics=dhcp
/system routerboard settings
set silent-boot=no
/tool mac-server
set allowed-interface-list=LAN
/tool mac-server mac-winbox
set allowed-interface-list=LAN

## DHCP LOGGING ##

nov/02 00:53:54 dhcp,debug discovering... 
nov/02 00:53:54 dhcp,debug,packet send ether1 -> ff02::1:2%6 
nov/02 00:53:54 dhcp,debug,packet type: solicit 
nov/02 00:53:54 dhcp,debug,packet transaction-id: b90b1e 
nov/02 00:53:54 dhcp,debug,packet  -> clientid:   00030001 cc2de07b 4604 
nov/02 00:53:54 dhcp,debug,packet  -> oro: 23  
nov/02 00:53:54 dhcp,debug,packet  -> elapsed_time: 0 
nov/02 00:53:54 dhcp,debug,packet  -> rapid_commit: [empty] 
nov/02 00:53:54 dhcp,debug,packet  -> ia_pd:  
nov/02 00:53:54 dhcp,debug,packet    t1: 1800 
nov/02 00:53:54 dhcp,debug,packet    t2: 2880 
nov/02 00:53:54 dhcp,debug,packet    id: 0x2 
nov/02 00:53:54 dhcp,debug,packet recv client: ether1 fe80::3e94:d5ff:fe2c:6015 ->
 fe80::ce2d:e0ff:fe7b:4604 
nov/02 00:53:54 dhcp,debug,packet type: advertise 
nov/02 00:53:54 dhcp,debug,packet transaction-id: b90b1e 
nov/02 00:53:54 dhcp,debug,packet  -> clientid:   00030001 cc2de07b 4604 
nov/02 00:53:54 dhcp,debug,packet  -> serverid:   00010001 20dd4deb 00144ffa d708 
nov/02 00:53:54 dhcp,debug,packet  -> vendor_opts:   00000440 00020030 52553544 55
48746a 4e576f57 414a6d48 536a6c33 2b46792b 
nov/02 00:53:54 dhcp,debug,packet 6f455a53 764e7938 77567041 7575334f 74454272 764
2773d 
nov/02 00:53:54 dhcp,debug,packet  -> ia_pd:  
nov/02 00:53:54 dhcp,debug,packet    t1: 7101 
nov/02 00:53:54 dhcp,debug,packet    t2: 11361 
nov/02 00:53:54 dhcp,debug,packet    id: 0x2 
nov/02 00:53:54 dhcp,debug,packet   -> ia_prefix:  
nov/02 00:53:54 dhcp,debug,packet     prefix: 2001:8003:####:####::/56 
nov/02 00:53:54 dhcp,debug,packet     valid time: 14202 
nov/02 00:53:54 dhcp,debug,packet     pref. time: 14202 
nov/02 00:53:54 dhcp,debug handle advertise 
nov/02 00:53:54 dhcp,debug ia_pd 2001:8003:####:####:: recorded 
nov/02 00:53:55 dhcp,debug using recorded advertise 
nov/02 00:53:55 dhcp,debug,packet send ether1 -> ff02::1:2%6 
nov/02 00:53:55 dhcp,debug,packet type: request 
nov/02 00:53:55 dhcp,debug,packet transaction-id: 50d410 
nov/02 00:53:55 dhcp,debug,packet  -> clientid:   00030001 cc2de07b 4604 
nov/02 00:53:55 dhcp,debug,packet  -> serverid:   00010001 20dd4deb 00144ffa d708 
nov/02 00:53:55 dhcp,debug,packet  -> oro: 23  
nov/02 00:53:55 dhcp,debug,packet  -> elapsed_time: 0 
nov/02 00:53:55 dhcp,debug,packet  -> ia_pd:  
nov/02 00:53:55 dhcp,debug,packet    t1: 7101 
nov/02 00:53:55 dhcp,debug,packet    t2: 11361 
nov/02 00:53:55 dhcp,debug,packet    id: 0x2 
nov/02 00:53:55 dhcp,debug,packet   -> ia_prefix:  
nov/02 00:53:55 dhcp,debug,packet     prefix: 2001:8003:####:####::/56 
nov/02 00:53:55 dhcp,debug,packet     valid time: 14202 
nov/02 00:53:55 dhcp,debug,packet     pref. time: 14202 
nov/02 00:53:56 dhcp,debug resending.. 
nov/02 00:53:56 dhcp,debug,packet send ether1 -> ff02::1:2%6 
nov/02 00:53:56 dhcp,debug,packet type: request 
nov/02 00:53:56 dhcp,debug,packet transaction-id: 50d410 
nov/02 00:53:56 dhcp,debug,packet  -> clientid:   00030001 cc2de07b 4604 
nov/02 00:53:56 dhcp,debug,packet  -> serverid:   00010001 20dd4deb 00144ffa d708 
nov/02 00:53:56 dhcp,debug,packet  -> oro: 23  
nov/02 00:53:56 dhcp,debug,packet  -> elapsed_time: 1 
nov/02 00:53:56 dhcp,debug,packet  -> ia_pd:  
nov/02 00:53:56 dhcp,debug,packet    t1: 7101 
nov/02 00:53:56 dhcp,debug,packet    t2: 11361 
nov/02 00:53:56 dhcp,debug,packet    id: 0x2 
nov/02 00:53:56 dhcp,debug,packet   -> ia_prefix:  
nov/02 00:53:56 dhcp,debug,packet     prefix: 2001:8003:####:####::/56 
nov/02 00:53:56 dhcp,debug,packet     valid time: 14202 
nov/02 00:53:56 dhcp,debug,packet     pref. time: 14202 
nov/02 00:53:58 dhcp,debug resending.. 
nov/02 00:53:58 dhcp,debug,packet send ether1 -> ff02::1:2%6 
nov/02 00:53:58 dhcp,debug,packet type: request 
nov/02 00:53:58 dhcp,debug,packet transaction-id: 50d410 
nov/02 00:53:58 dhcp,debug,packet  -> clientid:   00030001 cc2de07b 4604 
nov/02 00:53:58 dhcp,debug,packet  -> serverid:   00010001 20dd4deb 00144ffa d708 
nov/02 00:53:58 dhcp,debug,packet  -> oro: 23  
nov/02 00:53:58 dhcp,debug,packet  -> elapsed_time: 3 
nov/02 00:53:58 dhcp,debug,packet  -> ia_pd:  
nov/02 00:53:58 dhcp,debug,packet    t1: 7101 
nov/02 00:53:58 dhcp,debug,packet    t2: 11361 
nov/02 00:53:58 dhcp,debug,packet    id: 0x2 
nov/02 00:53:58 dhcp,debug,packet   -> ia_prefix:  
nov/02 00:53:58 dhcp,debug,packet     prefix: 2001:8003:####:####::/56 
nov/02 00:53:58 dhcp,debug,packet     valid time: 14202 
nov/02 00:53:58 dhcp,debug,packet     pref. time: 14202 
nov/02 00:54:02 dhcp,debug resending.. 
nov/02 00:54:02 dhcp,debug,packet send ether1 -> ff02::1:2%6 
nov/02 00:54:02 dhcp,debug,packet type: request 
nov/02 00:54:02 dhcp,debug,packet transaction-id: 50d410 
nov/02 00:54:02 dhcp,debug,packet  -> clientid:   00030001 cc2de07b 4604 
nov/02 00:54:02 dhcp,debug,packet  -> serverid:   00010001 20dd4deb 00144ffa d708 
nov/02 00:54:02 dhcp,debug,packet  -> oro: 23  
nov/02 00:54:02 dhcp,debug,packet  -> elapsed_time: 7 
nov/02 00:54:02 dhcp,debug,packet  -> ia_pd:  
nov/02 00:54:02 dhcp,debug,packet    t1: 7101 
nov/02 00:54:02 dhcp,debug,packet    t2: 11361 
nov/02 00:54:02 dhcp,debug,packet    id: 0x2 
nov/02 00:54:02 dhcp,debug,packet   -> ia_prefix:  
nov/02 00:54:02 dhcp,debug,packet     prefix: 2001:8003:####:####::/56 
nov/02 00:54:02 dhcp,debug,packet     valid time: 14202 
nov/02 00:54:02 dhcp,debug,packet     pref. time: 14202 
nov/02 00:54:10 dhcp,debug resending.. 
nov/02 00:54:10 dhcp,debug,packet send ether1 -> ff02::1:2%6 
nov/02 00:54:10 dhcp,debug,packet type: request 
nov/02 00:54:10 dhcp,debug,packet transaction-id: 50d410 
nov/02 00:54:10 dhcp,debug,packet  -> clientid:   00030001 cc2de07b 4604 
nov/02 00:54:10 dhcp,debug,packet  -> serverid:   00010001 20dd4deb 00144ffa d708 
nov/02 00:54:10 dhcp,debug,packet  -> oro: 23  
nov/02 00:54:10 dhcp,debug,packet  -> elapsed_time: 15 
nov/02 00:54:10 dhcp,debug,packet  -> ia_pd:  
nov/02 00:54:10 dhcp,debug,packet    t1: 7101 
nov/02 00:54:10 dhcp,debug,packet    t2: 11361 
nov/02 00:54:10 dhcp,debug,packet    id: 0x2 
nov/02 00:54:10 dhcp,debug,packet   -> ia_prefix:  
nov/02 00:54:10 dhcp,debug,packet     prefix: 2001:8003:####:####::/56 
nov/02 00:54:10 dhcp,debug,packet     valid time: 14202 
nov/02 00:54:10 dhcp,debug,packet     pref. time: 14202 
nov/02 00:54:25 dhcp,debug resending.. 
nov/02 00:54:25 dhcp,debug,packet send ether1 -> ff02::1:2%6 
nov/02 00:54:25 dhcp,debug,packet type: request 
nov/02 00:54:25 dhcp,debug,packet transaction-id: 50d410 
nov/02 00:54:25 dhcp,debug,packet  -> clientid:   00030001 cc2de07b 4604 
nov/02 00:54:25 dhcp,debug,packet  -> serverid:   00010001 20dd4deb 00144ffa d708 
nov/02 00:54:25 dhcp,debug,packet  -> oro: 23  
nov/02 00:54:25 dhcp,debug,packet  -> elapsed_time: 30 
nov/02 00:54:25 dhcp,debug,packet  -> ia_pd:  
nov/02 00:54:25 dhcp,debug,packet    t1: 7101 
nov/02 00:54:25 dhcp,debug,packet    t2: 11361 
nov/02 00:54:25 dhcp,debug,packet    id: 0x2 
nov/02 00:54:25 dhcp,debug,packet   -> ia_prefix:  
nov/02 00:54:25 dhcp,debug,packet     prefix: 2001:8003:####:####::/56 
nov/02 00:54:25 dhcp,debug,packet     valid time: 14202 
nov/02 00:54:25 dhcp,debug,packet     pref. time: 14202 
nov/02 00:54:25 dhcp,debug max retransmit timeout

Lodion · November 30, 2018, 5:07am

Hi ewoodzy,

I’m having the same issue on my home Mikrotik router, and based on the IPv6 address in your info we’re on the same ISP: Telstra (2001:8000::/20). I’ve been posting on Whirlpool about this, so far without any luck: https://forums.whirlpool.net.au/forum-replies.cfm?t=2767959

I assume you’re also on Telstra HFC NBN?

edit: I’ve recently come to the conclusion that a Mikrotik bug in DHCPv6 related to “rapid commit”, is the source of my IPv6 woes.

Rapid commit is intended to accelerate IPv6 address configuration on the client. Rather than a 4 packet process before an IP is usable, it only takes 2.

However Mikrotik seems to be buggy. It sets the “rapid commit” option flag in its outbound DHCPv6 requests, but does not make use of the provided IP/prefix when an advertise packet is received from a server. Instead, it continues to operate in 4 packet mode… and sends a follow up request to the server… which ignores it.

Eventually the client gives up and goes into an error state.