radvd[...]: sendmsg: Permission denied

[gothbert]

Hi,

I do not know since when this occurs and if it was already there before the update to 17.7.9. My routing.log gets spilled with messages. This is how the log looks like after a reboot:

Code: [Select]

Dec 12 20:05:41 opnsense rtsold: Starting dhcp6 client for interface wan(igb0)
Dec 12 20:05:45 opnsense rtsold: Starting dhcp6 client for interface wan(igb0)
Dec 12 20:05:54 opnsense radvd[12509]: version 1.15 started
Dec 12 20:07:57 opnsense radvd[12772]: sendmsg: Permission denied
Dec 12 20:08:06 opnsense radvd[12772]: sendmsg: Permission denied
Dec 12 20:08:13 opnsense radvd[12772]: sendmsg: Permission denied
Dec 12 20:08:22 opnsense radvd[12772]: sendmsg: Permission denied
Dec 12 20:08:26 opnsense radvd[12772]: sendmsg: Permission denied
Dec 12 20:08:31 opnsense radvd[12772]: sendmsg: Permission denied
Dec 12 20:08:37 opnsense radvd[12772]: sendmsg: Permission denied
Dec 12 20:08:46 opnsense radvd[12772]: sendmsg: Permission denied
Dec 12 20:08:55 opnsense radvd[12772]: sendmsg: Permission denied
Dec 12 20:09:01 opnsense radvd[12772]: sendmsg: Permission denied
Dec 12 20:09:09 opnsense radvd[12772]: sendmsg: Permission denied
Dec 12 20:09:16 opnsense radvd[12772]: sendmsg: Permission denied
Dec 12 20:09:19 opnsense radvd[12772]: sendmsg: Permission denied
Dec 12 20:09:24 opnsense radvd[12772]: sendmsg: Permission denied
Dec 12 20:09:30 opnsense radvd[12772]: sendmsg: Permission denied
Dec 12 20:09:32 opnsense radvd[12772]: Exiting, sigterm or sigint received.
Dec 12 20:09:32 opnsense radvd[12772]: sending stop adverts
Dec 12 20:09:32 opnsense radvd[12772]: sendmsg: Permission denied
Dec 12 20:09:32 opnsense radvd[12772]: removing /var/run/radvd.pid
Dec 12 20:09:36 opnsense rtsold: Starting dhcp6 client for interface wan(igb0)
Dec 12 20:09:40 opnsense radvd[64346]: version 1.15 started
Dec 12 20:09:40 opnsense radvd[64868]: sendmsg: Permission denied
Dec 12 20:09:40 opnsense radvd[64868]: sendmsg: Can't assign requested address
Dec 12 20:09:40 opnsense radvd[64868]: Exiting, sigterm or sigint received.
Dec 12 20:09:40 opnsense radvd[64868]: sending stop adverts
Dec 12 20:09:40 opnsense radvd[64868]: sendmsg: Can't assign requested address
Dec 12 20:09:40 opnsense radvd[64868]: sendmsg: Can't assign requested address
Dec 12 20:09:40 opnsense radvd[64868]: removing /var/run/radvd.pid
Dec 12 20:09:41 opnsense radvd[78492]: version 1.15 started
Dec 12 20:09:41 opnsense radvd[78845]: sendmsg: Can't assign requested address
Dec 12 20:09:41 opnsense radvd[78845]: sendmsg: Can't assign requested address
Dec 12 20:09:41 opnsense rtsold: Starting dhcp6 client for interface wan(igb0)
Dec 12 20:09:45 opnsense radvd[78845]: Exiting, sigterm or sigint received.
Dec 12 20:09:45 opnsense radvd[78845]: sending stop adverts
Dec 12 20:09:45 opnsense radvd[78845]: sendmsg: Permission denied
Dec 12 20:09:45 opnsense radvd[78845]: removing /var/run/radvd.pid
Dec 12 20:09:45 opnsense radvd[96804]: version 1.15 started
Dec 12 20:09:45 opnsense radvd[98771]: sendmsg: Permission denied
Dec 12 20:09:46 opnsense radvd[98771]: Exiting, sigterm or sigint received.
Dec 12 20:09:46 opnsense radvd[98771]: sending stop adverts
Dec 12 20:09:46 opnsense radvd[98771]: sendmsg: Permission denied
Dec 12 20:09:46 opnsense radvd[98771]: sendmsg: Can't assign requested address
Dec 12 20:09:46 opnsense radvd[98771]: removing /var/run/radvd.pid
Dec 12 20:09:46 opnsense radvd[25046]: version 1.15 started
Dec 12 20:09:46 opnsense radvd[25054]: sendmsg: Permission denied
Dec 12 20:09:46 opnsense radvd[25054]: sendmsg: Can't assign requested address
Dec 12 20:09:46 opnsense radvd[25054]: Exiting, sigterm or sigint received.
Dec 12 20:09:46 opnsense radvd[25054]: sending stop adverts
Dec 12 20:09:46 opnsense radvd[25054]: sendmsg: Can't assign requested address
Dec 12 20:09:46 opnsense radvd[25054]: sendmsg: Can't assign requested address
Dec 12 20:09:46 opnsense radvd[25054]: removing /var/run/radvd.pid
Dec 12 20:09:46 opnsense radvd[36299]: version 1.15 started
Dec 12 20:09:46 opnsense radvd[36965]: sendmsg: Can't assign requested address
Dec 12 20:09:46 opnsense radvd[36965]: sendmsg: Can't assign requested address
Dec 12 20:09:46 opnsense radvd[36965]: Exiting, sigterm or sigint received.
Dec 12 20:09:46 opnsense radvd[36965]: sending stop adverts
Dec 12 20:09:46 opnsense radvd[36965]: sendmsg: Can't assign requested address
Dec 12 20:09:46 opnsense radvd[36965]: sendmsg: Can't assign requested address
Dec 12 20:09:46 opnsense radvd[36965]: removing /var/run/radvd.pid
Dec 12 20:09:47 opnsense rtsold: Starting dhcp6 client for interface wan(igb0)
Dec 12 20:09:48 opnsense radvd[69684]: version 1.15 started
Dec 12 20:09:48 opnsense radvd[69906]: sendmsg: Permission denied
Dec 12 20:09:48 opnsense radvd[69906]: sendmsg: Can't assign requested address
Dec 12 20:09:48 opnsense radvd[69906]: Exiting, sigterm or sigint received.
Dec 12 20:09:48 opnsense radvd[69906]: sending stop adverts
Dec 12 20:09:48 opnsense radvd[69906]: sendmsg: Can't assign requested address
Dec 12 20:09:48 opnsense radvd[69906]: sendmsg: Can't assign requested address
Dec 12 20:09:48 opnsense radvd[69906]: removing /var/run/radvd.pid
Dec 12 20:09:48 opnsense radvd[77485]: version 1.15 started
Dec 12 20:09:48 opnsense radvd[78132]: sendmsg: Can't assign requested address
Dec 12 20:09:48 opnsense radvd[78132]: sendmsg: Can't assign requested address
Dec 12 20:09:48 opnsense rtsold: Starting dhcp6 client for interface wan(igb0)
Dec 12 20:09:53 opnsense radvd[78132]: Exiting, sigterm or sigint received.
Dec 12 20:09:53 opnsense radvd[78132]: sending stop adverts
Dec 12 20:09:53 opnsense radvd[78132]: sendmsg: Permission denied
Dec 12 20:09:53 opnsense radvd[78132]: removing /var/run/radvd.pid
Dec 12 20:09:54 opnsense radvd[63529]: version 1.15 started
Dec 12 20:09:54 opnsense radvd[64432]: sendmsg: Permission denied
Dec 12 20:10:04 opnsense radvd[64432]: sendmsg: Permission denied
Dec 12 20:10:08 opnsense radvd[64432]: sendmsg: Permission denied
Dec 12 20:10:16 opnsense radvd[64432]: sendmsg: Permission denied
Dec 12 20:10:21 opnsense radvd[64432]: sendmsg: Permission denied
Dec 12 20:10:27 opnsense radvd[64432]: sendmsg: Permission denied
Dec 12 20:10:31 opnsense radvd[64432]: sendmsg: Permission denied
Dec 12 20:10:40 opnsense radvd[64432]: sendmsg: Permission denied
Dec 12 20:10:48 opnsense radvd[64432]: sendmsg: Permission denied
Dec 12 20:10:56 opnsense radvd[64432]: sendmsg: Permission denied
Dec 12 20:11:01 opnsense radvd[64432]: sendmsg: Permission denied
Dec 12 20:11:10 opnsense radvd[64432]: sendmsg: Permission denied
Dec 12 20:11:16 opnsense radvd[64432]: sendmsg: Permission denied
Dec 12 20:11:20 opnsense radvd[64432]: sendmsg: Permission denied
Dec 12 20:11:29 opnsense radvd[64432]: sendmsg: Permission denied
Dec 12 20:11:36 opnsense radvd[64432]: sendmsg: Permission denied
Dec 12 20:11:45 opnsense radvd[64432]: sendmsg: Permission denied
And from there on the message repeats all over every 4 to 6 seconds. I did not touch anything in the first 10 minutes after the reboot to let the system settle. IPv6 works well.

Anything I can do to track the cause?

Best regards,
Boris

[franco]

Hi Boris,

Seems that an interface disappears and comes back up, but radvd isn't restarted.

Where are you using interface tracking? Do you have manual router advertisements set up on other interfaces as well?


Cheers,
Franco

[gothbert]

Hi Franco,

this is the interface setup:

interface WAN, igb0 gets IPv6 from Fritzbox
interface HOME, igb1, IPv6 tracks interface
interface LET, igb2, IPv6 tracks interface
interface DMZ, igb3, -
OpenVPN, ovpbc1, -

Regards,
Boris

[gothbert]

Hi,

this issue is still present in OPNsense 18.1.9-amd64. Anything I can do about it?

Best regards
Boris

[marjohn56]

Can I ask what hardware you are using?

[gothbert]

Can I ask what hardware you are using?

It is a Supermicro X11SBA-LN4F board with 4 Intel i210 Ethernet Controllers on board. It sits behind a Fritz!Box 6490 Cable that connects me to the internet via cable modem.

[marjohn56]

Checking back through the archives there seems to be several users running these boards, no-one else has reported this issue.


Have you tried a clean install and configuring from scratch?


I know I have had problems in the past where a config has got corrupted in some way and just copying it from an old installation to a new one did not help. A clean install and a new config fixed my issues. I know it's a pain, but that would be the first thing I'd try.

[gothbert]

I know I have had problems in the past where a config has got corrupted in some way and just copying it from an old installation to a new one did not help. A clean install and a new config fixed my issues. I know it's a pain, but that would be the first thing I'd try.

That appeared such a painful workaround for me, given alone the large amount of hostnames configured in unbound, that I continued to search the internets and found this: https://forum.netgate.com/topic/58316/no-dhcpv6-on-internal-net-radvd-issue-sendmsg-permission-denied

With some further trial-and-error work, I found out that the message appears if and only if the only configured zone in the captive portal is active. Zone turned off: no message, zone turned on: message.

Further inspired by the cited article, I disabled all firewall rules on the local net the captive portal was assigned to. But this did not make the message disappear. DHCPv6 is off. Disabling DHCPv4 on this local net did nothing to the message. Neither does removing this local net from forward proxying through Squid.

Maybe this gives some ideas where to further search for the culprit.

Best regards,
Boris

[franco]

Hello,

Not sure if related, but on PPPoE radvd isn't reconfigured when "Use IPv4 connectivity" is set and DHCPv6 or SLAAC is used as the WAN IPv6 config type.

https://github.com/opnsense/core/commit/baf292e91a


Cheers,
Franco

[marjohn56]

As soon as we've finished with dhclient/dhcp6c stuff I'll be pushing on with the ability to edit dhcpd6 and radvd when in that mode, that may fix this issue as you'll be able to configure it.

[gothbert]

Is there any issue on GitHub I can subscribe to and at some stage contribute to as a tester if needed?

[marjohn56]

There's only my own local code at present, there will be a PR later this week with any luck.

[franco]

It could be https://github.com/opnsense/core/issues/2314 ?


Cheers,
Franco

[gothbert]

subscribed

[marjohn56]

If you want to try where I have got to so far, and I am not quite ready for a PR yet, but you can try it, you'll need to switch the dev stream. Once you have done that, then update. That will update the binaries as needed.


Once that is complete you'll need to update the core by doing this, open a shell and issue the following commands:


# opnsense-code core
# cd /usr/core
# make upgrade


That will bring you bang up to date with where the code is at for 18.7.b*


Next, you'll need to patch my commit.. do this by issuing the following command.


# opnsense-patch -a marjohn56  40fb7e8


Now, you'll need to enable the option to manually adjust dhcpd6 and RADVD, do this by going to system->Settings->General and enable “Manual IPv6 DHCPD and RA”


Have a play, there is still work to be done, for example if the prefix changes then the config needs to be re-written and dhcpd restarted.


If it doesn't work for you or you have issues, then issue the same command

# opnsense-patch -a marjohn56  40fb7e8

to revert it. If that fails then a



# cd /usr/core
# make upgrade


will restore things to original.


Good Luck, and let me know how you get on.