Messages

[An error occurred while attempting XMLRPC sync with username test and https://192.168.x.x/xmlrpc.php parse error. not well formed]

Hello,

I'm testing the update 20.7.7(_1) on a two node OPNsense HA-Cluster and everytime I want to sync the config from Master to Backup I get the following error: "An error occurred while attempting XMLRPC sync with username test and https://192.168.x.x/xmlrpc.php parse error. not well formed"
The changes I made on the Master node didn't affect the GUI of the Backup Node (for example: new alias, new firewall rule,...) but after a checksum test of the config.xml (md5 /usr/local/etc/config.xml) and ipsec config file (md5 /usr/local/etc/ipsec.conf) on both nodes the checksums were equal as they should be.

Am I checking the wrong files or is there a problem with applying the config to the GUI?

PS: Except for updating the nodes I didn't change anything in the configuration of "High Availability".

Greetz,
bitmusician

Thanks for your reply!

Using "/usr/local/bin/openssl speed -evp aes-256-cbc" doesn't make any difference.

Code Select Expand

Doing aes-256-cbc for 3s on 16 size blocks: 51683849 aes-256-cbc's in 3.09s
Doing aes-256-cbc for 3s on 64 size blocks: 21974176 aes-256-cbc's in 3.06s
Doing aes-256-cbc for 3s on 256 size blocks: 5865967 aes-256-cbc's in 3.06s
Doing aes-256-cbc for 3s on 1024 size blocks: 1462847 aes-256-cbc's in 3.02s
Doing aes-256-cbc for 3s on 8192 size blocks: 185138 aes-256-cbc's in 3.04s
Doing aes-256-cbc for 3s on 16384 size blocks: 91663 aes-256-cbc's in 3.01s
OpenSSL 1.1.1g  21 Apr 2020
built on: Mon Jul 27 22:42:08 2020 UTC
options:bn(64,64) rc4(16x,int) des(int) aes(partial) blowfish(ptr)
compiler: cc -fPIC -pthread -Wa,--noexecstack -Qunused-arguments -O2 -pipe  -DHARDENEDBSD -fPIE -fPIC -fstack-protector-all -fno-strict-aliasing -DL_ENDIAN -DOPENSSL_PIC -DOPENSSL_CPUID_OBJ -DOPENSSL_IA32_SSE2 -DOPENSSL_BN_ASM_MONT -DOPENSSL_BN_ASM_MONT5 -DOPENSSL_BN_ASM_GF2m -DSHA1_ASM -DSHA256_ASM -DSHA512_ASM -DKECCAK1600_ASM -DRC4_ASM -DMD5_ASM -DAESNI_ASM -DVPAES_ASM -DGHASH_ASM -DECP_NISTZ256_ASM -DX25519_ASM -DPOLY1305_ASM -D_THREAD_SAFE -D_REENTRANT -DNDEBUG
The 'numbers' are in 1000s of bytes per second processed.
type             16 bytes     64 bytes    256 bytes   1024 bytes   8192 bytes  16384 bytes
aes-256-cbc     267970.94k   459215.43k   490346.96k   496731.30k   499052.09k   499301.93k

I test the hardware acceleration every time there's an update and the last time that "bad" values like these appeared was (I think) in version 19.1.8. So well I thought I could trust that command line output. Do you have a more trustful method of testing that mechanism?

Hi,

since updating from 20.1.9 to 20.7 the hardware acceleration isn't working properly. The time it takes to do the encryption has increased a lot (like if there's no hardware acceleration enabled). I've tested this on different hardware and tried it before updating, where it was working like expected.

Before updating the output of "openssl speed -evp aes-256-cbc" was:

Code Select Expand

Doing aes-256-cbc for 3s on 16 size blocks: 342721 aes-256-cbc's in 0.38s
Doing aes-256-cbc for 3s on 64 size blocks: 600792 aes-256-cbc's in 0.38s
Doing aes-256-cbc for 3s on 256 size blocks: 315407 aes-256-cbc's in 0.41s
Doing aes-256-cbc for 3s on 1024 size blocks: 257082 aes-256-cbc's in 0.27s
Doing aes-256-cbc for 3s on 8192 size blocks: 104498 aes-256-cbc's in 0.08s
OpenSSL 1.0.2o-freebsd  27 Mar 2018
built on: date not available
options:bn(64,64) rc4(16x,int) des(idx,cisc,16,int) aes(partial) idea(int) blowfish(idx)
compiler: clang
The 'numbers' are in 1000s of bytes per second processed.
type             16 bytes     64 bytes    256 bytes   1024 bytes   8192 bytes
aes-256-cbc      14324.34k   100442.61k   198754.93k   991066.23k 10957409.48k


After updating it's:

Code Select Expand

Doing aes-256-cbc for 3s on 16 size blocks: 55925433 aes-256-cbc's in 3.06s
Doing aes-256-cbc for 3s on 64 size blocks: 22414986 aes-256-cbc's in 3.02s
Doing aes-256-cbc for 3s on 256 size blocks: 5712456 aes-256-cbc's in 3.05s
Doing aes-256-cbc for 3s on 1024 size blocks: 1069014 aes-256-cbc's in 3.01s
Doing aes-256-cbc for 3s on 8192 size blocks: 183532 aes-256-cbc's in 3.05s
Doing aes-256-cbc for 3s on 16384 size blocks: 62895 aes-256-cbc's in 3.00s
OpenSSL 1.1.1d-freebsd  10 Sep 2019
built on: reproducible build, date unspecified
options:bn(64,64) rc4(16x,int) des(int) aes(partial) idea(int) blowfish(ptr)
compiler: clang
The 'numbers' are in 1000s of bytes per second processed.
type             16 bytes     64 bytes    256 bytes   1024 bytes   8192 bytes  16384 bytes
aes-256-cbc     292181.85k   475708.72k   479963.48k   363942.35k   492192.46k   343490.56k


greetz,
bitmusician

I opened an issue on github https://github.com/opnsense/core/issues/4106 where mimugmail suggested to try and let the unbound service listen on all interfaces.

Now the service doesn't crash anymore but it may not be the best solution if you don't want to have the unbound listening on for example the WAN interface.

Is there any news already? In version 20.1.7 it's the same problem.

opnsense-revert -r 20.1.4 unbound

Does this fix it?

No, unfortunately not.

Do you use DoT or Blacklist from Unboudplus plugin?

We do not use any additional plugins for unbound, only the basic dns service.

Hi,
our Unbound DNS crashes only on the Backup-Node in our Cluster as soon as the Master has performed the HA-sync with the Backup-Node. We have the problem since updating to 20.1.6 (We went from 20.1.4 straight to 20.1.6).

Unbound DNS-Log:

Code Select Expand

2020-05-05T13:34:47 unbound: [67336:0] info: server stats for thread 3: requestlist max 0 avg 0 exceeded 0 jostled 0
2020-05-05T13:34:47 unbound: [67336:0] info: server stats for thread 3: 0 queries, 0 answers from cache, 0 recursions, 0 prefetch, 0 rejected by ip ratelimiting
2020-05-05T13:34:47 unbound: [67336:0] info: server stats for thread 2: requestlist max 0 avg 0 exceeded 0 jostled 0
2020-05-05T13:34:47 unbound: [67336:0] info: server stats for thread 2: 0 queries, 0 answers from cache, 0 recursions, 0 prefetch, 0 rejected by ip ratelimiting
2020-05-05T13:34:47 unbound: [67336:0] info: server stats for thread 1: requestlist max 0 avg 0 exceeded 0 jostled 0
2020-05-05T13:34:47 unbound: [67336:0] info: server stats for thread 1: 0 queries, 0 answers from cache, 0 recursions, 0 prefetch, 0 rejected by ip ratelimiting
2020-05-05T13:34:47 unbound: [67336:0] info: server stats for thread 0: requestlist max 0 avg 0 exceeded 0 jostled 0
2020-05-05T13:34:47 unbound: [67336:0] info: server stats for thread 0: 0 queries, 0 answers from cache, 0 recursions, 0 prefetch, 0 rejected by ip ratelimiting
2020-05-05T13:34:47 unbound: [67336:0] info: service stopped (unbound 1.10.0).
2020-05-05T13:34:44 unbound: [67336:0] info: start of service (unbound 1.10.0).
2020-05-05T13:34:44 unbound: [67336:0] notice: init module 1: iterator
2020-05-05T13:34:44 unbound: [67336:0] notice: init module 0: validator
2020-05-05T13:34:44 unbound: [67336:0] notice: Restart of unbound 1.10.0.
2020-05-05T13:34:44 unbound: [67336:0] info: server stats for thread 3: requestlist max 0 avg 0 exceeded 0 jostled 0
2020-05-05T13:34:44 unbound: [67336:0] info: server stats for thread 3: 0 queries, 0 answers from cache, 0 recursions, 0 prefetch, 0 rejected by ip ratelimiting
2020-05-05T13:34:44 unbound: [67336:0] info: server stats for thread 2: requestlist max 0 avg 0 exceeded 0 jostled 0
2020-05-05T13:34:44 unbound: [67336:0] info: server stats for thread 2: 0 queries, 0 answers from cache, 0 recursions, 0 prefetch, 0 rejected by ip ratelimiting
2020-05-05T13:34:44 unbound: [67336:0] info: server stats for thread 1: requestlist max 0 avg 0 exceeded 0 jostled 0
2020-05-05T13:34:44 unbound: [67336:0] info: server stats for thread 1: 0 queries, 0 answers from cache, 0 recursions, 0 prefetch, 0 rejected by ip ratelimiting
2020-05-05T13:34:44 unbound: [67336:0] info: server stats for thread 0: requestlist max 0 avg 0 exceeded 0 jostled 0
2020-05-05T13:34:44 unbound: [67336:0] info: server stats for thread 0: 0 queries, 0 answers from cache, 0 recursions, 0 prefetch, 0 rejected by ip ratelimiting
2020-05-05T13:34:44 unbound: [67336:0] info: service stopped (unbound 1.10.0).

Hi,

since the firmware update from version 20.1.2 to 20.1.3 we are experiencing some issues with our policy based routing. We have one Firewall rule with a configured specific gateway group and since I updated the firewall the traffic is sent over the default route and not the gateway group in the firewall rule. We also tested it with a single Gateway in the firewall rule but it didn't work out, so we had to configure a route for this traffic over one of the specific gateways.

Does anybody have a solution for this problem?

Greetz,
bitmusician :)

Hello,

what I'm writing now is not only an issue in version 20.1 but it got "worse" with the update.

Every time we change the IPsec tunnel configuration over the WebGUI, the configuration change is only written in the /conf/conf.xml on the Backup-Host but not in the /usr/local/etc/ipsec.conf. On the WebGUI of the Backup host it looks like the changes have been made but after comparing the files of both Master and Backup with the command "md5 /usr/local/etc/ipsec.conf" you can see that the changes didn't affect on the Backup Host.

So before 20.1 we had to make some kind of "dummy-change" on the Backup-Host that means to simply open one of the tunnel configurations, save and apply again. This was the solution until now because now you have to additionally perform a HA-Sync BEFORE the dummy-change.

Is there any planned change about this in further versions? I mean it's ok when you know what to do but it would be great if a normal HA-Sync would synchronize the IPsec configuration too!  ;D

Thanks,
Bitmusician

I don't get it ... from reading the logs after switching off mnt mode second machine should be backup???

Yes when switching it off its Backup again. But when I turn on maintenance mode on the first node in the GUI both are shown as Master and nobody answers the requests to the VIP.

I had to revert, couldn't leave that in production. Sorry.
I'll have to start over soon and try again.

Did you have the problem already in 19.1.8 or only after updating to 19.1.10?

[node01 (normally the MASTER):when switching into maintenance mode:]

So, you left mnt mode and both were master and had the sysctl from above? Strange. Then go to CLI, do a clog -f /var/log/system.log and post the new lines when leaving mnt mode

node01 (normally the MASTER):
when switching into maintenance mode:

Jul 10 12:53:30 node01 kernel: carp: demoted by 240 to 240 (sysctl)

when switching out of maintenance mode:

Jul 10 12:54:42 node01 kernel: carp: demoted by -240 to 0 (sysctl)

-----------------------------------------------------

node02 (normally the BACKUP):
when switching into maintenance mode:

Jul 10 12:53:30 node02 kernel: carp: 31@igb0: BACKUP -> MASTER (preempting a slower master)
Jul 10 12:53:31 node02 opnsense: /usr/local/etc/rc.syshook.d/carp/20-openvpn: Carp cluster member "xxx.xxx.xxx.xxx - VIP WAN (31@igb0)" has resumed the state "MASTER" for vhid 31
Jul 10 12:53:31 node02 opnsense: /usr/local/etc/rc.syshook.d/carp/20-openvpn: Starting OpenVPN server instance on xxx.xxx.xxx.xxx - VIP WAN because of transition to CARP master.
Jul 10 12:53:31 node02 kernel: ovpns1: link state changed to DOWN
Jul 10 12:53:35 node02 kernel: ovpns1: link state changed to UP
Jul 10 12:53:35 node02 opnsense: /usr/local/etc/rc.syshook.d/carp/20-openvpn: OpenVPN server 1 instance started on PID 34541.
Jul 10 12:53:36 node02 opnsense: /usr/local/etc/rc.newwanip: IP renewal is starting on 'ovpns1'
Jul 10 12:53:36 node02 opnsense: /usr/local/etc/rc.newwanip: Interface '' is disabled or empty, nothing to do.

when switching out of maintenance mode:


Jul 10 12:54:41 node02 kernel: carp: 31@igb0: MASTER -> BACKUP (more frequent advertisement received)
Jul 10 12:54:41 node02 kernel: ifa_maintain_loopback_route: deletion failed for interface igb0: 3
Jul 10 12:54:42 node02 opnsense: /usr/local/etc/rc.syshook.d/carp/20-openvpn: Carp cluster member "xxx.xxx.xxx.xxx - VIP WAN (31@igb0)" has resumed the state "BACKUP" for vhid 31

- currently it looks, like the secondary is every time master not backup as in 19.1.7
- Tried to edit Virtual IP Setting and re-save it
- HAVE TO CONFIRM THAT: both become master on this IP regardless of the advertising Frequency settings

We are facing the same issue right now. In the GUI it looks like both nodes are Master after setting the first node into persistant CARP Maintenance mode but when we reboot this node the other "Master" (the actual Backup node) doesn't answer the Requests to the VIPs.

Is there already a solution?

We didn't make any changes in the tunables and we also did not have packet loss.
Since I did the workaround we don't have the problem anymore.