Bug #7462
openHAproxy not rebinding properly after WAN DHCP IP change
0%
Description
Hi,
This is copy/pasted from the forum (https://forum.pfsense.org/index.php?topic=121345.0?) as i have the same issue and it doesn't look like its been reported but:-
pfSense 2.3.3-RELEASE-p1
haproxy package 0.52_7
Issue:
After my WAN interface received a new IP (DHCP), the haproxy service did not rebind properly to the new IP.
HAproxy configuration interface showed the new IP correctly in the "address" column for my frontend, but attempting to access the backend via my domain name over https, redirected me to pfsense, which gave me the typical "Potential DNS Rebind attack detected" warning.
Nov 11 02:08:53 check_reload_status updating dyndns WAN_DHCP
Nov 11 02:08:53 check_reload_status Restarting ipsec tunnels
Nov 11 02:08:53 check_reload_status Restarting OpenVPN tunnels/interfaces
Nov 11 02:08:53 check_reload_status Reloading filter
Nov 11 02:08:55 php-fpm 53556 /rc.openvpn: OpenVPN: One or more OpenVPN tunnel endpoints may have changed its IP. Reloading endpoints that may use WAN_DHCP.
Nov 11 02:08:55 xinetd 18912 Starting reconfiguration
Nov 11 02:08:55 xinetd 18912 Swapping defaults
Nov 11 02:08:55 xinetd 18912 readjusting service 6969-udp
Nov 11 02:08:55 xinetd 18912 Reconfigured: new=0 old=1 dropped=0 (services)
Nov 11 02:09:10 php-fpm 64326 /rc.newipsecdns: IPSEC: One or more IPsec tunnel endpoints has changed its IP. Refreshing.
Nov 11 02:09:10 php-fpm 64326 /rc.newipsecdns: WARNING: Setting i_dont_care_about_security_and_use_aggressive_mode_psk option because a phase 1 is configured using aggressive mode with pre-shared keys. This is not a secure configuration.
Nov 11 02:09:10 check_reload_status Reloading filter
Nov 11 02:09:11 xinetd 18912 Starting reconfiguration
Nov 11 02:09:11 xinetd 18912 Swapping defaults
Nov 11 02:09:11 xinetd 18912 readjusting service 6969-udp
Nov 11 02:09:11 xinetd 18912 Reconfigured: new=0 old=1 dropped=0 (services)
Nov 11 02:56:35 kernel arpresolve: can't allocate llinfo for <IP-of-old-default-route> on vmx0
Nov 11 02:56:35 kernel arpresolve: can't allocate llinfo for <IP-of-old-default-route> on vmx0
Nov 11 02:56:36 kernel arpresolve: can't allocate llinfo for <IP-of-old-default-route> on vmx0
Nov 11 02:56:36 kernel arpresolve: can't allocate llinfo for <IP-of-old-default-route> on vmx0
Nov 11 02:56:36 kernel arpresolve: can't allocate llinfo for <IP-of-old-default-route> on vmx0
Nov 11 02:56:36 kernel arpresolve: can't allocate llinfo for <IP-of-old-default-route> on vmx0
Nov 11 02:56:36 kernel arpresolve: can't allocate llinfo for <IP-of-old-default-route> on vmx0
Nov 11 02:56:36 kernel arpresolve: can't allocate llinfo for <IP-of-old-default-route> on vmx0
Nov 11 02:56:36 kernel arpresolve: can't allocate llinfo for <IP-of-old-default-route> on vmx0
Nov 11 02:56:36 kernel arpresolve: can't allocate llinfo for <IP-of-old-default-route> on vmx0
Nov 11 02:56:36 kernel arpresolve: can't allocate llinfo for <IP-of-old-default-route> on vmx0
Nov 11 02:56:37 kernel arpresolve: can't allocate llinfo for <IP-of-old-default-route> on vmx0
Nov 11 02:56:37 kernel arpresolve: can't allocate llinfo for <IP-of-old-default-route> on vmx0
Nov 11 02:56:37 kernel arpresolve: can't allocate llinfo for <IP-of-old-default-route> on vmx0
Nov 11 02:56:37 kernel arpresolve: can't allocate llinfo for <IP-of-old-default-route> on vmx0
Nov 11 02:56:38 kernel arpresolve: can't allocate llinfo for <IP-of-old-default-route> on vmx0
Nov 11 02:56:38 kernel arpresolve: can't allocate llinfo for <IP-of-old-default-route> on vmx0
Nov 11 02:56:38 kernel arpresolve: can't allocate llinfo for <IP-of-old-default-route> on vmx0
Nov 11 02:56:38 kernel arpresolve: can't allocate llinfo for <IP-of-old-default-route> on vmx0
Nov 11 02:56:38 kernel arpresolve: can't allocate llinfo for <IP-of-old-default-route> on vmx0
Nov 11 02:56:38 kernel arpresolve: can't allocate llinfo for <IP-of-old-default-route> on vmx0
Nov 11 02:56:39 kernel arpresolve: can't allocate llinfo for <IP-of-old-default-route> on vmx0
Nov 11 02:56:39 kernel arpresolve: can't allocate llinfo for <IP-of-old-default-route> on vmx0
Nov 11 02:56:39 kernel arpresolve: can't allocate llinfo for <IP-of-old-default-route> on vmx0
Nov 11 02:56:39 kernel arpresolve: can't allocate llinfo for <IP-of-old-default-route> on vmx0
Nov 11 02:56:40 kernel arpresolve: can't allocate llinfo for <IP-of-old-default-route> on vmx0
Nov 11 02:56:40 kernel arpresolve: can't allocate llinfo for <IP-of-old-default-route> on vmx0
Nov 11 02:56:40 kernel arpresolve: can't allocate llinfo for <IP-of-old-default-route> on vmx0
Nov 11 02:56:41 kernel arpresolve: can't allocate llinfo for <IP-of-old-default-route> on vmx0
Nov 11 02:56:41 kernel arpresolve: can't allocate llinfo for <IP-of-old-default-route> on vmx0
Nov 11 02:56:41 kernel arpresolve: can't allocate llinfo for <IP-of-old-default-route> on vmx0
Nov 11 02:56:41 kernel arpresolve: can't allocate llinfo for <IP-of-old-default-route> on vmx0
Nov 11 02:56:41 kernel arpresolve: can't allocate llinfo for <IP-of-old-default-route> on vmx0
Nov 11 02:56:42 kernel arpresolve: can't allocate llinfo for <IP-of-old-default-route> on vmx0
Nov 11 02:56:42 kernel arpresolve: can't allocate llinfo for <IP-of-old-default-route> on vmx0
Nov 11 02:56:42 kernel arpresolve: can't allocate llinfo for <IP-of-old-default-route> on vmx0
Nov 11 02:56:43 kernel arpresolve: can't allocate llinfo for <IP-of-old-default-route> on vmx0
Nov 11 02:56:44 kernel arpresolve: can't allocate llinfo for <IP-of-old-default-route> on vmx0
Nov 11 02:56:45 kernel arpresolve: can't allocate llinfo for <IP-of-old-default-route> on vmx0
Nov 11 02:56:45 kernel arpresolve: can't allocate llinfo for <IP-of-old-default-route> on vmx0
Nov 11 02:56:45 kernel arpresolve: can't allocate llinfo for <IP-of-old-default-route> on vmx0
Nov 11 02:56:47 kernel arpresolve: can't allocate llinfo for <IP-of-old-default-route> on vmx0
Nov 11 02:56:51 kernel arpresolve: can't allocate llinfo for <IP-of-old-default-route> on vmx0
Nov 11 02:56:51 kernel arpresolve: can't allocate llinfo for <IP-of-old-default-route> on vmx0
Nov 11 02:56:51 kernel arpresolve: can't allocate llinfo for <IP-of-old-default-route> on vmx0
Nov 11 02:56:51 kernel arpresolve: can't allocate llinfo for <IP-of-old-default-route> on vmx0
Nov 11 02:56:57 kernel arpresolve: can't allocate llinfo for <IP-of-old-default-route> on vmx0
Nov 11 02:57:39 kernel arpresolve: can't allocate llinfo for <IP-of-old-default-route> on vmx0
Nov 11 03:06:48 check_reload_status rc.newwanip starting vmx0
Nov 11 03:06:48 kernel arpresolve: can't allocate llinfo for <IP-of-old-default-route> on vmx0
Nov 11 03:06:48 kernel arpresolve: can't allocate llinfo for <IP-of-old-default-route> on vmx0
Nov 11 03:06:48 kernel arpresolve: can't allocate llinfo for <IP-of-old-default-route> on vmx0
Nov 11 03:06:49 kernel arpresolve: can't allocate llinfo for <IP-of-old-default-route> on vmx0
Nov 11 03:06:49 kernel arpresolve: can't allocate llinfo for <IP-of-old-default-route> on vmx0
Nov 11 03:06:49 php-fpm 53556 /rc.newwanip: rc.newwanip: Info: starting on vmx0.
Nov 11 03:06:49 php-fpm 53556 /rc.newwanip: rc.newwanip: on (IP address: <NEW-WAN-IP>) (interface: WAN[wan]) (real interface: vmx0).
Nov 11 03:06:49 php-fpm 53556 /rc.newwanip: IP has changed, killing states on former IP 0.0.0.0.
Nov 11 03:06:49 kernel arpresolve: can't allocate llinfo for <IP-of-old-default-route> on vmx0
Nov 11 03:06:49 xinetd 18912 Starting reconfiguration
Nov 11 03:06:49 xinetd 18912 Swapping defaults
Nov 11 03:06:49 xinetd 18912 readjusting service 6969-udp
Nov 11 03:06:49 xinetd 18912 Reconfigured: new=0 old=1 dropped=0 (services)
Nov 11 03:06:49 kernel arpresolve: can't allocate llinfo for <IP-of-old-default-route> on vmx0
Nov 11 03:06:49 php-fpm 53556 /rc.newwanip: ROUTING: setting default route to <IP-of-NEW-default-route>
Nov 11 03:06:51 kernel arpresolve: can't allocate llinfo for <IP-of-old-default-route> on vmx0
Nov 11 03:06:51 kernel arpresolve: can't allocate llinfo for <IP-of-old-default-route> on vmx0
Nov 11 03:06:51 kernel arpresolve: can't allocate llinfo for <IP-of-old-default-route> on vmx0
Nov 11 03:06:52 kernel arpresolve: can't allocate llinfo for <IP-of-old-default-route> on vmx0
Nov 11 03:06:52 kernel arpresolve: can't allocate llinfo for <IP-of-old-default-route> on vmx0
Nov 11 03:06:52 kernel arpresolve: can't allocate llinfo for <IP-of-old-default-route> on vmx0
Nov 11 03:06:54 php-fpm 53556 /rc.newwanip: Forcefully reloading IPsec
Nov 11 03:06:54 check_reload_status Reloading filter
Nov 11 03:06:54 php-fpm 53556 /rc.newwanip: WARNING: Setting i_dont_care_about_security_and_use_aggressive_mode_psk option because a phase 1 is configured using aggressive mode with pre-shared keys. This is not a secure configuration.
Nov 11 03:06:54 php-fpm 53556 /rc.newwanip: Resyncing OpenVPN instances for interface WAN.
Nov 11 03:06:54 kernel ovpns2: link state changed to DOWN
Nov 11 03:06:54 check_reload_status Reloading filter
Nov 11 03:06:54 php-fpm 53556 /rc.newwanip: Creating rrd update script
Nov 11 03:06:54 kernel ovpns2: link state changed to UP
Nov 11 03:06:54 check_reload_status rc.newwanip starting ovpns2
Nov 11 03:06:55 xinetd 18912 Starting reconfiguration
Nov 11 03:06:55 xinetd 18912 Swapping defaults
Nov 11 03:06:55 xinetd 18912 readjusting service 6969-udp
Nov 11 03:06:55 xinetd 18912 Reconfigured: new=0 old=1 dropped=0 (services)
Nov 11 03:06:56 xinetd 18912 Starting reconfiguration
Nov 11 03:06:56 xinetd 18912 Swapping defaults
Nov 11 03:06:56 xinetd 18912 readjusting service 6969-udp
Nov 11 03:06:56 xinetd 18912 Reconfigured: new=0 old=1 dropped=0 (services)
Nov 11 03:06:56 php-fpm 37660 /rc.newwanip: rc.newwanip: Info: starting on ovpns2.
Nov 11 03:06:56 php-fpm 37660 /rc.newwanip: rc.newwanip: on (IP address: <Internal-VPN-IP>) (interface: []) (real interface: ovpns2).
Nov 11 03:06:56 php-fpm 37660 /rc.newwanip: rc.newwanip called with empty interface.
Nov 11 03:06:56 php-fpm 37660 /rc.newwanip: pfSense package system has detected an IP change or dynamic WAN reconnection - -> <Internal-VPN-IP> - Restarting packages.
Nov 11 03:06:56 check_reload_status Reloading filter
Nov 11 03:06:56 check_reload_status Starting packages
Nov 11 03:06:56 php-fpm 53556 /rc.newwanip: pfSense package system has detected an IP change or dynamic WAN reconnection - 0.0.0.0 -> <NEW-WAN-IP> - Restarting packages.
Nov 11 03:06:56 check_reload_status Starting packages
Nov 11 03:06:56 snmpd 73950 disk_OS_get_disks: adding device 'da0' to device list
Nov 11 03:06:56 snmpd 73950 disk_OS_get_disks: adding device 'cd0' to device list
Nov 11 03:06:56 snmpd 73950 hrPrinterTable: printcap entry for <noname?> has errors, skipping
Nov 11 03:06:57 php-fpm 37660 /rc.start_packages: Restarting/Starting all packages.
Nov 11 03:06:57 php-fpm 64326 /rc.start_packages: Skipping STARTing packages process because previous/another instance is already running
Recovery:
Restart HAproxy service.
There's nothing obvious in syslog to indicate why haproxy did not restart properly.
Is this a known issue fixed in later versions of this package, or pfSense?
It was mentioned in a followup post the following:-
Even though your log mentions "/rc.start_packages: Restarting/Starting all packages." that command does not actually REstart packages.. It only calls start_service($internal_name); which means for haproxy that it checks if its already running and does nothing if it is.. The fix seems simple enough, change it to restart_service($internal_name); however that stops+starts packages, while it should actually be restarting/reloading them.. As with a stop+start its shortly not running at all. possibly interfering with internal services that should not be affected by a wan-ip change.