FIOS - getting /56 PD via DHCP6 but no V6 is assigned to WAN

luckman212

To anyone following this thread:

I pushed a few updates this morning to make the script more robust, add some logging, error checking etc, skipping unnecessary updates etc.

Also added a patch that you can hook in with System Patches to integrate this into /var/etc/dhcp6c.conf so it gets triggered automatically (no need for a cronjob)

SirSilentBob

@luckman212 As I mentioned in the dslr forums where I first saw you post about this, you are awesome and thanks for creating it! Please mention or PM me your paypay so I can throw you a few bucks for your favorite drink.

I have downloaded and installed the shell script, put it in /root and made it executable. Your instructions mention "Make sure the DHCP6 Debug checkbox is enabled at System → Advanced → Networking." I don't have that particular checkbox at that location on my system (2.6.0 CE), however I have it under "DHCP6 Client Configuration" on my Interfaces / WAN page. I have checked it. I rebooted the firewall and success, the WAN has a IPv6 GUA!

The only thing I have is an alert on the top of the dashboard "pfSense has detected a crash report or programming bug. Click here for more information."

Here's the contents of the crash report below. Not sure if this is because I am using CE 2.6.0 but so far the script has worked as far as I can tell. As for if it will detect when the PD changes and update the WAN accordingly with this error, I can't say at this time. Somehow despite the hurricane, I have managed to not loose power so I guess just time will tell on that.

Please let me know if I need to poke around more, ssh in or give more info. Or if it's a benign error that isn't any real concern. Crash report and a clip of the system log file provided below.

Crash report begins.  Anonymous machine information:

amd64
12.3-STABLE
FreeBSD 12.3-STABLE RELENG_2_6_0-n226742-1285d6d205f pfSense

Crash report details:

PHP Errors:
[01-Oct-2022 21:12:22 America/New_York] PHP Fatal error:  Uncaught Error: Call to undefined function create_interface_ipv6_cfgcache() in Command line code:1
Stack trace:
#0 {main}
  thrown in Command line code on line 1



No FreeBSD crash data found.

Here's the info from the patch debug:

"Patch does not apply cleanly (detail)"

/usr/bin/patch --directory='/' -t  --strip '2' -i '/var/patches/6338e3a0e63dd.patch' --check --forward --ignore-whitespace

Hmm...  Looks like a unified diff to me...
The text leading up to this was:
--------------------------
|From a20cd10a34020e09dcdc14882c04dc749d3c6487 Mon Sep 17 00:00:00 2001
|From: luckman212 <1992842+luckman212@users.noreply.github.com>
|Date: Thu, 29 Sep 2022 08:59:11 -0400
|Subject: [PATCH] companion patch for
| https://github.com/luckman212/assign-gua-from-iapd
|
|auto assign GUA when dhcp6c script is called
|---
| src/etc/inc/interfaces.inc | 2 ++
| 1 file changed, 2 insertions(+)
|
|diff --git a/src/etc/inc/interfaces.inc b/src/etc/inc/interfaces.inc
|index a7fe25497eb..630dfb9ccfe 100644
|--- a/src/etc/inc/interfaces.inc
|+++ b/src/etc/inc/interfaces.inc
--------------------------
Patching file etc/inc/interfaces.inc using Plan A...
Ignoring previously applied (or reversed) patch.
Hunk #1 ignored at 4990.
Hunk #2 ignored at 5042.
2 out of 2 hunks ignored while patching etc/inc/interfaces.inc
done

And small clip of log activity:

Oct 1 21:12:22	assign_gua_from_iapd	34083	done, removing lockfile
Oct 1 21:12:22	php	33798	thrown
Oct 1 21:12:22	php	33798	#0 {main}
Oct 1 21:12:22	php	33798	Stack trace:
Oct 1 21:12:22	php	33798	Standard input code: New alert found: PHP ERROR: Type: 1, File: Command line code, Line: 1, Message: Uncaught Error: Call to undefined function create_interface_ipv6_cfgcache() in Command line code:1
Oct 1 21:12:22	php	33798	thrown
Oct 1 21:12:22	php	33798	#0 {main}
Oct 1 21:12:22	php	33798	Stack trace:
Oct 1 21:12:22	php	33798	Standard input code: PHP ERROR: Type: 1, File: Command line code, Line: 1, Message: Uncaught Error: Call to undefined function create_interface_ipv6_cfgcache() in Command line code:1
Oct 1 21:12:20	assign_gua_from_iapd	88073	restarting dpinger
Oct 1 21:12:20	assign_gua_from_iapd	87791	assigning 2600:4040:XXXX:6cff::1 to interface igb0
Oct 1 21:12:20	assign_gua_from_iapd	87398	GUA: 2600:4040:XXXX:6cff::1
Oct 1 21:12:20	assign_gua_from_iapd	86800	IA_PD found: 2600:4040:XXXX:6c00::/56
Oct 1 21:12:20	php	511	rc.bootup: dhcp6 init complete. Continuing
Oct 1 21:12:20	assign_gua_from_iapd	84682	lockfile present, aborting
Oct 1 21:12:19	php-fpm	460	/rc.newwanipv6: rc.newwanipv6: on (IP address: fe80::21b:21ff:fe73:d358%igb0) (interface: wan) (real interface: igb0).
Oct 1 21:12:19	php-fpm	460	/rc.newwanipv6: rc.newwanipv6: Info: starting on igb0.
Oct 1 21:12:19	php	511	rc.bootup: Unbound start waiting on dhcp6c.
Oct 1 21:12:18	rtsold	67737	Received RA specifying route fe80::f6b5:2fff:fe04:d9da for interface wan(igb0)
Oct 1 21:12:18	php	511	rc.bootup: Unbound start waiting on dhcp6c.
Oct 1 21:12:17	assign_gua_from_iapd	67145	acquiring lockfile
Oct 1 21:12:17	php	511	rc.bootup: Unbound start waiting on dhcp6c.

luckman212

@sirsilentbob That's very kind but no need for any paypal etc I am glad to hear this might be useful.

So yeah without applying the patch you'll be missing a function called create_interface_ipv6_cfgcache() which is so the script can be a little more efficient and check if the IP is the same or not before applying any redundant changes.

It's not strictly necessary, so if you can't apply the patch using System Patches (probably due to differences between CE and Plus) then you can just comment out the line using 2 forward slashes //. I added a note about this to the README on github. Hopefully after doing that and rebooting it shouldn't cause any more crashes.

SirSilentBob

@luckman212 Oh I DID apply the patch, but it's still giving those hourly errors.

I can comment out the specific line, but before I do, anything else I should modify or anything else you need info on? I guess I could go from CE to plus maybe next weekend or so...

luckman212

@sirsilentbob You only applied the companion patch which activates the automatic assignment (so a cronjob isn't needed.)

You still need the other patch from https://github.com/pfsense/pfsense/pull/4595/ to bring in the missing function.

If you don't want to (or can't) apply that one, then I suggest just commenting out line 57 as mentioned in the readme and going with a cronjob every XX min.

SirSilentBob

@luckman212 Ok. Sorry, I misunderstood! I thought there was just the one.

betapc

@luckman212 Hi,

Nice work. I follow all the instructions and I have when a run the command assign_gua_from_iapd.sh, there are 2 error the first one "specify an interface", so then run the command specifying the interface assign_gua_from_iapd.sh igb0 then I had the follow out put "waiting a few seconds for IA_PD no IA_PD detected in logs". I am on Verizon FiOS and I have access to IPv6. So what I am doing wrong?

Thanks

luckman212

@betapc What prefix are you requesting in your FIOS WAN Interface config? I just checked because it's been a while since I looked at this script tbh. The script is hardcoded to look for a prefix delegation of /56 (if you request a /64 for example, it won't work).

How does your config look? For example, here's mine

Can you run this command from your firewall console and post the output?

grep 'IA_PD prefix' /var/log/dhcpd.log

betapc

@luckman212 Thank you for replied. I run the command in the console and the output is nothing, just a blank line.

I am using FiOS and have same setting requesting /56 prefix delegation like in your screen shot.

The only thing is for my LANS show like this "SubnetPrefix Delegation (2600:xxxx:xxxx:xxxx::/64)". I don't have any control about that part.

Screenshot 2023-01-26 055624.png

Thanks again for your help.

luckman212

@betapc Something seems to be missing from your dhcpd.log. Mine looks like this

ae0c5151-960a-4b46-be8a-354acbc188a5-screenshot_jJHk9EoW.png

Are you doing something unique with your logging setup? What does tail -n50 /var/log/dhcpd.log show?

betapc

@luckman212 said in FIOS - getting /56 PD via DHCP6 but no V6 is assigned to WAN:

Are you doing something unique with your logging setup? What does tail -n50 /var/log/dhcpd.log show?

I don't think so. I have default setting for logging.

[22.05-RELEASE][admin@yyyyyy.com]/root: tail -n** /var/log/dhcpd.log
Jan 26 21:48:00 yyyy dhcpd[82179]: Copyright 2004-2021 Internet Systems Consortium.
Jan 26 21:48:00 yyyy dhcpd[82179]: All rights reserved.
Jan 26 21:48:00 yyyy dhcpd[82179]: For info, please visit https://www.isc.org/software/dhcp/
Jan 26 21:48:00 yyyy dhcpd[82179]: Config file: /etc/dhcpdv6.conf
Jan 26 21:48:00 yyyy dhcpd[82179]: Database file: /var/db/dhcpd6.leases
Jan 26 21:48:00 yyyy dhcpd[82179]: Internet Systems Consortium DHCP Server 4.4.2-P1
Jan 26 21:48:00 yyyy dhcpd[82179]: PID file: /var/run/dhcpdv6.pid
Jan 26 21:48:00 yyyy dhcpd[82179]: Copyright 2004-2021 Internet Systems Consortium.
Jan 26 21:48:00 yyyy dhcpd[82179]: All rights reserved.
Jan 26 21:48:00 yyyy dhcpd[82179]: For info, please visit https://www.isc.org/software/dhcp/
Jan 26 21:48:00 yyyy dhcpd[82179]: Wrote 1 NA, 0 TA, 0 PD leases to lease file.
Jan 26 21:48:00 yyyy dhcpd[82179]: Bound to :5*
Jan 26 21:48:00 yyyy dhcpd[82179]: Listening on Socket/7/igb2./20:xxxx:xxxx:xxxx::/64
Jan 26 21:48:00 yyyy dhcpd[82179]: Sending on Socket/7/igb2./20:xxxx:xxxx:xxxx::/64
Jan 26 21:48:00 yyyy dhcpd[82179]: Listening on Socket/7/igb2./20:xxxx:xxxx:xxxx::/64
Jan 26 21:48:00 yyyy dhcpd[82179]: Sending on Socket/7/igb2./20:xxxx:xxxx:xxxx::/64
Jan 26 21:48:00 yyyy dhcpd[82179]: Listening on Socket/7/igb1./20:xxxx:xxxx:xxxx::/64
Jan 26 21:48:00 yyyy dhcpd[82179]: Sending on Socket/7/igb1./20:xxxx:xxxx:xxxx::/64
Jan 26 21:48:00 yyyy dhcpd[82179]: Listening on Socket/7/igb1./20:xxxx:xxxx:xxxx::/64
Jan 26 21:48:00 yyyy dhcpd[82179]: Sending on Socket/7/igb1./20:xxxx:xxxx:xxxx::/64
Jan 26 21:48:00 yyyy dhcpd[82179]: Listening on Socket/7/igb1./20:xxxx:xxxx:xxxx::/64
Jan 26 21:48:00 yyyy dhcpd[82179]: Sending on Socket/7/igb1./20:xxxx:xxxx:xxxx::/64
Jan 26 21:48:00 yyyy dhcpd[82179]: Listening on Socket/7/igb1./20:xxxx:xxxx:xxxx::/64
Jan 26 21:48:00 yyyy dhcpd[82179]: Sending on Socket/7/igb1./20:xxxx:xxxx:xxxx::/64
Jan 26 21:48:00 yyyy dhcpd[82179]: Listening on Socket/7/igb1/20:xxxx:xxxx:xxxx::/64
Jan 26 21:48:00 yyyy dhcpd[82179]: Sending on Socket/7/igb1/20:xxxx:xxxx:xxxx::/64
Jan 26 21:48:00 yyyy dhcpd[82179]: Server starting service.
Jan 26 21:48:01 yyyy dhcpd[71932]: DHCPRELEASE of 192.168..106 from :::::** () via igb1.** (found)
Jan 26 21:48:01 yyyy dhcpleases[25523]: Sending HUP signal to dns daemon(54451)
Jan 26 21:48:14 yyyy dhcpd[71932]: DHCPDISCOVER from 2c:::::d via igb1.*
Jan 26 21:48:** yyyy dhcpd[71932]: DHCPDISCOVER from 7c:::::8 via igb1.*
Jan 26 21:48:** yyyy dhcpd[71932]: DHCPOFFER on 192.168.**.101 to 2:::**::d () via igb1.**
Jan 26 21:48:** yyyy dhcpd[71932]: DHCPREQUEST for 192.168..101 (192.168..1) from 2:::::4d () via igb1.
Jan 26 21:48:* yyyy dhcpd[71932]: DHCPACK on 192.168..101 to 2*:::::d (******) via igb1.
Jan 26 21:48:** yyyy dhcpleases[25523]: Sending HUP signal to dns daemon(54451)
Jan 26 21:48:** yyyy dhcpd[71932]: ICMP Echo Reply for 192.168..101 late or spurious.
Jan 26 21:48:16 yyyy dhcpd[71932]: DHCPOFFER on 192.168..106 to 7*:::::** () via igb1.
Jan 26 21:48:16 yyyy dhcpd[71932]: DHCPREQUEST for 192.168..106 (192.168..1) from 7*:::::8 (******) via igb1.
Jan 26 21:48:16 yyyy dhcpd[71932]: DHCPACK on 192.168..106 to 7*::::: () via igb1.
Jan 26 21:48:16 yyyy dhcpleases[25523]: Sending HUP signal to dns daemon(54451)
Jan 26 21:48:21 yyyy dhcpd[71932]: reuse_lease: lease age 1411 (secs) under 25% threshold, reply with unaltered, existing lease for 192.168..135
Jan 26 21:48:21 yyyy dhcpd[71932]: DHCPDISCOVER from 2:::::* () via igb1.
Jan 26 21:48:21 yyyy dhcpd[71932]: DHCPOFFER on 192.168..135 to 2:::::5 () via igb1.
Jan 26 21:48:21 yyyy dhcpd[71932]: reuse_lease: lease age 1411 (secs) under 25% threshold, reply with unaltered, existing lease for 192.168..135
Jan 26 21:48:21 yyyy dhcpd[71932]: DHCPREQUEST for 192.168..135 (192.168..1) from 2*:::::*** () via igb1.
Jan 26 21:48:21 yyyy dhcpd[71932]: DHCPACK on 192.168..135 to 2:::::* () via igb1.
Jan 26 21:52:08 yyyy dhcpd[71932]: DHCPDISCOVER from 7*:::::** via igb1.**
Jan 26 21:52:08 yyyy dhcpd[71932]: DHCPOFFER on 192.168.. to 7:::::** via igb1.**
Jan 26 21:52:08 yyyy dhcpd[71932]: DHCPREQUEST for 192.168.. (192.168..1) from :::::** via igb1.**
Jan 26 21:52:08 yyyy dhcpd[71932]: DHCPACK on 192.168.. to ::c::: via igb1.**

luckman212

@betapc Which interface is your FIOS attached to? igb0? What does ifconfig -m igb0 say?

betapc

@luckman212 said in FIOS - getting /56 PD via DHCP6 but no V6 is assigned to WAN:

ifconfig -m igb0

I am connected to igb0 for WAN

[22.05-RELEASE][admin@xxx.xxxx.com]/root: ifconfig -m igb0
igb0: flags=8843<UP,BROADCAST,RUNNING,SIMPLEX,MULTICAST> metric 0 mtu 1500
description: WAN
options=8120b8<VLAN_MTU,VLAN_HWTAGGING,JUMBO_MTU,VLAN_HWCSUM,WOL_MAGIC,VLAN_HWFILTER>
capabilities=f53fbb<RXCSUM,TXCSUM,VLAN_MTU,VLAN_HWTAGGING,JUMBO_MTU,VLAN_HWCSUM,TSO4,TSO6,LRO,WOL_UCAST,WOL_MCAST,WOL_MAGIC,VLAN_HWFILTER,VLAN_HWTSO,NETMAP,RXCSUM_IPV6,TXCSUM_IPV6>
ether xx:xx:xx:xx:xx:xx
inet6 fe80::2e0:67ff:fe2c:6828%igb0 prefixlen 64 scopeid 0x1
inet 1xx.xx.xx.xxx netmask 0xffffff00 broadcast 1xx.xx.xx.xxx
media: Ethernet autoselect (1000baseT <full-duplex>)
status: active
supported media:
media autoselect
media 1000baseT
media 1000baseT mediaopt full-duplex
media 100baseTX mediaopt full-duplex
media 100baseTX
media 10baseT/UTP mediaopt full-duplex
media 10baseT/UTP
nd6 options=23<PERFORMNUD,ACCEPT_RTADV,AUTO_LINKLOCAL>

Thanks

luckman212

@betapc Hmm. I wonder if you're hitting this known bug affecting Alcatel ONTs + Intel PHYs by chance? Could you retry after disabling Hardware Checksum Offloading at System → Advanced → Networking?

betapc

@luckman212 I already have disable the checksum, I have all 4 checks as show in the picture above, when I run the ifconfig -m igb0 command.

luckman212

@betapc I'm running out of ideas. What does the command below output?

sh -c '/sbin/rtsol -DF igb0 2>&1'

betapc

@luckman212 said in FIOS - getting /56 PD via DHCP6 but no V6 is assigned to WAN:

sh -c '/sbin/rtsol -DF igb0 2>&1'

[22.05-RELEASE][admin@xxx.xxxx.com]/root: sh -c '/sbin/rtsol -DF igb0 2>&1'
rtsol: checking if igb0 is ready...
rtsol: igb0 is ready
rtsol: set timer for igb0 to 1s
rtsol: New timer is 1s
rtsol: timer expiration on igb0, state = 1
rtsol: set timer for igb0 to 4s
rtsol: New timer is 4s
rtsol: received RA from xxx::xxx:xxx:xxx:xxx on igb0, state is 2
rtsol: ManagedConfigFlag on igb0 is turned on
rtsol: Processing RA
rtsol: ndo = 0x7fffffffe2e0
rtsol: ndo->nd_opt_type = 1
rtsol: ndo->nd_opt_len = 1
rtsol: rsid = [igb0:slaac]
rtsol: stop timer for igb0
rtsol: there is no timer
[22.05-RELEASE][admin@xxx.xxxx.com]/root:

luckman212

@betapc Is that the full output? Doesn't seem like you're receiving a PD in those frames.

There should be lines like this

rtsol: ndo->nd_opt_type = 25
rtsol: ndo->nd_opt_len = 3
rtsol: nsbuf = 2600:4041:xxxx:xxxx:xxxx:xxxx:xxxx:xxxx
...
rtsol: write to child = 2600:4041:xxxx:xxxx:xxxx:xxxx:xxxx:xxxx(39)

betapc

@luckman212 Yes that is the full output, I don't see those line. I have IPv6, all my LANs received IPv6 and I can connect to the internet with IPv6 only. I release all the IP address and renew same didn't change anything.

So, what do you think will be the problem here?

luckman212

@betapc I'm not sure. Do you have debug enabled for dhcp6?