Bug #8489
closed
DHCPv6 Client Failure to Initialize with "Do not wait for RA"
Added by Daryl Morse about 6 years ago. Updated over 5 years ago.
0%
Description
Since snapshot 2.4.4-DEVELOPMENT (amd64) built on Thu Apr 26 14:32:50 CDT 2018, the DHCPv6 Client will not initialize after booting or restarting the WAN interface.
Here are the pertinent log messages:
Apr 27 16:02:11 dhcp6c 12949 transmit failed: Input/output error
Apr 27 16:02:11 dhcp6c 12949 Sending Solicit
Apr 27 16:02:11 dhcp6c 12652 skip opening control port
Apr 27 16:02:11 dhcp6c 12652 failed initialize control message authentication
Apr 27 16:02:11 dhcp6c 12652 failed to open /usr/local/etc/dhcp6cctlkey: No such file or directory
The DHCP6 gateway is stuck in the pending state, so there is no IPv6.
This problem was not present before updating to this snapshot and it is not present on my other system which is running pfsense 2.4.2.
Updated by Daryl Morse about 6 years ago
I should also add that I am using the "Do not wait for a RA" feature.
Updated by Daryl Morse about 6 years ago
Here is a post reboot log file with debug enabled.
Apr 28 14:51:55 dhcp6c 9814 reset a timer on hn1, state=SOLICIT, timeo=6, retrans=64469
Apr 28 14:51:55 dhcp6c 9814 transmit failed: Input/output error
Apr 28 14:51:55 dhcp6c 9814 set IA_PD
Apr 28 14:51:55 dhcp6c 9814 set option request (len 4)
Apr 28 14:51:55 dhcp6c 9814 set elapsed time (len 2)
Apr 28 14:51:55 dhcp6c 9814 set client ID (len 14)
Apr 28 14:51:55 dhcp6c 9814 Sending Solicit
Apr 28 14:51:23 dhcp6c 9814 reset a timer on hn1, state=SOLICIT, timeo=5, retrans=31928
Apr 28 14:51:23 dhcp6c 9814 transmit failed: Input/output error
Apr 28 14:51:23 dhcp6c 9814 set IA_PD
Apr 28 14:51:23 dhcp6c 9814 set option request (len 4)
Apr 28 14:51:23 dhcp6c 9814 set elapsed time (len 2)
Apr 28 14:51:23 dhcp6c 9814 set client ID (len 14)
Apr 28 14:51:23 dhcp6c 9814 Sending Solicit
[...]
Apr 28 14:51:06 dhcp6c 9814 reset a timer on hn1, state=SOLICIT, timeo=4, retrans=16326
Apr 28 14:51:06 dhcp6c 9814 transmit failed: Input/output error
Apr 28 14:51:06 dhcp6c 9814 set IA_PD
Apr 28 14:51:06 dhcp6c 9814 set option request (len 4)
Apr 28 14:51:06 dhcp6c 9814 set elapsed time (len 2)
Apr 28 14:51:06 dhcp6c 9814 set client ID (len 14)
Apr 28 14:51:06 dhcp6c 9814 Sending Solicit
Apr 28 14:50:58 dhcp6c 9814 reset a timer on hn1, state=SOLICIT, timeo=3, retrans=8065
Apr 28 14:50:58 dhcp6c 9814 transmit failed: Input/output error
Apr 28 14:50:58 dhcp6c 9814 set IA_PD
Apr 28 14:50:58 dhcp6c 9814 set option request (len 4)
Apr 28 14:50:58 dhcp6c 9814 set elapsed time (len 2)
Apr 28 14:50:58 dhcp6c 9814 set client ID (len 14)
Apr 28 14:50:58 dhcp6c 9814 Sending Solicit
Apr 28 14:50:54 dhcp6c 9814 reset a timer on hn1, state=SOLICIT, timeo=2, retrans=3982
Apr 28 14:50:54 dhcp6c 9814 transmit failed: Input/output error
Apr 28 14:50:54 dhcp6c 9814 set IA_PD
Apr 28 14:50:54 dhcp6c 9814 set option request (len 4)
Apr 28 14:50:54 dhcp6c 9814 set elapsed time (len 2)
Apr 28 14:50:54 dhcp6c 9814 set client ID (len 14)
Apr 28 14:50:54 dhcp6c 9814 Sending Solicit
Apr 28 14:50:52 dhcp6c 9814 reset a timer on hn1, state=SOLICIT, timeo=1, retrans=2083
Apr 28 14:50:52 dhcp6c 9814 transmit failed: Input/output error
Apr 28 14:50:52 dhcp6c 9814 set IA_PD
Apr 28 14:50:52 dhcp6c 9814 set option request (len 4)
Apr 28 14:50:52 dhcp6c 9814 set elapsed time (len 2)
Apr 28 14:50:52 dhcp6c 9814 set client ID (len 14)
Apr 28 14:50:52 dhcp6c 9814 Sending Solicit
Apr 28 14:50:51 dhcp6c 9814 reset a timer on hn1, state=SOLICIT, timeo=0, retrans=1091
Apr 28 14:50:51 dhcp6c 9814 transmit failed: Input/output error
Apr 28 14:50:51 dhcp6c 9814 set IA_PD
Apr 28 14:50:51 dhcp6c 9814 set option request (len 4)
Apr 28 14:50:51 dhcp6c 9814 set elapsed time (len 2)
Apr 28 14:50:51 dhcp6c 9814 set client ID (len 14)
Apr 28 14:50:51 dhcp6c 9814 a new XID (847d63) is generated
Apr 28 14:50:51 dhcp6c 9814 Sending Solicit
Apr 28 14:50:50 dhcp6c 9814 reset a timer on hn1, state=INIT, timeo=0, retrans=891
Apr 28 14:50:50 dhcp6c 9657 called
Apr 28 14:50:50 dhcp6c 9657 called
Apr 28 14:50:50 dhcp6c 9657 <3>end of sentence [;] (1)
Apr 28 14:50:50 dhcp6c 9657 <3>end of closure [}] (1)
Apr 28 14:50:50 dhcp6c 9657 <3>end of sentence [;] (1)
Apr 28 14:50:50 dhcp6c 9657 <3>end of closure [}] (1)
Apr 28 14:50:50 dhcp6c 9657 <3>end of sentence [;] (1)
Apr 28 14:50:50 dhcp6c 9657 <3>[8] (1)
Apr 28 14:50:50 dhcp6c 9657 <3>[sla-len] (7)
Apr 28 14:50:50 dhcp6c 9657 <3>end of sentence [;] (1)
Apr 28 14:50:50 dhcp6c 9657 <3>[0] (1)
Apr 28 14:50:50 dhcp6c 9657 <3>[sla-id] (6)
Apr 28 14:50:50 dhcp6c 9657 <3>begin of closure [{] (1)
Apr 28 14:50:50 dhcp6c 9657 <5>[hn0] (3)
Apr 28 14:50:50 dhcp6c 9657 <3>[prefix-interface] (16)
Apr 28 14:50:50 dhcp6c 9657 <13>begin of closure [{] (1)
Apr 28 14:50:50 dhcp6c 9657 <13>[0] (1)
Apr 28 14:50:50 dhcp6c 9657 <13>[pd] (2)
Apr 28 14:50:50 dhcp6c 9657 <3>[id-assoc] (8)
Apr 28 14:50:50 dhcp6c 9657 <3>end of sentence [;] (1)
Apr 28 14:50:50 dhcp6c 9657 <3>end of closure [}] (1)
Apr 28 14:50:50 dhcp6c 9657 <3>comment [# we'd like nameservers and RTSOLD to do all the work] (53)
Apr 28 14:50:50 dhcp6c 9657 <3>end of sentence [;] (1)
Apr 28 14:50:50 dhcp6c 9657 <3>["/var/etc/dhcp6c_wan_dhcp6withoutra_script.sh"] (46)
Apr 28 14:50:50 dhcp6c 9657 <3>[script] (6)
Apr 28 14:50:50 dhcp6c 9657 <3>end of sentence [;] (1)
Apr 28 14:50:50 dhcp6c 9657 <3>[domain-name] (11)
Apr 28 14:50:50 dhcp6c 9657 <3>[request] (7)
Apr 28 14:50:50 dhcp6c 9657 <3>end of sentence [;] (1)
Apr 28 14:50:50 dhcp6c 9657 <3>[domain-name-servers] (19)
Apr 28 14:50:50 dhcp6c 9657 <3>[request] (7)
Apr 28 14:50:50 dhcp6c 9657 <3>comment [# request prefix delegation] (27)
Apr 28 14:50:50 dhcp6c 9657 <3>end of sentence [;] (1)
Apr 28 14:50:50 dhcp6c 9657 <3>[0] (1)
Apr 28 14:50:50 dhcp6c 9657 <3>[ia-pd] (5)
Apr 28 14:50:50 dhcp6c 9657 <3>[send] (4)
Apr 28 14:50:50 dhcp6c 9657 <3>begin of closure [{] (1)
Apr 28 14:50:50 dhcp6c 9657 <5>[hn1] (3)
Apr 28 14:50:50 dhcp6c 9657 <3>[interface] (9)
Apr 28 14:50:50 dhcp6c 9657 skip opening control port
Apr 28 14:50:50 dhcp6c 9657 failed initialize control message authentication
Apr 28 14:50:50 dhcp6c 9657 failed to open /usr/local/etc/dhcp6cctlkey: No such file or directory
Apr 28 14:50:50 dhcp6c 9657 extracted an existing DUID from /var/db/dhcp6c_duid: 00:01:00:01:21:85:5f:a0:XX:XX:XX:XX:XX:XX
Updated by Daryl Morse almost 6 years ago
I performed a clean installation from the latest snapshot (May 21st). The problem is still present.
These DHCP log messages seem to be related:
May 21 14:51:51 dhcp6c 49073 transmit failed: Input/output error
May 21 14:51:51 dhcp6c 49073 Sending Solicit
Wireshark is not detecting any ipv6 traffic.
I'm available to test or provide more log files if required.
Updated by Jim Pingle almost 6 years ago
- Status changed from New to Not a Bug
- Priority changed from High to Low
I can't reproduce this here on any hardware I have, real or virtual.
It might be in that NIC driver, or some other setting you have. Please post a message on the forum or pfSense subreddit with your interface configuration to discuss the problem until a bug can be positively identified.
Updated by Daryl Morse almost 6 years ago
Jim Pingle wrote:
I can't reproduce this here on any hardware I have, real or virtual.
It might be in that NIC driver, or some other setting you have. Please post a message on the forum or pfSense subreddit with your interface configuration to discuss the problem until a bug can be positively identified.
I posted the details in this thread: https://forum.netgate.com/topic/130219/dhcpv6-client-broken-in-latest-snapshot
I'm really at a loss. It was working fine, then it stopped working with an update. The other system has worked continuously.
Updated by Daryl Morse almost 6 years ago
Is this error: May 21 14:51:51 dhcp6c 49073 transmit failed: Input/output error generated by pfsense or freebsd? I noticed that the development snapshot is running on a newer version of freebsd than the release version. When did this change take place? Is a snapshot available from before the change? If this error is from freebsd, it's a smoking gun, IMO. I'm running pfsense on windows server 2012R2 hyper-v. Maybe there is an issue in freebsd pertaining to this configuration.
Updated by Jim Pingle almost 6 years ago
- Subject changed from DHCPv6 Client Failure to Initialize to DHCPv6 Client Failure to Initialize with "Do not wait for RA"
- Status changed from Not a Bug to New
- Target version set to 2.4.4
I still can't replicate this here even by checking "Do not wait for RA", but I do not have a provider that requires it.
I've reopened it since there is one other person on the forum that can replicate it, but we need to work on the forum thread to find out more specifically what is leading to the error. It may be a custom change to dhcp6c that was lost along the way or some other similar change.
Updated by Daryl Morse almost 6 years ago
Jim Pingle wrote:
I still can't replicate this here even by checking "Do not wait for RA", but I do not have a provider that requires it.
I've reopened it since there is one other person on the forum that can replicate it, but we need to work on the forum thread to find out more specifically what is leading to the error. It may be a custom change to dhcp6c that was lost along the way or some other similar change.
If older versions of the snapshot are available, I will install them to find where the change was introduced.
Updated by Anonymous
Updated by Daryl Morse over 5 years ago
I'm disappointed this bug is being punted. On the forum, I offered my system (via teamviewer) if anyone wants to take a look at it. The offer still stands.
Updated by Moritz Hartwig over 5 years ago
More people get this bug now in the 2.4.4 release. It seems the common part is that pfsense is running as hyper-v VM.
See the forum post from Daryl.
Please resolve this issue :)
Updated by Jim Pingle over 5 years ago
Hyper-V appears to be the common factor but as far as I can see, nobody has attempted to take the exact same config/environment and see if it works on bare metal hardware to confirm that. Or tried it with emulated instead of synthetic drivers.
It would also help if someone could attempt to replicate the problem on FreeBSD 11.2 itself (not pfSense) to see if it's a problem upstream.
It may very well be a problem with the Hyper-V hn driver on FreeBSD 11.2. See #8954 for another hn problem.
Updated by Kevin Morse over 5 years ago
Just updated to 2.4.4 and lost IPv6...
I am also running pfsense as a Gen2 hyper-v guest.
My NIC is an Intel I350-T2, I will try to replicate in FreeBSD 11.2
Updated by Benjamin Rechsteiner over 5 years ago
i have the same problem since 2.4.3
my pfsense is running on bare metal
here a few logs:
Sep 28 16:10:31 dhcp6c 54243 extracted an existing DUID from /var/db/dhcp6c_duid: 00:01:00:01:21:1f:a3:e5:80:ee:73:cb:38:60
Sep 28 16:10:31 dhcp6c 54243 failed to open /usr/local/etc/dhcp6cctlkey: No such file or directory
Sep 28 16:10:31 dhcp6c 54243 failed initialize control message authentication
Sep 28 16:10:31 dhcp6c 54243 skip opening control port
Sep 28 16:10:31 dhcp6c 54243 <3>[interface] (9)
Sep 28 16:10:31 dhcp6c 54243 <5>[em0] (3)
Sep 28 16:10:31 dhcp6c 54243 <3>begin of closure [{] (1)
Sep 28 16:10:31 dhcp6c 54243 <3>[send] (4)
Sep 28 16:10:31 dhcp6c 54243 <3>[ia-pd] (5)
Sep 28 16:10:31 dhcp6c 54243 <3>[0] (1)
Sep 28 16:10:31 dhcp6c 54243 <3>end of sentence [;] (1)
Sep 28 16:10:31 dhcp6c 54243 <3>[script] (6)
Sep 28 16:10:31 dhcp6c 54243 <3>["/var/etc/dhcp6c_wan_script.sh"] (31)
Sep 28 16:10:31 dhcp6c 54243 <3>end of sentence [;] (1)
Sep 28 16:10:31 dhcp6c 54243 <3>end of closure [}] (1)
Sep 28 16:10:31 dhcp6c 54243 <3>end of sentence [;] (1)
Sep 28 16:10:31 dhcp6c 54243 <3>[id-assoc] (8)
Sep 28 16:10:31 dhcp6c 54243 <13>[pd] (2)
Sep 28 16:10:31 dhcp6c 54243 <13>begin of closure [{] (1)
Sep 28 16:10:31 dhcp6c 54243 <3>end of closure [}] (1)
Sep 28 16:10:31 dhcp6c 54243 <3>end of sentence [;] (1)
Sep 28 16:10:31 dhcp6c 54243 called
Sep 28 16:10:31 dhcp6c 54243 called
Sep 28 16:10:31 dhcp6c 55265 reset a timer on em0, state=INIT, timeo=0, retrans=891
Sep 28 16:10:32 dhcp6c 55265 Sending Solicit
Sep 28 16:10:32 dhcp6c 55265 a new XID (244963) is generated
Sep 28 16:10:32 dhcp6c 55265 set client ID (len 14)
Sep 28 16:10:32 dhcp6c 55265 set elapsed time (len 2)
Sep 28 16:10:32 dhcp6c 55265 set IA_PD
Sep 28 16:10:32 dhcp6c 55265 transmit failed: Can't assign requested address
Sep 28 16:10:32 dhcp6c 55265 reset a timer on em0, state=SOLICIT, timeo=0, retrans=1091
Updated by Jim Pingle over 5 years ago
That's a different error than the others, and most likely a separate issue.
Updated by Benjamin Rechsteiner over 5 years ago
And to which other issue is it related?
root@pfsense:~ [0]# cat /var/etc/dhcp6c_wan.conf
interface em0 {
send ia-na 0; # request stateful address
};
id-assoc na 0 { };
root@pfsense:~ [0]# dhcp6c -c /var/etc/dhcp6c_wan.conf -f em0
Sep/28/2018 17:06:02: failed to open /usr/local/etc/dhcp6cctlkey: No such file or directory
Sep/28/2018 17:06:03: transmit failed: Can't assign requested address
Sep/28/2018 17:06:04: transmit failed: Can't assign requested address
Sep/28/2018 17:06:07: transmit failed: Can't assign requested address
Updated by Matt _ over 5 years ago
For the original issue,
ifconfig hn0 -txcsum6
seems to fix this, as well as disabling any checksum offloading in the pfSense GUI. There might be some funny business with hn (Hyper-V network driver), it seems to intend to calculate a checksum for a UDP packet in the upstream FreeBSD driver source in if_hn.c at hn_set_hlen(), but perhaps trips over its own shoelaces by expecting it to be a TCP packet only. Take this all with a grain of salt and verify this, it's pretty late and I'm taking guesses.
https://reviews.freebsd.org/D12417 I think this is the commit that did it. If TCP6 offload != UDP6 offload (not yes/yes or no/no), an EIO is thrown for all UDP6 packets sent into hn by at least dhcp6c
Updated by Daryl Morse over 5 years ago
Matt _ wrote:
For the original issue,
[...]
seems to fix this, as well as disabling any checksum offloading in the pfSense GUI. There might be some funny business with hn (Hyper-V network driver), it seems to intend to calculate a checksum for a UDP packet in the upstream FreeBSD driver source in if_hn.c at hn_set_hlen(), but perhaps trips over its own shoelaces by expecting it to be a TCP packet only. Take this all with a grain of salt and verify this, it's pretty late and I'm taking guesses.
https://reviews.freebsd.org/D12417 I think this is the commit that did it. If TCP6 offload != UDP6 offload (not yes/yes or no/no), an EIO is thrown for all UDP6 packets sent into hn by at least dhcp6c
The original issue seems to have been fixed by inclusion of FreeBSD r339863. (Reference https://redmine.pfsense.org/issues/9019.)
Matt, thanks for identifying the root cause of the problem.
Updated by Jim Pingle over 5 years ago
- Status changed from New to Feedback
So this is working OK now?
If so, we can close it out, or mark it as a duplicate of #9019 if the root cause was identical.
Updated by Daryl Morse over 5 years ago
Updated by Jim Pingle over 5 years ago
- Status changed from Feedback to Duplicate
- Target version deleted (
48)