PfSense/strongSwan “deleting half open IKE_SA after timeout” – IPSec connection Android 4.4 to pfSense 2.2.1 fails

androidipsecpfsensevpn

pfSense in version 2.2 switched from Racoon to strongSwan.

Since that change, users can no longer connect to the VPN from Android clients (Type IPSec Xauth PSK).


The current configuration on Android is as follows:

|_. Name                       | _[irrelevant]_  |
|_. Type                       | IPSec Auth PSK  |
|_. Server address             | $THE_PFSENSE_IP |
|_. IPSec identifier           | the.identifier  |
|_. IPSec pre-shared key       | 3yZuE7kLFGqOj79hRAqM3vQpPWC7DRlY6ep8hfoVtkZWVqNd8C3W |
|_. DNS search domains         | _[(not used}]_  |
|_. DNS servers                | _[(not used}]_  |
|_. Forwarding routes          | _$LOCAL_IP/32_  |

The current configuration on pfSense is as follows:

  • IPSec > Tunnels = Enable IPSec

Phase 1: Mobile Client

General information

|_. Disabled              | _[unset]_        |
|_. Key Exchange version  | _V1_             |
|_. Internet Protocol     | _IPv4_           |
|_. Interface             | WAN              |
|_. Description           | _[irrelevant]_   |

Phase 1 proposal (Authentication)

|_. Authentication method | _Mutual PSK + Xauth_ |
|_. Negotiation mode      | _Aggressive_         |
|_. My identifier         | _My IP address       |
|_. Peer identifier       | _Distinguished name_ _the.identifier_ |
|_. Pre-Shared Key        | 3yZuE7kLFGqOj79hRAqM3vQpPWC7DRlY6ep8hfoVtkZWVqNd8C3W |

Phase 1 proposal (Algorithms)

|_. Encryption algorithm  | _AES_ _256 bits_ |
|_. Hash algorithm        | _SHA1_           |
|_. DH key group          | _2 (1024 bit)_   |
|_. Lifetime              | _28800_ seconds  |

Advanced Options

|_. Disable Rekey         | _[unset]_        |
|_. Responder Only        | _[unset]_        |
|_. NAT Traversal         | _Auto_           |
|_. Dead Peer Detection   | _[enabled]_ _10_ seconds, _5_ retries |

Phase 2: Mobile Client

|_. Disabled              | _[unset]_        |
|_. Mode                  | _Tunnel IPv4_    |
|_. Local Network         | *Type:* _Address_ *Address:* _$LOCAL_IP_ *NAT:* _[none/empty]_ |
|_. Description           | _[irrelevant]_   |

Phase 2 proposal (SA/Key Exchange)

|_. Protocol              | _ESP_               |
|_. Encryption algorithms | _AES_ _auto_ *only* |
|_. Hash algorithms       | _SHA1_ *only*       |
|_. PFS key group         | _off_               |
|_. Lifetime              | _3600_ _seconds_    |

Advanced Options

|_. Automatically ping host | _[empty]_         |

Log Output on pfSense

IPSec Log (startup)

 
Mar 23 02:10:43  ipsec_starter[88815]: Starting weakSwan 5.2.1 IPsec [starter]...
Mar 23 02:10:43  ipsec_starter[88815]: no netkey IPsec stack detected
Mar 23 02:10:43  ipsec_starter[88815]: no KLIPS IPsec stack detected
Mar 23 02:10:43  ipsec_starter[88815]: no known IPsec stack detected, ignoring!
Mar 23 02:10:43  charon: 00[DMN] Starting IKE charon daemon (strongSwan 5.2.1, FreeBSD 10.1-RELEASE-p6, i386)
Mar 23 02:10:44  charon: 00[KNL] unable to set UDP_ENCAP: Invalid argument
Mar 23 02:10:44  charon: 00[NET] enabling UDP decapsulation for IPv6 on port 4500 failed
Mar 23 02:10:44  charon: 00[CFG] ipseckey plugin is disabled
Mar 23 02:10:44  charon: 00[CFG] loading ca certificates from '/var/etc/ipsec/ipsec.d/cacerts'
Mar 23 02:10:44  charon: 00[CFG] loaded ca certificate "$CERT1_INFO" from '/var/etc/ipsec/ipsec.d/cacerts/a85fc367.0.crt'
Mar 23 02:10:44  charon: 00[CFG] loaded ca certificate "$CERT2_INFO" from '/var/etc/ipsec/ipsec.d/cacerts/5eb84096.0.crt'
Mar 23 02:10:44  charon: 00[CFG] loaded ca certificate "$CERT3_INFO" from '/var/etc/ipsec/ipsec.d/cacerts/16eb0859.0.crt'
Mar 23 02:10:44  charon: 00[CFG] loaded ca certificate "$CERT4_INFO" from '/var/etc/ipsec/ipsec.d/cacerts/e06d03ef.0.crt'
Mar 23 02:10:44  charon: 00[CFG] loaded ca certificate "$CERT5_INFO" from '/var/etc/ipsec/ipsec.d/cacerts/01c1b386.0.crt'
Mar 23 02:10:44  charon: 00[CFG] loading aa certificates from '/var/etc/ipsec/ipsec.d/aacerts'
Mar 23 02:10:44  charon: 00[CFG] loading ocsp signer certificates from '/var/etc/ipsec/ipsec.d/ocspcerts'
Mar 23 02:10:44  charon: 00[CFG] loading attribute certificates from '/var/etc/ipsec/ipsec.d/acerts'
Mar 23 02:10:44  charon: 00[CFG] loading crls from '/var/etc/ipsec/ipsec.d/crls'
Mar 23 02:10:44  charon: 00[CFG] loading secrets from '/var/etc/ipsec/ipsec.secrets'
Mar 23 02:10:44  charon: 00[CFG] loaded IKE secret for $PFSENSE_IP the.identifier
Mar 23 02:10:44  charon: 00[CFG] loaded IKE secret for %any the.identifier
Mar 23 02:10:44  charon: 00[CFG] opening triplet file /var/etc/ipsec/ipsec.d/triplets.dat failed: No such file or directory
Mar 23 02:10:44  charon: 00[CFG] loaded 0 RADIUS server configurations
Mar 23 02:10:44  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
Mar 23 02:10:44  charon: 00[LIB] unable to load 6 plugin features (5 due to unmet dependencies)
Mar 23 02:10:44  charon: 00[JOB] spawning 16 worker threads
Mar 23 02:10:44  ipsec_starter[89411]: charon (89559) started after 600 ms
Mar 23 02:10:44  charon: 06[CFG] received stroke: add connection 'con1'
Mar 23 02:10:44  charon: 06[CFG] adding virtual IP address pool 192.168.97.0/24
Mar 23 02:10:44  charon: 06[CFG] added configuration 'con1'
Mar 23 02:11:02  charon: 06[CFG] rereading secrets
Mar 23 02:11:02  charon: 06[CFG] loading secrets from '/var/etc/ipsec/ipsec.secrets'
Mar 23 02:11:02  charon: 06[CFG] loaded IKE secret for $PFSENSE_IP the.identifier
Mar 23 02:11:02  charon: 06[CFG] loaded IKE secret for %any the.identifier
Mar 23 02:11:02  charon: 06[CFG] rereading ca certificates from '/var/etc/ipsec/ipsec.d/cacerts'
Mar 23 02:11:02  charon: 06[CFG] loaded ca certificate "$CERT1_INFO" from '/var/etc/ipsec/ipsec.d/cacerts/a85fc367.0.crt'
Mar 23 02:11:02  charon: 06[CFG] loaded ca certificate "$CERT2_INFO" from '/var/etc/ipsec/ipsec.d/cacerts/5eb84096.0.crt'
Mar 23 02:11:02  charon: 06[CFG] loaded ca certificate "$CERT3_INFO" from '/var/etc/ipsec/ipsec.d/cacerts/16eb0859.0.crt'
Mar 23 02:11:02  charon: 06[CFG] loaded ca certificate "$CERT4_INFO" from '/var/etc/ipsec/ipsec.d/cacerts/e06d03ef.0.crt'
Mar 23 02:11:02  charon: 06[CFG] loaded ca certificate "$CERT5_INFO" from '/var/etc/ipsec/ipsec.d/cacerts/01c1b386.0.crt'
Mar 23 02:11:02  charon: 06[CFG] rereading ocsp signer certificates from '/var/etc/ipsec/ipsec.d/ocspcerts'
Mar 23 02:11:02  charon: 06[CFG] rereading aa certificates from '/var/etc/ipsec/ipsec.d/aacerts'
Mar 23 02:11:02  charon: 06[CFG] rereading attribute certificates from '/var/etc/ipsec/ipsec.d/acerts'
Mar 23 02:11:02  charon: 06[CFG] rereading crls from '/var/etc/ipsec/ipsec.d/crls'

IPSec Log (connection)

Mar 23 02:13:50  charon: 14[ENC] parsed AGGRESSIVE request 0 [ SA KE No ID V V V V V V V V ]
Mar 23 02:13:50  charon: 14[IKE]  received FRAGMENTATION vendor ID
Mar 23 02:13:50  charon: 14[IKE] received FRAGMENTATION vendor ID
Mar 23 02:13:50  charon: 14[IKE]  received NAT-T (RFC 3947) vendor ID
Mar 23 02:13:50  charon: 14[IKE] received NAT-T (RFC 3947) vendor ID
Mar 23 02:13:50  charon: 14[IKE]  received draft-ietf-ipsec-nat-t-ike-02 vendor ID
Mar 23 02:13:50  charon: 14[IKE] received draft-ietf-ipsec-nat-t-ike-02 vendor ID
Mar 23 02:13:50  charon: 14[IKE]  received draft-ietf-ipsec-nat-t-ike-02\n vendor ID
Mar 23 02:13:50  charon: 14[IKE] received draft-ietf-ipsec-nat-t-ike-02\n vendor ID
Mar 23 02:13:50  charon: 14[IKE]  received draft-ietf-ipsec-nat-t-ike-00 vendor ID
Mar 23 02:13:50  charon: 14[IKE] received draft-ietf-ipsec-nat-t-ike-00 vendor ID
Mar 23 02:13:50  charon: 14[IKE]  received XAuth vendor ID
Mar 23 02:13:50  charon: 14[IKE] received XAuth vendor ID
Mar 23 02:13:50  charon: 14[IKE]  received Cisco Unity vendor ID
Mar 23 02:13:50  charon: 14[IKE] received Cisco Unity vendor ID
Mar 23 02:13:50  charon: 14[IKE]  received DPD vendor ID
Mar 23 02:13:50  charon: 14[IKE] received DPD vendor ID
Mar 23 02:13:50  charon: 14[IKE]  $REMOTE_IP is initiating a Aggressive Mode IKE_SA
Mar 23 02:13:50  charon: 14[IKE] $REMOTE_IP is initiating a Aggressive Mode IKE_SA
Mar 23 02:13:50  charon: 14[CFG] looking for XAuthInitPSK peer configs matching $PFSENSE_IP...$REMOTE_IP[the.identifier]
Mar 23 02:13:50  charon: 14[CFG] selected peer config "con1"
Mar 23 02:13:50  charon: 14[ENC] generating AGGRESSIVE response 0 [ SA KE No ID NAT-D NAT-D HASH V V V V V ]
Mar 23 02:13:50  charon: 14[NET] sending packet: from $PFSENSE_IP[500] to $REMOTE_IP[500] (432 bytes)
Mar 23 02:13:52  charon: 14[NET] received packet: from $REMOTE_IP[500] to $PFSENSE_IP[500] (646 bytes)
Mar 23 02:13:52  charon: 14[IKE]  received retransmit of request with ID 0, retransmitting response
Mar 23 02:13:52  charon: 14[IKE] received retransmit of request with ID 0, retransmitting response
Mar 23 02:13:52  charon: 14[NET] sending packet: from $PFSENSE_IP[500] to $REMOTE_IP[500] (432 bytes)
Mar 23 02:13:54  charon: 14[IKE]  sending retransmit 1 of response message ID 0, seq 1
Mar 23 02:13:54  charon: 14[IKE] sending retransmit 1 of response message ID 0, seq 1
Mar 23 02:13:54  charon: 14[NET] sending packet: from $PFSENSE_IP[500] to $REMOTE_IP[500] (432 bytes)
Mar 23 02:13:55  charon: 14[NET] received packet: from $REMOTE_IP[500] to $PFSENSE_IP[500] (646 bytes)
Mar 23 02:13:55  charon: 14[IKE]  received retransmit of request with ID 0, retransmitting response
Mar 23 02:13:55  charon: 14[IKE] received retransmit of request with ID 0, retransmitting response
Mar 23 02:13:55  charon: 14[NET] sending packet: from $PFSENSE_IP[500] to $REMOTE_IP[500] (432 bytes)
Mar 23 02:13:59  charon: 14[NET] received packet: from $REMOTE_IP[500] to $PFSENSE_IP[500] (646 bytes)
Mar 23 02:13:59  charon: 14[IKE]  received retransmit of request with ID 0, retransmitting response
Mar 23 02:13:59  charon: 14[IKE] received retransmit of request with ID 0, retransmitting response
Mar 23 02:13:59  charon: 14[NET] sending packet: from $PFSENSE_IP[500] to $REMOTE_IP[500] (432 bytes)
Mar 23 02:14:01  charon: 14[IKE]  sending retransmit 2 of response message ID 0, seq 1
Mar 23 02:14:01  charon: 14[IKE] sending retransmit 2 of response message ID 0, seq 1
Mar 23 02:14:01  charon: 14[NET] sending packet: from $PFSENSE_IP[500] to $REMOTE_IP[500] (432 bytes)
Mar 23 02:14:01  charon: 14[NET] received packet: from $REMOTE_IP[500] to $PFSENSE_IP[500] (646 bytes)
Mar 23 02:14:01  charon: 14[IKE]  received retransmit of request with ID 0, retransmitting response
Mar 23 02:14:01  charon: 14[IKE] received retransmit of request with ID 0, retransmitting response
Mar 23 02:14:01  charon: 14[NET] sending packet: from $PFSENSE_IP[500] to $REMOTE_IP[500] (432 bytes)
Mar 23 02:14:05  charon: 16[NET] received packet: from $REMOTE_IP[500] to $PFSENSE_IP[500] (646 bytes)
Mar 23 02:14:05  charon: 16[IKE]  received retransmit of request with ID 0, retransmitting response
Mar 23 02:14:05  charon: 16[IKE] received retransmit of request with ID 0, retransmitting response
Mar 23 02:14:05  charon: 16[NET] sending packet: from $PFSENSE_IP[500] to $REMOTE_IP[500] (432 bytes)
Mar 23 02:14:07  charon: 16[NET] received packet: from $REMOTE_IP[500] to $PFSENSE_IP[500] (646 bytes)
Mar 23 02:14:07  charon: 16[IKE]  received retransmit of request with ID 0, retransmitting response
Mar 23 02:14:07  charon: 16[IKE] received retransmit of request with ID 0, retransmitting response
Mar 23 02:14:07  charon: 16[NET] sending packet: from $PFSENSE_IP[500] to $REMOTE_IP[500] (432 bytes)
Mar 23 02:14:11  charon: 16[NET] received packet: from $REMOTE_IP[500] to $PFSENSE_IP[500] (646 bytes)
Mar 23 02:14:11  charon: 16[IKE]  received retransmit of request with ID 0, retransmitting response
Mar 23 02:14:11  charon: 16[IKE] received retransmit of request with ID 0, retransmitting response
Mar 23 02:14:11  charon: 16[NET] sending packet: from $PFSENSE_IP[500] to $REMOTE_IP[500] (432 bytes)
Mar 23 02:14:13  charon: 16[NET] received packet: from $REMOTE_IP[500] to $PFSENSE_IP[500] (646 bytes)
Mar 23 02:14:13  charon: 16[IKE]  received retransmit of request with ID 0, retransmitting response
Mar 23 02:14:13  charon: 16[IKE] received retransmit of request with ID 0, retransmitting response
Mar 23 02:14:13  charon: 16[NET] sending packet: from $PFSENSE_IP[500] to $REMOTE_IP[500] (432 bytes)
Mar 23 02:14:14  charon: 16[IKE]  sending retransmit 3 of response message ID 0, seq 1
Mar 23 02:14:14  charon: 16[IKE] sending retransmit 3 of response message ID 0, seq 1
Mar 23 02:14:14  charon: 16[NET] sending packet: from $PFSENSE_IP[500] to $REMOTE_IP[500] (432 bytes)
Mar 23 02:14:16  charon: 16[NET] received packet: from $REMOTE_IP[500] to $PFSENSE_IP[500] (646 bytes)
Mar 23 02:14:16  charon: 16[IKE]  received retransmit of request with ID 0, retransmitting response
Mar 23 02:14:16  charon: 16[IKE] received retransmit of request with ID 0, retransmitting response
Mar 23 02:14:16  charon: 16[NET] sending packet: from $PFSENSE_IP[500] to $REMOTE_IP[500] (432 bytes)
Mar 23 02:14:20  charon: 16[JOB] deleting half open IKE_SA after timeout

What could be the reasons for the connection to fail and how may they be resolved?

Best Answer

I've been having this exact same issue.

As per this [IKEv1 can't connect from Android's default vpn client], there is a bug in the current Android VPN IKEv1 client that happens if aggressive mode is selected and a "IPsec identifier" is used to configure the Android client.

The solution is to clear the "IPsec identifier" entry from the android client and in Phase 1 proposal the negotiation mode should be Main.

In my setup the Phase 1 proposal (Authentication) : Authentication method is Mutual PSK + Xauth and not just Mutual PSK.