Bug #1591
closedSync issues on June 8 Snapshot
0%
Description
Since the changes to check_reload_status yesterday, a primary is not syncing its config to a secondary. It's acting almost as though the actual sync event is ignored and only the filter reload event is happening. It logs the message that it is syncing the firewall but doesn't appear to actually run /etc/rc.filter_synchronize.
With the new check_reload_status binary, if I run /etc/rc.filter_synchronize by hand it does sync, but still appears to have some of the same issues it had before in terms of what happens to CARP VIPs.
Log from the slave after running /etc/rc.filter_synchronize by hand on the master with a current check_reload_status binary:
Jun 9 14:02:01 pfSense-b check_reload_status: Syncing firewall Jun 9 14:02:01 pfSense-b kernel: vip40: link state changed to DOWN Jun 9 14:02:01 pfSense-b kernel: vip40: INIT -> MASTER (preempting) Jun 9 14:02:01 pfSense-b kernel: vip40: link state changed to UP Jun 9 14:02:01 pfSense-b kernel: vip72: link state changed to DOWN Jun 9 14:02:01 pfSense-b kernel: vip72: INIT -> MASTER (preempting) Jun 9 14:02:01 pfSense-b kernel: vip72: link state changed to UP Jun 9 14:02:01 pfSense-b kernel: vip40: link state changed to DOWN Jun 9 14:02:01 pfSense-b kernel: vip40: INIT -> MASTER (preempting) Jun 9 14:02:01 pfSense-b kernel: vip40: link state changed to UP Jun 9 14:02:01 pfSense-b kernel: vip73: link state changed to DOWN Jun 9 14:02:01 pfSense-b kernel: vip73: INIT -> MASTER (preempting) Jun 9 14:02:01 pfSense-b kernel: vip73: link state changed to UP Jun 9 14:02:01 pfSense-b kernel: vip74: link state changed to DOWN Jun 9 14:02:01 pfSense-b kernel: vip74: INIT -> MASTER (preempting) Jun 9 14:02:01 pfSense-b kernel: vip74: link state changed to UP Jun 9 14:02:01 pfSense-b kernel: vip75: link state changed to DOWN Jun 9 14:02:01 pfSense-b kernel: vip75: INIT -> MASTER (preempting) Jun 9 14:02:01 pfSense-b kernel: vip75: link state changed to UP Jun 9 14:02:01 pfSense-b check_reload_status: Syncing firewall Jun 9 14:02:02 pfSense-b kernel: vip40: link state changed to DOWN Jun 9 14:02:02 pfSense-b kernel: vip40: INIT -> MASTER (preempting) Jun 9 14:02:02 pfSense-b kernel: vip40: link state changed to UP Jun 9 14:02:02 pfSense-b kernel: vip72: link state changed to DOWN Jun 9 14:02:02 pfSense-b kernel: vip72: INIT -> MASTER (preempting) Jun 9 14:02:02 pfSense-b kernel: vip72: link state changed to UP Jun 9 14:02:02 pfSense-b kernel: vip40: link state changed to DOWN Jun 9 14:02:02 pfSense-b kernel: vip40: INIT -> MASTER (preempting) Jun 9 14:02:02 pfSense-b kernel: vip40: link state changed to UP Jun 9 14:02:02 pfSense-b kernel: vip73: link state changed to DOWN Jun 9 14:02:02 pfSense-b kernel: vip73: INIT -> MASTER (preempting) Jun 9 14:02:02 pfSense-b kernel: vip73: link state changed to UP Jun 9 14:02:02 pfSense-b kernel: vip74: link state changed to DOWN Jun 9 14:02:02 pfSense-b kernel: vip74: INIT -> MASTER (preempting) Jun 9 14:02:02 pfSense-b kernel: vip74: link state changed to UP Jun 9 14:02:02 pfSense-b kernel: vip75: link state changed to DOWN Jun 9 14:02:02 pfSense-b check_reload_status: Reloading filter Jun 9 14:02:02 pfSense-b kernel: vip75: INIT -> MASTER (preempting) Jun 9 14:02:02 pfSense-b kernel: vip75: link state changed to UP Jun 9 14:02:02 pfSense-b php: /xmlrpc.php: ROUTING: change default route to 192.168.197.2 Jun 9 14:02:02 pfSense-b kernel: vip40: MASTER -> BACKUP (more frequent advertisement received) Jun 9 14:02:02 pfSense-b kernel: vip40: link state changed to DOWN Jun 9 14:02:02 pfSense-b kernel: vip72: MASTER -> BACKUP (more frequent advertisement received) Jun 9 14:02:02 pfSense-b kernel: vip73: MASTER -> BACKUP (more frequent advertisement received) Jun 9 14:02:02 pfSense-b kernel: vip74: MASTER -> BACKUP (more frequent advertisement received) Jun 9 14:02:02 pfSense-b kernel: vip75: MASTER -> BACKUP (more frequent advertisement received) Jun 9 14:02:02 pfSense-b kernel: vip72: link state changed to DOWN Jun 9 14:02:02 pfSense-b kernel: vip73: link state changed to DOWN Jun 9 14:02:02 pfSense-b kernel: vip74: link state changed to DOWN Jun 9 14:02:02 pfSense-b kernel: vip75: link state changed to DOWN Jun 9 14:02:02 pfSense-b apinger: Exiting on signal 15. Jun 9 14:02:03 pfSense-b apinger: Starting Alarm Pinger, apinger(20859) Jun 9 14:02:03 pfSense-b php: /xmlrpc.php: Resyncing OpenVPN instances. Jun 9 14:02:03 pfSense-b kernel: ovpns1: link state changed to DOWN Jun 9 14:02:03 pfSense-b check_reload_status: Reloading filter Jun 9 14:02:03 pfSense-b kernel: ovpns1: link state changed to UP Jun 9 14:02:03 pfSense-b check_reload_status: rc.newwanip starting ovpns1 Jun 9 14:02:03 pfSense-b dnsmasq[56937]: read /etc/hosts - 5 addresses Jun 9 14:02:05 pfSense-b dnsmasq[56937]: read /etc/hosts - 5 addresses Jun 9 14:02:05 pfSense-b dhcpd: Internet Systems Consortium DHCP Server 4.2.1-P1 Jun 9 14:02:05 pfSense-b dhcpd: Copyright 2004-2011 Internet Systems Consortium. Jun 9 14:02:05 pfSense-b dhcpd: All rights reserved. Jun 9 14:02:05 pfSense-b dhcpd: For info, please visit https://www.isc.org/software/dhcp/ Jun 9 14:02:05 pfSense-b dnsmasq[56937]: read /etc/hosts - 5 addresses Jun 9 14:02:05 pfSense-b dhcpd: failover peer dhcp0: operation in progress Jun 9 14:02:05 pfSense-b dnsmasq[56937]: exiting on receipt of SIGTERM Jun 9 14:02:05 pfSense-b dhcpleases: Could not deliver signal HUP to process because its pidfile does not exist, No such process. Jun 9 14:02:05 pfSense-b dhcpleases: Could not deliver signal HUP to process because its pidfile does not exist, No such process. Jun 9 14:02:06 pfSense-b dhcpleases: Could not deliver signal HUP to process because its pidfile does not exist, No such process. Jun 9 14:02:06 pfSense-b dnsmasq[31437]: started, version 2.55 cachesize 10000 Jun 9 14:02:06 pfSense-b dnsmasq[31437]: compile time options: IPv6 GNU-getopt no-DBus I18N DHCP TFTP Jun 9 14:02:06 pfSense-b dnsmasq[31437]: reading /etc/resolv.conf Jun 9 14:02:06 pfSense-b dnsmasq[31437]: using nameserver 192.168.20.1#53 Jun 9 14:02:06 pfSense-b dnsmasq[31437]: using nameserver 192.168.197.2#53 Jun 9 14:02:06 pfSense-b dnsmasq[31437]: read /etc/hosts - 5 addresses Jun 9 14:02:06 pfSense-b dnsmasq[31437]: read /etc/hosts - 5 addresses Jun 9 14:02:07 pfSense-b dnsmasq[31437]: read /etc/hosts - 5 addresses Jun 9 14:02:07 pfSense-b dhcpd: Internet Systems Consortium DHCP Server 4.2.1-P1 Jun 9 14:02:07 pfSense-b dhcpd: Copyright 2004-2011 Internet Systems Consortium. Jun 9 14:02:07 pfSense-b dhcpd: All rights reserved. Jun 9 14:02:07 pfSense-b dhcpd: For info, please visit https://www.isc.org/software/dhcp/ Jun 9 14:02:07 pfSense-b dnsmasq[31437]: read /etc/hosts - 5 addresses Jun 9 14:02:07 pfSense-b dnsmasq[31437]: read /etc/hosts - 5 addresses Jun 9 14:02:07 pfSense-b dnsmasq[31437]: read /etc/hosts - 5 addresses
No CARP VIPs were changed on the master before that sync attempt.
If I replace the check_reload_status binary with one from yesterday, it syncs as expected, and has a similar log to above but with a couple minor differences:
Jun 9 14:09:48 pfSense-b check_reload_status: Syncing firewall Jun 9 14:09:49 pfSense-b kernel: vip40: link state changed to DOWN Jun 9 14:09:49 pfSense-b kernel: vip40: INIT -> MASTER (preempting) Jun 9 14:09:49 pfSense-b kernel: vip40: link state changed to UP Jun 9 14:09:49 pfSense-b kernel: vip72: link state changed to DOWN Jun 9 14:09:49 pfSense-b kernel: vip72: INIT -> MASTER (preempting) Jun 9 14:09:49 pfSense-b kernel: vip72: link state changed to UP Jun 9 14:09:49 pfSense-b kernel: vip40: link state changed to DOWN Jun 9 14:09:49 pfSense-b kernel: vip40: INIT -> MASTER (preempting) Jun 9 14:09:49 pfSense-b kernel: vip40: link state changed to UP Jun 9 14:09:49 pfSense-b kernel: vip73: link state changed to DOWN Jun 9 14:09:49 pfSense-b kernel: vip73: INIT -> MASTER (preempting) Jun 9 14:09:49 pfSense-b kernel: vip73: link state changed to UP Jun 9 14:09:49 pfSense-b kernel: vip74: link state changed to DOWN Jun 9 14:09:49 pfSense-b kernel: vip74: INIT -> MASTER (preempting) Jun 9 14:09:49 pfSense-b kernel: vip74: link state changed to UP Jun 9 14:09:49 pfSense-b kernel: vip75: link state changed to DOWN Jun 9 14:09:49 pfSense-b kernel: vip75: INIT -> MASTER (preempting) Jun 9 14:09:49 pfSense-b kernel: vip75: link state changed to UP Jun 9 14:09:49 pfSense-b php: : Config sync not being done because of missing sync IP (normal on secondary systems). Jun 9 14:09:49 pfSense-b check_reload_status: Syncing firewall Jun 9 14:09:49 pfSense-b kernel: vip40: MASTER -> BACKUP (more frequent advertisement received) Jun 9 14:09:49 pfSense-b kernel: vip40: link state changed to DOWN Jun 9 14:09:49 pfSense-b kernel: vip72: MASTER -> BACKUP (more frequent advertisement received) Jun 9 14:09:49 pfSense-b kernel: vip73: MASTER -> BACKUP (more frequent advertisement received) Jun 9 14:09:49 pfSense-b kernel: vip74: MASTER -> BACKUP (more frequent advertisement received) Jun 9 14:09:49 pfSense-b kernel: vip75: MASTER -> BACKUP (more frequent advertisement received) Jun 9 14:09:49 pfSense-b kernel: vip72: link state changed to DOWN Jun 9 14:09:49 pfSense-b kernel: vip73: link state changed to DOWN Jun 9 14:09:49 pfSense-b kernel: vip74: link state changed to DOWN Jun 9 14:09:49 pfSense-b kernel: vip75: link state changed to DOWN Jun 9 14:09:49 pfSense-b kernel: vip40: link state changed to DOWN Jun 9 14:09:49 pfSense-b kernel: vip40: INIT -> MASTER (preempting) Jun 9 14:09:49 pfSense-b kernel: vip40: link state changed to UP Jun 9 14:09:49 pfSense-b kernel: vip72: link state changed to DOWN Jun 9 14:09:49 pfSense-b kernel: vip72: INIT -> MASTER (preempting) Jun 9 14:09:49 pfSense-b kernel: vip72: link state changed to UP Jun 9 14:09:49 pfSense-b kernel: vip40: link state changed to DOWN Jun 9 14:09:49 pfSense-b kernel: vip40: INIT -> MASTER (preempting) Jun 9 14:09:49 pfSense-b kernel: vip40: link state changed to UP Jun 9 14:09:49 pfSense-b kernel: vip73: link state changed to DOWN Jun 9 14:09:49 pfSense-b kernel: vip73: INIT -> MASTER (preempting) Jun 9 14:09:49 pfSense-b kernel: vip73: link state changed to UP Jun 9 14:09:49 pfSense-b kernel: vip74: link state changed to DOWN Jun 9 14:09:49 pfSense-b check_reload_status: Reloading filter Jun 9 14:09:49 pfSense-b kernel: vip74: INIT -> MASTER (preempting) Jun 9 14:09:49 pfSense-b kernel: vip74: link state changed to UP Jun 9 14:09:49 pfSense-b kernel: vip75: link state changed to DOWN Jun 9 14:09:49 pfSense-b kernel: vip75: INIT -> MASTER (preempting) Jun 9 14:09:49 pfSense-b kernel: vip75: link state changed to UP Jun 9 14:09:50 pfSense-b php: /xmlrpc.php: ROUTING: change default route to 192.168.197.2 Jun 9 14:09:50 pfSense-b apinger: Exiting on signal 15. Jun 9 14:09:50 pfSense-b php: : Config sync not being done because of missing sync IP (normal on secondary systems). Jun 9 14:09:50 pfSense-b kernel: vip40: MASTER -> BACKUP (more frequent advertisement received) Jun 9 14:09:50 pfSense-b kernel: vip40: link state changed to DOWN Jun 9 14:09:50 pfSense-b kernel: vip72: MASTER -> BACKUP (more frequent advertisement received) Jun 9 14:09:50 pfSense-b kernel: vip73: MASTER -> BACKUP (more frequent advertisement received) Jun 9 14:09:50 pfSense-b kernel: vip74: MASTER -> BACKUP (more frequent advertisement received) Jun 9 14:09:50 pfSense-b kernel: vip75: MASTER -> BACKUP (more frequent advertisement received) Jun 9 14:09:50 pfSense-b kernel: vip72: link state changed to DOWN Jun 9 14:09:50 pfSense-b kernel: vip73: link state changed to DOWN Jun 9 14:09:50 pfSense-b kernel: vip74: link state changed to DOWN Jun 9 14:09:50 pfSense-b kernel: vip75: link state changed to DOWN Jun 9 14:09:51 pfSense-b apinger: Starting Alarm Pinger, apinger(47049) Jun 9 14:09:51 pfSense-b php: /xmlrpc.php: Resyncing OpenVPN instances. Jun 9 14:09:51 pfSense-b kernel: ovpns1: link state changed to DOWN Jun 9 14:09:51 pfSense-b check_reload_status: Reloading filter Jun 9 14:09:51 pfSense-b check_reload_status: Reloading filter Jun 9 14:09:51 pfSense-b kernel: ovpns1: link state changed to UP Jun 9 14:09:51 pfSense-b check_reload_status: rc.newwanip starting ovpns1 Jun 9 14:09:51 pfSense-b dnsmasq[61277]: read /etc/hosts - 6 addresses Jun 9 14:09:52 pfSense-b php: : rc.newwanip: Informational is starting ovpns1. Jun 9 14:09:52 pfSense-b php: : rc.newwanip: on (IP address: 10.0.8.1) (interface: ) (real interface: ovpns1). Jun 9 14:09:52 pfSense-b check_reload_status: Reloading filter Jun 9 14:09:52 pfSense-b php: : The command '/usr/bin/killall 'ntpd'' returned exit code '1', the output was 'killall: warning: kill -TERM 50291: No such process' Jun 9 14:09:52 pfSense-b php: : OpenNTPD is starting up. Jun 9 14:09:52 pfSense-b php: : pfSense package system has detected an ip change -> ... Restarting packages. Jun 9 14:09:52 pfSense-b check_reload_status: Starting packages Jun 9 14:09:52 pfSense-b php: : Restarting/Starting all packages. Jun 9 14:09:53 pfSense-b dnsmasq[61277]: read /etc/hosts - 6 addresses Jun 9 14:09:53 pfSense-b dhcpd: Internet Systems Consortium DHCP Server 4.2.1-P1 Jun 9 14:09:53 pfSense-b dhcpd: Copyright 2004-2011 Internet Systems Consortium. Jun 9 14:09:53 pfSense-b dhcpd: All rights reserved. Jun 9 14:09:53 pfSense-b dhcpd: For info, please visit https://www.isc.org/software/dhcp/ Jun 9 14:09:53 pfSense-b dnsmasq[61277]: read /etc/hosts - 6 addresses Jun 9 14:09:53 pfSense-b dnsmasq[61277]: exiting on receipt of SIGTERM Jun 9 14:09:53 pfSense-b dhcpleases: Could not deliver signal HUP to process because its pidfile does not exist, No such process. Jun 9 14:09:53 pfSense-b dhcpleases: Could not deliver signal HUP to process because its pidfile does not exist, No such process. Jun 9 14:09:54 pfSense-b dhcpleases: Could not deliver signal HUP to process because its pidfile does not exist, No such process. Jun 9 14:09:54 pfSense-b dnsmasq[17436]: started, version 2.55 cachesize 10000 Jun 9 14:09:54 pfSense-b dnsmasq[17436]: compile time options: IPv6 GNU-getopt no-DBus I18N DHCP TFTP Jun 9 14:09:54 pfSense-b dnsmasq[17436]: reading /etc/resolv.conf Jun 9 14:09:54 pfSense-b dnsmasq[17436]: using nameserver 192.168.20.1#53 Jun 9 14:09:54 pfSense-b dnsmasq[17436]: using nameserver 192.168.197.2#53 Jun 9 14:09:54 pfSense-b dnsmasq[17436]: read /etc/hosts - 5 addresses Jun 9 14:09:54 pfSense-b dnsmasq[17436]: read /etc/hosts - 5 addresses Jun 9 14:09:55 pfSense-b dnsmasq[17436]: read /etc/hosts - 5 addresses Jun 9 14:09:55 pfSense-b dhcpd: Internet Systems Consortium DHCP Server 4.2.1-P1 Jun 9 14:09:55 pfSense-b dhcpd: Copyright 2004-2011 Internet Systems Consortium. Jun 9 14:09:55 pfSense-b dhcpd: All rights reserved. Jun 9 14:09:55 pfSense-b dhcpd: For info, please visit https://www.isc.org/software/dhcp/ Jun 9 14:09:55 pfSense-b dnsmasq[17436]: read /etc/hosts - 5 addresses Jun 9 14:09:55 pfSense-b dnsmasq[17436]: read /etc/hosts - 5 addresses Jun 9 14:09:55 pfSense-b dnsmasq[17436]: read /etc/hosts - 5 addresses