IPSec problem after Update 2.1.5 -> 2.2 Beta



  • Hi,

    after updating my 2.1.5 to 2.2 Beta my IPSec seems to be broken. In dashboad the tunnels shows up. Also on my asa the tunnel seems to be "there". But i can't ping and can't make a network connection anymore now. Of course there are rules alowing the traffic.

    Before the update there was no problem. This is was my log tells me:

    Dec 16 08:23:51 	charon: 11[KNL] unable to query SAD entry with SPI d0f43476: No such file or directory (2)
    Dec 16 08:23:28 	charon: 14[IKE] CHILD_SA con1{1} established with SPIs cbe750c5_i d909f4f7_o and TS 192.168.111.0/24|/0 === 10.20.0.0/16|/0
    Dec 16 08:23:28 	charon: 14[IKE] <con1|9> CHILD_SA con1{1} established with SPIs cbe750c5_i d909f4f7_o and TS 192.168.111.0/24|/0 === 10.20.0.0/16|/0
    Dec 16 08:23:28 	charon: 14[ENC] parsed QUICK_MODE request 864280355 [ HASH ]
    Dec 16 08:23:28 	charon: 14[NET] received packet: from 222.222.222.222[500] to 111.111.111.111[500] (76 bytes)
    Dec 16 08:23:28 	charon: 14[NET] sending packet: from 111.111.111.111[500] to 222.222.222.222[500] (332 bytes)
    Dec 16 08:23:28 	charon: 14[ENC] generating QUICK_MODE response 864280355 [ HASH SA No KE ID ID ]
    Dec 16 08:23:28 	charon: 14[IKE] received 4608000000 lifebytes, configured 0
    Dec 16 08:23:28 	charon: 14[IKE] <con1|9> received 4608000000 lifebytes, configured 0
    Dec 16 08:23:28 	charon: 14[ENC] parsed QUICK_MODE request 864280355 [ HASH SA No KE ID ID ]
    Dec 16 08:23:28 	charon: 14[NET] received packet: from 222.222.222.222[500] to 111.111.111.111[500] (796 bytes)
    Dec 16 08:22:34 	charon: 08[NET] sending packet: from 111.111.111.111[500] to 222.222.222.222[500] (60 bytes)
    Dec 16 08:22:34 	charon: 08[ENC] generating QUICK_MODE request 4260479534 [ HASH ]
    Dec 16 08:22:34 	charon: 08[IKE] CHILD_SA con1{1} established with SPIs cb800ad7_i d0f43476_o and TS 192.168.111.0/24|/0 === 192.168.30.0/24|/0
    Dec 16 08:22:34 	charon: 08[IKE] <con1|9> CHILD_SA con1{1} established with SPIs cb800ad7_i d0f43476_o and TS 192.168.111.0/24|/0 === 192.168.30.0/24|/0
    Dec 16 08:22:34 	charon: 08[ENC] parsed QUICK_MODE response 4260479534 [ HASH SA No KE ID ID ]
    Dec 16 08:22:34 	charon: 08[NET] received packet: from 222.222.222.222[500] to 111.111.111.111[500] (300 bytes)
    Dec 16 08:22:34 	charon: 08[NET] sending packet: from 111.111.111.111[500] to 222.222.222.222[500] (316 bytes)
    Dec 16 08:22:34 	charon: 08[ENC] generating QUICK_MODE request 4260479534 [ HASH SA No KE ID ID ]
    Dec 16 08:22:34 	charon: 08[IKE] DPD not supported by peer, disabled
    Dec 16 08:22:34 	charon: 08[IKE] <con1|9> DPD not supported by peer, disabled
    Dec 16 08:22:34 	charon: 08[IKE] maximum IKE_SA lifetime 86385s
    Dec 16 08:22:34 	charon: 08[IKE] <con1|9> maximum IKE_SA lifetime 86385s
    Dec 16 08:22:34 	charon: 08[IKE] scheduling reauthentication in 85845s
    Dec 16 08:22:34 	charon: 08[IKE] <con1|9> scheduling reauthentication in 85845s
    Dec 16 08:22:34 	charon: 08[IKE] IKE_SA con1[9] established between 111.111.111.111[111.111.111.111]...222.222.222.222[222.222.222.222]
    Dec 16 08:22:34 	charon: 08[IKE] <con1|9> IKE_SA con1[9] established between 111.111.111.111[111.111.111.111]...222.222.222.222[222.222.222.222]
    Dec 16 08:22:34 	charon: 08[ENC] parsed ID_PROT response 0 [ ID HASH ]
    Dec 16 08:22:34 	charon: 08[NET] received packet: from 222.222.222.222[500] to 111.111.111.111[500] (76 bytes)
    Dec 16 08:22:34 	charon: 08[NET] sending packet: from 111.111.111.111[500] to 222.222.222.222[500] (76 bytes)
    Dec 16 08:22:34 	charon: 08[ENC] generating ID_PROT request 0 [ ID HASH ]
    Dec 16 08:22:34 	charon: 08[ENC] received unknown vendor ID: 1f:07:f7:0e:aa:65:14:d3:b0:fa:96:54:2a:50:01:00
    Dec 16 08:22:34 	charon: 08[ENC] received unknown vendor ID: 77:cb:35:1f:bc:72:95:6d:d4:32:16:ff:f6:ec:17:66
    Dec 16 08:22:34 	charon: 08[IKE] received XAuth vendor ID
    Dec 16 08:22:34 	charon: 08[IKE] <con1|9> received XAuth vendor ID
    Dec 16 08:22:34 	charon: 08[IKE] received Cisco Unity vendor ID
    Dec 16 08:22:34 	charon: 08[IKE] <con1|9> received Cisco Unity vendor ID
    Dec 16 08:22:34 	charon: 08[ENC] parsed ID_PROT response 0 [ KE No V V V V ]
    Dec 16 08:22:34 	charon: 08[NET] received packet: from 222.222.222.222[500] to 111.111.111.111[500] (256 bytes)
    Dec 16 08:22:34 	charon: 08[NET] sending packet: from 111.111.111.111[500] to 222.222.222.222[500] (196 bytes)
    Dec 16 08:22:34 	charon: 08[ENC] generating ID_PROT request 0 [ KE No ]
    Dec 16 08:22:34 	charon: 08[IKE] received FRAGMENTATION vendor ID
    Dec 16 08:22:34 	charon: 08[IKE] <con1|9> received FRAGMENTATION vendor ID
    Dec 16 08:22:34 	charon: 08[ENC] parsed ID_PROT response 0 [ SA V ]
    Dec 16 08:22:34 	charon: 08[NET] received packet: from 222.222.222.222[500] to 111.111.111.111[500] (112 bytes)
    Dec 16 08:22:34 	charon: 08[NET] sending packet: from 111.111.111.111[500] to 222.222.222.222[500] (204 bytes)
    Dec 16 08:22:34 	charon: 08[ENC] generating ID_PROT request 0 [ SA V V V V V V ]
    Dec 16 08:22:34 	charon: 08[IKE] initiating Main Mode IKE_SA con1[9] to 222.222.222.222
    Dec 16 08:22:34 	charon: 08[IKE] <con1|9> initiating Main Mode IKE_SA con1[9] to 222.222.222.222</con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9></con1|9>
    

    In this example 111.111.111.111 is pfSense, while 222.222.222.222 is a Cisco ASA. Anyone got a hint what's to do? Maybe there are some extra steps after update to 2.2 … or could it be a bug?

    Thx
    EmL



  • What do the ASA logs show from the same time?



  • I think, it's not more neccesary to look for the asa logs anymore. The symptoms seems to be a little like the problem reported in https://forum.pfsense.org/index.php?topic=85365.0

    IMHO the problem is at follows:

    I have a P1 with 6 P2 entries. All tunnels are showing up in dashboard. And one of them is really up! Its the first of the P2, which i'm not often using, so i didn't realize that this one is really up. Child P2 2-6 showing also up, but are not. When I delete the first of the 6 P2 entries (that one thats working) and reboot, the new first P2 entry builds up the tunnel and the remaining entries 2-5 displayed up/green, but arent.

    This means, that only the first P2 child entry is beeing processed properly. Here's again my log after a clean reboot (newest up):

    Last 1000 IPsec log entries
    Dec 21 09:37:47 	charon: 05[IKE] CHILD_SA not found, ignored
    Dec 21 09:37:47 	charon: 05[IKE] <con1|1> CHILD_SA not found, ignored
    Dec 21 09:37:47 	charon: 05[IKE] received DELETE for ESP CHILD_SA with SPI cd1abb69
    Dec 21 09:37:47 	charon: 05[IKE] <con1|1> received DELETE for ESP CHILD_SA with SPI cd1abb69
    Dec 21 09:37:47 	charon: 05[ENC] parsed INFORMATIONAL_V1 request 3656835076 [ HASH D ]
    Dec 21 09:37:47 	charon: 05[NET] received packet: from 222.222.222.222[500] to 111.111.111.111[500] (76 bytes)
    Dec 21 09:37:47 	charon: 05[NET] sending packet: from 111.111.111.111[500] to 222.222.222.222[500] (60 bytes)
    Dec 21 09:37:47 	charon: 05[ENC] generating QUICK_MODE request 2475235189 [ HASH ]
    Dec 21 09:37:47 	charon: 05[IKE] CHILD_SA con1{1} established with SPIs c3120c06_i aa87e597_o and TS 192.168.111.0/24|/0 === 10.20.0.0/16|/0
    Dec 21 09:37:47 	charon: 05[IKE] <con1|1> CHILD_SA con1{1} established with SPIs c3120c06_i aa87e597_o and TS 192.168.111.0/24|/0 === 10.20.0.0/16|/0
    Dec 21 09:37:47 	charon: 05[ENC] parsed QUICK_MODE response 2475235189 [ HASH SA No KE ID ID ]
    Dec 21 09:37:47 	charon: 05[NET] received packet: from 222.222.222.222[500] to 111.111.111.111[500] (300 bytes)
    Dec 21 09:37:47 	charon: 05[NET] sending packet: from 111.111.111.111[500] to 222.222.222.222[500] (316 bytes)
    Dec 21 09:37:47 	charon: 05[ENC] generating QUICK_MODE request 2475235189 [ HASH SA No KE ID ID ]
    Dec 21 09:37:47 	charon: 05[IKE] DPD not supported by peer, disabled
    Dec 21 09:37:47 	charon: 05[IKE] <con1|1> DPD not supported by peer, disabled
    Dec 21 09:37:47 	charon: 05[IKE] maximum IKE_SA lifetime 86031s
    Dec 21 09:37:47 	charon: 05[IKE] <con1|1> maximum IKE_SA lifetime 86031s
    Dec 21 09:37:47 	charon: 05[IKE] scheduling reauthentication in 85491s
    Dec 21 09:37:47 	charon: 05[IKE] <con1|1> scheduling reauthentication in 85491s
    Dec 21 09:37:47 	charon: 05[IKE] IKE_SA con1[1] established between 111.111.111.111[111.111.111.111]...222.222.222.222[222.222.222.222]
    Dec 21 09:37:47 	charon: 05[IKE] <con1|1> IKE_SA con1[1] established between 111.111.111.111[111.111.111.111]...222.222.222.222[222.222.222.222]
    Dec 21 09:37:47 	charon: 05[ENC] parsed ID_PROT response 0 [ ID HASH ]
    Dec 21 09:37:47 	charon: 05[NET] received packet: from 222.222.222.222[500] to 111.111.111.111[500] (76 bytes)
    Dec 21 09:37:47 	charon: 05[NET] sending packet: from 111.111.111.111[500] to 222.222.222.222[500] (76 bytes)
    Dec 21 09:37:47 	charon: 05[ENC] generating ID_PROT request 0 [ ID HASH ]
    Dec 21 09:37:47 	charon: 05[ENC] received unknown vendor ID: 1f:07:f7:0e:aa:65:14:d3:b0:fa:96:54:2a:50:01:00
    Dec 21 09:37:47 	charon: 05[ENC] received unknown vendor ID: ad:93:86:4c:0f:54:aa:da:5f:21:bb:d4:67:6d:99:52
    Dec 21 09:37:47 	charon: 05[IKE] received XAuth vendor ID
    Dec 21 09:37:47 	charon: 05[IKE] <con1|1> received XAuth vendor ID
    Dec 21 09:37:47 	charon: 05[IKE] received Cisco Unity vendor ID
    Dec 21 09:37:47 	charon: 05[IKE] <con1|1> received Cisco Unity vendor ID
    Dec 21 09:37:47 	charon: 05[ENC] parsed ID_PROT response 0 [ KE No V V V V ]
    Dec 21 09:37:47 	charon: 05[NET] received packet: from 222.222.222.222[500] to 111.111.111.111[500] (256 bytes)
    Dec 21 09:37:46 	charon: 05[NET] sending packet: from 111.111.111.111[500] to 222.222.222.222[500] (196 bytes)
    Dec 21 09:37:46 	charon: 05[ENC] generating ID_PROT request 0 [ KE No ]
    Dec 21 09:37:46 	charon: 05[IKE] received FRAGMENTATION vendor ID
    Dec 21 09:37:46 	charon: 05[IKE] <con1|1> received FRAGMENTATION vendor ID
    Dec 21 09:37:46 	charon: 05[ENC] parsed ID_PROT response 0 [ SA V ]
    Dec 21 09:37:46 	charon: 05[NET] received packet: from 222.222.222.222[500] to 111.111.111.111[500] (112 bytes)
    Dec 21 09:37:46 	charon: 05[NET] sending packet: from 111.111.111.111[500] to 222.222.222.222[500] (204 bytes)
    Dec 21 09:37:46 	charon: 05[ENC] generating ID_PROT request 0 [ SA V V V V V V ]
    Dec 21 09:37:46 	charon: 05[IKE] initiating Main Mode IKE_SA con1[1] to 222.222.222.222
    Dec 21 09:37:46 	charon: 05[IKE] <con1|1> initiating Main Mode IKE_SA con1[1] to 222.222.222.222
    Dec 21 09:37:46 	charon: 05[KNL] creating acquire job for policy 111.111.111.111/32|/0 === 222.222.222.222/32|/0 with reqid {1}
    Dec 21 09:37:45 	ipsec_starter[55511]:
    Dec 21 09:37:45 	ipsec_starter[55511]: 'con1' routed
    Dec 21 09:37:45 	charon: 05[CFG] received stroke: route 'con1'
    Dec 21 09:37:45 	charon: 16[CFG] added configuration 'con1'
    Dec 21 09:37:45 	charon: 16[CFG] received stroke: add connection 'con1'
    Dec 21 09:37:45 	ipsec_starter[55511]: charon (55575) started after 420 ms
    Dec 21 09:37:45 	charon: 00[JOB] spawning 16 worker threads
    Dec 21 09:37:45 	charon: 00[LIB] unable to load 6 plugin features (5 due to unmet dependencies)
    Dec 21 09:37:45 	charon: 00[LIB] loaded plugins: charon unbound aes des blowfish rc2 sha1 sha2 md4 md5 random nonce x509 revocation constraints pubkey pkcs1 pkcs7 pkcs8 pkcs12 pgp dnskey sshkey ipseckey pem openssl fips-prf gmp xcbc cmac hmac curl attr kernel-pfkey kernel-pfroute resolve socket-default stroke smp updown eap-identity eap-sim eap-aka eap-aka-3gpp2 eap-md5 eap-mschapv2 eap-dynamic eap-radius eap-tls eap-ttls eap-peap xauth-generic xauth-eap whitelist addrblock unity
    Dec 21 09:37:45 	charon: 00[CFG] loaded 0 RADIUS server configurations
    Dec 21 09:37:45 	charon: 00[CFG] opening triplet file /var/etc/ipsec/ipsec.d/triplets.dat failed: No such file or directory
    Dec 21 09:37:45 	charon: 00[CFG] loaded IKE secret for 222.222.222.222
    Dec 21 09:37:45 	charon: 00[CFG] loading secrets from '/var/etc/ipsec/ipsec.secrets'
    Dec 21 09:37:45 	charon: 00[CFG] loading crls from '/var/etc/ipsec/ipsec.d/crls'
    Dec 21 09:37:45 	charon: 00[CFG] loading attribute certificates from '/var/etc/ipsec/ipsec.d/acerts'
    Dec 21 09:37:45 	charon: 00[CFG] loading ocsp signer certificates from '/var/etc/ipsec/ipsec.d/ocspcerts'
    Dec 21 09:37:45 	charon: 00[CFG] loading aa certificates from '/var/etc/ipsec/ipsec.d/aacerts'
    Dec 21 09:37:45 	charon: 00[CFG] loaded ca certificate "C=DE, ST=myState, L=myCity, O=myOrganization, OU=myOrganisationUnit, CN=myCA, E=do@not.use" from '/var/etc/ipsec/ipsec.d/cacerts/cdc05c4c.0.crt'
    Dec 21 09:37:45 	charon: 00[CFG] loaded ca certificate "C=DE, ST=Bayern, L=Hannberg, O=wegscheider office solution gmbh, OU=RootCA, CN=RootCA, E=support@wegscheider-os.de" from '/var/etc/ipsec/ipsec.d/cacerts/7f75f5d6.0.crt'
    Dec 21 09:37:45 	charon: 00[CFG] loading ca certificates from '/var/etc/ipsec/ipsec.d/cacerts'
    Dec 21 09:37:45 	charon: 00[CFG] ipseckey plugin is disabled
    Dec 21 09:37:45 	charon: 00[NET] enabling UDP decapsulation for IPv6 on port 4500 failed
    Dec 21 09:37:45 	charon: 00[KNL] unable to set UDP_ENCAP: Invalid argument
    Dec 21 09:37:44 	charon: 00[DMN] Starting IKE charon daemon (strongSwan 5.2.1, FreeBSD 10.1-RELEASE-p2, i386)
    Dec 21 09:37:44 	ipsec_starter[54817]: no known IPsec stack detected, ignoring!
    Dec 21 09:37:44 	ipsec_starter[54817]: no KLIPS IPsec stack detected
    Dec 21 09:37:44 	ipsec_starter[54817]: no netkey IPsec stack detected
    Dec 21 09:37:44 	ipsec_starter[54817]: Starting strongSwan 5.2.1 IPsec [starter]...</con1|1></con1|1></con1|1></con1|1></con1|1></con1|1></con1|1></con1|1></con1|1></con1|1></con1|1>
    

    Maybe the first log entry "CHILD_SA not found, ignored" … could point in the right direction?



  • Addition: Even if I only deactivate the first remaining P2 entry (instead of deleting it) the next P2 entry becomes funcitional and the 2nd-? are not working. If I would have only one P1 with one P2 entry, i wouldn't expect any problem. It only occurs if you have more thane one P2 entry.



  • Can you replace vpn.inc with this one attached on your system and notify if this solves the issue for you?

    NOTE: you have to rename the file to vpn.inc from the attachment.

    vpn.inc.txt



  • @ermal:

    Can you replace vpn.inc with this one attached on your system and notify if this solves the issue for you?

    Of course, just a little hint: I'm not a BSD/*X geek … can you tell me the location of the file? How to put it there ...via shell command or scp or what would you suggest? Thx a lot in advance.



  • From the GUI will be easy - Diagnostics->Edit File
    /etc/inc/vpn.inc
    Press Load
    Select all the text and replace it with the text provided by Ermal.
    Press Save

    It avoids any need to know any editors or commands in the underlying FreeBSD.



  • This fixed the problem (almost). All my tunnels are now functional again! But a little issue is now left at the dashboard. Even if a tunnel is really up, it's not shown up there …

    I don't know if it's really needed, but here's the actual log after reboot again:

    Last 1000 IPsec log entries
    Dec 22 15:10:22 	charon: 08[IKE] CHILD_SA not found, ignored
    Dec 22 15:10:22 	charon: 08[IKE] <con1000|1> CHILD_SA not found, ignored
    Dec 22 15:10:22 	charon: 08[IKE] received DELETE for ESP CHILD_SA with SPI 8f01860d
    Dec 22 15:10:22 	charon: 08[IKE] <con1000|1> received DELETE for ESP CHILD_SA with SPI 8f01860d
    Dec 22 15:10:22 	charon: 08[ENC] parsed INFORMATIONAL_V1 request 3905131992 [ HASH D ]
    Dec 22 15:10:22 	charon: 08[NET] received packet: from 222.222.222.222[500] to 111.111.111.111[500] (76 bytes)
    Dec 22 15:10:21 	charon: 12[NET] sending packet: from 111.111.111.111[500] to 222.222.222.222[500] (60 bytes)
    Dec 22 15:10:21 	charon: 12[ENC] generating QUICK_MODE request 2242275122 [ HASH ]
    Dec 22 15:10:21 	charon: 12[IKE] CHILD_SA con1005{10005} established with SPIs c7a9ceee_i 40c2be6e_o and TS 192.168.111.0/24|/0 === 192.168.30.0/24|/0
    Dec 22 15:10:21 	charon: 12[IKE] <con1000|1> CHILD_SA con1005{10005} established with SPIs c7a9ceee_i 40c2be6e_o and TS 192.168.111.0/24|/0 === 192.168.30.0/24|/0
    Dec 22 15:10:21 	charon: 12[ENC] parsed QUICK_MODE response 2242275122 [ HASH SA No KE ID ID ]
    Dec 22 15:10:21 	charon: 12[NET] received packet: from 222.222.222.222[500] to 111.111.111.111[500] (300 bytes)
    Dec 22 15:10:21 	charon: 13[NET] sending packet: from 111.111.111.111[500] to 222.222.222.222[500] (316 bytes)
    Dec 22 15:10:21 	charon: 13[ENC] generating QUICK_MODE request 2242275122 [ HASH SA No KE ID ID ]
    Dec 22 15:10:21 	charon: 13[KNL] creating acquire job for policy 111.111.111.111/32|/0 === 222.222.222.222/32|/0 with reqid {10005}
    Dec 22 15:09:57 	charon: 13[IKE] CHILD_SA not found, ignored
    Dec 22 15:09:57 	charon: 13[IKE] <con1000|1> CHILD_SA not found, ignored
    Dec 22 15:09:57 	charon: 13[IKE] received DELETE for ESP CHILD_SA with SPI ec0d1a13
    Dec 22 15:09:57 	charon: 13[IKE] <con1000|1> received DELETE for ESP CHILD_SA with SPI ec0d1a13
    Dec 22 15:09:57 	charon: 13[ENC] parsed INFORMATIONAL_V1 request 407982143 [ HASH D ]
    Dec 22 15:09:57 	charon: 13[NET] received packet: from 222.222.222.222[500] to 111.111.111.111[500] (76 bytes)
    Dec 22 15:09:56 	charon: 13[NET] sending packet: from 111.111.111.111[500] to 222.222.222.222[500] (60 bytes)
    Dec 22 15:09:56 	charon: 13[ENC] generating QUICK_MODE request 3891877266 [ HASH ]
    Dec 22 15:09:56 	charon: 13[IKE] CHILD_SA con1004{10004} established with SPIs cd340446_i 052eedf9_o and TS 192.168.111.0/24|/0 === 192.168.1.0/24|/0
    Dec 22 15:09:56 	charon: 13[IKE] <con1000|1> CHILD_SA con1004{10004} established with SPIs cd340446_i 052eedf9_o and TS 192.168.111.0/24|/0 === 192.168.1.0/24|/0
    Dec 22 15:09:56 	charon: 13[ENC] parsed QUICK_MODE response 3891877266 [ HASH SA No KE ID ID ]
    Dec 22 15:09:56 	charon: 13[NET] received packet: from 222.222.222.222[500] to 111.111.111.111[500] (300 bytes)
    Dec 22 15:09:56 	charon: 13[NET] sending packet: from 111.111.111.111[500] to 222.222.222.222[500] (316 bytes)
    Dec 22 15:09:56 	charon: 13[ENC] generating QUICK_MODE request 3891877266 [ HASH SA No KE ID ID ]
    Dec 22 15:09:56 	charon: 10[KNL] creating acquire job for policy 111.111.111.111/32|/0 === 222.222.222.222/32|/0 with reqid {10004}
    Dec 22 15:09:52 	charon: 10[IKE] CHILD_SA not found, ignored
    Dec 22 15:09:52 	charon: 10[IKE] <con1000|1> CHILD_SA not found, ignored
    Dec 22 15:09:52 	charon: 10[IKE] received DELETE for ESP CHILD_SA with SPI 789ab902
    Dec 22 15:09:52 	charon: 10[IKE] <con1000|1> received DELETE for ESP CHILD_SA with SPI 789ab902
    Dec 22 15:09:52 	charon: 10[ENC] parsed INFORMATIONAL_V1 request 3157639166 [ HASH D ]
    Dec 22 15:09:52 	charon: 10[NET] received packet: from 222.222.222.222[500] to 111.111.111.111[500] (76 bytes)
    Dec 22 15:09:51 	charon: 13[NET] sending packet: from 111.111.111.111[500] to 222.222.222.222[500] (60 bytes)
    Dec 22 15:09:51 	charon: 13[ENC] generating QUICK_MODE request 3912449148 [ HASH ]
    Dec 22 15:09:51 	charon: 13[IKE] CHILD_SA con1003{10003} established with SPIs c64ac329_i b2f7c26f_o and TS 192.168.111.0/24|/0 === 192.168.10.0/24|/0
    Dec 22 15:09:51 	charon: 13[IKE] <con1000|1> CHILD_SA con1003{10003} established with SPIs c64ac329_i b2f7c26f_o and TS 192.168.111.0/24|/0 === 192.168.10.0/24|/0
    Dec 22 15:09:51 	charon: 13[ENC] parsed QUICK_MODE response 3912449148 [ HASH SA No KE ID ID ]
    Dec 22 15:09:51 	charon: 13[NET] received packet: from 222.222.222.222[500] to 111.111.111.111[500] (300 bytes)
    Dec 22 15:09:50 	charon: 13[NET] sending packet: from 111.111.111.111[500] to 222.222.222.222[500] (316 bytes)
    Dec 22 15:09:50 	charon: 13[ENC] generating QUICK_MODE request 3912449148 [ HASH SA No KE ID ID ]
    Dec 22 15:09:50 	charon: 10[KNL] creating acquire job for policy 111.111.111.111/32|/0 === 222.222.222.222/32|/0 with reqid {10003}
    Dec 22 15:09:46 	charon: 11[IKE] CHILD_SA not found, ignored
    Dec 22 15:09:46 	charon: 11[IKE] <con1000|1> CHILD_SA not found, ignored
    Dec 22 15:09:46 	charon: 11[IKE] received DELETE for ESP CHILD_SA with SPI bd32f924
    Dec 22 15:09:46 	charon: 11[IKE] <con1000|1> received DELETE for ESP CHILD_SA with SPI bd32f924
    Dec 22 15:09:46 	charon: 11[ENC] parsed INFORMATIONAL_V1 request 1197046715 [ HASH D ]
    Dec 22 15:09:46 	charon: 11[NET] received packet: from 222.222.222.222[500] to 111.111.111.111[500] (76 bytes)
    Dec 22 15:09:45 	charon: 11[NET] sending packet: from 111.111.111.111[500] to 222.222.222.222[500] (60 bytes)
    Dec 22 15:09:45 	charon: 11[ENC] generating QUICK_MODE request 1467456426 [ HASH ]
    Dec 22 15:09:45 	charon: 11[IKE] CHILD_SA con1002{10002} established with SPIs c66cbb65_i c4016eb5_o and TS 192.168.111.0/24|/0 === 10.0.0.0/24|/0
    Dec 22 15:09:45 	charon: 11[IKE] <con1000|1> CHILD_SA con1002{10002} established with SPIs c66cbb65_i c4016eb5_o and TS 192.168.111.0/24|/0 === 10.0.0.0/24|/0
    Dec 22 15:09:45 	charon: 11[ENC] parsed QUICK_MODE response 1467456426 [ HASH SA No KE ID ID ]
    Dec 22 15:09:45 	charon: 11[NET] received packet: from 222.222.222.222[500] to 111.111.111.111[500] (300 bytes)
    Dec 22 15:09:45 	charon: 11[NET] sending packet: from 111.111.111.111[500] to 222.222.222.222[500] (316 bytes)
    Dec 22 15:09:45 	charon: 11[ENC] generating QUICK_MODE request 1467456426 [ HASH SA No KE ID ID ]
    Dec 22 15:09:45 	charon: 10[KNL] creating acquire job for policy 111.111.111.111/32|/0 === 222.222.222.222/32|/0 with reqid {10002}
    Dec 22 15:09:41 	charon: 10[IKE] CHILD_SA not found, ignored
    Dec 22 15:09:41 	charon: 10[IKE] <con1000|1> CHILD_SA not found, ignored
    Dec 22 15:09:41 	charon: 10[IKE] received DELETE for ESP CHILD_SA with SPI 40d441dd
    Dec 22 15:09:41 	charon: 10[IKE] <con1000|1> received DELETE for ESP CHILD_SA with SPI 40d441dd
    Dec 22 15:09:41 	charon: 10[ENC] parsed INFORMATIONAL_V1 request 493701617 [ HASH D ]
    Dec 22 15:09:41 	charon: 10[NET] received packet: from 222.222.222.222[500] to 111.111.111.111[500] (76 bytes)
    Dec 22 15:09:40 	charon: 10[NET] sending packet: from 111.111.111.111[500] to 222.222.222.222[500] (60 bytes)
    Dec 22 15:09:40 	charon: 10[ENC] generating QUICK_MODE request 2788292895 [ HASH ]
    Dec 22 15:09:40 	charon: 10[IKE] CHILD_SA con1001{10001} established with SPIs c95b529d_i 996639ba_o and TS 192.168.111.0/24|/0 === 10.255.255.0/24|/0
    Dec 22 15:09:40 	charon: 10[IKE] <con1000|1> CHILD_SA con1001{10001} established with SPIs c95b529d_i 996639ba_o and TS 192.168.111.0/24|/0 === 10.255.255.0/24|/0
    Dec 22 15:09:40 	charon: 10[ENC] parsed QUICK_MODE response 2788292895 [ HASH SA No KE ID ID ]
    Dec 22 15:09:40 	charon: 10[NET] received packet: from 222.222.222.222[500] to 111.111.111.111[500] (300 bytes)
    Dec 22 15:09:40 	charon: 10[NET] sending packet: from 111.111.111.111[500] to 222.222.222.222[500] (316 bytes)
    Dec 22 15:09:40 	charon: 10[ENC] generating QUICK_MODE request 2788292895 [ HASH SA No KE ID ID ]
    Dec 22 15:09:40 	charon: 09[KNL] creating acquire job for policy 111.111.111.111/32|/0 === 222.222.222.222/32|/0 with reqid {10001}
    Dec 22 15:09:36 	charon: 09[IKE] CHILD_SA not found, ignored
    Dec 22 15:09:36 	charon: 09[IKE] <con1000|1> CHILD_SA not found, ignored
    Dec 22 15:09:36 	charon: 09[IKE] received DELETE for ESP CHILD_SA with SPI 854be1e5
    Dec 22 15:09:36 	charon: 09[IKE] <con1000|1> received DELETE for ESP CHILD_SA with SPI 854be1e5
    Dec 22 15:09:36 	charon: 09[ENC] parsed INFORMATIONAL_V1 request 3039964438 [ HASH D ]
    Dec 22 15:09:36 	charon: 09[NET] received packet: from 222.222.222.222[500] to 111.111.111.111[500] (76 bytes)
    Dec 22 15:09:35 	charon: 12[NET] sending packet: from 111.111.111.111[500] to 222.222.222.222[500] (60 bytes)
    Dec 22 15:09:35 	charon: 12[ENC] generating QUICK_MODE request 2275084269 [ HASH ]
    Dec 22 15:09:35 	charon: 12[IKE] CHILD_SA con1000{10000} established with SPIs c42ee6dd_i e2f95a88_o and TS 192.168.111.0/24|/0 === 10.20.0.0/16|/0
    Dec 22 15:09:35 	charon: 12[IKE] <con1000|1> CHILD_SA con1000{10000} established with SPIs c42ee6dd_i e2f95a88_o and TS 192.168.111.0/24|/0 === 10.20.0.0/16|/0
    Dec 22 15:09:35 	charon: 12[ENC] parsed QUICK_MODE response 2275084269 [ HASH SA No KE ID ID ]
    Dec 22 15:09:35 	charon: 12[NET] received packet: from 222.222.222.222[500] to 111.111.111.111[500] (300 bytes)
    Dec 22 15:09:35 	charon: 12[NET] sending packet: from 111.111.111.111[500] to 222.222.222.222[500] (316 bytes)
    Dec 22 15:09:35 	charon: 12[ENC] generating QUICK_MODE request 2275084269 [ HASH SA No KE ID ID ]
    Dec 22 15:09:35 	charon: 12[IKE] DPD not supported by peer, disabled
    Dec 22 15:09:35 	charon: 12[IKE] <con1000|1> DPD not supported by peer, disabled
    Dec 22 15:09:35 	charon: 12[IKE] maximum IKE_SA lifetime 86012s
    Dec 22 15:09:35 	charon: 12[IKE] <con1000|1> maximum IKE_SA lifetime 86012s
    Dec 22 15:09:35 	charon: 12[IKE] scheduling reauthentication in 85472s
    Dec 22 15:09:35 	charon: 12[IKE] <con1000|1> scheduling reauthentication in 85472s
    Dec 22 15:09:35 	charon: 12[IKE] IKE_SA con1000[1] established between 111.111.111.111[111.111.111.111]...222.222.222.222[222.222.222.222]
    Dec 22 15:09:35 	charon: 12[IKE] <con1000|1> IKE_SA con1000[1] established between 111.111.111.111[111.111.111.111]...222.222.222.222[222.222.222.222]
    Dec 22 15:09:35 	charon: 12[ENC] parsed ID_PROT response 0 [ ID HASH ]
    Dec 22 15:09:35 	charon: 12[NET] received packet: from 222.222.222.222[500] to 111.111.111.111[500] (76 bytes)
    Dec 22 15:09:35 	charon: 12[NET] sending packet: from 111.111.111.111[500] to 222.222.222.222[500] (76 bytes)
    Dec 22 15:09:35 	charon: 12[ENC] generating ID_PROT request 0 [ ID HASH ]
    Dec 22 15:09:35 	charon: 12[ENC] received unknown vendor ID: 1f:07:f7:0e:aa:65:14:d3:b0:fa:96:54:2a:50:01:00
    Dec 22 15:09:35 	charon: 12[ENC] received unknown vendor ID: 93:16:f4:19:4d:bb:bc:95:e0:64:f6:bc:30:92:59:e3
    Dec 22 15:09:35 	charon: 12[IKE] received XAuth vendor ID
    Dec 22 15:09:35 	charon: 12[IKE] <con1000|1> received XAuth vendor ID
    Dec 22 15:09:35 	charon: 12[IKE] received Cisco Unity vendor ID
    Dec 22 15:09:35 	charon: 12[IKE] <con1000|1> received Cisco Unity vendor ID
    Dec 22 15:09:35 	charon: 12[ENC] parsed ID_PROT response 0 [ KE No V V V V ]
    Dec 22 15:09:35 	charon: 12[NET] received packet: from 222.222.222.222[500] to 111.111.111.111[500] (256 bytes)
    Dec 22 15:09:35 	charon: 12[NET] sending packet: from 111.111.111.111[500] to 222.222.222.222[500] (196 bytes)
    Dec 22 15:09:35 	charon: 12[ENC] generating ID_PROT request 0 [ KE No ]
    Dec 22 15:09:35 	charon: 12[IKE] received FRAGMENTATION vendor ID
    Dec 22 15:09:35 	charon: 12[IKE] <con1000|1> received FRAGMENTATION vendor ID
    Dec 22 15:09:35 	charon: 12[ENC] parsed ID_PROT response 0 [ SA V ]
    Dec 22 15:09:35 	charon: 12[NET] received packet: from 222.222.222.222[500] to 111.111.111.111[500] (112 bytes)
    Dec 22 15:09:35 	charon: 12[NET] sending packet: from 111.111.111.111[500] to 222.222.222.222[500] (204 bytes)
    Dec 22 15:09:35 	charon: 12[ENC] generating ID_PROT request 0 [ SA V V V V V V ]
    Dec 22 15:09:35 	charon: 12[IKE] initiating Main Mode IKE_SA con1000[1] to 222.222.222.222
    Dec 22 15:09:35 	charon: 12[IKE] <con1000|1> initiating Main Mode IKE_SA con1000[1] to 222.222.222.222
    Dec 22 15:05:01 	ipsec_starter[55377]:
    Dec 22 15:05:01 	ipsec_starter[55377]: 'con1005' routed
    Dec 22 15:05:01 	charon: 12[CFG] received stroke: route 'con1005'
    Dec 22 15:05:01 	charon: 13[CFG] added child to existing configuration 'con1000'
    Dec 22 15:05:01 	charon: 13[CFG] received stroke: add connection 'con1005'
    Dec 22 15:05:01 	ipsec_starter[55377]:
    Dec 22 15:05:01 	ipsec_starter[55377]: 'con1004' routed
    Dec 22 15:05:01 	charon: 12[CFG] received stroke: route 'con1004'
    Dec 22 15:05:01 	charon: 13[CFG] added child to existing configuration 'con1000'
    Dec 22 15:05:01 	charon: 13[CFG] received stroke: add connection 'con1004'
    Dec 22 15:05:01 	ipsec_starter[55377]:
    Dec 22 15:05:01 	ipsec_starter[55377]: 'con1003' routed
    Dec 22 15:05:01 	charon: 16[CFG] received stroke: route 'con1003'
    Dec 22 15:05:01 	charon: 15[CFG] added child to existing configuration 'con1000'
    Dec 22 15:05:01 	charon: 15[CFG] received stroke: add connection 'con1003'
    Dec 22 15:05:01 	ipsec_starter[55377]:
    Dec 22 15:05:01 	ipsec_starter[55377]: 'con1002' routed
    Dec 22 15:05:01 	charon: 13[CFG] received stroke: route 'con1002'
    Dec 22 15:05:01 	charon: 16[CFG] added child to existing configuration 'con1000'
    Dec 22 15:05:01 	charon: 16[CFG] received stroke: add connection 'con1002'
    Dec 22 15:05:01 	ipsec_starter[55377]:
    Dec 22 15:05:01 	ipsec_starter[55377]: 'con1001' routed
    Dec 22 15:05:01 	charon: 15[CFG] received stroke: route 'con1001'
    Dec 22 15:05:01 	charon: 13[CFG] added child to existing configuration 'con1000'
    Dec 22 15:05:01 	charon: 13[CFG] received stroke: add connection 'con1001'
    Dec 22 15:05:01 	ipsec_starter[55377]:
    Dec 22 15:05:01 	ipsec_starter[55377]: 'con1000' routed
    Dec 22 15:05:01 	charon: 16[CFG] received stroke: route 'con1000'
    Dec 22 15:05:01 	charon: 13[CFG] added configuration 'con1000'
    Dec 22 15:05:01 	charon: 13[CFG] received stroke: add connection 'con1000'
    Dec 22 15:05:01 	ipsec_starter[55377]: charon (55459) started after 980 ms
    Dec 22 15:05:01 	charon: 00[JOB] spawning 16 worker threads
    Dec 22 15:05:01 	charon: 00[LIB] unable to load 6 plugin features (5 due to unmet dependencies)
    Dec 22 15:05:01 	charon: 00[LIB] loaded plugins: charon unbound aes des blowfish rc2 sha1 sha2 md4 md5 random nonce x509 revocation constraints pubkey pkcs1 pkcs7 pkcs8 pkcs12 pgp dnskey sshkey ipseckey pem openssl fips-prf gmp xcbc cmac hmac curl attr kernel-pfkey kernel-pfroute resolve socket-default stroke smp updown eap-identity eap-sim eap-aka eap-aka-3gpp2 eap-md5 eap-mschapv2 eap-dynamic eap-radius eap-tls eap-ttls eap-peap xauth-generic xauth-eap whitelist addrblock unity
    Dec 22 15:05:01 	charon: 00[CFG] loaded 0 RADIUS server configurations
    Dec 22 15:05:01 	charon: 00[CFG] opening triplet file /var/etc/ipsec/ipsec.d/triplets.dat failed: No such file or directory
    Dec 22 15:05:01 	charon: 00[CFG] loaded IKE secret for 222.222.222.222
    Dec 22 15:05:01 	charon: 00[CFG] loading secrets from '/var/etc/ipsec/ipsec.secrets'
    Dec 22 15:05:01 	charon: 00[CFG] loading crls from '/var/etc/ipsec/ipsec.d/crls'
    Dec 22 15:05:01 	charon: 00[CFG] loading attribute certificates from '/var/etc/ipsec/ipsec.d/acerts'
    Dec 22 15:05:01 	charon: 00[CFG] loading ocsp signer certificates from '/var/etc/ipsec/ipsec.d/ocspcerts'
    Dec 22 15:05:01 	charon: 00[CFG] loading aa certificates from '/var/etc/ipsec/ipsec.d/aacerts'
    Dec 22 15:05:01 	charon: 00[CFG] loaded ca certificate "C=DE, ST=myState, L=myCity, O=myOrganization, OU=myOrganisationUnit, CN=myCA, E=do@not.use" from '/var/etc/ipsec/ipsec.d/cacerts/cdc05c4c.0.crt'
    Dec 22 15:05:01 	charon: 00[CFG] loaded ca certificate "C=DE, ST=Bayern, L=Hannberg, O=wegscheider office solution gmbh, OU=RootCA, CN=RootCA, E=support@wegscheider-os.de" from '/var/etc/ipsec/ipsec.d/cacerts/7f75f5d6.0.crt'
    Dec 22 15:05:01 	charon: 00[CFG] loading ca certificates from '/var/etc/ipsec/ipsec.d/cacerts'
    Dec 22 15:05:01 	charon: 00[CFG] ipseckey plugin is disabled
    Dec 22 15:05:01 	charon: 00[NET] enabling UDP decapsulation for IPv6 on port 4500 failed
    Dec 22 15:05:01 	charon: 00[KNL] unable to set UDP_ENCAP: Invalid argument
    Dec 22 15:05:00 	charon: 00[DMN] Starting IKE charon daemon (strongSwan 5.2.1, FreeBSD 10.1-RELEASE-p2, i386)
    Dec 22 15:05:00 	ipsec_starter[55006]: no known IPsec stack detected, ignoring!
    Dec 22 15:05:00 	ipsec_starter[55006]: no KLIPS IPsec stack detected
    Dec 22 15:05:00 	ipsec_starter[55006]: no netkey IPsec stack detected
    Dec 22 15:05:00 	ipsec_starter[55006]: Starting strongSwan 5.2.1 IPsec [starter]...</con1000|1></con1000|1></con1000|1></con1000|1></con1000|1></con1000|1></con1000|1></con1000|1></con1000|1></con1000|1></con1000|1></con1000|1></con1000|1></con1000|1></con1000|1></con1000|1></con1000|1></con1000|1></con1000|1></con1000|1></con1000|1></con1000|1></con1000|1></con1000|1></con1000|1></con1000|1>
    


  • I pushed this on repository.
    Also the dashboard and status pages should behave with latest snapshots.



  • I downloaded the latest version this morning  "2.2-RC (amd64)  built on Tue Dec 23 05:11:07 CST 2014" I can now reach all of my subnets behind the remote firewall, however the IPsec GUI is still showing the wrong state "0 tunnels up"
    and the following errors:

    Warning: Invalid argument supplied for foreach() in /usr/local/www/widgets/widgets/ipsec.widget.php on line 89 Warning: Invalid argument supplied for foreach() in /usr/local/www/widgets/widgets/ipsec.widget.php on line 89 Warning: Invalid argument supplied for foreach() in /usr/local/www/widgets/widgets/ipsec.widget.php on line 89




  • @samham:

    I downloaded the latest version this morning  "2.2-RC (amd64)  built on Tue Dec 23 05:11:07 CST 2014" I can now reach all of my subnets behind the remote firewall, however the IPsec GUI is still showing the wrong state "0 tunnels up"
    and the following errors:

    Warning: Invalid argument supplied for foreach() in /usr/local/www/widgets/widgets/ipsec.widget.php on line 89 Warning: Invalid argument supplied for foreach() in /usr/local/www/widgets/widgets/ipsec.widget.php on line 89 Warning: Invalid argument supplied for foreach() in /usr/local/www/widgets/widgets/ipsec.widget.php on line 89

    For me, using today's snapshot, the whole "Warning: Invalid argument supplied for foreach() in /usr/local/www/widgets/widgets/ipsec.widget.php on line 89 Warning: Invalid argument supplied for foreach() in /usr/local/www/widgets/widgets/ipsec.widget.php on line 89 Warning: Invalid argument supplied for foreach() in /usr/local/www/widgets/widgets/ipsec.widget.php on line 89" only appears while the animation for the packages update, do not make any GUI changes is running, seems to go away once its done. It does however show all zeros for the tunnels. Going to Status -> IP SEC show the true status, but lacks description for the tunnel. I believe it's being worked on based on https://redmine.pfsense.org/issues/4138



  • The error messages goes away when the tunnel is brought up and the screen is refreshed, however the "active tunnels" counter is still wrong, and furthermore the errors reappear after the tunnel is brought down.

    tracked here:

    https://redmine.pfsense.org/issues/4139#change-16266



  • I updated to "2.2-RC (i386) built on Sun Dec 28 04:40:24 CST 2014" and my dashboard IPSec widged shows now 1 tunnel up and 5 down. So the widged has now the issue left, that it shows only the first P1 entry, while any other entry 2-? is shown as down (also if it's up). The IPSec status overview page displays me all my working 6 tunnels - these tunnels now working as a charm again.



  • 2.2-RC (i386)
    built on Sun Dec 28 04:40:24 CST 2014

    In my case, the widget -> "Active tunnels" is always 0, even if all ph1(ike) and ph2(ipsec) entries are established.



  • As far as I've been able to determine, all the IPsec widget issues should be fine now. If you can still replicate anything there on the newest available snapshot, please provide details in a new thread on this board rather than continuing to hijack this one so we can follow up with everyone.


Log in to reply