IPSec tunnel problems after pfSense 2.2.3 upgrade
-
@stephenw10 - Here is an IKE debug from Shrewsoft VPN client
(IP's removed for security)
I upgraded from 2.2.2 to 2.2.3 on an ALIX 2C2.
15/06/26 16:20:45 ## : IKE Daemon, ver 2.2.2
15/06/26 16:20:45 ## : Copyright 2013 Shrew Soft Inc.
15/06/26 16:20:45 ## : This product linked OpenSSL 1.0.1c 10 May 2012
15/06/26 16:20:45 ii : opened 'C:\Program Files\ShrewSoft\VPN Client\debug\iked.log'
15/06/26 16:20:45 ii : opened 'C:\Program Files\ShrewSoft\VPN Client/debug/dump-ike-decrypt.cap'
15/06/26 16:20:45 ii : opened 'C:\Program Files\ShrewSoft\VPN Client/debug/dump-ike-encrypt.cap'
15/06/26 16:20:45 ii : rebuilding vnet device list …
15/06/26 16:20:45 ii : device ROOT\VNET\0000 disabled
15/06/26 16:20:45 ii : network process thread begin ...
15/06/26 16:20:45 ii : pfkey process thread begin ...
15/06/26 16:20:45 ii : ipc server process thread begin ...
15/06/26 16:22:22 ii : ipc client process thread begin ...
15/06/26 16:22:22 <a :="" peer="" config="" add="" message<br="">15/06/26 16:22:22</a> <a :="" proposal="" config="" message<br="">15/06/26 16:22:22</a> <a :="" proposal="" config="" message<br="">15/06/26 16:22:22</a> <a :="" client="" config="" message<br="">15/06/26 16:22:22</a> <a :="" xauth="" username="" message<br="">15/06/26 16:22:22</a> <a :="" xauth="" password="" message<br="">15/06/26 16:22:22</a> <a :="" local="" id="" 'blah@blah.com'="" message<br="">15/06/26 16:22:22</a> <a :="" preshared="" key="" message<br="">15/06/26 16:22:22</a> <a :="" peer="" tunnel="" enable="" message<br="">15/06/26 16:22:22 DB : peer ref increment ( ref count = 1, obj count = 0 )
15/06/26 16:22:22 DB : peer added ( obj count = 1 )
15/06/26 16:22:22 ii : local address blah blah selected for peer
15/06/26 16:22:22 DB : peer ref increment ( ref count = 2, obj count = 1 )
15/06/26 16:22:22 DB : tunnel ref increment ( ref count = 1, obj count = 0 )
15/06/26 16:22:22 DB : tunnel added ( obj count = 1 )
15/06/26 16:22:22 DB : tunnel ref increment ( ref count = 2, obj count = 1 )
15/06/26 16:22:22 DB : new phase1 ( ISAKMP initiator )
15/06/26 16:22:22 DB : exchange type is aggressive
15/06/26 16:22:22 DB : blah blah:500 <-> blah blah:500
15/06/26 16:22:22 DB : 36e8a65f4ceb8136:0000000000000000
15/06/26 16:22:22 DB : phase1 ref increment ( ref count = 1, obj count = 0 )
15/06/26 16:22:22 DB : phase1 added ( obj count = 1 )
15/06/26 16:22:22 >> : security association payload
15/06/26 16:22:22 >> : - proposal #1 payload
15/06/26 16:22:22 >> : -- transform #1 payload
15/06/26 16:22:22 >> : -- transform #2 payload
15/06/26 16:22:22 >> : -- transform #3 payload
15/06/26 16:22:22 >> : -- transform #4 payload
15/06/26 16:22:22 >> : -- transform #5 payload
15/06/26 16:22:22 >> : -- transform #6 payload
15/06/26 16:22:22 >> : key exchange payload
15/06/26 16:22:22 >> : nonce payload
15/06/26 16:22:22 >> : identification payload
15/06/26 16:22:22 >> : vendor id payload
15/06/26 16:22:22 ii : local supports XAUTH
15/06/26 16:22:22 >> : vendor id payload
15/06/26 16:22:22 ii : local supports nat-t ( draft v00 )
15/06/26 16:22:22 >> : vendor id payload
15/06/26 16:22:22 ii : local supports nat-t ( draft v01 )
15/06/26 16:22:22 >> : vendor id payload
15/06/26 16:22:22 ii : local supports nat-t ( draft v02 )
15/06/26 16:22:22 >> : vendor id payload
15/06/26 16:22:22 ii : local supports nat-t ( draft v03 )
15/06/26 16:22:22 >> : vendor id payload
15/06/26 16:22:22 ii : local supports nat-t ( rfc )
15/06/26 16:22:22 >> : vendor id payload
15/06/26 16:22:22 ii : local supports FRAGMENTATION
15/06/26 16:22:22 >> : vendor id payload
15/06/26 16:22:22 >> : vendor id payload
15/06/26 16:22:22 ii : local supports DPDv1
15/06/26 16:22:22 >> : vendor id payload
15/06/26 16:22:22 ii : local is SHREW SOFT compatible
15/06/26 16:22:22 >> : vendor id payload
15/06/26 16:22:22 ii : local is NETSCREEN compatible
15/06/26 16:22:22 >> : vendor id payload
15/06/26 16:22:22 ii : local is SIDEWINDER compatible
15/06/26 16:22:22 >> : vendor id payload
15/06/26 16:22:22 ii : local is CISCO UNITY compatible
15/06/26 16:22:22 >= : cookies 36e8a65f4ceb8136:0000000000000000
15/06/26 16:22:22 >= : message 00000000
15/06/26 16:22:22 -> : send IKE packet blah blah:500 -> blah blah:500 ( 774 bytes )
15/06/26 16:22:22 DB : phase1 resend event scheduled ( ref count = 2 )
15/06/26 16:22:22 DB : phase1 ref decrement ( ref count = 1, obj count = 1 )
15/06/26 16:22:22 <- : recv IKE packet blah blah:500 -> blah blah:500 ( 436 bytes )
15/06/26 16:22:22 DB : phase1 found
15/06/26 16:22:22 DB : phase1 ref increment ( ref count = 2, obj count = 1 )
15/06/26 16:22:22 ii : processing phase1 packet ( 436 bytes )
15/06/26 16:22:22 =< : cookies 36e8a65f4ceb8136:76baa49b68ee1f4d
15/06/26 16:22:22 =< : message 00000000
15/06/26 16:22:22 << : security association payload
15/06/26 16:22:22 << : - propsal #1 payload
15/06/26 16:22:22 << : -- transform #1 payload
15/06/26 16:22:22 ii : unmatched isakmp proposal/transform
15/06/26 16:22:22 ii : hash type ( hmac-sha1 != hmac-md5 )
15/06/26 16:22:22 !! : peer violates RFC, transform number mismatch ( 1 != 2 )
15/06/26 16:22:22 ii : matched isakmp proposal #1 transform #1
15/06/26 16:22:22 ii : - transform = ike
15/06/26 16:22:22 ii : - cipher type = aes
15/06/26 16:22:22 ii : - key length = 256 bits
15/06/26 16:22:22 ii : - hash type = sha1
15/06/26 16:22:22 ii : - dh group = group2 ( modp-1024 )
15/06/26 16:22:22 ii : - auth type = xauth-initiator-psk
15/06/26 16:22:22 ii : - life seconds = 86400
15/06/26 16:22:22 ii : - life kbytes = 0
15/06/26 16:22:22 << : key exchange payload
15/06/26 16:22:22 << : nonce payload
15/06/26 16:22:22 << : identification payload
15/06/26 16:22:22 ii : phase1 id match ( natt prevents ip match )
15/06/26 16:22:22 ii : received = ipv4-host blah blah
15/06/26 16:22:22 << : nat discovery payload
15/06/26 16:22:22 << : nat discovery payload
15/06/26 16:22:22 << : hash payload
15/06/26 16:22:22 << : vendor id payload
15/06/26 16:22:22 ii : peer supports XAUTH
15/06/26 16:22:22 << : vendor id payload
15/06/26 16:22:22 ii : peer supports DPDv1
15/06/26 16:22:22 << : vendor id payload
15/06/26 16:22:22 ii : peer is CISCO UNITY compatible
15/06/26 16:22:22 << : vendor id payload
15/06/26 16:22:22 ii : peer supports FRAGMENTATION
15/06/26 16:22:22 << : vendor id payload
15/06/26 16:22:22 ii : peer supports nat-t ( rfc )
15/06/26 16:22:22 ii : nat discovery - remote address is translated
15/06/26 16:22:22 ii : switching to src nat-t udp port 4500
15/06/26 16:22:22 ii : switching to dst nat-t udp port 4500
15/06/26 16:22:22 == : DH shared secret ( 128 bytes )
15/06/26 16:22:22 == : SETKEYID ( 20 bytes )
15/06/26 16:22:22 == : SETKEYID_d ( 20 bytes )
15/06/26 16:22:22 == : SETKEYID_a ( 20 bytes )
15/06/26 16:22:22 == : SETKEYID_e ( 20 bytes )
15/06/26 16:22:22 == : cipher key ( 32 bytes )
15/06/26 16:22:22 == : cipher iv ( 16 bytes )
15/06/26 16:22:22 == : phase1 hash_i ( computed ) ( 20 bytes )
15/06/26 16:22:22 >> : hash payload
15/06/26 16:22:22 >> : nat discovery payload
15/06/26 16:22:22 >> : nat discovery payload
15/06/26 16:22:22 >= : cookies 36e8a65f4ceb8136:76baa49b68ee1f4d
15/06/26 16:22:22 >= : message 00000000
15/06/26 16:22:22 >= : encrypt iv ( 16 bytes )
15/06/26 16:22:22 == : encrypt packet ( 100 bytes )
15/06/26 16:22:22 == : stored iv ( 16 bytes )
15/06/26 16:22:22 DB : phase1 resend event canceled ( ref count = 1 )
15/06/26 16:22:22 -> : send NAT-T:IKE packet blah blah:4500 -> blah blah:4500 ( 140 bytes )
15/06/26 16:22:22 == : phase1 hash_r ( computed ) ( 20 bytes )
15/06/26 16:22:22 == : phase1 hash_r ( received ) ( 20 bytes )
15/06/26 16:22:22 !! : phase1 sa rejected, invalid auth data
15/06/26 16:22:22 !! : blah blah:4500 <-> blah blah:4500
15/06/26 16:22:22 !! : 36e8a65f4ceb8136:76baa49b68ee1f4d
15/06/26 16:22:22 ii : sending peer DELETE message
15/06/26 16:22:22 ii : - blah blah:4500 -> blah blah:4500
15/06/26 16:22:22 ii : - isakmp spi = 36e8a65f4ceb8136:76baa49b68ee1f4d
15/06/26 16:22:22 ii : - data size 0
15/06/26 16:22:22 >> : hash payload
15/06/26 16:22:22 >> : delete payload
15/06/26 16:22:22 == : new informational hash ( 20 bytes )
15/06/26 16:22:22 == : new informational iv ( 16 bytes )
15/06/26 16:22:22 >= : cookies 36e8a65f4ceb8136:76baa49b68ee1f4d
15/06/26 16:22:22 >= : message adcf7119
15/06/26 16:22:22 >= : encrypt iv ( 16 bytes )
15/06/26 16:22:22 == : encrypt packet ( 80 bytes )
15/06/26 16:22:22 == : stored iv ( 16 bytes )
15/06/26 16:22:22 -> : send NAT-T:IKE packet blah blah:4500 -> blah blah:4500 ( 124 bytes )
15/06/26 16:22:22 ii : phase1 removal before expire time
15/06/26 16:22:22 DB : phase1 deleted ( obj count = 0 )
15/06/26 16:22:22 DB : tunnel ref decrement ( ref count = 1, obj count = 1 )
15/06/26 16:22:22 DB : policy not found
15/06/26 16:22:22 DB : policy not found
15/06/26 16:22:22 DB : policy not found
15/06/26 16:22:22 DB : policy not found
15/06/26 16:22:22 <- : recv IKE packet blah blah:500 -> blah blah:500 ( 76 bytes )
15/06/26 16:22:22 DB : phase1 not found
15/06/26 16:22:22 ww : ike packet from blah blah ignored, unknown phase1 sa for peer
15/06/26 16:22:22 ww : 36e8a65f4ceb8136:76baa49b68ee1f4d
15/06/26 16:22:22 DB : removing tunnel config references
15/06/26 16:22:22 DB : removing tunnel phase2 references
15/06/26 16:22:22 DB : removing tunnel phase1 references
15/06/26 16:22:22 DB : tunnel deleted ( obj count = 0 )
15/06/26 16:22:22 DB : peer ref decrement ( ref count = 1, obj count = 1 )
15/06/26 16:22:22 DB : removing all peer tunnel references
15/06/26 16:22:22 DB : peer deleted ( obj count = 0 )
15/06/26 16:22:22 ii : ipc client process thread exit ...Cheers</a>
-
We had same issue, and had to revert to 2.2.2. All IPSEC tunnels not routed. On boot we saw that it was REALLY slow reinstalling all packages, and it also displayed in the log, IPSEC con2000 unrouted . or something to that effect. Seems like all connections P1 and p2 go through, but nothing is routed….
-
Ok, this looks like a problem with AES-CBC crypto at Phase2.
Try changing your Phase2 to anything other than AES-CBC (the default value). We are using AES-GCM which is working fine but anything Blowfish also works.
Steve
-
I reverted one of my 2.2.3 NanoBSD firewalls back to 2.2.2. This gives me a setup similar to what some have described here… having one firewall on 2.2.3 and one on 2.2.2. And my IPSEC... still works. :-\
I've hit the weird issues before so I can appreciate what you guys are dealing with... but I can't seem to replicate the issue. If I have time today, I might try to fire up a tunnel on an ASA to a PFS 2.2.2 and 2.2.3 and see what results I get.
I've reinstalled 2.2.2 to get things working again but I'm wondering if the problem is an upgrade issue on a 2.2.2 installation and not a fresh new install of 2.2.3 . Installing 2.2.2 or 2.2.3 on NanoBSD isn't that really a fresh install.
I have just downloaded the 2.2.3 64-bit CD Installer and will do the following:-
On working 2.2.2 remote host…
1. Disable pfBlockerNG.
2. Backup config and save on laptop.
3. Re-enable pfBlockerNG.
4. Shutdown, disconnect and keep ready for reinstatement.On identical hardware test box...
5. Install pfSense 2.2.3 from CD
6. Login from laptop and restore backup config from working 2.2.2 host
7. When restore is complete, reboot.
8. Enable pfBlocker.
9. Check IPsec 3DES tunnels from 2.2.3 remote host to 2.2.2 central host are up and passing packets. -
Hi,
Bug created for further investigation.
https://redmine.pfsense.org/issues/4791
-=david=-
-
Any of you confirm that an alternative Phase2 encryption type fixes this?
Steve
-
Ok, this looks like a problem with AES-CBC crypto at Phase2.
Try changing your Phase2 to anything other than AES-CBC (the default value). We are using AES-GCM which is working fine but anything Blowfish also works.
I will try this shortly and report back (these units aren't production yet so I can test at will)
-
Ok, I setup my phase 2 as AES-128 - AES-XCBC (only; no other options selected). It now appears I have a phase 1 tunnel up, but no phase 2 connection exists between the sites. If I set it as one of several options under hash, phase 2 comes up. I noticed that several of the configs posted here appear to have SHA1 selected as the hash algorithm though.
@vbentley
I am not 100% clear on how nanoBSD updates, but I am pretty sure its just writes a new image on one of the boot slices of the flash drive. So yes, that is probably more akin to a fresh install than an upgrade. That definitely is a big difference! -
Specifying AES-256-GCM only for phase2 results in the same error for me in the Shrewsoft client.
-
Changed to 3DES and the tunnel works fine, I'll try the other AES modes shortly but tight on time right now… on the OpenBSD side it didn't like me simply changing "aes" to "aes-128-gcm", so I'll have to dig a bit more.
-
frmpf - Which hash algorithm are you using with 3DES?
Cheers
-
The Shrewsoft client is extremely picky.
Just to sure you use 3DES in the Phase2 config frmpf?
Steve
-
I've left the hash as SHA1 in all trials… I had success with 3DES for quick mode, left main mode as AES:
On the pfSense side, I only changed the enc for phase 2 from aes to 3des, everything else the same.
Similarly on OpenBSD, just a single quick mode change from aes to 3des
Doesn't work with 2.2.3
ike dynamic esp from 192.168.87.0/24 to { 172.29.200.0/24, 192.168.77.0/24 } peer 2.2.2.80
main auth hmac-sha1 enc aes group modp1024 lifetime 28800
quick auth hmac-sha1 enc aes group modp1024 lifetime 3600
srcid 1.1.1.251 dstid 2.2.2.80 psk xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxWorks with 2.2.3
ike dynamic esp from 192.168.87.0/24 to { 172.29.200.0/24, 192.168.77.0/24 } peer 2.2.2.80
main auth hmac-sha1 enc aes group modp1024 lifetime 28800
quick auth hmac-sha1 enc 3des group modp1024 lifetime 3600
srcid 1.1.1.251 dstid 2.2.2.80 psk xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx -
The issue here is the encryption type set on the Phase2 only. If anyone is seeing something different please say so.
The cause seems to be the AES-NI module that is trying to decrypt traffic that it can't so an alternative solution is to disable the AES-NI module if you must use AES-CBC for example.Is anybody here NOT using the AES-NI module/AES-NI capable hardware?
Steve
-
I tried a fresh CD install of 2.2.3 on the remote host but still no luck. My phase 1 fails using RSA certs. So my problem may be useful aid to diagnosis as it shows:-
1. I cannot establish Phase 1
2. I am using 3DES SHA1 for P1 and P2
3. My logs for 2.2.3 show the key exchange AUTHENTICATION_FAILEDWhat makes my case different? I am using hardware crypto at each end.
Jun 26 18:47:53 charon: 06[IKE] <con1|2> received AUTHENTICATION_FAILED notify error Jun 26 18:47:53 charon: 06[IKE] <con1|2> received AUTHENTICATION_FAILED notify error Jun 26 18:47:53 charon: 06[ENC] <con1|2> parsed IKE_AUTH response 1 [ N(AUTH_FAILED) ] Jun 26 18:47:53 charon: 06[NET] <con1|2> received packet: from xxx.xxx.xxx.xxx[500] to yyy.yyy.yyy.yyy[500] (68 bytes) Jun 26 18:47:52 charon: 06[NET] <con1|2> sending packet: from yyy.yyy.yyy.yyy[500] to xxx.xxx.xxx.xxx[500] (512 bytes) Jun 26 18:47:52 charon: 06[NET] <con1|2> sending packet: from yyy.yyy.yyy.yyy[500] to xxx.xxx.xxx.xxx[500] (544 bytes) Jun 26 18:47:52 charon: 06[NET] <con1|2> sending packet: from yyy.yyy.yyy.yyy[500] to xxx.xxx.xxx.xxx[500] (544 bytes) Jun 26 18:47:52 charon: 06[NET] <con1|2> sending packet: from yyy.yyy.yyy.yyy[500] to xxx.xxx.xxx.xxx[500] (544 bytes) Jun 26 18:47:52 charon: 06[ENC] <con1|2> generating IKE_AUTH request 1 [ EF(4/4) ] Jun 26 18:47:52 charon: 06[ENC] <con1|2> generating IKE_AUTH request 1 [ EF(3/4) ] Jun 26 18:47:52 charon: 06[ENC] <con1|2> generating IKE_AUTH request 1 [ EF(2/4) ] Jun 26 18:47:52 charon: 06[ENC] <con1|2> generating IKE_AUTH request 1 [ EF(1/4) ] Jun 26 18:47:52 charon: 06[ENC] <con1|2> splitting IKE message with length of 1972 bytes into 4 fragments Jun 26 18:47:52 charon: 06[ENC] <con1|2> generating IKE_AUTH request 1 [ IDi CERT N(INIT_CONTACT) CERTREQ IDr AUTH N(IPCOMP_SUP) N(ESP_TFC_PAD_N) SA TSi TSr N(MULT_AUTH) N(EAP_ONLY) ] Jun 26 18:47:52 charon: 06[IKE] <con1|2> establishing CHILD_SA con1 Jun 26 18:47:52 charon: 06[IKE] <con1|2> establishing CHILD_SA con1 Jun 26 18:47:52 charon: 06[IKE] <con1|2> sending end entity cert "C=GB, ...</con1|2></con1|2></con1|2></con1|2></con1|2></con1|2></con1|2></con1|2></con1|2></con1|2></con1|2></con1|2></con1|2></con1|2></con1|2></con1|2></con1|2> -
The issue here is the encryption type set on the Phase2 only. If anyone is seeing something different please say so.
The cause seems to be the AES-NI module that is trying to decrypt traffic that it can't so an alternative solution is to disable the AES-NI module if you must use AES-CBC for example.Is anybody here NOT using the AES-NI module/AES-NI capable hardware?
Steve
Can confirm, disabled AES-NI on the 2.2.3 device and now the tunnels work in the original configuration. Does that leave room for hope that a fix won't be too tough, since 2.2.2 still works fine with the AES-NI component enabled? It's just the kernel module loaded for the hardware aes?
-
I can confirm that everything is working after switching across to 3DES for phase 2 (algorithm SHA1)
I did not have the AES-NI module enabled on my box at any point.
Thanks guys - Hopefully we'll see a fix for AES fairly soon :)
Chris
-
https://redmine.pfsense.org/issues/4791
might be "fixed"in the snapshots dating after renato's comments
-
Still does not work for me, even if not using AES encryption
Here is my setup:
- On PFSense 2.2.3:
- On cisco RV042:
And the results are
on PFSense:
on RV042:
Now the logs show incomplete ISAKMP SA on the RV042
and conn unrouted on PFSense
Of course, no machine on the remote VPN side can be reached.
I don't really think it's a AES issue here, since I'm not using it…. or am I doing something wrong ???
Everything was fine on PFSense 2.2.2Thanks for any suggestion
-
That looks like an identifier mismatch, nothing to do with this bug.
The Linksys is complainiung about the identifier sent by pfSense being an FQDN not an IP.Steve
