23.05 pf was wedged/busy and has been reset
-
Hmm, that looks a lot like this: https://redmine.pfsense.org/issues/13408
However that is fixed in 23.05. What version did you upgrade from? I assume it didn't do this in the previous version.
-
@stephenw10 Yes, it is similar to that error although that states the rules do not load. I think my rules are loading because everything is working as expected.
I upgraded from 23.01 to 23.05. I had similar trouble others reported about the GUI upgrade saying I was already on the latest. Using "pfsense-upgrade" via SSH got me updated.I have been able to confirm rebooting does not solve the issue. In the meantime, I changed my Xbox power settings to avoid this. I can't say for sure if this was a problem or not in 23.01 because, like I said my Xbox power setting changed recently, so it's possible the problem was there present in 23.01 but not being triggered since the gaming LAN interface was not going down and back up. I'm not sure exactly, but my scenario is 100% reproducible at this point.
-
Do you have the system logs showing what happens when the xbox wakes up and reconnects?
If it detects pf not responding and resets it should then load the rules again and succeed. That should show in the log.
-
If it's only when it wakes up you could try a small 4 port switch as that would stay up all the time and connect the Xbox to the switch. But that would only fix the symptoms not the root issue. Have you tried fresh firmware?
-
@JonathanLee said in 23.05 pf was wedged/busy and has been reset:
If it's only when it wakes up you could try a small 4 port switch as that would stay up all the time and connect the Xbox to the switch. But that would only fix the symptoms not the root issue. Have you tried fresh firmware?
Thanks for the suggestion. That was exactly my thought and one of my proposed work-arounds in my original post. A 4/5 port switch would use less energy than the Xbox in sleep mode. I would prefer to not buy a switch, but I may end up doing that since it may also benefit my other console which I hardly ever use anymore.
I'm a little more concerned about my pfsense install than this particular issue though. If something isn't right on this install, what else could be going on under the hood I don't know about. I did this update to 23.05 on my home firewall as a test. I'm giving it some time before doing the update on the office firewall. It looks like I may give it more time than I originally planned. I have not tried fresh firmware. I would have to go back to the latest CE and then upgrade to 23.01 and then to 23.05. It's not exactly something I want to do if I don't have to. I have other things on my plate at the moment.
-
@stephenw10 said in 23.05 pf was wedged/busy and has been reset:
Do you have the system logs showing what happens when the xbox wakes up and reconnects?
If it detects pf not responding and resets it should then load the rules again and succeed. That should show in the log.
Here is the log...
Jun 12 13:08:56 check_reload_status 428 Linkup starting igb2 Jun 12 13:08:56 kernel igb2: link state changed to UP Jun 12 13:08:56 check_reload_status 428 Linkup starting igb2 Jun 12 13:08:56 kernel igb2: link state changed to DOWN Jun 12 13:08:57 php-fpm 69398 /rc.linkup: Hotplug event detected for GAMING(opt1) static IP address (4: 192.168.20.1) Jun 12 13:08:57 php-fpm 69398 /rc.linkup: DEVD Ethernet attached event for opt1 Jun 12 13:08:57 php-fpm 69398 /rc.linkup: HOTPLUG: Triggering address refresh on opt1 (igb2) Jun 12 13:08:57 check_reload_status 428 rc.newwanip starting igb2 Jun 12 13:08:57 check_reload_status 428 Reloading filter Jun 12 13:08:57 php-fpm 69398 /rc.linkup: Hotplug event detected for GAMING(opt1) static IP address (4: 192.168.20.1) Jun 12 13:08:57 php-fpm 69398 /rc.linkup: DEVD Ethernet detached event for opt1 Jun 12 13:08:57 check_reload_status 428 Reloading filter Jun 12 13:08:58 php-fpm 398 /rc.newwanip: rc.newwanip: Info: starting on igb2. Jun 12 13:08:58 php-fpm 398 /rc.newwanip: rc.newwanip: on (IP address: 192.168.20.1) (interface: GAMING[opt1]) (real interface: igb2). Jun 12 13:09:01 kernel igb2: link state changed to UP Jun 12 13:09:02 check_reload_status 428 Linkup starting igb2 Jun 12 13:09:03 php-fpm 3098 /rc.linkup: Hotplug event detected for GAMING(opt1) static IP address (4: 192.168.20.1) Jun 12 13:09:03 php-fpm 3098 /rc.linkup: DEVD Ethernet attached event for opt1 Jun 12 13:09:03 check_reload_status 428 rc.newwanip starting igb2 Jun 12 13:09:03 php-fpm 3098 /rc.linkup: HOTPLUG: Triggering address refresh on opt1 (igb2) Jun 12 13:09:03 check_reload_status 428 Reloading filter Jun 12 13:09:04 php-fpm 3098 /rc.newwanip: rc.newwanip: Info: starting on igb2. Jun 12 13:09:04 php-fpm 3098 /rc.newwanip: rc.newwanip: on (IP address: 192.168.20.1) (interface: GAMING[opt1]) (real interface: igb2). Jun 12 13:09:05 php-fpm 398 /rc.newwanip: New alert found: PF was wedged/busy and has been reset. Jun 12 13:09:05 php-fpm 398 /rc.newwanip: New alert found: There were error(s) loading the rules: pfctl: DIOCADDRULENV: Device busy - The line in question reads [0]: Jun 12 13:09:07 php-fpm 398 /rc.newwanip: Gateway, NONE AVAILABLE Jun 12 13:09:07 php-fpm 398 /rc.newwanip: Gateway, NONE AVAILABLE Jun 12 13:09:07 php-fpm 398 /rc.newwanip: Resyncing OpenVPN instances for interface GAMING. Jun 12 13:09:07 php-fpm 398 /rc.newwanip: Creating rrd update script Jun 12 13:09:08 php-fpm 3098 /rc.newwanip: Gateway, NONE AVAILABLE Jun 12 13:09:08 php-fpm 3098 /rc.newwanip: Gateway, NONE AVAILABLE Jun 12 13:09:08 php-fpm 3098 /rc.newwanip: Resyncing OpenVPN instances for interface GAMING. Jun 12 13:09:08 php-fpm 3098 /rc.newwanip: Creating rrd update script Jun 12 13:09:09 php-fpm 398 /rc.newwanip: Netgate pfSense Plus package system has detected an IP change or dynamic WAN reconnection - 192.168.20.1 -> 192.168.20.1 - Restarting packages. Jun 12 13:09:09 check_reload_status 428 Starting packages Jun 12 13:09:09 check_reload_status 428 Reloading filter Jun 12 13:09:10 php-cgi 41308 notify_monitor.php: Message sent to gmail.com OK Jun 12 13:09:10 php-fpm 399 /rc.start_packages: Restarting/Starting all packages. Jun 12 13:09:11 php-fpm 3098 /rc.newwanip: Netgate pfSense Plus package system has detected an IP change or dynamic WAN reconnection - 192.168.20.1 -> 192.168.20.1 - Restarting packages. Jun 12 13:09:11 check_reload_status 428 Starting packages Jun 12 13:09:11 check_reload_status 428 Reloading filter Jun 12 13:09:12 php-fpm 398 /rc.start_packages: Skipping STARTing packages process because previous/another instance is already running Jun 12 13:09:14 kernel igb1: promiscuous mode disabled Jun 12 13:09:14 kernel igb0: promiscuous mode disabled Jun 12 13:09:17 php-fpm 399 /rc.start_packages: The command '/usr/local/etc/rc.d/ntopng.sh stop' returned exit code '1', the output was 'No matching processes were found No matching processes were found' Jun 12 13:09:19 kernel igb1: promiscuous mode enabled Jun 12 13:09:19 kernel igb0: promiscuous mode enabled Jun 12 13:09:43 ntopng 86565 [HTTPserver.cpp:1388] ERROR: [HTTP] set_ports_option: cannot bind to 3000s: Address already in use Jun 12 13:09:43 ntopng 86565 [mongoose.c:4647] ERROR: set_ports_option: cannot bind to 3000s: No error: 0 Jun 12 13:09:43 ntopng 86565 [HTTPserver.cpp:1673] ERROR: Unable to start HTTP server (IPv4) on ports 3000s Jun 12 13:09:43 ntopng 86565 [HTTPserver.cpp:1679] ERROR: Either port in use or another ntopng instance is running (using the same port) -
Ok, great. That shows it. Let me do some digging...
-
Hmm, does that interface have an IPv6 config?
I once spent a while digging into a related issue here but could never pin it down. Link state changes to an interface that is set to track-interface for IPv6 do not trigger those changes.
Can you set that to track-interface for v6?Steve
-
@stephenw10 I don't have IPV6 setup at all. I'm not familiar with IPV6 so I have that disabled. I'm afraid of breaking the setup due to my lack of IPV6 knowledge. It would not allow me to set IPV6 to track interface on the OPT1 since the WAN has no IPV6. Should I set WAN to DHCP6? I have AT&T fiber if that matters. Their device is setup in passthrough mode and I had to disable every single security and additional option on it to get it to stop interfering with the ports.
-
You don't actually have to have IPv6 to trigger this you just need to set GAMING(opt1) to track-interface for v6. However you do need an interface to track! So, if you can, set the WAN to DHCPv6 which will then allow that. It doesn't matter if the WAN doesn't actually pull a v6 address.
If it does actually pull a v6 address it might have unintended effects though so be ready to roll that back. It likely won't without further work though.Steve
-
@stephenw10 I enabled DHCP6 on WAN and then set OPT1 IPV6 to track interface. It seems like I did get an IPV6 address since I now have that showing up as one of the gateways on the dashboard. I tried to reproduce the issue once, and it hasn't occurred since making this change. Before this, it was reproducible every time.
-
Hmm, interesting. That lines up with what I was seeing in earlier versions.
Do you have the log showing the xbox waking with track-interface set?
-
Here is that log with IPV6 address removed from the lines...
Jun 14 09:49:44 check_reload_status 428 Linkup starting igb2
Jun 14 09:49:44 kernel igb2: link state changed to UP
Jun 14 09:49:44 check_reload_status 428 Linkup starting igb2
Jun 14 09:49:44 kernel igb2: link state changed to DOWN
Jun 14 09:49:45 php-fpm 3098 /rc.linkup: Hotplug event detected for GAMING(opt1) dynamic IP address (4: 192.168.20.1, 6: track6)
Jun 14 09:49:45 php-fpm 3098 /rc.linkup: DEVD Ethernet attached event for opt1
Jun 14 09:49:45 php-fpm 3098 /rc.linkup: HOTPLUG: Configuring interface opt1
Jun 14 09:49:45 php-fpm 8142 /rc.newwanipv6: rc.newwanipv6: Info: starting on igb0.
Jun 14 09:49:45 php-fpm 8142 /rc.newwanipv6: rc.newwanipv6: on (IP address: ) (interface: wan) (real interface: igb0).
Jun 14 09:49:45 php-fpm 3098 /rc.linkup: Gateway, NONE AVAILABLE
Jun 14 09:49:45 php-fpm 3098 /rc.linkup: Gateway, NONE AVAILABLE
Jun 14 09:49:46 check_reload_status 428 Restarting IPsec tunnels
Jun 14 09:49:46 check_reload_status 428 updating dyndns opt1
Jun 14 09:49:46 check_reload_status 428 Reloading filter
Jun 14 09:49:46 php-fpm 88718 /rc.linkup: Hotplug event detected for GAMING(opt1) dynamic IP address (4: 192.168.20.1, 6: track6)
Jun 14 09:49:46 php-fpm 88718 /rc.linkup: DEVD Ethernet detached event for opt1
Jun 14 09:49:46 check_reload_status 428 Reloading filter
Jun 14 09:49:47 php-fpm 8142 /rc.newwanipv6: Gateway, NONE AVAILABLE
Jun 14 09:49:47 php-fpm 8142 /rc.newwanipv6: Gateway, NONE AVAILABLE
Jun 14 09:49:47 check_reload_status 428 Reloading filter
Jun 14 09:49:47 php-fpm 8142 /rc.newwanipv6: The command '/sbin/ifconfig igb0 inet6 delete' returned exit code '1', the output was 'ifconfig: ioctl (SIOCDIFADDR): Can't assign requested address'
Jun 14 09:49:47 php-fpm 8142 /rc.newwanipv6: Resyncing OpenVPN instances for interface WAN.
Jun 14 09:49:47 php-fpm 8142 /rc.newwanipv6: Creating rrd update script
Jun 14 09:49:47 php-fpm 8142 /rc.newwanipv6: Netgate pfSense Plus package system has detected an IP change or dynamic WAN reconnection - - Restarting packages.
Jun 14 09:49:47 check_reload_status 428 Starting packages
Jun 14 09:49:47 php-fpm 399 /rc.newwanipv6: rc.newwanipv6: Info: starting on igb0.
Jun 14 09:49:47 php-fpm 399 /rc.newwanipv6: rc.newwanipv6: on (IP address: ) (interface: wan) (real interface: igb0).
Jun 14 09:49:48 php-fpm 69398 /rc.start_packages: Restarting/Starting all packages.
Jun 14 09:49:49 kernel igb2: link state changed to UP
Jun 14 09:49:49 check_reload_status 428 Linkup starting igb2
Jun 14 09:49:49 php-fpm 399 /rc.newwanipv6: Gateway, NONE AVAILABLE
Jun 14 09:49:49 php-fpm 399 /rc.newwanipv6: Gateway, NONE AVAILABLE
Jun 14 09:49:50 php-fpm 3098 /rc.newwanipv6: rc.newwanipv6: Info: starting on igb0.
Jun 14 09:49:50 php-fpm 3098 /rc.newwanipv6: rc.newwanipv6: on (IP address: ) (interface: wan) (real interface: igb0).
Jun 14 09:49:50 php-fpm 8142 /rc.linkup: Hotplug event detected for GAMING(opt1) dynamic IP address (4: 192.168.20.1, 6: track6)
Jun 14 09:49:50 php-fpm 8142 /rc.linkup: DEVD Ethernet attached event for opt1
Jun 14 09:49:50 php-fpm 8142 /rc.linkup: HOTPLUG: Configuring interface opt1
Jun 14 09:49:50 php-fpm 8142 /rc.linkup: Gateway, NONE AVAILABLE
Jun 14 09:49:50 php-fpm 8142 /rc.linkup: Gateway, NONE AVAILABLE
Jun 14 09:49:50 check_reload_status 428 Restarting IPsec tunnels
Jun 14 09:49:50 check_reload_status 428 updating dyndns opt1
Jun 14 09:49:52 php-fpm 3098 /rc.newwanipv6: Gateway, NONE AVAILABLE
Jun 14 09:49:52 kernel igb1: promiscuous mode disabled
Jun 14 09:49:52 kernel igb0: promiscuous mode disabled
Jun 14 09:49:52 php-fpm 3098 /rc.newwanipv6: Gateway, NONE AVAILABLE
Jun 14 09:49:52 php-fpm 3098 /rc.newwanipv6: Resyncing OpenVPN instances for interface WAN.
Jun 14 09:49:52 php-fpm 3098 /rc.newwanipv6: Creating rrd update script
Jun 14 09:49:52 php-fpm 3098 /rc.newwanipv6: Netgate pfSense Plus package system has detected an IP change or dynamic WAN reconnection - - Restarting packages.
Jun 14 09:49:52 check_reload_status 428 Starting packages
Jun 14 09:49:52 php-fpm 8142 /rc.newwanipv6: rc.newwanipv6: Info: starting on igb0.
Jun 14 09:49:52 php-fpm 8142 /rc.newwanipv6: rc.newwanipv6: No IPv6 address found for interface WAN [wan].
Jun 14 09:49:52 php-fpm 88718 /rc.newwanipv6: rc.newwanipv6: Info: starting on igb0.
Jun 14 09:49:52 php-fpm 88718 /rc.newwanipv6: rc.newwanipv6: No IPv6 address found for interface WAN [wan].
Jun 14 09:49:53 php-fpm 89455 /rc.newwanipv6: rc.newwanipv6: Info: starting on igb0.
Jun 14 09:49:53 php-fpm 89455 /rc.newwanipv6: rc.newwanipv6: on (IP address: ) (interface: wan) (real interface: igb0).
Jun 14 09:49:53 php-fpm 399 /rc.start_packages: Skipping STARTing packages process because previous/another instance is already running
Jun 14 09:49:55 php-fpm 89455 /rc.newwanipv6: Gateway, NONE AVAILABLE
Jun 14 09:49:55 php-fpm 89455 /rc.newwanipv6: Gateway, NONE AVAILABLE -
Hmm, so still runs on igb0. Which is a little odd since that didn't bounce.Butt not on igb2 after it initially comes back up.
-
@stephenw10 I don't fully know what that means, but I see what you mean by igb0. It was doing the rc.newwan on igb2 (OPT1) before, but now it's doing it on igb0. If there is no issue with this, I will leave it as is. I'm not noticing any problems due to the IPV6 as of yet.
Thank you for looking into it. Let me know if you need anything else. -
Yeah I'm going to open a bug for the track-interface issue though I don't think it's actually the cause here just related to it.
If you're not seeing any other issues I'd say it's safe to leave that way.
Is it actually passing you a v6 subnet or just a IP on the WAN? If you are passed a subnet then setting OPT1 or LAN to track it should give you real v6 IPs on those subnets too which might not be what you want.
You might want to set 'Prefer IPv4' in Sys > Adv > Networking so the firewall itself doesn't try to use IPv6.
-
@stephenw10 I'm only seeing an IPV6 address on WAN and as an additional gateway. LAN and OPT1 don't have IPV6 subnet addresses. Thanks for the suggestion, I checked prefer ipv4 just in case.
-
S stephenw10 referenced this topic on
-
@stephenw10 unfortunately, the problem came back. It seems to happen far less frequent. Before it was happening at every power on event. I will leave the settings alone for now. I may want to play with IPV6 at some point anyway to learn. I did change the Xbox power setting back. I may also get a switch for the Xbox
-
Hmm. It still seems like unexpected/unwanted behaviour on an internal interface. We should look at it anyway.
