Netgate Discussion Forum
    • Categories
    • Recent
    • Tags
    • Popular
    • Users
    • Search
    • Register
    • Login

    Unbound ipv6 problems anyone?

    2.4 Development Snapshots
    6
    63
    13.9k
    Loading More Posts
    • Oldest to Newest
    • Newest to Oldest
    • Most Votes
    Reply
    • Reply as topic
    Log in to reply
    This topic has been deleted. Only users with topic management privileges can see it.
    • johnpozJ
      johnpoz LAYER 8 Global Moderator
      last edited by

      Its possible your ipv6 is not coming up as fast as your ipv4?  Your dhcp with tracking on your interfaces?  Or maybe your ipv6 is changing on reboot?

      I looked into my error - doh!  Not my lan interface, my wan.. Which has no ipv6 on it so yeah makes sense why the error.  Changed it to no bind to link-local on wan and no more log spam ;)

      An intelligent man is sometimes forced to be drunk to spend time with his fools
      If you get confused: Listen to the Music Play
      Please don't Chat/PM me for help, unless mod related
      SG-4860 24.11 | Lab VMs 2.7.2, 24.11

      1 Reply Last reply Reply Quote 0
      • B
        bimmerdriver
        last edited by

        @johnpoz:

        Its possible your ipv6 is not coming up as fast as your ipv4?  Your dhcp with tracking on your interfaces?  Or maybe your ipv6 is changing on reboot?

        I looked into my error - doh!  Not my lan interface, my wan.. Which has no ipv6 on it so yeah makes sense why the error.  Changed it to no bind to link-local on wan and no more log spam ;)

        It's definitely repeatable that the problem occurs after reboot and persists until unbound is restarted.

        I cleared the logs and rebooted. unbound and dhcp6c appear to be starting up concurrently. Maybe this is the problem.

        Here are log messages from unbound from after reboot to the first error:

        Jul 11 09:51:18	unbound	16498:1	info: error sending query to auth server 2001:500:84::b port 53
        Jul 11 09:51:18	unbound	16498:1	info: error sending query to auth server 2001:500:84::b port 53
        Jul 11 09:51:18	unbound	16498:1	info: priming . IN NS
        Jul 11 09:51:18	unbound	16498:1	info: resolving localdomain.localdomain. A IN
        Jul 11 09:51:18	unbound	16498:0	info: priming . IN NS
        Jul 11 09:51:18	unbound	16498:0	info: resolving localdomain.localdomain. AAAA IN
        Jul 11 09:51:14	unbound	16498:0	info: start of service (unbound 1.6.3).
        Jul 11 09:51:14	unbound	16498:0	notice: init module 1: iterator
        Jul 11 09:51:14	unbound	16498:0	notice: init module 0: validator
        

        Here are the first log messages from dhcp6c:

        Jul 11 09:51:15	dhcp6c	9281	add an address 2001:569:74c0:da00:215:5dff:fe5c:e21e/64 on hn0
        Jul 11 09:51:15	dhcp6c	9281	dhcp6c Received REQUEST
        Jul 11 09:51:15	dhcp6c	9281	Sending Request
        Jul 11 09:51:14	dhcp6c	9281	Sending Solicit
        Jul 11 09:51:13	dhcp6c	9249	skip opening control port
        Jul 11 09:51:13	dhcp6c	9249	failed initialize control message authentication
        Jul 11 09:51:13	dhcp6c	9249	failed to open /usr/local/etc/dhcp6cctlkey: No such file or directory
        
        1 Reply Last reply Reply Quote 0
        • B
          bimmerdriver
          last edited by

          I should have added that my isp requires dhcpv6 solicit before RA.

          1 Reply Last reply Reply Quote 0
          • B
            bimmerdriver
            last edited by

            I updated to the latest snapshot from today and after the reboot, the nslookup / dig problem was back. After restarting unbound, nslookup and dig worked properly. It seems to be a solid problem that restarting unbound is required after a reboot. This time, there were no errors in the log. Since most users do not require the do not wait for RA flag, possibly that's why this is occurring on my system. Are there any tests I should do or log info that I should post? Is this a bug?

            1 Reply Last reply Reply Quote 0
            • w0wW
              w0w
              last edited by

              I think it can be related to https://forum.pfsense.org/index.php?topic=133129.0 not directly but somehow…
              I don't see any other changes regarding unbound last days.

              1 Reply Last reply Reply Quote 0
              • B
                bimmerdriver
                last edited by

                @w0w:

                I think it can be related to https://forum.pfsense.org/index.php?topic=133129.0 not directly but somehow…
                I don't see any other changes regarding unbound last days.

                This has been going on for more than a month, so it's not just from the past few days.

                1 Reply Last reply Reply Quote 0
                • C
                  chrcoluk
                  last edited by

                  not on latest snapshot but am using 2.4, no issues with ipv6 lookups using unbound resolver.

                  pfSense CE 2.7.2

                  1 Reply Last reply Reply Quote 0
                  • B
                    bimmerdriver
                    last edited by

                    I just updated and for the first time in a long time, nslookup and dig both worked without restarting unbound. However, I rebooted again to see if it would stick and unfortunately, both were broken again until after I restarted unbound.

                    1 Reply Last reply Reply Quote 0
                    • C
                      chrcoluk
                      last edited by

                      I suggest you examine your logs to look for indicators of whats going on.

                      In unbound settings, disable options to bind to specific interfaces (so it binds to everything) as that can cause the problem you are reporting, basically it starts before ipv6 is up so doesnt bind to it.

                      pfSense CE 2.7.2

                      1 Reply Last reply Reply Quote 0
                      • B
                        bimmerdriver
                        last edited by

                        I noticed watching the console while the system was rebooting that unbound starts well before dhcpv6. I am using the do not wait for RA setting, so PD does not happen until dhcp6c starts. That may be a problem, because dhcp6c and unbound are starting almost concurrently, as you can see from the log messages (in reverse chronological order).

                        All of the unbound settings are default. I have not enabled any options to bind to specific interfaces.

                        Here are the first few log messages from unbound after booting (note error messages):

                        Jul 18 18:44:30	unbound	23934:1	info: query response was ANSWER
                        Jul 18 18:44:30	unbound	23934:1	info: reply from <.> 192.33.4.12#53
                        Jul 18 18:44:30	unbound	23934:1	info: response for . DNSKEY IN
                        Jul 18 18:44:30	unbound	23934:1	info: resolving . DNSKEY IN
                        Jul 18 18:44:30	unbound	23934:1	info: prime trust anchor
                        Jul 18 18:44:30	unbound	23934:1	info: query response was NXDOMAIN ANSWER
                        Jul 18 18:44:30	unbound	23934:1	info: reply from <.> 192.33.4.12#53
                        Jul 18 18:44:30	unbound	23934:1	info: response for localdomain. AAAA IN
                        Jul 18 18:44:30	unbound	23934:1	info: priming successful for . NS IN
                        Jul 18 18:44:30	unbound	23934:1	info: query response was ANSWER
                        Jul 18 18:44:30	unbound	23934:1	info: reply from <.> 192.36.148.17#53
                        Jul 18 18:44:30	unbound	23934:1	info: response for . NS IN
                        Jul 18 18:44:29	unbound	23934:1	info: error sending query to auth server 2001:500:84::b port 53
                        Jul 18 18:44:29	unbound	23934:1	info: error sending query to auth server 2001:500:1::53 port 53
                        Jul 18 18:44:29	unbound	23934:1	info: error sending query to auth server 2001:500:2f::f port 53
                        Jul 18 18:44:29	unbound	23934:1	info: priming . IN NS
                        Jul 18 18:44:29	unbound	23934:1	info: resolving localdomain. AAAA IN
                        Jul 18 18:44:27	unbound	23934:0	info: start of service (unbound 1.6.3).
                        Jul 18 18:44:27	unbound	23934:0	notice: init module 1: iterator
                        Jul 18 18:44:27	unbound	23934:0	notice: init module 0: validator
                        

                        Here are the first few log messages from dhcp after booting:

                        Jul 18 18:44:28	dhcp6c	12378	add an address 2001:a:b:c:215:5dff:fe5c:e21e/64 on hn0
                        Jul 18 18:44:28	dhcp6c	12378	dhcp6c Received REQUEST
                        Jul 18 18:44:27	dhcp6c	12378	Sending Request
                        Jul 18 18:44:26	dhcp6c	12378	Sending Solicit
                        Jul 18 18:44:25	dhcp6c	12058	skip opening control port
                        Jul 18 18:44:25	dhcp6c	12058	failed initialize control message authentication
                        Jul 18 18:44:25	dhcp6c	12058	failed to open /usr/local/etc/dhcp6cctlkey: No such file or directory
                        Jul 18 18:44:22	dhclient		Creating resolv.conf
                        Jul 18 18:44:22	dhclient		/sbin/route add default 154.20.116.1
                        Jul 18 18:44:22	dhclient		Adding new routes to interface: hn1
                        Jul 18 18:44:22	dhclient		New Routers (hn1): 154.20.116.1
                        Jul 18 18:44:22	dhclient		New Broadcast Address (hn1): 154.20.119.255
                        Jul 18 18:44:22	dhclient		New Subnet Mask (hn1): 255.255.252.0
                        Jul 18 18:44:22	dhclient		New IP Address (hn1): 154.20.118.8
                        Jul 18 18:44:22	dhclient		ifconfig hn1 inet 154.20.118.8 netmask 255.255.252.0 broadcast 154.20.119.255
                        Jul 18 18:44:22	dhclient		Starting add_new_address()
                        Jul 18 18:44:22	dhclient		REBOOT
                        Jul 18 18:44:22	dhclient		PREINIT
                        

                        Here are the first few log messages from unbound after restarting unbound (note no error messages):

                        Jul 18 18:47:35	unbound	90108:1	info: query response was REFERRAL
                        Jul 18 18:47:35	unbound	90108:1	info: reply from <.> 198.97.190.53#53
                        Jul 18 18:47:35	unbound	90108:1	info: response for ns1.netgate.com. AAAA IN
                        Jul 18 18:47:35	unbound	90108:1	info: query response was REFERRAL
                        Jul 18 18:47:35	unbound	90108:1	info: reply from <.> 2001:7fd::1#53
                        Jul 18 18:47:35	unbound	90108:1	info: response for ns1.netgate.com. A IN
                        Jul 18 18:47:34	unbound	90108:1	info: query response was REFERRAL
                        Jul 18 18:47:34	unbound	90108:1	info: reply from <.> 2001:500:12::d0d#53
                        Jul 18 18:47:34	unbound	90108:1	info: response for ns2.netgate.com. A IN
                        Jul 18 18:47:34	unbound	90108:1	info: resolving ns1.netgate.com. A IN
                        Jul 18 18:47:34	unbound	90108:1	info: resolving ns2.netgate.com. AAAA IN
                        Jul 18 18:47:34	unbound	90108:1	info: resolving ns2.netgate.com. A IN
                        Jul 18 18:47:34	unbound	90108:1	info: resolving ns1.netgate.com. AAAA IN
                        Jul 18 18:47:34	unbound	90108:1	info: query response was REFERRAL
                        Jul 18 18:47:34	unbound	90108:1	info: reply from <org.> 2001:500:e::1#53
                        Jul 18 18:47:34	unbound	90108:1	info: response for _https._tcp.beta.pfsense.org. SRV IN
                        Jul 18 18:47:34	unbound	90108:1	info: query response was REFERRAL
                        Jul 18 18:47:34	unbound	90108:1	info: reply from <.> 192.5.5.241#53
                        Jul 18 18:47:34	unbound	90108:1	info: response for _https._tcp.beta.pfsense.org. SRV IN
                        Jul 18 18:47:34	unbound	90108:1	info: priming successful for . NS IN
                        Jul 18 18:47:34	unbound	90108:1	info: query response was ANSWER
                        Jul 18 18:47:34	unbound	90108:1	info: reply from <.> 2001:500:12::d0d#53
                        Jul 18 18:47:34	unbound	90108:1	info: response for . NS IN
                        Jul 18 18:47:34	unbound	90108:1	info: priming . IN NS
                        Jul 18 18:47:34	unbound	90108:1	info: resolving _https._tcp.beta.pfsense.org. SRV IN
                        Jul 18 18:47:32	unbound	90108:0	info: start of service (unbound 1.6.3).
                        Jul 18 18:47:32	unbound	90108:0	notice: init module 1: iterator
                        Jul 18 18:47:32	unbound	90108:0	notice: init module 0: validator</org.>
                        
                        1 Reply Last reply Reply Quote 0
                        • ?
                          Guest
                          last edited by

                          It would not be difficult to force Unbound to restart on a valid update from dhcp6c, the changes implemented a while back means that it's now possible to differentiate between an a refresh or new lease. However, Chris was having a lot of issues with unbound that I think are now fine and I am not sure if an Unbound restart on a new lease might bring his problems back.

                          If you like, I can have a look and send out a patch to you and Chris to see if it works for both of you.

                          The other option is a flag to enable or disable an unbound restart on a new ipv6 lease.

                          Thoughts.

                          1 Reply Last reply Reply Quote 0
                          • C
                            chrcoluk
                            last edited by

                            please no :)

                            unbound restarting on every dhcp6 renew is crazy.

                            As long as the renew keeps the same prefix/ip I dont see why unbound would have a problem.

                            Martin I will test the patch tho.  As I expect a new lease wont be triggered on a renew, as long as you also exclude a rebind.

                            pfSense CE 2.7.2

                            1 Reply Last reply Reply Quote 0
                            • ?
                              Guest
                              last edited by

                              :) I did not intend to restart it on a renew or rebind, that would be silly.

                              1 Reply Last reply Reply Quote 0
                              • C
                                chrcoluk
                                last edited by

                                yeah I know you will find a solution that works for everyone, email me when ready with the patch I will test no problem. :)

                                Your optional flag seems a good idea.

                                pfSense CE 2.7.2

                                1 Reply Last reply Reply Quote 0
                                • ?
                                  Guest
                                  last edited by

                                  I'll try and find time tomorrow… if I can stop playing Elite Dangerous :o

                                  1 Reply Last reply Reply Quote 0
                                  • ?
                                    Guest
                                    last edited by

                                    Something else is afoot here. I have rebooted multiple times, using dhcp6 before RA, and I cannot make it fall over.

                                    Bimmer, is it possible that sometimes there is a slow response from your ISP for the v6 lease, hence the 'sometimes' its OK?

                                    It maybe that if that is the case that there is a bit of a catch 22 going on, in that rc.newwanipv6 cannot restart unbound as it's still in the booting up process. Also, and I've not delved into that bit of the code before, unbound is being killed and restarted, if already running, rather than a SIGHUP; I need to study that a bit more to see if there is a reason for that.

                                    • note *

                                    Having studied and read Jimp's note that unbound should be killed then that answers that question. Whilst there is already work going on in this area I will not mess with it, too many cooks….

                                    1 Reply Last reply Reply Quote 0
                                    • B
                                      bimmerdriver
                                      last edited by

                                      Sorry for the slow response. I've been away all week… I'll try running wireshark to see what's happening. I suspect it will the same as it always was. I have a suspicion this problem has been present all along, but I haven't noticed it because unbound was getting restarted so often. Possibly now that it's not getting restarted, the problem is visible. That would explain why I didn't notice it before recently, along with the other changes.

                                      1 Reply Last reply Reply Quote 0
                                      • B
                                        bimmerdriver
                                        last edited by

                                        I captured icmpv6 and dhcpv6 packets with wireshark during a reboot. Everything appears the way it always has. There are no significant delays in any of the replies.

                                        Capture.PNG
                                        Capture.PNG_thumb

                                        1 Reply Last reply Reply Quote 0
                                        • B
                                          bimmerdriver
                                          last edited by

                                          I created bug #7750 "unbound refuses ipv6 queries after reboot" for this issue.

                                          1 Reply Last reply Reply Quote 0
                                          • B
                                            bimmerdriver
                                            last edited by

                                            I just did another reboot to capture log info. It's consistent that unbound starts before the PD process has completed.

                                            Aug 2 13:12:15	dhcp6c	11947	add an address 2001:*:*:*:215:5dff:fe5c:e21e/64 on hn0
                                            Aug 2 13:12:15	dhcp6c	11947	dhcp6c Received REQUEST
                                            Aug 2 13:12:15	dhcp6c	11947	Sending Request
                                            Aug 2 13:12:14	dhcp6c	11947	Sending Solicit
                                            Aug 2 13:12:13	dhcp6c	11867	skip opening control port
                                            Aug 2 13:12:13	dhcp6c	11867	failed initialize control message authentication
                                            Aug 2 13:12:13	dhcp6c	11867	failed to open /usr/local/etc/dhcp6cctlkey: No such file or directory
                                            
                                            Aug 2 13:12:27	unbound	24093:1	info: response for . NS IN
                                            Aug 2 13:12:27	unbound	24093:1	info: priming . IN NS
                                            Aug 2 13:12:27	unbound	24093:1	info: resolving ipv6.msftconnecttest.com. A IN
                                            Aug 2 13:12:27	unbound	24093:1	info: priming . IN NS
                                            Aug 2 13:12:27	unbound	24093:1	info: resolving ipv6.msftconnecttest.com. AAAA IN
                                            Aug 2 13:12:27	unbound	24093:1	info: priming . IN NS
                                            Aug 2 13:12:27	unbound	24093:1	info: resolving 0.pfsense.pool.ntp.org. A IN
                                            Aug 2 13:12:14	unbound	24093:0	info: start of service (unbound 1.6.3).
                                            Aug 2 13:12:14	unbound	24093:0	notice: init module 1: iterator
                                            Aug 2 13:12:14	unbound	24093:0	notice: init module 0: validator
                                            
                                            1 Reply Last reply Reply Quote 0
                                            • First post
                                              Last post
                                            Copyright 2025 Rubicon Communications LLC (Netgate). All rights reserved.