Alert "XMLRPC method captive_portal_sync" in 2.5
-
There is something wrong with your configuration. The secondary shouldn't be seeing gateway events like that when a CARP transition happens. That makes me think you have some incorrect NAT rules, or possibly incorrect gateway definitions as well.
It's also possible you have the option set to kill firewall states when a gateway goes down which, coupled with those gateway events, could lead to communication errors between the nodes.
It may be behaving differently on 2.5.0 for a variety of reasons, but it looks more like a configuration error than a bug.
-
... I can try to recreate full gateways structure in the isolated box, exactly like in production environment. NAT seems ok, NAT inbond/outbond use only CARP (or alias CARP) VIPs.
I refine the box configuration by adding the missing gateways and try. Thank you very much, if I have any news I will update you.
-
@luca-de-andreis unable to reproduce your issue on my 2.5 HA cluster,
Please check your configuration, make sure you have set captive portal HA (
services_captiveportal_hasync.php
) on the slave node only! -
OK, full gateways structure is online, all gateways are UP.
- Yes, captive portal HA is set only on secondary node (PfSense 2.4.5p1 did not have this setting).
- State Killing on Gateway Failure is disabled on all nodes.
Now the new logs:
Primary in state Master going to state Backup:
**** Primary LOG ****
Jan 7 08:09:53 check_reload_status 371 Carp backup event
Jan 7 08:09:53 kernel carp: 3@vtnet4: MASTER -> BACKUP (more frequent advertisement received)
Jan 7 08:09:53 kernel carp: 1@vtnet2: MASTER -> BACKUP (more frequent advertisement received)
Jan 7 08:09:53 kernel carp: 5@vtnet6: MASTER -> BACKUP (more frequent advertisement received)
Jan 7 08:09:53 kernel carp: 2@vtnet3: MASTER -> BACKUP (more frequent advertisement received)
Jan 7 08:09:53 kernel carp: 6@vtnet7: MASTER -> BACKUP (more frequent advertisement received)
Jan 7 08:09:53 check_reload_status 371 Carp backup event
Jan 7 08:09:53 check_reload_status 371 Carp backup event
Jan 7 08:09:53 kernel carp: 12@vtnet0: MASTER -> BACKUP (more frequent advertisement received)
Jan 7 08:09:53 kernel carp: 15@vtnet13: MASTER -> BACKUP (more frequent advertisement received)
Jan 7 08:09:53 kernel carp: 9@vtnet10: MASTER -> BACKUP (more frequent advertisement received)
Jan 7 08:09:53 kernel carp: 17@vtnet9: MASTER -> BACKUP (more frequent advertisement received)
Jan 7 08:09:53 kernel carp: 13@vtnet1: MASTER -> BACKUP (more frequent advertisement received)
Jan 7 08:09:53 kernel carp: 16@vtnet14: MASTER -> BACKUP (more frequent advertisement received)
Jan 7 08:09:53 kernel carp: 7@vtnet8: MASTER -> BACKUP (more frequent advertisement received)
Jan 7 08:09:53 kernel carp: 10@vtnet11: MASTER -> BACKUP (more frequent advertisement received)
Jan 7 08:09:53 kernel carp: 14@vtnet5: MASTER -> BACKUP (more frequent advertisement received)
Jan 7 08:09:53 check_reload_status 371 Carp backup event
Jan 7 08:09:53 check_reload_status 371 Carp backup event
Jan 7 08:09:53 check_reload_status 371 Carp backup event
Jan 7 08:09:53 check_reload_status 371 Carp backup event
Jan 7 08:09:53 check_reload_status 371 Carp backup event
Jan 7 08:09:53 check_reload_status 371 Carp backup event
Jan 7 08:09:53 check_reload_status 371 Carp backup event
Jan 7 08:09:53 check_reload_status 371 Carp backup event
Jan 7 08:09:53 check_reload_status 371 Carp backup event
Jan 7 08:09:53 check_reload_status 371 Carp backup event
Jan 7 08:09:53 check_reload_status 371 Carp backup event
Jan 7 08:09:55 php-fpm 89749 /rc.carpbackup: HA cluster member "(10.19.15.1@vtnet13): (LABORATORI_INTERNET)" has resumed CARP state "BACKUP" for vhid 15**** Secondary LOG ****
Jan 7 08:09:53 check_reload_status 371 Carp master event
Jan 7 08:09:53 kernel carp: 3@vtnet4: BACKUP -> MASTER (preempting a slower master)
Jan 7 08:09:53 kernel carp: 2@vtnet3: BACKUP -> MASTER (preempting a slower master)
Jan 7 08:09:53 kernel carp: 5@vtnet6: BACKUP -> MASTER (preempting a slower master)
Jan 7 08:09:53 kernel carp: 1@vtnet2: BACKUP -> MASTER (preempting a slower master)
Jan 7 08:09:53 kernel carp: 6@vtnet7: BACKUP -> MASTER (preempting a slower master)
Jan 7 08:09:53 check_reload_status 371 Carp master event
Jan 7 08:09:53 check_reload_status 371 Carp master event
Jan 7 08:09:53 kernel carp: 9@vtnet10: BACKUP -> MASTER (preempting a slower master)
Jan 7 08:09:53 kernel carp: 12@vtnet0: BACKUP -> MASTER (preempting a slower master)
Jan 7 08:09:53 kernel carp: 15@vtnet13: BACKUP -> MASTER (preempting a slower master)
Jan 7 08:09:53 kernel carp: 17@vtnet9: BACKUP -> MASTER (preempting a slower master)
Jan 7 08:09:53 kernel carp: 13@vtnet1: BACKUP -> MASTER (preempting a slower master)
Jan 7 08:09:53 kernel carp: 16@vtnet14: BACKUP -> MASTER (preempting a slower master)
Jan 7 08:09:53 kernel carp: 7@vtnet8: BACKUP -> MASTER (preempting a slower master)
Jan 7 08:09:53 kernel carp: 10@vtnet11: BACKUP -> MASTER (preempting a slower master)
Jan 7 08:09:53 kernel carp: 14@vtnet5: BACKUP -> MASTER (preempting a slower master)
Jan 7 08:09:53 check_reload_status 371 Carp master event
Jan 7 08:09:53 check_reload_status 371 Carp master event
Jan 7 08:09:53 check_reload_status 371 Carp master event
Jan 7 08:09:53 check_reload_status 371 Carp master event
Jan 7 08:09:53 check_reload_status 371 Carp master event
Jan 7 08:09:53 check_reload_status 371 Carp master event
Jan 7 08:09:53 check_reload_status 371 Carp master event
Jan 7 08:09:53 check_reload_status 371 Carp master event
Jan 7 08:09:53 check_reload_status 371 Carp master event
Jan 7 08:09:53 check_reload_status 371 Carp master event
Jan 7 08:09:53 check_reload_status 371 Carp master event
Jan 7 08:09:55 php-fpm 50633 /rc.carpmaster: HA cluster member "(10.19.16.1@vtnet14): (VIDEOCONFERENZA)" has resumed CARP state "MASTER" for vhid 16
Jan 7 08:09:55 minicron 75224 (/etc/rc.prunecaptiveportal) terminated by signal 15 (Terminated)Primary in state Backup going to state Master:
**** Primary LOG ****
Jan 7 08:15:23 check_reload_status 371 Carp master event
Jan 7 08:15:23 kernel carp: 2@vtnet3: BACKUP -> MASTER (preempting a slower master)
Jan 7 08:15:23 kernel carp: 1@vtnet2: BACKUP -> MASTER (preempting a slower master)
Jan 7 08:15:23 kernel carp: 3@vtnet4: BACKUP -> MASTER (preempting a slower master)
Jan 7 08:15:23 kernel carp: 6@vtnet7: BACKUP -> MASTER (preempting a slower master)
Jan 7 08:15:23 kernel carp: 5@vtnet6: BACKUP -> MASTER (preempting a slower master)
Jan 7 08:15:23 kernel arp: 10.19.5.130 moved from 00:00:5e:00:01:01 to aa:7a:fa:ff:fd:e0 on vtnet2
Jan 7 08:15:23 check_reload_status 371 Carp master event
Jan 7 08:15:23 check_reload_status 371 Carp master event
Jan 7 08:15:23 kernel carp: 12@vtnet0: BACKUP -> MASTER (preempting a slower master)
Jan 7 08:15:23 kernel carp: 15@vtnet13: BACKUP -> MASTER (preempting a slower master)
Jan 7 08:15:23 kernel carp: 9@vtnet10: BACKUP -> MASTER (preempting a slower master)
Jan 7 08:15:23 kernel carp: 17@vtnet9: BACKUP -> MASTER (preempting a slower master)
Jan 7 08:15:23 kernel carp: 13@vtnet1: BACKUP -> MASTER (preempting a slower master)
Jan 7 08:15:23 kernel carp: 10@vtnet11: BACKUP -> MASTER (preempting a slower master)
Jan 7 08:15:23 kernel carp: 7@vtnet8: BACKUP -> MASTER (preempting a slower master)
Jan 7 08:15:23 kernel carp: 16@vtnet14: BACKUP -> MASTER (preempting a slower master)
Jan 7 08:15:23 kernel carp: 14@vtnet5: BACKUP -> MASTER (preempting a slower master)
Jan 7 08:15:23 check_reload_status 371 Carp master event
Jan 7 08:15:23 check_reload_status 371 Carp master event
Jan 7 08:15:23 check_reload_status 371 Carp master event
Jan 7 08:15:23 check_reload_status 371 Carp master event
Jan 7 08:15:23 check_reload_status 371 Carp master event
Jan 7 08:15:23 check_reload_status 371 Carp master event
Jan 7 08:15:23 check_reload_status 371 Carp master event
Jan 7 08:15:23 check_reload_status 371 Carp master event
Jan 7 08:15:23 check_reload_status 371 Carp master event
Jan 7 08:15:23 check_reload_status 371 Carp master event
Jan 7 08:15:23 check_reload_status 371 Carp master event
Jan 7 08:15:24 php-fpm 89749 /rc.carpmaster: HA cluster member "(10.19.10.1@vtnet7): (LABORATORI)" has resumed CARP state "MASTER" for vhid 6
Jan 7 08:15:24 php-fpm 88005 /rc.carpmaster: HA cluster member "(10.19.15.1@vtnet13): (LABORATORI_INTERNET)" has resumed CARP state "MASTER" for vhid 15
Jan 7 08:15:25 php-fpm 89749 /rc.carpmaster: Beginning XMLRPC sync data to https://10.19.99.2:443/xmlrpc.php.
Jan 7 08:15:25 php-fpm 88005 /rc.carpmaster: Beginning XMLRPC sync data to https://10.19.99.2:443/xmlrpc.php.
Jan 7 08:15:35 php-fpm 89749 /rc.carpmaster: A communications error occurred while attempting to call XMLRPC method captive_portal_sync:
Jan 7 08:15:35 php-fpm 89749 /rc.carpmaster: New alert found: A communications error occurred while attempting to call XMLRPC method captive_portal_sync:
Jan 7 08:15:35 php-fpm 89749 /rc.carpmaster: Beginning XMLRPC sync data to https://10.19.99.2:443/xmlrpc.php.
Jan 7 08:15:35 php-fpm 88005 /rc.carpmaster: A communications error occurred while attempting to call XMLRPC method captive_portal_sync:
Jan 7 08:15:35 php-fpm 88005 /rc.carpmaster: New alert found: A communications error occurred while attempting to call XMLRPC method captive_portal_sync:
Jan 7 08:15:35 php-fpm 88005 /rc.carpmaster: Beginning XMLRPC sync data to https://10.19.99.2:443/xmlrpc.php.
Jan 7 08:15:45 php-fpm 89749 /rc.carpmaster: A communications error occurred while attempting to call XMLRPC method captive_portal_sync:
Jan 7 08:15:45 php-fpm 89749 /rc.carpmaster: New alert found: A communications error occurred while attempting to call XMLRPC method captive_portal_sync:
Jan 7 08:15:45 php-fpm 88005 /rc.carpmaster: A communications error occurred while attempting to call XMLRPC method captive_portal_sync:
Jan 7 08:15:45 php-fpm 88005 /rc.carpmaster: New alert found: A communications error occurred while attempting to call XMLRPC method captive_portal_sync:**** Secondary LOG ****
Jan 7 08:15:23 check_reload_status 371 Carp backup event
Jan 7 08:15:23 kernel carp: 2@vtnet3: MASTER -> BACKUP (more frequent advertisement received)
Jan 7 08:15:23 kernel carp: 6@vtnet7: MASTER -> BACKUP (more frequent advertisement received)
Jan 7 08:15:23 kernel carp: 1@vtnet2: MASTER -> BACKUP (more frequent advertisement received)
Jan 7 08:15:23 kernel carp: 3@vtnet4: MASTER -> BACKUP (more frequent advertisement received)
Jan 7 08:15:23 kernel carp: 5@vtnet6: MASTER -> BACKUP (more frequent advertisement received)
Jan 7 08:15:23 check_reload_status 371 Carp backup event
Jan 7 08:15:23 check_reload_status 371 Carp backup event
Jan 7 08:15:23 kernel carp: 12@vtnet0: MASTER -> BACKUP (more frequent advertisement received)
Jan 7 08:15:23 kernel carp: 15@vtnet13: MASTER -> BACKUP (more frequent advertisement received)
Jan 7 08:15:23 kernel carp: 9@vtnet10: MASTER -> BACKUP (more frequent advertisement received)
Jan 7 08:15:23 kernel carp: 17@vtnet9: MASTER -> BACKUP (more frequent advertisement received)
Jan 7 08:15:23 kernel carp: 10@vtnet11: MASTER -> BACKUP (more frequent advertisement received)
Jan 7 08:15:23 kernel carp: 13@vtnet1: MASTER -> BACKUP (more frequent advertisement received)
Jan 7 08:15:23 kernel carp: 7@vtnet8: MASTER -> BACKUP (more frequent advertisement received)
Jan 7 08:15:23 kernel carp: 14@vtnet5: MASTER -> BACKUP (more frequent advertisement received)
Jan 7 08:15:23 kernel carp: 16@vtnet14: MASTER -> BACKUP (more frequent advertisement received)
Jan 7 08:15:23 check_reload_status 371 Carp backup event
Jan 7 08:15:23 check_reload_status 371 Carp backup event
Jan 7 08:15:23 check_reload_status 371 Carp backup event
Jan 7 08:15:23 check_reload_status 371 Carp backup event
Jan 7 08:15:23 check_reload_status 371 Carp backup event
Jan 7 08:15:23 check_reload_status 371 Carp backup event
Jan 7 08:15:23 check_reload_status 371 Carp backup event
Jan 7 08:15:23 check_reload_status 371 Carp backup event
Jan 7 08:15:23 check_reload_status 371 Carp backup event
Jan 7 08:15:23 check_reload_status 371 Carp backup event
Jan 7 08:15:23 check_reload_status 371 Carp backup event
Jan 7 08:15:25 php-fpm 67498 /rc.carpbackup: HA cluster member "(10.19.17.1@vtnet5): (DMZ_2)" has resumed CARP state "BACKUP" for vhid 14
Jan 7 08:15:25 minicron 85350 (/etc/rc.prunecaptiveportal) terminated by signal 15 (Terminated) -
Another information:
If I disable xmlrpc on "Captive Portal" all works fine..... -
@luca-de-andreis Please provide more info about your CP configuration
-
Thanks for reply !!!!
I tried to completely delete all the configuration imported from version 2.4.5p1.
-
If I disable the captive portal everything works without warning.
-
If I set even a minimal configuration: define a zone, enable captive portal, select the interface and everything else set by default, no MAC no voucher no customization, nothing ...
-
-
I tried to convert NICs from virtio (vtnet) to e1000 (em) getting exactly the same error.
With the latest versions of PfSense the virtio works correctly even in HA mode. I double-checked everything and I don't think there are any errors in the HA configuration. It seems a problem of version 2.5, with 2.4.5p1 it works perfectly, I don't know .... -
I keep trying, with no results.
I updated to the latest version: 2.5.0.a.20210124 without success, the behavior is absolutely the same.
-
If I disable the "Captive portal" item in XMLRPC sync everything works correctly, the problem disappears.
-
No problems in the LOG regarding the gateways or network, everything works as it should and there are no alerts.
The alert occurs during the transition from secondary to primary.
I ran out of ideas :(
-
-
... I use 15 interfaces and 14 CARP VIPs (other several ALIAS VIPs).
Possible internal timeout ? -
YESSSSSSSSSSSS found the solution !!!!!!!!!!!!!!!!!!!!!
It's a bug. The problem disappears if I use the default web interface port (443) I used to use a non-standard port before (8443)
It is not an ACL problem, it's a bug.
-
@luca-de-andreis Hi,
I'm the user who developed this feature
I am actually a bit sorry for this issue... It's basically a stupid copy paste issue (coming from from there) where I forgot to properly rename a variable (
$port
=>$xmlrpc_port
) ...It also passed through all my tests (and the ones of Netgate) because I didn't think of changing the GUI port during them...I guess everyone's make mistakes
.
It's not really critical through : the issue can easily be fixed by updating the file (using the Services->File manager menu. It's a one-line fix so it's ok i guess), by using the patch package (with this URL), or by simply reverting the GUI to the port 443 (which may not be an acceptable workaround...I understand)
I'm not entirely sure of what Netgate will do now that 2.5.0 is out there. If I read correctly @jimp comment on the issue i guess there will be a day-one patch containing few hotfixes including this one ?
-
Hi, no problem, for now the version 2.5.0 still presents this problem, however it is sufficient to modify the php file as you specified and everything will work again.
It's really not a problem, I just went crazy for at least a month because I thought it was my configuration problem and I couldn't find a solution ... everything seemed correct.Thanks so much
-
@luca-de-andreis the day-one patch just got applied on git. I'm guessing the new ISO is being generated, it should be available for everyone soon
-
We don't re-roll releases like that. There isn't really a "day one patch" per se. I committed a fix into git but that doesn't mean it goes anywhere beyond that yet.
You can install the System Patches package and then create an entry for
fef846ce7ec4158a140f359b0fb35182f6ae9db9
to apply the fix, or you can make the change manually. -
@jimp Oh ok
But wait...What's the point to backport the fix into RELENG_2_5_0 then ?
-
@free4 said in Alert "XMLRPC method captive_portal_sync" in 2.5:
@jimp Oh ok
But wait...What's the point to backport the fix into RELENG_2_5_0 then ?
So it will be included in the next patch release, whenever that may be.