DHCPv6 Client Broken in latest snapshot
-
Does anyone know if "transmit failed: Input/output error" is a pfsense error or a BSD error? Is there any way to get more information about the cause? It's pretty useless without knowing what caused it.
-
I noticed that 2.4.4 development is running a different version of freebsd. Does anyone know when the change was introduced? I'm suspicious that it's related.
-
I can not find any trace when Netgate moved from FreeBSD 11.1 to 11.2 beta, but it have happened in May, I think. There are also a bunch of PHP7 related changes happened in the same period of time, but I don't see any related to DHCPv6, so your problem can be related to base system only.
-
@w0w Martin (who did a bunch of work on interfaces.inc, but since left for other pastures), took a look at interfaces.inc and didn't see any changes, so the change of freebsd is a smoking gun.
-
I have the exact same problem with my DHCPv6 Client since the last update to 2.4.3-RELEASE-p1.
-
@bimmerdriver said in DHCPv6 Client Broken in latest snapshot:
Does anyone know if "transmit failed: Input/output error" is a pfsense error or a BSD error? Is there any way to get more information about the cause? It's pretty useless without knowing what caused it.
That would be from the dhcp6c client
-
@darkfire said in DHCPv6 Client Broken in latest snapshot:
I have the exact same problem with my DHCPv6 Client since the last update to 2.4.3-RELEASE-p1.
Are you also using "Do not wait for RA"?
-
Yes, i do. Without โDo not wait for RAโ the dhcp6c client will not start anymore.
/var/etc/dhcp6c_wan.conf
interface em0 { send ia-pd 0; script "/var/etc/dhcp6c_wan_script.sh"; }; id-assoc pd { };
logs with โDo not wait for RAโ
May 29 23:02:14 dhcp6c 53193 failed to open /usr/local/etc/dhcp6cctlkey: No such file or directory May 29 23:02:14 dhcp6c 53193 failed initialize control message authentication May 29 23:02:14 dhcp6c 53193 skip opening control port May 29 23:02:15 dhcp6c 53211 Sending Solicit May 29 23:02:15 dhcp6c 53211 transmit failed: Can't assign requested address May 29 23:02:16 dhcp6c 53211 Sending Solicit May 29 23:02:16 dhcp6c 53211 transmit failed: Can't assign requested address
process list
ps aux | grep dhcp6c root 53211 0.0 0.1 8380 2364 - Is 23:02 0:00.00 /usr/local/sbin/dhcp6c -d -c /var/etc/dhcp6c_wan.conf -p /var/run/dhcp6c_em0.pid em0
-
@darkfire said in DHCPv6 Client Broken in latest snapshot:
Without โDo not wait for RAโ the dhcp6c client will not start anymore.
So it fails without that enabled? Or it fails both ways but with different errors?
-
My system behaves differently. If I disable do not wait for ra, dhcp6c never runs, because it's waiting for an RA, which will not be sent. Also, the error message is different.
-
If i disable โDo not wait for RAโ the client won't start. If i enable โDo not wait for RAโ the client starts, but I do not get a prefix delegation.
-
I'm bumping this thread to see if anyone else is experiencing this issue. I'm dead in the water trying to find out the cause, at least without the snapshots from the April time frame.
-
I haven't seen any additional complaints, and though I have kept one of my boxes here configured with "do not wait for RA", I have yet to see the same errors others have posted here.
The error messages above,
transmit failed: Can't assign requested address
, would seem to imply that an address disappeared from the interface at some point but it's a fairly generic error even in the source. And since there is no address specified in the config file, that makes me curious how that is happening. The previous error,transmit failed: Input/output error
is also very generic.If you can, please go into the WAN options in the dhcp6 section and check Start DHCP6 client in debug mode and see if anything more informative gets put in the logs, and post anything in the logs from
dhcp6c
. -
I enabled DHCP debug. The DHCP log from the start of a reboot is below. The only thing that appears to be abnormal is the transmit failed: Input/output error.
Jun 9 09:21:41 dhcp6c 11661 reset a timer on hn1, state=SOLICIT, timeo=5, retrans=31928 Jun 9 09:21:41 dhcp6c 11661 transmit failed: Input/output error Jun 9 09:21:41 dhcp6c 11661 set IA_PD Jun 9 09:21:41 dhcp6c 11661 set option request (len 4) Jun 9 09:21:41 dhcp6c 11661 set elapsed time (len 2) Jun 9 09:21:41 dhcp6c 11661 set client ID (len 14) Jun 9 09:21:41 dhcp6c 11661 Sending Solicit Jun 9 09:21:34 dhcpd Server starting service. Jun 9 09:21:34 dhcpd Sending on Socket/fallback/fallback-net Jun 9 09:21:34 dhcpd Sending on BPF/hn0/00:15:5d:5c:e2:31/192.168.1.0/24 Jun 9 09:21:34 dhcpd Listening on BPF/hn0/00:15:5d:5c:e2:31/192.168.1.0/24 Jun 9 09:21:33 dhcpd Wrote 1 leases to leases file. Jun 9 09:21:33 dhcpd For info, please visit https://www.isc.org/software/dhcp/ Jun 9 09:21:33 dhcpd All rights reserved. Jun 9 09:21:33 dhcpd Copyright 2004-2018 Internet Systems Consortium. Jun 9 09:21:33 dhcpd Internet Systems Consortium DHCP Server 4.3.6-P1 Jun 9 09:21:33 dhcpd PID file: /var/run/dhcpd.pid Jun 9 09:21:33 dhcpd Database file: /var/db/dhcpd.leases Jun 9 09:21:33 dhcpd Config file: /etc/dhcpd.conf Jun 9 09:21:33 dhcpd For info, please visit https://www.isc.org/software/dhcp/ Jun 9 09:21:33 dhcpd All rights reserved. Jun 9 09:21:33 dhcpd Copyright 2004-2018 Internet Systems Consortium. Jun 9 09:21:33 dhcpd Internet Systems Consortium DHCP Server 4.3.6-P1 Jun 9 09:21:25 dhcp6c 11661 reset a timer on hn1, state=SOLICIT, timeo=4, retrans=16326 Jun 9 09:21:25 dhcp6c 11661 transmit failed: Input/output error Jun 9 09:21:25 dhcp6c 11661 set IA_PD Jun 9 09:21:25 dhcp6c 11661 set option request (len 4) Jun 9 09:21:25 dhcp6c 11661 set elapsed time (len 2) Jun 9 09:21:25 dhcp6c 11661 set client ID (len 14) Jun 9 09:21:25 dhcp6c 11661 Sending Solicit Jun 9 09:21:17 dhcp6c 11661 reset a timer on hn1, state=SOLICIT, timeo=3, retrans=8065 Jun 9 09:21:17 dhcp6c 11661 transmit failed: Input/output error Jun 9 09:21:17 dhcp6c 11661 set IA_PD Jun 9 09:21:17 dhcp6c 11661 set option request (len 4) Jun 9 09:21:17 dhcp6c 11661 set elapsed time (len 2) Jun 9 09:21:17 dhcp6c 11661 set client ID (len 14) Jun 9 09:21:17 dhcp6c 11661 Sending Solicit Jun 9 09:21:13 dhcp6c 11661 reset a timer on hn1, state=SOLICIT, timeo=2, retrans=3982 Jun 9 09:21:13 dhcp6c 11661 transmit failed: Input/output error Jun 9 09:21:13 dhcp6c 11661 set IA_PD Jun 9 09:21:13 dhcp6c 11661 set option request (len 4) Jun 9 09:21:13 dhcp6c 11661 set elapsed time (len 2) Jun 9 09:21:13 dhcp6c 11661 set client ID (len 14) Jun 9 09:21:13 dhcp6c 11661 Sending Solicit Jun 9 09:21:11 dhcp6c 11661 reset a timer on hn1, state=SOLICIT, timeo=1, retrans=2083 Jun 9 09:21:11 dhcp6c 11661 transmit failed: Input/output error Jun 9 09:21:11 dhcp6c 11661 set IA_PD Jun 9 09:21:11 dhcp6c 11661 set option request (len 4) Jun 9 09:21:11 dhcp6c 11661 set elapsed time (len 2) Jun 9 09:21:11 dhcp6c 11661 set client ID (len 14) Jun 9 09:21:11 dhcp6c 11661 Sending Solicit Jun 9 09:21:09 dhcp6c 11661 reset a timer on hn1, state=SOLICIT, timeo=0, retrans=1091 Jun 9 09:21:09 dhcp6c 11661 transmit failed: Input/output error Jun 9 09:21:09 dhcp6c 11661 set IA_PD Jun 9 09:21:09 dhcp6c 11661 set option request (len 4) Jun 9 09:21:09 dhcp6c 11661 set elapsed time (len 2) Jun 9 09:21:09 dhcp6c 11661 set client ID (len 14) Jun 9 09:21:09 dhcp6c 11661 a new XID (1bb44a) is generated Jun 9 09:21:09 dhcp6c 11661 Sending Solicit Jun 9 09:21:09 dhcp6c 11661 reset a timer on hn1, state=INIT, timeo=0, retrans=891 Jun 9 09:21:09 dhcp6c 11654 called Jun 9 09:21:09 dhcp6c 11654 called Jun 9 09:21:09 dhcp6c 11654 <3>end of sentence [;] (1) Jun 9 09:21:09 dhcp6c 11654 <3>end of closure [}] (1) Jun 9 09:21:09 dhcp6c 11654 <3>end of sentence [;] (1) Jun 9 09:21:09 dhcp6c 11654 <3>end of closure [}] (1) Jun 9 09:21:09 dhcp6c 11654 <3>end of sentence [;] (1) Jun 9 09:21:09 dhcp6c 11654 <3>[8] (1) Jun 9 09:21:09 dhcp6c 11654 <3>[sla-len] (7) Jun 9 09:21:09 dhcp6c 11654 <3>end of sentence [;] (1) Jun 9 09:21:09 dhcp6c 11654 <3>[0] (1) Jun 9 09:21:09 dhcp6c 11654 <3>[sla-id] (6) Jun 9 09:21:09 dhcp6c 11654 <3>begin of closure [{] (1) Jun 9 09:21:09 dhcp6c 11654 <5>[hn0] (3) Jun 9 09:21:09 dhcp6c 11654 <3>[prefix-interface] (16) Jun 9 09:21:09 dhcp6c 11654 <13>begin of closure [{] (1) Jun 9 09:21:09 dhcp6c 11654 <13>[0] (1) Jun 9 09:21:09 dhcp6c 11654 <13>[pd] (2) Jun 9 09:21:09 dhcp6c 11654 <3>[id-assoc] (8) Jun 9 09:21:09 dhcp6c 11654 <3>end of sentence [;] (1) Jun 9 09:21:09 dhcp6c 11654 <3>end of closure [}] (1) Jun 9 09:21:09 dhcp6c 11654 <3>comment [# we'd like nameservers and RTSOLD to do all the work] (53) Jun 9 09:21:09 dhcp6c 11654 <3>end of sentence [;] (1) Jun 9 09:21:09 dhcp6c 11654 <3>["/var/etc/dhcp6c_wan_dhcp6withoutra_script.sh"] (46) Jun 9 09:21:09 dhcp6c 11654 <3>[script] (6) Jun 9 09:21:09 dhcp6c 11654 <3>end of sentence [;] (1) Jun 9 09:21:09 dhcp6c 11654 <3>[domain-name] (11) Jun 9 09:21:09 dhcp6c 11654 <3>[request] (7) Jun 9 09:21:09 dhcp6c 11654 <3>end of sentence [;] (1) Jun 9 09:21:09 dhcp6c 11654 <3>[domain-name-servers] (19) Jun 9 09:21:09 dhcp6c 11654 <3>[request] (7) Jun 9 09:21:09 dhcp6c 11654 <3>comment [# request prefix delegation] (27) Jun 9 09:21:09 dhcp6c 11654 <3>end of sentence [;] (1) Jun 9 09:21:09 dhcp6c 11654 <3>[0] (1) Jun 9 09:21:09 dhcp6c 11654 <3>[ia-pd] (5) Jun 9 09:21:09 dhcp6c 11654 <3>[send] (4) Jun 9 09:21:09 dhcp6c 11654 <3>begin of closure [{] (1) Jun 9 09:21:09 dhcp6c 11654 <5>[hn1] (3) Jun 9 09:21:09 dhcp6c 11654 <3>[interface] (9) Jun 9 09:21:09 dhcp6c 11654 skip opening control port Jun 9 09:21:09 dhcp6c 11654 failed initialize control message authentication Jun 9 09:21:09 dhcp6c 11654 failed to open /usr/local/etc/dhcp6cctlkey: No such file or directory Jun 9 09:21:09 dhcp6c 11654 extracted an existing DUID from /var/db/dhcp6c_duid: 00:01:00:01:22:95:fa:13:00:15:5d:5c:e2:31 Jun 9 09:21:05 dhclient Creating resolv.conf Jun 9 09:21:05 dhclient /sbin/route add default 154.20.116.1 Jun 9 09:21:05 dhclient Adding new routes to interface: hn1 Jun 9 09:21:05 dhclient New Routers (hn1): 154.20.116.1 Jun 9 09:21:05 dhclient New Broadcast Address (hn1): 154.20.119.255 Jun 9 09:21:05 dhclient New Subnet Mask (hn1): 255.255.252.0 Jun 9 09:21:05 dhclient New IP Address (hn1): 154.20.119.154 Jun 9 09:21:05 dhclient ifconfig hn1 inet 154.20.119.154 netmask 255.255.252.0 broadcast 154.20.119.255 Jun 9 09:21:05 dhclient Starting add_new_address() Jun 9 09:21:05 dhclient REBOOT Jun 9 09:21:04 dhclient PREINIT
-
Do you have a different piece of hardware (real or virtual) you can try here to see if it's isolated to those
hnX
NICs or your environment (hyperv?)?Also we recently, in the last few days, resynchronized with FreeBSD 11.2 so it's possible we picked up a bug fix, so it's worth testing on the latest snapshot.
-
@jimp said in DHCPv6 Client Broken in latest snapshot:
Do you have a different piece of hardware (real or virtual) you can try here to see if it's isolated to those
hnX
NICs or your environment (hyperv?)?Also we recently, in the last few days, resynchronized with FreeBSD 11.2 so it's possible we picked up a bug fix, so it's worth testing on the latest snapshot.
Unfortunately, I don't have any other hardware to try.
I just updated to the latest snapshot and unfortunately, the error is exactly the same.
If it would be useful to you, I could set up teamviewer so you can get on the system and take a look.
-
@jimp is there something we can do to help you?
-
a link to a related issue on the pfsense bug tracker
https://redmine.pfsense.org/issues/8489 -
@darkfire said in DHCPv6 Client Broken in latest snapshot:
@jimp is there something we can do to help you?
Find a way to reproduce it reliably that doesn't rely on being connected to an ISP that requires "do not wait for RA".
As far as I'm aware, nobody here has been able to replicate the problem behavior or error message(s).
-
@darkfire said in DHCPv6 Client Broken in latest snapshot:
a link to a related issue on the pfsense bug tracker
https://redmine.pfsense.org/issues/8489Issue 8489 isn't a "related issue". It's the bug report for the issue I reported in this thread.