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

    Hotplug event causes rc.start_packages: Restarting/Starting all packages

    Scheduled Pinned Locked Moved
    General pfSense Questions
    9
    52
    6.0k
    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.
    • stephenw10S
      stephenw10 Netgate Administrator
      last edited by

      The repo issue is still being worked on.

      The package restart issue is odd. Seems like there's a logic error there. I managed to replicate it on a different interface and the only difference is that it doesn't have 'track-interface' set for IPv6.

      You don't appear to have any v6 connectivity there so to test it you would need to enable dhcpv6 on something in order to set opt4 to track it. If you can test that and confirm that prevents rc.newwanip running then we'll need to dig into that deeper.

      Steve

      3 B 2 Replies Last reply Reply Quote 0
      • 3
        32G3LiQxu8 @stephenw10
        last edited by

        @stephenw10

        I turned on v6 connectivity on my WAN interface. I set OPT4 to track the interface gateway of WAN_DHCP6. I powered on my laptop, and I am not seeing the rc.newwanip for em5, but it does occur for WAN_DHCP6, and that's likely because the WAN_DHCP6 is offline. I'm not sure I set that part up correctly. I'm not very familiar with IPv6. Let me know if this is not a good enough test

        Sep 17 12:35:36 pfSense check_reload_status[401]: Linkup starting em5
Sep 17 12:35:36 pfSense kernel: em5: link state changed to DOWN
Sep 17 12:35:37 pfSense php-fpm[42065]: /rc.linkup: DEVD Ethernet detached event for opt4
Sep 17 12:35:37 pfSense check_reload_status[401]: Reloading filter
Sep 17 12:35:38 pfSense check_reload_status[401]: Linkup starting em5
Sep 17 12:35:38 pfSense kernel: em5: link state changed to UP
Sep 17 12:35:38 pfSense php-fpm[42065]: /rc.filter_configure_sync: GW States: One or more gateways is down, flushing all states: WAN_DHCP6 
Sep 17 12:35:39 pfSense php-fpm[371]: /rc.linkup: DEVD Ethernet attached event for opt4
Sep 17 12:35:39 pfSense php-fpm[371]: /rc.linkup: HOTPLUG: Configuring interface opt4
Sep 17 12:35:39 pfSense php-fpm[371]: /rc.linkup: Gateway, none 'available' for inet6, use the first one configured. 'WAN_DHCP6'
Sep 17 12:35:39 pfSense check_reload_status[401]: Restarting IPsec tunnels
Sep 17 12:35:40 pfSense php-fpm[69043]: /rc.newwanipv6: rc.newwanipv6: Info: starting on em0.
Sep 17 12:35:40 pfSense php-fpm[69043]: /rc.newwanipv6: rc.newwanipv6: on (IP address: 2603:900a:ff00:1b:596b:b440:d2fb:e381) (interface: wan) (real interface: em0).
Sep 17 12:35:41 pfSense nginx: 2022/09/17 12:35:41 [crit] 71665#100551: *7384 SSL_write() failed (13: Permission denied) while processing HTTP/2 connection, client: 192.168.1.51, server: 0.0.0.0:443
Sep 17 12:35:42 pfSense php-fpm[371]: /rc.linkup: The command '/usr/local/sbin/unbound -c /var/unbound/unbound.conf' returned exit code '1', the output was '[1663432542] unbound[69211:0] error: bind: address already in use [1663432542] unbound[69211:0] fatal error: could not open ports' 
Sep 17 12:35:44 pfSense rc.gateway_alarm[18167]: >>> Gateway alarm: WAN_DHCP6 (Addr:fe80::2bc:60ff:fe93:419%em0 Alarm:1 RTT:0.000ms RTTsd:0.000ms Loss:100%)
Sep 17 12:35:44 pfSense check_reload_status[401]: updating dyndns WAN_DHCP6
Sep 17 12:35:44 pfSense check_reload_status[401]: Restarting IPsec tunnels
Sep 17 12:35:44 pfSense check_reload_status[401]: Restarting OpenVPN tunnels/interfaces
Sep 17 12:35:44 pfSense check_reload_status[401]: Reloading filter
Sep 17 12:35:44 pfSense php-fpm[69043]: /rc.newwanipv6: Gateway, none 'available' for inet6, use the first one configured. 'WAN_DHCP6'
Sep 17 12:35:44 pfSense check_reload_status[401]: Reloading filter
Sep 17 12:35:45 pfSense check_reload_status[401]: updating dyndns opt4
Sep 17 12:35:46 pfSense php-fpm[69043]: /rc.openvpn: Gateway, none 'available' for inet6, use the first one configured. 'WAN_DHCP6'
Sep 17 12:35:46 pfSense php-fpm[42065]: /rc.filter_configure_sync: GW States: One or more gateways is down, flushing all states: WAN_DHCP6 
Sep 17 12:35:47 pfSense php-fpm[39466]: /rc.filter_configure_sync: GW States: One or more gateways is down, flushing all states: WAN_DHCP6 
Sep 17 12:36:00 pfSense sshguard[43717]: Exiting on signal.
        1 Reply Last reply Reply Quote 0
        • B
          bblacey @stephenw10
          last edited by

          @stephenw10

          I there a redmine issue for this bug? I'd like to follow it and if there is a patch, apply it on one of my systems. Thanks.

          1 Reply Last reply Reply Quote 0
          • stephenw10S
            stephenw10 Netgate Administrator
            last edited by

            Not yet.It's not clear which way the intended behaviour is but I'm pretty sure it should be the same for a link-up/down event regardless of whether it's tracking something else for v6.
            What behaviour are you seeing?

            Steve

            B 1 Reply Last reply Reply Quote 0
            • B
              bblacey @stephenw10
              last edited by

              @stephenw10

              Thanks. I'm seeing behavior to that reported here. On a NetGate 6100 Max running pfSense 22.05-Release without ipv6. Whenever I connect to a LAN port, it runs rc.renewwanip and in some cases, whatever else it does affects other LAN segments connected to NICs on the 6100.

              Given that the issue manifests when ipv6 is disabled, from your analysis, do you know the minimum ipv6 config that I would need to work around the issue?

              1 Reply Last reply Reply Quote 0
              • stephenw10S
                stephenw10 Netgate Administrator
                last edited by

                When I was testing it did not do it on an interface set to track WAN for v6. So I would try setting WAN to DHCPv6 (even if no DHCPv6 server exists) and setting LAN to track that. That's the default config which is why I suspect it's not seen by more people.

                Steve

                B 1 Reply Last reply Reply Quote 0
                • B
                  bblacey @stephenw10
                  last edited by

                  @stephenw10 I ran a couple tests and confirmed that enabling ipv6 tracking on the hot-plug interface works around the problem so it seems like a logic bug.

                  Without ipv6 tracking (WAN DHCP6, ADMIN none)

                  Nov  9 16:52:40 firewall kernel: ix3: link state changed to DOWN
Nov  9 16:52:41 firewall php-fpm[384]: /rc.linkup: Hotplug event detected for ADMIN(opt1) static IP (172.16.50.200 )
Nov  9 16:52:41 firewall check_reload_status[422]: Reloading filter
Nov  9 16:52:44 firewall check_reload_status[422]: Linkup starting ix3
Nov  9 16:52:44 firewall kernel: ix3: link state changed to UP
Nov  9 16:52:45 firewall php-fpm[383]: /rc.linkup: Hotplug event detected for ADMIN(opt1) static IP (172.16.50.200 )
Nov  9 16:52:45 firewall check_reload_status[422]: rc.newwanip starting ix3
Nov  9 16:52:45 firewall check_reload_status[422]: Reloading filter
Nov  9 16:52:46 firewall php-fpm[383]: /rc.newwanip: rc.newwanip: Info: starting on ix3.
Nov  9 16:52:46 firewall php-fpm[383]: /rc.newwanip: rc.newwanip: on (IP address: 172.16.50.200) (interface: ADMIN[opt1]) (real interface: ix3).
Nov  9 16:52:47 firewall php-fpm[383]: /rc.newwanip: Gateway, NONE AVAILABLE
Nov  9 16:52:47 firewall php-fpm[383]: /rc.newwanip: Gateway, NONE AVAILABLE
Nov  9 16:52:49 firewall dhcpleases[52345]: Could not deliver signal HUP to process 65492: No such process.
Nov  9 16:52:52 firewall php-fpm[383]: /rc.newwanip: Resyncing OpenVPN instances for interface ADMIN.
Nov  9 16:52:52 firewall php-fpm[383]: /rc.newwanip: Creating rrd update script
Nov  9 16:52:54 firewall php-fpm[383]: /rc.newwanip: Netgate pfSense Plus package system has detected an IP change or dynamic WAN reconnection - 172.16.50.200 ->  172.16.50.200 - Restarting packages.
Nov  9 16:52:54 firewall check_reload_status[422]: Starting packages
Nov  9 16:52:55 firewall php-fpm[65895]: /rc.start_packages: Restarting/Starting all packages.
Nov  9 16:52:55 firewall check_reload_status[422]: Reloading filter
Nov  9 16:52:55 firewall ftp-proxy[31983]: listening on 127.0.0.1 port 8021

                  With ipv6 (WAN DHCP6, ADMIN track WAN)

                  Nov  9 16:54:59 firewall check_reload_status[422]: Linkup starting ix3
Nov  9 16:54:59 firewall kernel: ix3: link state changed to DOWN
Nov  9 16:55:00 firewall php-fpm[11301]: /rc.linkup: DEVD Ethernet detached event for opt1
Nov  9 16:55:00 firewall check_reload_status[422]: Reloading filter
Nov  9 16:55:02 firewall check_reload_status[422]: Linkup starting ix3
Nov  9 16:55:02 firewall kernel: ix3: link state changed to UP
Nov  9 16:55:03 firewall php-fpm[6082]: /rc.linkup: DEVD Ethernet attached event for opt1
Nov  9 16:55:03 firewall php-fpm[6082]: /rc.linkup: HOTPLUG: Configuring interface opt1
Nov  9 16:55:03 firewall php-fpm[6082]: /rc.linkup: Gateway, NONE AVAILABLE
Nov  9 16:55:03 firewall php-fpm[6082]: /rc.linkup: Gateway, NONE AVAILABLE
Nov  9 16:55:03 firewall check_reload_status[422]: Restarting IPsec tunnels
Nov  9 16:55:05 firewall dhcpleases[87360]: Could not deliver signal HUP to process 39205: No such process.
Nov  9 16:55:09 firewall check_reload_status[422]: updating dyndns opt1

                  Do these tests make it actionable enough for a redmine issue and fix?

                  1 Reply Last reply Reply Quote 0
                  • stephenw10S
                    stephenw10 Netgate Administrator
                    last edited by

                    Yes, I believe so. Let me discuss it internally and get something open.

                    B 1 Reply Last reply Reply Quote 1
                    • L
                      lcbbcl
                      last edited by

                      Hello i know that is not my threat but i think that i might have the same problem.
                      If i restart one of my pc (it is connected directly to pfsense) my wg tunnel will go down and only after rebooting my pfsense i am able to make it work again. Some one can give me a workaround for my Wg tunnel to come up without restarting my pfsense.
                      Thank you.

                      Nov 10 14:25:35 	php 	50499 	[pfBlockerNG] filterlog daemon started
Nov 10 14:25:35 	tail_pfb 	50062 	[pfBlockerNG] Firewall Filter Service started
Nov 10 14:25:35 	php_pfb 	47352 	[pfBlockerNG] filterlog daemon stopped
Nov 10 14:25:35 	tail_pfb 	47026 	[pfBlockerNG] Firewall Filter Service stopped
Nov 10 14:25:35 	lighttpd_pfb 	44920 	[pfBlockerNG] DNSBL Webserver started
Nov 10 14:25:35 	lighttpd_pfb 	43815 	[pfBlockerNG] DNSBL Webserver stopped
Nov 10 14:25:35 	php-fpm 	60035 	/rc.start_packages: Configuration Change: (system): [pfSense-pkg-WireGuard] Applied package default settings as necessary.
Nov 10 14:25:35 	php-fpm 	60035 	/rc.start_packages: Configuration Change: (system): [pfSense-pkg-WireGuard] Installed Unbound ACL group (WireGuard).
Nov 10 14:25:35 	php-fpm 	60035 	/rc.start_packages: Configuration Change: (system): [pfSense-pkg-WireGuard] De-installed Unbound ACL group (WireGuard).
Nov 10 14:25:35 	php-fpm 	60035 	/rc.start_packages: Configuration Change: (system): [pfSense-pkg-WireGuard] De-installed interface group (WireGuard).
Nov 10 14:25:35 	check_reload_status 	411 	Syncing firewall
Nov 10 14:25:35 	php-fpm 	60035 	/rc.start_packages: Configuration Change: (system): [pfSense-pkg-WireGuard] Installed earlyshellcmd(s).
Nov 10 14:25:35 	check_reload_status 	411 	Syncing firewall
Nov 10 14:25:35 	php-fpm 	60035 	/rc.start_packages: Configuration Change: (system): [pfSense-pkg-WireGuard] De-installed earlyshellcmd(s).
Nov 10 14:25:32 	upsd 	24397 	Startup successful
Nov 10 14:25:32 	upsd 	24142 	Connected to UPS [APC]: usbhid-ups-APC
Nov 10 14:25:32 	upsd 	24142 	listening on 127.0.0.1 port 3493
Nov 10 14:25:32 	upsd 	24142 	listening on ::1 port 3493
Nov 10 14:25:32 	upsd 	24142 	listening on 192.168.2.1 port 3493
Nov 10 14:25:32 	upsd 	24142 	listening on 192.168.4.1 port 3493
Nov 10 14:25:32 	usbhid-ups 	22587 	Startup successful
Nov 10 14:25:31 	upsmon 	21917 	Startup successful
Nov 10 14:25:31 	php-fpm 	60035 	/rc.start_packages: Starting service nut
Nov 10 14:25:31 	usbhid-ups 	79003 	Signal 15: exiting
Nov 10 14:25:31 	upsd 	19203 	Signal 15: exiting
Nov 10 14:25:31 	upsd 	19203 	mainloop: Interrupted system call
Nov 10 14:25:31 	upsd 	19203 	User local-monitor@127.0.0.1 logged out from UPS [APC]
Nov 10 14:25:31 	upsmon 	77054 	Signal 15: exiting
Nov 10 14:25:31 	php-fpm 	60035 	/rc.start_packages: Stopping service nut
Nov 10 14:25:31 	check_reload_status 	411 	Syncing firewall
Nov 10 14:25:31 	php-fpm 	60035 	/rc.start_packages: Configuration Change: (system): pfBlockerNG: saving Aliases
Nov 10 14:25:31 	php-fpm 	60035 	/rc.start_packages: Restarting/Starting all packages.
Nov 10 14:25:30 	check_reload_status 	411 	Starting packages
Nov 10 14:25:30 	php-fpm 	60035 	/rc.newwanip: Netgate pfSense Plus package system has detected an IP change or dynamic WAN reconnection - 192.168.4.1 -> 192.168.4.1 - Restarting packages.
Nov 10 14:25:29 	php-fpm 	14803 	/rc.newwanip: dpinger: timeout while retrieving status for gateway WAN_EPORTS_PPPOE
Nov 10 14:25:28 	php-fpm 	60035 	/rc.newwanip: Creating rrd update script
Nov 10 14:25:28 	php-fpm 	60035 	/rc.newwanip: Resyncing OpenVPN instances for interface DMZ.
Nov 10 14:25:27 	check_reload_status 	411 	Reloading filter
Nov 10 14:25:27 	check_reload_status 	411 	Restarting OpenVPN tunnels/interfaces
Nov 10 14:25:27 	check_reload_status 	411 	Restarting IPsec tunnels
Nov 10 14:25:27 	check_reload_status 	411 	updating dyndns WG_mamaGW 
Nov 10 14:25:27 	rc.gateway_alarm 	76312 	>>> Gateway alarm: WG_mamaGW (Addr:10.1.1.1 Alarm:1 RTT:0.000ms RTTsd:0.000ms Loss:100%)
Nov 10 14:25:25 	php-fpm 	14803 	/rc.newwanip: Removing static route for monitor xxx.xxx.xxx.242 and adding a new route through xxx.xxx.xxx.193
Nov 10 14:25:25 	php-fpm 	14803 	/rc.newwanip: rc.newwanip: on (IP address: 192.168.4.1) (interface: DMZ[opt3]) (real interface: em3).
Nov 10 14:25:25 	php-fpm 	14803 	/rc.newwanip: rc.newwanip: Info: starting on em3.
Nov 10 14:25:24 	check_reload_status 	411 	Reloading filter
Nov 10 14:25:24 	check_reload_status 	411 	rc.newwanip starting em3
Nov 10 14:25:24 	php-fpm 	14803 	/rc.linkup: Hotplug event detected for DMZ(opt3) static IP (192.168.4.1 )
Nov 10 14:25:23 	kernel 		em3: link state changed to UP
Nov 10 14:25:23 	check_reload_status 	411 	Linkup starting em3
Nov 10 14:25:22 	php-fpm 	60035 	/rc.newwanip: dpinger: timeout while retrieving status for gateway WAN_EPORTS_PPPOE
Nov 10 14:25:21 	check_reload_status 	411 	Reloading filter
Nov 10 14:25:21 	php-fpm 	31658 	/rc.linkup: Hotplug event detected for DMZ(opt3) static IP (192.168.4.1 )
Nov 10 14:25:21 	check_reload_status 	411 	Reloading filter
Nov 10 14:25:21 	check_reload_status 	411 	Restarting OpenVPN tunnels/interfaces
Nov 10 14:25:21 	check_reload_status 	411 	Restarting IPsec tunnels
Nov 10 14:25:21 	check_reload_status 	411 	updating dyndns WG_mamaGW
Nov 10 14:25:21 	rc.gateway_alarm 	56603 	>>> Gateway alarm: WG_mamaGW (Addr:10.1.1.1 Alarm:1 RTT:0.000ms RTTsd:0.000ms Loss:100%)
Nov 10 14:25:20 	kernel 		em3: link state changed to DOWN
Nov 10 14:25:20 	check_reload_status 	411 	Linkup starting em3
Nov 10 14:25:19 	php-fpm 	60035 	/rc.newwanip: Removing static route for monitor xxx.xxx.xxx.242 and adding a new route through xxx.xxx.xxx.193
Nov 10 14:25:18 	php-fpm 	60035 	/rc.newwanip: rc.newwanip: on (IP address: 192.168.4.1) (interface: DMZ[opt3]) (real interface: em3).
Nov 10 14:25:18 	php-fpm 	60035 	/rc.newwanip: rc.newwanip: Info: starting on em3.
Nov 10 14:25:17 	check_reload_status 	411 	Reloading filter
Nov 10 14:25:17 	check_reload_status 	411 	rc.newwanip starting em3
Nov 10 14:25:17 	php-fpm 	60035 	/rc.linkup: Hotplug event detected for DMZ(opt3) static IP (192.168.4.1 )
Nov 10 14:25:16 	kernel 		em3: link state changed to UP
Nov 10 14:25:16 	check_reload_status 	411 	Linkup starting em3
Nov 10 14:25:15 	check_reload_status 	411 	Reloading filter
Nov 10 14:25:15 	php-fpm 	12840 	/rc.linkup: Hotplug event detected for DMZ(opt3) static IP (192.168.4.1 )
Nov 10 14:25:14 	check_reload_status 	411 	Linkup starting em3
Nov 10 14:25:14 	kernel 		em3: link state changed to DOWN
                      1 Reply Last reply Reply Quote 0
                      • stephenw10S
                        stephenw10 Netgate Administrator
                        last edited by

                        Well if you set DMZ to track WAN for v6 it will probably prevent it running rc.newwanip which in turn should prevent the WG tunnel restarting.
                        However the WG tunnel should just come back up when it's restarted. It looks like you might have some other issue there that should probably be addressed in a new thread.

                        Steve

                        1 Reply Last reply Reply Quote 0
                        • B
                          bblacey @stephenw10
                          last edited by

                          @stephenw10 just checking to see if anything came of the internal discussions. If you guys opened a redmine issue, please provide the id here so I can watch it. Thanks.

                          1 Reply Last reply Reply Quote 0
                          • stephenw10S
                            stephenw10 Netgate Administrator
                            last edited by

                            Not yet, let me re-raise it...

                            B 1 Reply Last reply Reply Quote 0
                            • B
                              bblacey @stephenw10
                              last edited by

                              @stephenw10 any movement on this yet?

                              1 Reply Last reply Reply Quote 0
                              • stephenw10S
                                stephenw10 Netgate Administrator
                                last edited by

                                Not yet. I ran it past a few developers and the consensus was that restarting packages on a link state change is probably expected. However that doesn't explain the interaction with track6. And it seems completely unnecessary in many cases, such as this one.
                                Fixing this correctly may involve a lot more work than we have time for in 23.01. I suspect a complete review of the service start scripts is in order.
                                I'll try to get something opened. There's definitely a bug there somewhere, one of those behaviours is wrong.

                                Steve

                                3 1 Reply Last reply Reply Quote 1
                                • S SteveITS referenced this topic on
                                • S SteveITS referenced this topic on
                                • 3
                                  32G3LiQxu8 @stephenw10
                                  last edited by

                                  @stephenw10 just curious if any additional discussions have been had since your last post?

                                  Thanks!

                                  1 Reply Last reply Reply Quote 0
                                  • stephenw10S
                                    stephenw10 Netgate Administrator
                                    last edited by

                                    Actually this was discussed recently here: https://forum.netgate.com/topic/180783/23-05-pf-was-wedged-busy-and-has-been-reset

                                    I'll be opening a bug for this shortly.

                                    3 1 Reply Last reply Reply Quote 1
                                    • 3
                                      32G3LiQxu8 @stephenw10
                                      last edited by

                                      @stephenw10 Thank you!

                                      1 Reply Last reply Reply Quote 0
                                      • I
                                        Ienien77
                                        last edited by

                                        Hi,
                                        I have the same thing happening on my side, when something change, it restart packages. And of course my Wireguard tunnel is going down ... i absolutely have no clue on why it does that (wireguard not going back up).

                                        Did you figure this out yet ?

                                        1 Reply Last reply Reply Quote 0
                                        • stephenw10S
                                          stephenw10 Netgate Administrator
                                          last edited by

                                          Does it eventually reconnect? Does it reconnect manually? What do you do to recover?

                                          3 I 2 Replies Last reply Reply Quote 0
                                          • 3
                                            32G3LiQxu8 @stephenw10
                                            last edited by

                                            @stephenw10 @Ienien77

                                            Navigate to Interfaces > WAN
                                            Even if you do not use IPv6 environment, set IPv6 Configuration Type to DHCP6

                                            firefox_FOZVeAfuVH.png

                                            Navigate to the Interface that is causing the restart of packages (you may have to do this on more than one interface)
                                            Set IPv6 Configuration Type to Track Interface

                                            firefox_vey0KHKWfK.png

                                            Scroll down under Track IPv6 Interface section and set IPv6 Interface to WAN

                                            firefox_n30REhnLcJ.png

                                            This will keep Wireguard from restarting. It will, however, restart IPSec tunnels so if you have those it won't be of any help.

                                            Another workaround is to setup a switch on that interface so it thinks it is always up

                                            I believe a bug is going to be /has been opened up for this issue

                                            Hope this helps!

                                            I 1 Reply Last reply Reply Quote 1
                                            • First post
                                              Last post