XMLRPC issues - php-fm - Webconfigurator processes?



  • Hi everyone!

    We have a pfsense setup with carp failover installed.

    Actually, we have some 20 setups installed this way.  They are all running version 2.3.2 and running on VMWare ESXi 5.5 or VMWare ESXi 6.

    Unfortunately, we are getting a LOT of Failures of this type:

    /rc.filter_synchronize: New alert found: A communications error occurred while attempting XMLRPC sync with username admin https://x.x.x.x:443.

    I've noticed that option 16, php-fm restart fixes this issues once it happens.  I've also noticed that the issue seems to happen LESS frequently if I increase the number of webconfigurator processes.

    This definately seems to be some kind of bug.

    The php-fm option 16 restart indicates an xmlrpc lock exists and needs to be removed when I do it.  It seems some connection is not closing properly on the secondary unit in the carp setup.

    Can someone help?



  • I am also experiencing this issue after I upgraded 4 boxes running various levels of 2.3.1 up to 2.3.2.

    Same environment: pfsense on ESXi 5.5/6.0 hosts.

    On my end though, It might be an issue with how Suricata is using the XMLRPC sync? Appears to be breaking once a rules refresh is complete. Suricata is setup to NOT ask the target slave to refresh their own rules.

    Haven't had any XMLRPC errors from the other pair of 2.3.2 VMs that DO NOT have Suricata

    
    Sep 7 00:31:49 	php-fpm 	7073 	/rc.filter_synchronize: New alert found: A communications error occurred while attempting XMLRPC sync with username admin https://192.168.254.2:443.
    Sep 7 00:31:49 	php-fpm 	7073 	/rc.filter_synchronize: A communications error occurred while attempting XMLRPC sync with username admin https://192.168.254.2:443.
    Sep 7 00:31:49 	php-fpm 	7073 	/rc.filter_synchronize: XML_RPC_Client: Connection to RPC server 192.168.254.2:443 failed. Operation timed out 103
    Sep 7 00:30:33 	check_reload_status 		Syncing firewall
    Sep 7 00:30:33 	php-cgi 		suricata_check_for_rule_updates.php: [Suricata] The Rules update has finished.
    Sep 7 00:30:29 	php-cgi 		suricata_check_for_rule_updates.php: [Suricata] Snort GPLv2 Community Rules are up to date...
    Sep 7 00:30:28 	php-cgi 		suricata_check_for_rule_updates.php: [Suricata] Snort VRT rules file update downloaded successfully.
    Sep 7 00:30:09 	php-cgi 		suricata_check_for_rule_updates.php: [Suricata] There is a new set of Snort VRT rules posted. Downloading snortrules-snapshot-2983.tar.gz...
    Sep 7 00:30:08 	php-cgi 		suricata_check_for_rule_updates.php: [Suricata] Emerging Threats Open rules file update downloaded successfully.
    Sep 7 00:30:06 	php-cgi 		suricata_check_for_rule_updates.php: [Suricata] There is a new set of Emerging Threats Open rules posted. Downloading emerging.rules.tar.gz...
    Sep 6 17:59:01 	lonrogfw-bluesteel.voyageurtransportation.ca 		nginx: 2016/09/06 17:59:01 [error] 57076#100061: *2654 upstream timed out (60: Operation timed out) while reading response header from upstream, client: 10.1.100.7, server: , request: "POST /widgets/widgets/ipsec.widget.php HTTP/1.1", upstream: "fastcgi://unix:/var/run/php-fpm.socket", host: "10.1.100.30", referrer: "https://10.1.100.30/"
    Sep 6 17:27:55 	php-cgi 		rc.restart_webgui: Creating rrd update script
    Sep 6 17:27:53 	rc.php-fpm_restart 	54531 	>>> Restarting php-fpm
    Sep 6 17:27:50 	lonrogfw-bluesteel.voyageurtransportation.ca 		nginx: 2016/09/06 17:27:50 [alert] 28036#100081: *38216 kevent() reported about an closed connection (53: Software caused connection abort) while reading response header from upstream, client: 10.1.100.7, server: , request: "GET / HTTP/1.1", upstream: "fastcgi://unix:/var/run/php-fpm.socket:", host: "10.1.100.30"
    Sep 6 17:27:47 	login 		login on ttyv0 as root
    Sep 6 17:26:50 	php-fpm 	44517 	/pkg_edit.php: [suricata] XMLRPC sync sending auto-SID conf files to https://192.168.254.2:443.
    Sep 6 17:26:50 	php-fpm 	44517 	/pkg_edit.php: New alert found: A communications error occurred while attempting Suricata XMLRPC sync with https://192.168.254.2:443\. Failed to transfer file: enablesid-sample.conf
    Sep 6 17:26:50 	php-fpm 	44517 	/pkg_edit.php: A communications error occurred while attempting Suricata XMLRPC sync with https://192.168.254.2:443\. Failed to transfer file: enablesid-sample.conf
    Sep 6 17:26:50 	php-fpm 	44517 	/pkg_edit.php: XML_RPC_Client: Connection to RPC server 192.168.254.2:443 failed. Operation timed out 103
    Sep 6 17:26:05 	lonrogfw-bluesteel.voyageurtransportation.ca 		nginx: 2016/09/06 17:26:05 [error] 28036#100081: *38216 upstream timed out (60: Operation timed out) while reading response header from upstream, client: 10.1.100.7, server: , request: "POST /pkg_edit.php?xml=suricata/suricata_sync.xml HTTP/1.1", upstream: "fastcgi://unix:/var/run/php-fpm.socket", host: "10.1.100.30", referrer: "https://10.1.100.30/pkg_edit.php?xml=suricata/suricata_sync.xml"
    Sep 6 17:25:35 	php-fpm 	44517 	/pkg_edit.php: [suricata] XMLRPC sync sending auto-SID conf files to https://192.168.254.2:443.
    Sep 6 17:25:35 	php-fpm 	44517 	/pkg_edit.php: New alert found: A communications error occurred while attempting Suricata XMLRPC sync with https://192.168.254.2:443\. Failed to transfer file: dropsid-sample.conf
    Sep 6 17:25:35 	php-fpm 	44517 	/pkg_edit.php: A communications error occurred while attempting Suricata XMLRPC sync with https://192.168.254.2:443\. Failed to transfer file: dropsid-sample.conf
    Sep 6 17:25:35 	php-fpm 	44517 	/pkg_edit.php: XML_RPC_Client: Connection to RPC server 192.168.254.2:443 failed. Operation timed out 103
    Sep 6 17:24:20 	php-fpm 	44517 	/pkg_edit.php: [suricata] XMLRPC sync sending auto-SID conf files to https://192.168.254.2:443.
    Sep 6 17:24:20 	php-fpm 	44517 	/pkg_edit.php: New alert found: A communications error occurred while attempting Suricata XMLRPC sync with https://192.168.254.2:443\. Failed to transfer file: disablesid-sample.conf
    Sep 6 17:24:20 	php-fpm 	44517 	/pkg_edit.php: A communications error occurred while attempting Suricata XMLRPC sync with https://192.168.254.2:443\. Failed to transfer file: disablesid-sample.conf
    Sep 6 17:24:20 	php-fpm 	44517 	/pkg_edit.php: XML_RPC_Client: Connection to RPC server 192.168.254.2:443 failed. Operation timed out 103
    Sep 6 17:23:05 	php-fpm 	44517 	/pkg_edit.php: [suricata] XMLRPC sync sending auto-SID conf files to https://192.168.254.2:443.
    Sep 6 17:23:05 	php-fpm 	44517 	/pkg_edit.php: [suricata] XMLRPC sync is starting.
    Sep 6 17:23:05 	check_reload_status 		Syncing firewall
    Sep 6 17:23:05 	check_reload_status 		Syncing firewall
    Sep 6 12:31:22 	php-fpm 	49586 	/rc.filter_synchronize: New alert found: A communications error occurred while attempting XMLRPC sync with username admin https://192.168.254.2:443.
    Sep 6 12:31:22 	php-fpm 	49586 	/rc.filter_synchronize: A communications error occurred while attempting XMLRPC sync with username admin https://192.168.254.2:443.
    Sep 6 12:31:22 	php-fpm 	49586 	/rc.filter_synchronize: XML_RPC_Client: Connection to RPC server 192.168.254.2:443 failed. Operation timed out 103
    Sep 6 12:30:06 	check_reload_status 		Syncing firewall
    Sep 6 12:30:06 	php-cgi 		suricata_check_for_rule_updates.php: [Suricata] The Rules update has finished.
    Sep 6 12:30:06 	php-cgi 		suricata_check_for_rule_updates.php: [Suricata] Snort GPLv2 Community Rules are up to date...
    Sep 6 12:30:06 	php-cgi 		suricata_check_for_rule_updates.php: [Suricata] Snort VRT rules are up to date...
    Sep 6 12:30:04 	php-cgi 		suricata_check_for_rule_updates.php: [Suricata] Emerging Threats Open rules are up to date...
    Sep 6 12:16:07 	lonrogfw-bluesteel.voyageurtransportation.ca 		nginx: 2016/09/06 12:16:07 [error] 28036#100081: *12636 upstream timed out (60: Operation timed out) while reading response header from upstream, client: 10.1.100.7, server: , request: "POST /widgets/widgets/ipsec.widget.php HTTP/1.1", upstream: "fastcgi://unix:/var/run/php-fpm.socket", host: "10.1.100.30", referrer: "https://10.1.100.30/"