Project

General

Profile

Actions

Bug #1591

closed

Sync issues on June 8 Snapshot

Added by Jim Pingle over 13 years ago. Updated over 13 years ago.

Status:
Resolved
Priority:
Normal
Assignee:
-
Category:
CARP
Target version:
Start date:
06/09/2011
Due date:
% Done:

0%

Estimated time:
Plus Target Version:
Release Notes:
Affected Version:
2.0
Affected Architecture:
All

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
Actions

Also available in: Atom PDF