Error occurred while attempting to call XMLRPC method filter_configure
-
Hi!
Two pfsense 2.4.2-RELEASE-p1 on identical hardware with 6 Interfaces (2 on board, 4 on i350 card) are configured as HA cluster with dedicated interfaces for HA and Sync. That works very smart :)
HA adresses on the dedicated interfaces are 10.10.10.1/24 and 10.10.10.2/24, Web-GUI port is on both HA members 4443. I could use the Web-GUI on both members with a browser (CARP 172.16.4.250, ha1 172.16.4.251 and ha2 172.16.4.252). The HA interfaces are directly connected, the other interfaces are all on a switch with configured VLANs for WAN, DMZ, LAN and GUEST.
Since a few days there is sometimes a problem with the XMLRPC sync for the config, but only with filter_configure. The synchronisation of other configuration changes have no problems.
Log:
Mar 9 10:58:02 172.16.4.251 php-cgi: rc.filter_synchronize: Beginning XMLRPC sync data to https://10.10.10.2:4443/xmlrpc.php.
Mar 9 10:58:02 172.16.4.251 php-cgi: rc.filter_synchronize: XMLRPC reload data success with https://10.10.10.2:4443/xmlrpc.php (pfsense.host_firmware_version).
Mar 9 10:58:02 172.16.4.251 php-cgi: rc.filter_synchronize: XMLRPC versioncheck: 17.3 – 17.3
Mar 9 10:58:02 172.16.4.251 php-cgi: rc.filter_synchronize: Beginning XMLRPC sync data to https://10.10.10.2:4443/xmlrpc.php.
Mar 9 10:58:03 172.16.4.251 php-cgi: rc.filter_synchronize: XMLRPC reload data success with https://10.10.10.2:4443/xmlrpc.php (pfsense.restore_config_section).
Mar 9 10:58:03 172.16.4.251 php-cgi: rc.filter_synchronize: Beginning XMLRPC sync data to https://10.10.10.2:4443/xmlrpc.php.
Mar 9 10:59:03 172.16.4.251 php-cgi: rc.filter_synchronize: A communications error occurred while attempting to call XMLRPC method filter_configure:
Mar 9 10:59:03 172.16.4.251 php-cgi: rc.filter_synchronize: New alert found: A communications error occurred while attempting to call XMLRPC method filter_configure:
Mar 9 10:59:03 172.16.4.251 php-cgi: rc.filter_synchronize: Beginning XMLRPC sync data to https://10.10.10.2:4443/xmlrpc.php.
Mar 9 11:00:03 172.16.4.251 php-cgi: rc.filter_synchronize: A communications error occurred while attempting to call XMLRPC method filter_configure:
Mar 9 11:00:03 172.16.4.251 php-cgi: rc.filter_synchronize: New alert found: A communications error occurred while attempting to call XMLRPC method filter_configure:I compared both XML backup files with diff, but can't see anything, which could be wrong. I think about, that something is wrong with the firewall rules, i.e. some german Umlauts or other discrepancy, could that been? Is there a possibilty for a debug log or output if I call the rc.filter_synchronize script on console?
Have a nice weekend!
Tom
-
Is there any error shown on the secondary system log?
Steve
-
I have similar problem,
HA seems to work but very often both pfsesnse boxes are freezing while trying to make any changes or click here and there
Typically I get errors like that on both sets of HA using original SG4860s, all version 2.4.2-RELEASE-p1
A communications error occurred while attempting to call XMLRPC method host_firmware_version
or
A communications error occurred while attempting to call XMLRPC method filter_configure
or
A communications error occurred while attempting to call XMLRPC method restore_config_sectionWhat is weird I see HA generally working by what I mean I do see majority of times confings synched sucessfully in the logs but there are also a lot of errors
And yes I see logs with problems on the slave logs too along with successfull ones
-
Do you have a large number of users? If you see reported success followed by time-outs after 1min you may be hitting this: https://redmine.pfsense.org/issues/7469
That should be fixed in 2.4.3rel or in current snapshots if you're able to test them.
Steve
-
basicaly no, I am the only user, no load on pfsense
-
I double checked all passwords on my VIP, all interfaces seem to work fine, in general HA works e.g when I change a rule but those errors and freezing are driving me crazy, is this a bug?
Here are the typical master logs
Mar 14 13:39:06 php-fpm 5316 /rc.filter_configure_sync: The gateway: ISP2WINDSTREAMGW is invalid or unknown, not using it.
Mar 14 13:39:06 php-fpm 5316 /rc.filter_configure_sync: Default gateway down setting ISP1_VZ_DHCP as default!
Mar 14 13:39:05 check_reload_status Reloading filter
Mar 14 13:39:04 php-fpm 99980 /rc.filter_synchronize: Beginning XMLRPC sync data to https://1.1.1.2:8500/xmlrpc.php.
Mar 14 13:39:04 php-fpm 99980 /rc.filter_synchronize: XMLRPC versioncheck: 17.3 – 17.3
Mar 14 13:39:04 php-fpm 99980 /rc.filter_synchronize: XMLRPC reload data success with https://1.1.1.2:8500/xmlrpc.php (pfsense.host_firmware_version).
Mar 14 13:39:04 php-fpm 99980 /rc.filter_synchronize: Beginning XMLRPC sync data to https://1.1.1.2:8500/xmlrpc.php.
Mar 14 13:39:02 check_reload_status Syncing firewall
Mar 14 13:39:02 php-fpm 84556 /firewall_rules_edit.php: Default gateway down setting ISP1_VZ_DHCP as default!
Mar 14 13:38:56 php-fpm 84556 /firewall_rules_edit.php: Default gateway down setting ISP1_VZ_DHCP as default!
Mar 14 13:32:28 php-fpm 83784 /rc.filter_synchronize: New alert found: A communications error occurred while attempting to call XMLRPC method filter_configure:
Mar 14 13:32:28 php-fpm 83784 /rc.filter_synchronize: A communications error occurred while attempting to call XMLRPC method filter_configure:
Mar 14 13:31:28 php-fpm 83784 /rc.filter_synchronize: Beginning XMLRPC sync data to https://1.1.1.2:8500/xmlrpc.php.
Mar 14 13:31:28 php-fpm 83784 /rc.filter_synchronize: New alert found: A communications error occurred while attempting to call XMLRPC method filter_configure:
Mar 14 13:31:28 php-fpm 83784 /rc.filter_synchronize: A communications error occurred while attempting to call XMLRPC method filter_configure:
Mar 14 13:30:27 php-fpm 83784 /rc.filter_synchronize: Beginning XMLRPC sync data to https://1.1.1.2:8500/xmlrpc.php.
Mar 14 13:30:27 php-fpm 83784 /rc.filter_synchronize: XMLRPC reload data success with https://1.1.1.2:8500/xmlrpc.php (pfsense.restore_config_section).
Mar 14 13:29:54 php-fpm 83784 /rc.filter_synchronize: Beginning XMLRPC sync data to https://1.1.1.2:8500/xmlrpc.php.
Mar 14 13:29:54 php-fpm 83784 /rc.filter_synchronize: New alert found: A communications error occurred while attempting to call XMLRPC method restore_config_section:
Mar 14 13:29:54 php-fpm 83784 /rc.filter_synchronize: A communications error occurred while attempting to call XMLRPC method restore_config_section:Slave: (igb2 is the one of the WAN links connected but not online, ISP2WINDSTREAMGW - should not even be in the logs anymore since it was removed, only ISP1_VZ_DHCP is currently up)
Mar 14 13:39:37 php-fpm 37373 /xmlrpc.php: Configuring CARP settings finalize...
Mar 14 13:39:37 php-fpm 37373 /xmlrpc.php: pfsync done in 30 seconds.
Mar 14 13:39:06 php-fpm 37373 /xmlrpc.php: waiting for pfsync...
Mar 14 13:39:05 kernel igb2: promiscuous mode disabled
Mar 14 13:39:05 kernel carp: demoted by -240 to 0 (vhid removed)
Mar 14 13:39:05 kernel ifa_maintain_loopback_route: deletion failed for interface igb2: 3
Mar 14 13:39:05 kernel ifa_maintain_loopback_route: deletion failed for interface igb2: 3
Mar 14 13:39:05 kernel ifa_maintain_loopback_route: deletion failed for interface igb2: 3
Mar 14 13:39:05 kernel carp: demoted by 240 to 240 (interface down)
Mar 14 13:39:05 kernel igb2: promiscuous mode enabled
Mar 14 13:39:04 check_reload_status Syncing firewall
Mar 14 13:31:31 php-fpm 31492 /rc.filter_configure_sync: The gateway: ISP2WINDSTREAMGW is invalid or unknown, not using it.
Mar 14 13:31:31 php-fpm 31492 /rc.filter_configure_sync: Default gateway down setting ISP1_VZ_DHCP as default!
Mar 14 13:31:31 php-fpm 37373 /rc.dyndns.update: Default gateway down setting ISP1_VZ_DHCP as default!
Mar 14 13:31:30 php-fpm 31492 /rc.filter_configure_sync: The gateway: ISP2WINDSTREAMGW is invalid or unknown, not using it.
Mar 14 13:31:30 check_reload_status Reloading filter
Mar 14 13:31:30 check_reload_status Restarting OpenVPN tunnels/interfaces
Mar 14 13:31:30 check_reload_status Restarting ipsec tunnels
Mar 14 13:31:30 check_reload_status updating dyndns MSTGW
Mar 14 13:31:30 rc.gateway_alarm 37911 >>> Gateway alarm: MSTGW (Addr:8.8.8.8 Alarm:1 RTT:0ms RTTsd:0ms Loss:100%)
Mar 14 13:31:30 php-fpm 31492 /rc.filter_configure_sync: Default gateway down setting ISP1_VZ_DHCP as default!
Mar 14 13:31:28 php-fpm 73954 /xmlrpc.php: Resyncing OpenVPN instances.
Mar 14 13:31:28 php-fpm 73954 /xmlrpc.php: Removing static route for monitor 8.8.8.8 and adding a new route through HIDE-PUBLIC-GW-1
Mar 14 13:31:28 php-fpm 73954 /xmlrpc.php: ROUTING: setting default route to HIDE-PUBLIC-GW-1
Mar 14 13:31:28 check_reload_status Reloading filter
Mar 14 13:30:31 php-fpm 39022 /rc.filter_configure_sync: The gateway: ISP2WINDSTREAMGW is invalid or unknown, not using it.
Mar 14 13:30:31 php-fpm 39022 /rc.filter_configure_sync: Default gateway down setting ISP1_VZ_DHCP as default!
Mar 14 13:30:31 php-fpm 73954 /rc.dyndns.update: Default gateway down setting ISP1_VZ_DHCP as default!
Mar 14 13:30:30 php-fpm 39022 /rc.filter_configure_sync: The gateway: ISP2WINDSTREAMGW is invalid or unknown, not using it.
Mar 14 13:30:30 check_reload_status Reloading filter
Mar 14 13:30:30 check_reload_status Restarting OpenVPN tunnels/interfaces
Mar 14 13:30:30 check_reload_status Restarting ipsec tunnels
Mar 14 13:30:30 check_reload_status updating dyndns MSTGW
Mar 14 13:30:30 rc.gateway_alarm 74844 >>> Gateway alarm: MSTGW (Addr:8.8.8.8 Alarm:1 RTT:0ms RTTsd:0ms Loss:100%)
Mar 14 13:30:30 php-fpm 39022 /rc.filter_configure_sync: Default gateway down setting ISP1_VZ_DHCP as default!
Mar 14 13:30:28 php-fpm 1941 /xmlrpc.php: Resyncing OpenVPN instances.
Mar 14 13:30:28 php-fpm 1941 /xmlrpc.php: Removing static route for monitor 8.8.8.8 and adding a new route through HIDE-PUBLIC-GW-1
Mar 14 13:30:28 php-fpm 1941 /xmlrpc.php: ROUTING: setting default route to HIDE-PUBLIC-GW-1
Mar 14 13:30:28 check_reload_status Reloading filter
Mar 14 13:30:27 php-fpm 39022 /xmlrpc.php: Configuring CARP settings finalize...
Mar 14 13:30:27 php-fpm 39022 /xmlrpc.php: pfsync done in 30 seconds.
Mar 14 13:29:56 php-fpm 39022 /xmlrpc.php: waiting for pfsync...
Mar 14 13:29:55 kernel igb2: promiscuous mode disabled
Mar 14 13:29:55 kernel carp: demoted by -240 to 0 (vhid removed)
Mar 14 13:29:55 kernel ifa_maintain_loopback_route: deletion failed for interface igb2: 3
Mar 14 13:29:55 kernel ifa_maintain_loopback_route: deletion failed for interface igb2: 3
Mar 14 13:29:55 kernel ifa_maintain_loopback_route: deletion failed for interface igb2: 3
Mar 14 13:29:55 kernel carp: demoted by 240 to 240 (interface down)
Mar 14 13:29:55 kernel igb2: promiscuous mode enabled
Mar 14 13:29:55 check_reload_status Syncing firewall
Mar 14 13:29:27 php-fpm 23130 /xmlrpc.php: Configuring CARP settings finalize...
Mar 14 13:29:27 php-fpm 23130 /xmlrpc.php: pfsync done in 30 seconds.
Mar 14 13:28:56 php-fpm 23130 /xmlrpc.php: waiting for pfsync... -
Hi all, I am having identical issues to those listed. I am running a virtual HA pair on version 2.4.2-RELEASE-p1. Did you manage to get to the bottom of this?
-
Hi!
Yesterday I installed the update, the 2.4.3-Release. I have done some configurations and always the synchronisation runs without error. I can't see thes error again until yet.
Tom
-
Hello Friends,
I'm having the same issues... created a post here: https://forum.netgate.com/topic/131916/pfsense-with-ha-closing-sessions-when-apply-any-rule
Anyone have solved this issue? is this a bug?