CARP sync crashes after 2.2.2 upgrade

beatvjiking

I have a bunch of different pairs of CARP-enabled pfsense machines performing NAT for various networks, and after upgrading from 2.2.1 to 2.2.2 some of them started having problems with sync. After anything that would cause a filter reload, the primary would show the following error:

Crash report begins.  Anonymous machine information:

amd64
10.1-RELEASE-p9
FreeBSD 10.1-RELEASE-p9 #0 57b23e7(releng/10.1)-dirty: Mon Apr 13 20:30:25 CDT 2015     root@pfs22-amd64-builder:/usr/obj.amd64/usr/pfSensesrc/src/sys/pfSense_SMP.10

Crash report details:

PHP Errors:
[30-Apr-2015 10:23:57 EST5EDT] XML error: Not well-formed (invalid token) at line 2

All the info I can find about this error relates to package sync problems, but we're not running any packages on any of these machines. It appears the secondary is getting the synced config and passing some invalid reply back to the primary. Both machines stay up, so users aren't affected, but I worry that there's something weird happening here. I haven't seen any of these errors prior to 2.2.2, either. Has anyone else seen this? Any advice would be much appreciated.

beatvjiking

I'm willing to do some more digging here, I just need to know where to start. Can anyone tell me where I enable the debugging for this so I can dump the XML and see where the problem lies?

Hi,

I have exactly the same issue since the upgrade in the same configuration as you.

Sending to backup :


[2.2.2-RELEASE][admin@ZNA]/etc: ./rc.filter_synchronize
May  6 11:05:16 ZNA php: rc.filter_synchronize: Beginning XMLRPC sync to https://10.0.0.203:443.
May  6 11:05:17 ZNA php: rc.filter_synchronize: XMLRPC sync successfully completed with https://10.0.0.203:443.

---SENT---
POST /xmlrpc.php HTTP/1.0
User-Agent: PEAR XML_RPC
Host: 10.0.0.203
Authorization: Basic my_hashed_password_was_here
Content-Type: text/xml
Content-Length: 203

 <methodcall><methodname>pfsense.filter_configure</methodname>
 <params><param>
<value><string>my_password_was_here</string></value></params></methodcall> 

---END---

Answer I got back:


---GOT---
HTTP/1.0 200 OK
Expires: Fri, 08 May 2015 11:05:18 GMT
Cache-Control: max-age=180000
Content-type: text/html
Connection: close
Date: Wed, 06 May 2015 09:05:19 GMT
Server: lighttpd/1.4.35

Warning: in_array() expects parameter 2 to be array, null given in /etc/inc/unbound.inc on line 239

Warning: in_array() expects parameter 2 to be array, null given in /etc/inc/unbound.inc on line 239

Warning: in_array() expects parameter 2 to be array, null given in /etc/inc/unbound.inc on line 239

Warning: Cannot modify header information - headers already sent by (output started at /etc/inc/unbound.inc:239) in /etc/inc/xmlrpc_server.inc on line 431

Warning: Cannot modify header information - headers already sent by (output started at /etc/inc/unbound.inc:239) in /etc/inc/xmlrpc_server.inc on line 431

 <methodresponse><params><param>
<value><boolean>1</boolean></value></params></methodresponse> 
---END---

May  6 11:05:26 ZNA php: rc.filter_synchronize: An error code was received while attempting Filter sync with username admin https://10.0.0.203:443 - Code 2: Invalid return payload: enable debugging to examine incoming payload
May  6 11:05:26 ZNA php: rc.filter_synchronize: New alert found: An error code was received while attempting Filter sync with username admin https://10.0.0.203:443 - Code 2: Invalid return payload: enable debugging to examine incoming payload

/etc/inc/unbound.inc

        if (isset($config['unbound']['forwarding'])) {
                $dnsservers = array();
                if (isset($config['system']['dnsallowoverride'])) {
                        $ns = array_unique(get_nameservers());
                        foreach($ns as $nameserver) {
                                if ($nameserver)
                                        $dnsservers[] = $nameserver;
                        }
                }
                $sys_dnsservers = array_unique(get_dns_servers());
                foreach ($sys_dnsservers as $sys_dnsserver) {
239 -->                   if ($sys_dnsserver && (!in_array($sys_dnsserver, $ns))) {
                                $dnsservers[] = $sys_dnsserver;
                        }
                }

Seems that $ns is null when you don't have DNS Allow Override (I guess this is when you check the box that states that your DHCP interfaces can override your manually set DNS.

We probably miss a $ns = array(); in line 229 in the slave to prevent him to send PHP warnings that are not XML compliant indeed.

@patch

229a230
>               $ns = array();

I can't log a redmine issue :(

Hope that helps.

beatvjiking

Awesome! Just filed a redmine issue pointing to your post for the patch: https://redmine.pfsense.org/issues/4682

Can I ask how you got the XML dump? Did you just do a capture or is there a way to get the output elsewhere?

doktornotor

Already fixed here: https://redmine.pfsense.org/projects/pfsense/repository/revisions/98615a3156d86aed1a560f109087d7e1ad4bf990

See https://forum.pfsense.org/index.php?topic=92437.0

beatvjiking

Got it, I didn't see that since it was the same cause but a different symptom. Thanks for the heads-up, I'll update the redmine issue and flag it for closure.