Issue #570
Android native VPN client to Strongswan problem
Affected version:
5.1.2
Resolution:
No change required
Description
Hi everyone,
i've been banging my heads against this issue for several days and i cannot establish connection with VPN server (Centos/Strongswan v5.1.2) from my Android phone using IPSec Xauth RSA (ikev1) connection type. I tried various tutorials but the problem remains the same. Have no problem connecting from iPhone (ikev1).
I am getting "invalid HASH_V1 payload length, decryption failed?" error
This is the configuration for the strongswan connection
ipsec.conf:
conn %default
ikelifetime=60m
keylife=20m
rekeymargin=3m
keyingtries=1
conn android_IPSec_ikev1
keyexchange=ikev1
left=%defaultroute
leftsubnet=0.0.0.0/0
leftcert=serverCert.pem
leftfirewall=yes
right=%any
rightsourceip=10.255.0.0/24
rightdns=212.59.1.1
rightauth=pubkey
rightauth2=xauth
auto=add
ipsec.secret
: RSA serverKey.pem kemeris : XAUTH "pass1"
error.log
Apr 8 11:31:32 s1 charon: 11[NET] received packet: from 10.0.0.11[500] to 78.60.3.52[500] (476 bytes) Apr 8 11:31:32 s1 charon: 11[ENC] parsed ID_PROT request 0 [ SA V V V V V V V V ] Apr 8 11:31:32 s1 charon: 11[IKE] received NAT-T (RFC 3947) vendor ID Apr 8 11:31:32 s1 charon: 11[IKE] received draft-ietf-ipsec-nat-t-ike-02 vendor ID Apr 8 11:31:32 s1 charon: 11[IKE] received draft-ietf-ipsec-nat-t-ike-02\n vendor ID Apr 8 11:31:32 s1 charon: 11[IKE] received draft-ietf-ipsec-nat-t-ike-00 vendor ID Apr 8 11:31:32 s1 charon: 11[IKE] received XAuth vendor ID Apr 8 11:31:32 s1 charon: 11[IKE] received Cisco Unity vendor ID Apr 8 11:31:32 s1 charon: 11[IKE] received FRAGMENTATION vendor ID Apr 8 11:31:32 s1 charon: 11[IKE] received DPD vendor ID Apr 8 11:31:32 s1 charon: 11[IKE] 10.0.0.11 is initiating a Main Mode IKE_SA Apr 8 11:31:32 s1 charon: 11[ENC] generating ID_PROT response 0 [ SA V V V ] Apr 8 11:31:32 s1 charon: 11[NET] sending packet: from 78.60.3.52[500] to 10.0.0.11[500] (136 bytes) Apr 8 11:31:32 s1 charon: 10[NET] received packet: from 10.0.0.11[500] to 78.60.3.52[500] (228 bytes) Apr 8 11:31:32 s1 charon: 10[ENC] parsed ID_PROT request 0 [ KE No NAT-D NAT-D ] Apr 8 11:31:32 s1 charon: 10[IKE] sending cert request for "C=LT, S=Vilniaus m., L=Vilnius, O=Zeusman MB, CN=vpn.zeusman.lt" Apr 8 11:31:32 s1 charon: 10[ENC] generating ID_PROT response 0 [ KE No CERTREQ NAT-D NAT-D ] Apr 8 11:31:32 s1 charon: 10[NET] sending packet: from 78.60.3.52[500] to 10.0.0.11[500] (350 bytes) Apr 8 11:31:32 s1 charon: 12[NET] received packet: from 10.0.0.11[500] to 78.60.3.52[500] (1228 bytes) Apr 8 11:31:32 s1 charon: 12[ENC] parsed ID_PROT request 0 [ ID CERT SIG ] Apr 8 11:31:32 s1 charon: 12[IKE] received end entity cert "C=GB, O=Zeusman MB, CN=Tadas Blinda" Apr 8 11:31:32 s1 charon: 12[CFG] looking for XAuthInitRSA peer configs matching 78.60.3.52...10.0.0.11[C=GB, O=Zeusman MB, CN=Tadas Blinda] Apr 8 11:31:32 s1 charon: 12[CFG] selected peer config "ios_IPSec_ikev1" Apr 8 11:31:32 s1 charon: 12[CFG] using trusted ca certificate "C=LT, S=Vilniaus m., L=Vilnius, O=Zeusman MB, CN=vpn.zeusman.lt" Apr 8 11:31:32 s1 charon: 12[CFG] checking certificate status of "C=GB, O=Zeusman MB, CN=Tadas Blinda" Apr 8 11:31:32 s1 charon: 12[CFG] certificate status is not available Apr 8 11:31:32 s1 charon: 12[CFG] reached self-signed root ca with a path length of 0 Apr 8 11:31:32 s1 charon: 12[CFG] using trusted certificate "C=GB, O=Zeusman MB, CN=Tadas Blinda" Apr 8 11:31:32 s1 charon: 12[IKE] authentication of 'C=GB, O=Zeusman MB, CN=Tadas Blinda' with RSA successful Apr 8 11:31:32 s1 charon: 12[IKE] authentication of 'C=LT, S=Vilniaus m., L=Vilnius, O=Zeusman MB, CN=vpn.zeusman.lt' (myself) successful Apr 8 11:31:32 s1 charon: 12[ENC] generating ID_PROT response 0 [ ID SIG ] Apr 8 11:31:32 s1 charon: 12[NET] sending packet: from 78.60.3.52[500] to 10.0.0.11[500] (412 bytes) Apr 8 11:31:32 s1 charon: 12[ENC] generating TRANSACTION request 3632658472 [ HASH CPRQ(X_USER X_PWD) ] Apr 8 11:31:32 s1 charon: 12[NET] sending packet: from 78.60.3.52[500] to 10.0.0.11[500] (76 bytes) Apr 8 11:31:32 s1 charon: 13[NET] received packet: from 10.0.0.11[500] to 78.60.3.52[500] (92 bytes) Apr 8 11:31:32 s1 charon: 13[ENC] invalid HASH_V1 payload length, decryption failed? Apr 8 11:31:32 s1 charon: 13[ENC] could not decrypt payloads Apr 8 11:31:32 s1 charon: 13[IKE] message parsing failed Apr 8 11:31:32 s1 charon: 13[IKE] ignore malformed INFORMATIONAL request Apr 8 11:31:32 s1 charon: 13[IKE] INFORMATIONAL_V1 request with message ID 2246676801 processing failed Apr 8 11:31:35 s1 charon: 15[NET] received packet: from 10.0.0.11[500] to 78.60.3.52[500] (1228 bytes) Apr 8 11:31:35 s1 charon: 15[IKE] received retransmit of request with ID 0, retransmitting response Apr 8 11:31:35 s1 charon: 15[NET] sending packet: from 78.60.3.52[500] to 10.0.0.11[500] (412 bytes) Apr 8 11:31:35 s1 charon: 05[NET] received packet: from 10.0.0.11[500] to 78.60.3.52[500] (92 bytes) Apr 8 11:31:35 s1 charon: 05[ENC] invalid HASH_V1 payload length, decryption failed? Apr 8 11:31:35 s1 charon: 05[ENC] could not decrypt payloads Apr 8 11:31:35 s1 charon: 05[IKE] message parsing failed Apr 8 11:31:35 s1 charon: 05[IKE] ignore malformed INFORMATIONAL request
Is there something I did wrong?
Thanks
Related issues
History
#1 Updated by Ashok Thota over 10 years ago
Hi
Can you please the paste the configuration of iOS here, because i am getting this error from so many days and there is no clue how to dig out or you can help me out from this problem.
Thanks in advance
#2 Updated by Tobias Brunner over 10 years ago
- Description updated (diff)
- Status changed from New to Feedback
This may be related to #836. Are you sure the client is configured for XAuth/RSA authentication (and not only RSA authentication)? Do you have any logs from the client? What Android version is running on the client? On what kind of device?
Connecting from Android 4.4.4 (Nexus 5) with XAuth/RSA works fine here.
#3 Updated by Tobias Brunner over 10 years ago
- Related to Issue #836: invalid HASH_V1 payload length, decryption failed?could not decrypt payloads,message parsing failed,ignore malformed INFORMATIONAL request added
#4 Updated by G. G. about 10 years ago
Got the same issue on Android 5.0+.
According to the logs on the phone (adb / logcat), it looks like racoon has some issue with the certificate.
#5 Updated by Tobias Brunner almost 10 years ago
- Category set to configuration
- Status changed from Feedback to Closed
- Assignee set to Tobias Brunner
- Resolution set to No change required
Sounds like a client issue (or a configuration issue if the certificate is unsuitable). Closing this for now.
#6 Updated by Bowen Sun over 9 years ago
I'm having the same issue with strongswan 5.1.2, the same config works on iOS(9.3) but not OS X(10.11.4).
ipsec.conf
conn ipsec-ikev1-rsa keyexchange=ikev1 left=%defaultroute leftcert=vpn.crt leftid=@vpn leftsubnet=0.0.0.0/0 rightauth=pubkey rightauth2=xauth right=%any rightcert=client.crt rightid=client rightsubnet=10.20.0.0/16 rightsourceip=10.20.0.2/16 rightdns=8.8.8.8,8.8.4.4 auto=add
charon.conf
charon {
cisco_unity = yes
}
Logs from iOS connection
charon: 09[NET] received packet: from 2.3.4.5[12836] to 1.2.3.4[500]
charon: 09[NET] waiting for data on sockets
charon: 16[NET] received packet: from 2.3.4.5[12836] to 1.2.3.4[500] (848 bytes)
charon: 16[ENC] parsed ID_PROT request 0 [ SA V V V V V V V V V V V V V V ]
charon: 16[CFG] looking for an ike config for 1.2.3.4...2.3.4.5
charon: 16[CFG] candidate: %any...%any, prio 24
charon: 16[CFG] candidate: %any...%any, prio 24
charon: 16[CFG] candidate: %any...%any, prio 28
charon: 16[CFG] candidate: %any...%any, prio 28
charon: 16[CFG] found matching ike config: %any...%any with prio 28
charon: 16[IKE] received NAT-T (RFC 3947) vendor ID
charon: 16[IKE] received draft-ietf-ipsec-nat-t-ike vendor ID
charon: 16[IKE] received draft-ietf-ipsec-nat-t-ike-08 vendor ID
charon: 16[IKE] received draft-ietf-ipsec-nat-t-ike-07 vendor ID
charon: 16[IKE] received draft-ietf-ipsec-nat-t-ike-06 vendor ID
charon: 16[IKE] received draft-ietf-ipsec-nat-t-ike-05 vendor ID
charon: 16[IKE] received draft-ietf-ipsec-nat-t-ike-04 vendor ID
charon: 16[IKE] received draft-ietf-ipsec-nat-t-ike-03 vendor ID
charon: 16[IKE] received draft-ietf-ipsec-nat-t-ike-02 vendor ID
charon: 16[IKE] received draft-ietf-ipsec-nat-t-ike-02\n vendor ID
charon: 16[IKE] received XAuth vendor ID
charon: 16[IKE] received Cisco Unity vendor ID
charon: 16[IKE] received FRAGMENTATION vendor ID
charon: 16[IKE] received DPD vendor ID
charon: 16[IKE] 2.3.4.5 is initiating a Main Mode IKE_SA
charon: 16[IKE] IKE_SA (unnamed)[6] state change: CREATED => CONNECTING
charon: 16[CFG] selecting proposal:
charon: 16[CFG] no acceptable ENCRYPTION_ALGORITHM found
charon: 16[CFG] selecting proposal:
charon: 16[CFG] no acceptable ENCRYPTION_ALGORITHM found
charon: 16[CFG] selecting proposal:
charon: 16[CFG] no acceptable ENCRYPTION_ALGORITHM found
charon: 16[CFG] selecting proposal:
charon: 16[CFG] no acceptable ENCRYPTION_ALGORITHM found
charon: 16[CFG] selecting proposal:
charon: 16[CFG] no acceptable ENCRYPTION_ALGORITHM found
charon: 16[CFG] selecting proposal:
charon: 16[CFG] no acceptable ENCRYPTION_ALGORITHM found
charon: 16[CFG] selecting proposal:
charon: 16[CFG] no acceptable ENCRYPTION_ALGORITHM found
charon: 16[CFG] selecting proposal:
charon: 16[CFG] no acceptable ENCRYPTION_ALGORITHM found
charon: 16[CFG] selecting proposal:
charon: 16[CFG] no acceptable ENCRYPTION_ALGORITHM found
charon: 16[CFG] selecting proposal:
charon: 16[CFG] no acceptable DIFFIE_HELLMAN_GROUP found
charon: 16[CFG] selecting proposal:
charon: 16[CFG] no acceptable PSEUDO_RANDOM_FUNCTION found
charon: 16[CFG] selecting proposal:
charon: 16[CFG] no acceptable ENCRYPTION_ALGORITHM found
charon: 16[CFG] selecting proposal:
charon: 16[CFG] no acceptable ENCRYPTION_ALGORITHM found
charon: 16[CFG] selecting proposal:
charon: 16[CFG] no acceptable ENCRYPTION_ALGORITHM found
charon: 16[CFG] selecting proposal:
charon: 16[CFG] no acceptable ENCRYPTION_ALGORITHM found
charon: 16[CFG] selecting proposal:
charon: 16[CFG] no acceptable ENCRYPTION_ALGORITHM found
charon: 16[CFG] selecting proposal:
charon: 16[CFG] no acceptable ENCRYPTION_ALGORITHM found
charon: 16[CFG] selecting proposal:
charon: 16[CFG] no acceptable ENCRYPTION_ALGORITHM found
charon: 16[CFG] selecting proposal:
charon: 16[CFG] no acceptable ENCRYPTION_ALGORITHM found
charon: 16[CFG] selecting proposal:
charon: 16[CFG] no acceptable ENCRYPTION_ALGORITHM found
charon: 16[CFG] selecting proposal:
charon: 16[CFG] no acceptable ENCRYPTION_ALGORITHM found
charon: 16[CFG] selecting proposal:
charon: 16[CFG] no acceptable ENCRYPTION_ALGORITHM found
charon: 16[CFG] selecting proposal:
charon: 16[CFG] no acceptable ENCRYPTION_ALGORITHM found
charon: 16[CFG] selecting proposal:
charon: 16[CFG] no acceptable ENCRYPTION_ALGORITHM found
charon: 16[CFG] selecting proposal:
charon: 16[CFG] no acceptable ENCRYPTION_ALGORITHM found
charon: 16[CFG] selecting proposal:
charon: 16[CFG] no acceptable ENCRYPTION_ALGORITHM found
charon: 16[CFG] selecting proposal:
charon: 16[CFG] no acceptable DIFFIE_HELLMAN_GROUP found
charon: 16[CFG] selecting proposal:
charon: 16[CFG] no acceptable PSEUDO_RANDOM_FUNCTION found
charon: 16[CFG] selecting proposal:
charon: 16[CFG] no acceptable ENCRYPTION_ALGORITHM found
charon: 16[CFG] selecting proposal:
charon: 16[CFG] no acceptable ENCRYPTION_ALGORITHM found
charon: 16[CFG] selecting proposal:
charon: 16[CFG] proposal matches
charon: 16[CFG] received proposals: IKE:AES_CBC_256/HMAC_SHA2_256_128/PRF_HMAC_SHA2_256/MODP_2048, IKE:AES_CBC_256/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_2048, IKE:AES_CBC_256/HMAC_MD5_96/PRF_HMAC_MD5/MODP_2048, IKE:AES_CBC_256/HMAC_SHA2_512_256/PRF_HMAC_SHA2_512/MODP_2048, IKE:AES_CBC_256/HMAC_SHA2_256_128/PRF_HMAC_SHA2_256/MODP_1536, IKE:AES_CBC_256/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_1536, IKE:AES_CBC_256/HMAC_MD5_96/PRF_HMAC_MD5/MODP_1536, IKE:AES_CBC_256/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_1024, IKE:AES_CBC_256/HMAC_MD5_96/PRF_HMAC_MD5/MODP_1024, IKE:AES_CBC_128/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_1024, IKE:AES_CBC_128/HMAC_MD5_96/PRF_HMAC_MD5/MODP_1024, IKE:3DES_CBC/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_1024, IKE:3DES_CBC/HMAC_MD5_96/PRF_HMAC_MD5/MODP_1024, IKE:DES_CBC/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_1024, IKE:DES_CBC/HMAC_MD5_96/PRF_HMAC_MD5/MODP_1024
charon: 16[CFG] configured proposals: IKE:AES_CBC_128/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_2048, IKE:3DES_CBC/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_1536, IKE:3DES_CBC/AES_CBC_128/AES_CBC_192/AES_CBC_256/AES_CTR_128/AES_CTR_192/AES_CTR_256/CAMELLIA_CBC_128/CAMELLIA_CBC_192/CAMELLIA_CBC_256/CAMELLIA_CTR_128/CAMELLIA_CTR_192/CAMELLIA_CTR_256/AES_CCM_8_128/AES_CCM_8_192/AES_CCM_8_256/AES_CCM_12_128/AES_CCM_12_192/AES_CCM_12_256/AES_CCM_16_128/AES_CCM_16_192/AES_CCM_16_256/AES_GCM_8_128/AES_GCM_8_192/AES_GCM_8_256/AES_GCM_12_128/AES_GCM_12_192/AES_GCM_12_256/AES_GCM_16_128/AES_GCM_16_192/AES_GCM_16_256/CAMELLIA_CCM_8_128/CAMELLIA_CCM_8_192/CAMELLIA_CCM_8_256/CAMELLIA_CCM_12_128/CAMELLIA_CCM_12_192/CAMELLIA_CCM_12_256/CAMELLIA_CCM_16_128/CAMELLIA_CCM_16_192/CAMELLIA_CCM_16_256/HMAC_MD5_96/HMAC_SHA1_96/AES_XCBC_96/AES_CMAC_96/HMAC_SHA2_256_128/HMAC_SHA2_384_192/HMAC_SHA2_512_256/PRF_HMAC_MD5/PRF_HMAC_SHA1/PRF_AES128_XCBC/PRF_HMAC_SHA2_256/PRF_HMAC_SHA2_384/PRF_HMAC_SHA2_512/PRF_AES128_CMAC/MODP_1024/MODP_1536/MODP_2048/MODP_3072/MODP_4096/MODP_8192/ECP_256/ECP_384/ECP_521/MODP_1024_160/MODP_2048_224/MODP_2048_256/ECP_192/ECP_224/ECP_224_BP/ECP_256_BP/ECP_384_BP/ECP_512_BP
charon: 16[CFG] selected proposal: IKE:AES_CBC_256/HMAC_SHA2_256_128/PRF_HMAC_SHA2_256/MODP_2048
charon: 16[IKE] sending XAuth vendor ID
charon: 16[IKE] sending DPD vendor ID
charon: 16[IKE] sending Cisco Unity vendor ID
charon: 16[IKE] sending NAT-T (RFC 3947) vendor ID
charon: 16[ENC] generating ID_PROT response 0 [ SA V V V V ]
charon: 16[NET] sending packet: from 1.2.3.4[500] to 2.3.4.5[12836] (156 bytes)
charon: 10[NET] sending packet: from 1.2.3.4[500] to 2.3.4.5[12836]
charon: 09[NET] received packet: from 2.3.4.5[12836] to 1.2.3.4[500]
charon: 09[NET] waiting for data on sockets
charon: 04[NET] received packet: from 2.3.4.5[12836] to 1.2.3.4[500] (380 bytes)
charon: 04[ENC] parsed ID_PROT request 0 [ KE No NAT-D NAT-D ]
charon: 04[IKE] local host is behind NAT, sending keep alives
charon: 04[IKE] remote host is behind NAT
charon: 04[IKE] sending cert request for "C=GB, O=org, CN=org CA"
charon: 04[ENC] generating ID_PROT response 0 [ KE No CERTREQ NAT-D NAT-D ]
charon: 04[NET] sending packet: from 1.2.3.4[500] to 2.3.4.5[12836] (447 bytes)
charon: 10[NET] sending packet: from 1.2.3.4[500] to 2.3.4.5[12836]
charon: 09[NET] received packet: from 2.3.4.5[46876] to 1.2.3.4[4500]
charon: 09[NET] waiting for data on sockets
charon: 15[NET] received packet: from 2.3.4.5[46876] to 1.2.3.4[4500] (1164 bytes)
charon: 15[ENC] parsed ID_PROT request 0 [ ID CERT SIG CERTREQ N(INITIAL_CONTACT) ]
charon: 15[IKE] ignoring certificate request without data
charon: 15[IKE] received end entity cert "C=GB, O=org, CN=client"
charon: 15[CFG] looking for XAuthInitRSA peer configs matching 1.2.3.4...2.3.4.5[C=GB, O=org, CN=client]
charon: 15[CFG] candidate "ipsec-l2tp-psk", match: 1/1/24 (me/other/ike)
charon: 15[CFG] candidate "ipsec-l2tp-rsa", match: 1/1/24 (me/other/ike)
charon: 15[CFG] candidate "ipsec-ikev1-psk", match: 1/1/28 (me/other/ike)
charon: 15[CFG] candidate "ipsec-ikev1-rsa", match: 1/20/28 (me/other/ike)
charon: 15[CFG] selected peer config "ipsec-ikev1-rsa"
charon: 15[CFG] certificate "C=GB, O=org, CN=client" key: 2048 bit RSA
charon: 15[CFG] using trusted ca certificate "C=GB, O=org, CN=org CA"
charon: 15[CFG] checking certificate status of "C=GB, O=org, CN=client"
charon: 15[CFG] ocsp check skipped, no ocsp found
charon: 15[CFG] certificate status is not available
charon: 15[CFG] certificate "C=GB, O=org, CN=org CA" key: 2048 bit RSA
charon: 15[CFG] reached self-signed root ca with a path length of 0
charon: 15[CFG] using trusted certificate "C=GB, O=org, CN=client"
charon: 15[IKE] authentication of 'C=GB, O=org, CN=client' with RSA successful
charon: 15[IKE] authentication of 'vpn' (myself) successful
charon: 15[IKE] queueing XAUTH task
charon: 15[IKE] sending end entity cert "C=GB, O=org, CN=vpn"
charon: 15[ENC] generating ID_PROT response 0 [ ID CERT SIG ]
charon: 15[NET] sending packet: from 1.2.3.4[4500] to 2.3.4.5[46876] (1164 bytes)
charon: 10[NET] sending packet: from 1.2.3.4[4500] to 2.3.4.5[46876]
charon: 15[IKE] activating new tasks
charon: 15[IKE] activating XAUTH task
charon: 15[ENC] generating TRANSACTION request 3177247268 [ HASH CPRQ(X_USER X_PWD) ]
charon: 15[NET] sending packet: from 1.2.3.4[4500] to 2.3.4.5[46876] (92 bytes)
charon: 10[NET] sending packet: from 1.2.3.4[4500] to 2.3.4.5[46876]
charon: 09[NET] received packet: from 2.3.4.5[46876] to 1.2.3.4[4500]
charon: 09[NET] waiting for data on sockets
charon: 01[NET] received packet: from 2.3.4.5[46876] to 1.2.3.4[4500] (108 bytes)
charon: 01[ENC] parsed TRANSACTION response 3177247268 [ HASH CPRP(X_USER X_PWD) ]
charon: 01[IKE] XAuth authentication of 'avatar' successful
charon: 01[IKE] reinitiating already active tasks
charon: 01[IKE] XAUTH task
charon: 01[ENC] generating TRANSACTION request 37044732 [ HASH CPS(X_STATUS) ]
charon: 01[NET] sending packet: from 1.2.3.4[4500] to 2.3.4.5[46876] (92 bytes)
charon: 10[NET] sending packet: from 1.2.3.4[4500] to 2.3.4.5[46876]
charon: 09[NET] received packet: from 2.3.4.5[46876] to 1.2.3.4[4500]
charon: 09[NET] waiting for data on sockets
charon: 09[NET] received packet: from 2.3.4.5[46876] to 1.2.3.4[4500]
charon: 09[NET] waiting for data on sockets
charon: 06[NET] received packet: from 2.3.4.5[46876] to 1.2.3.4[4500] (92 bytes)
charon: 06[ENC] parsed TRANSACTION response 37044732 [ HASH CPA(X_STATUS) ]
charon: 06[IKE] IKE_SA ipsec-ikev1-rsa[6] established between 1.2.3.4[vpn]...2.3.4.5[C=GB, O=org, CN=client]
charon: 06[IKE] IKE_SA ipsec-ikev1-rsa[6] state change: CONNECTING => ESTABLISHED
charon: 06[IKE] scheduling reauthentication in 9988s
charon: 06[IKE] maximum IKE_SA lifetime 10528s
charon: 06[IKE] activating new tasks
charon: 06[IKE] nothing to initiate
charon: 03[NET] received packet: from 2.3.4.5[46876] to 1.2.3.4[4500] (188 bytes)
charon: 03[ENC] unknown attribute type (28683)
charon: 03[ENC] parsed TRANSACTION request 564327026 [ HASH CPRQ(ADDR MASK DNS NBNS EXP VER U_BANNER U_DEFDOM U_SPLITDNS U_SPLITINC U_LOCALLAN U_PFS U_SAVEPWD U_FWTYPE U_BKPSRV (28683)) ]
charon: 03[IKE] processing INTERNAL_IP4_ADDRESS attribute
charon: 03[IKE] processing INTERNAL_IP4_NETMASK attribute
charon: 03[IKE] processing INTERNAL_IP4_DNS attribute
charon: 03[IKE] processing INTERNAL_IP4_NBNS attribute
charon: 03[IKE] processing INTERNAL_ADDRESS_EXPIRY attribute
charon: 03[IKE] processing APPLICATION_VERSION attribute
charon: 03[IKE] processing UNITY_BANNER attribute
charon: 03[IKE] processing UNITY_DEF_DOMAIN attribute
charon: 03[IKE] processing UNITY_SPLITDNS_NAME attribute
charon: 03[IKE] processing UNITY_SPLIT_INCLUDE attribute
charon: 03[IKE] processing UNITY_LOCAL_LAN attribute
charon: 03[IKE] processing UNITY_PFS attribute
charon: 03[IKE] processing UNITY_SAVE_PASSWD attribute
charon: 03[IKE] processing UNITY_FW_TYPE attribute
charon: 03[IKE] processing UNITY_BACKUP_SERVERS attribute
charon: 03[IKE] processing (28683) attribute
charon: 03[IKE] peer requested virtual IP %any
charon: 03[CFG] assigning new lease to 'avatar'
charon: 03[IKE] assigning virtual IP 10.20.0.3 to peer 'avatar'
charon: 03[CFG] proposing traffic selectors for us:
charon: 03[CFG] 0.0.0.0/0
charon: 03[ENC] generating TRANSACTION response 564327026 [ HASH CPRP(ADDR DNS DNS) ]
charon: 03[NET] sending packet: from 1.2.3.4[4500] to 2.3.4.5[46876] (108 bytes)
charon: 10[NET] sending packet: from 1.2.3.4[4500] to 2.3.4.5[46876]
charon: 09[NET] received packet: from 2.3.4.5[46876] to 1.2.3.4[4500]
charon: 09[NET] waiting for data on sockets
charon: 02[NET] received packet: from 2.3.4.5[46876] to 1.2.3.4[4500] (300 bytes)
charon: 02[ENC] parsed QUICK_MODE request 768699248 [ HASH SA No ID ID ]
charon: 02[CFG] looking for a child config for 0.0.0.0/0 === 10.20.0.3/32
charon: 02[CFG] proposing traffic selectors for us:
charon: 02[CFG] 0.0.0.0/0
charon: 02[CFG] proposing traffic selectors for other:
charon: 02[CFG] 10.20.0.0/16
charon: 02[CFG] candidate "ipsec-ikev1-rsa" with prio 5+1
charon: 02[CFG] found matching child config "ipsec-ikev1-rsa" with prio 6
charon: 02[CFG] selecting traffic selectors for other:
charon: 02[CFG] config: 10.20.0.0/16, received: 10.20.0.3/32 => match: 10.20.0.3/32
charon: 02[CFG] selecting traffic selectors for us:
charon: 02[CFG] config: 0.0.0.0/0, received: 0.0.0.0/0 => match: 0.0.0.0/0
charon: 02[CFG] selecting proposal:
charon: 02[CFG] no acceptable ENCRYPTION_ALGORITHM found
charon: 02[CFG] selecting proposal:
charon: 02[CFG] no acceptable ENCRYPTION_ALGORITHM found
charon: 02[CFG] selecting proposal:
charon: 02[CFG] proposal matches
charon: 02[CFG] received proposals: ESP:AES_CBC_256/HMAC_SHA1_96/NO_EXT_SEQ, ESP:AES_CBC_256/HMAC_MD5_96/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_SHA1_96/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_MD5_96/NO_EXT_SEQ, ESP:3DES_CBC/HMAC_SHA1_96/NO_EXT_SEQ, ESP:3DES_CBC/HMAC_MD5_96/NO_EXT_SEQ
charon: 02[CFG] configured proposals: ESP:AES_CBC_128/HMAC_SHA1_96/NO_EXT_SEQ, ESP:3DES_CBC/HMAC_SHA1_96/NO_EXT_SEQ, ESP:AES_CBC_128/AES_CBC_192/AES_CBC_256/3DES_CBC/BLOWFISH_CBC_256/HMAC_SHA1_96/AES_XCBC_96/HMAC_MD5_96/NO_EXT_SEQ
charon: 02[CFG] selected proposal: ESP:AES_CBC_128/HMAC_SHA1_96/NO_EXT_SEQ
charon: 02[CFG] changing proposed traffic selectors for us:
charon: 02[CFG] 0.0.0.0/0
charon: 02[ENC] generating QUICK_MODE response 768699248 [ HASH SA No ID ID ]
charon: 02[NET] sending packet: from 1.2.3.4[4500] to 2.3.4.5[46876] (188 bytes)
charon: 10[NET] sending packet: from 1.2.3.4[4500] to 2.3.4.5[46876]
charon: 09[NET] received packet: from 2.3.4.5[46876] to 1.2.3.4[4500]
charon: 09[NET] waiting for data on sockets
charon: 11[NET] received packet: from 2.3.4.5[46876] to 1.2.3.4[4500] (76 bytes)
charon: 11[ENC] parsed QUICK_MODE request 768699248 [ HASH ]
charon: 11[CFG] proposing traffic selectors for us:
charon: 11[CFG] 0.0.0.0/0
charon: 11[IKE] CHILD_SA ipsec-ikev1-rsa{2} established with SPIs cda17068_i 09e76e13_o and TS 0.0.0.0/0 === 10.20.0.3/32
Logs from OS X which doesn't work
charon: 09[NET] received packet: from 2.3.4.5[12897] to 1.2.3.4[500] charon: 09[NET] waiting for data on sockets charon: 05[NET] received packet: from 2.3.4.5[12897] to 1.2.3.4[500] (848 bytes) charon: 05[ENC] parsed ID_PROT request 0 [ SA V V V V V V V V V V V V V V ] charon: 05[CFG] looking for an ike config for 1.2.3.4...2.3.4.5 charon: 05[CFG] candidate: %any...%any, prio 24 charon: 05[CFG] candidate: %any...%any, prio 24 charon: 05[CFG] candidate: %any...%any, prio 28 charon: 05[CFG] candidate: %any...%any, prio 28 charon: 05[CFG] found matching ike config: %any...%any with prio 28 charon: 05[IKE] received NAT-T (RFC 3947) vendor ID charon: 05[IKE] received draft-ietf-ipsec-nat-t-ike vendor ID charon: 05[IKE] received draft-ietf-ipsec-nat-t-ike-08 vendor ID charon: 05[IKE] received draft-ietf-ipsec-nat-t-ike-07 vendor ID charon: 05[IKE] received draft-ietf-ipsec-nat-t-ike-06 vendor ID charon: 05[IKE] received draft-ietf-ipsec-nat-t-ike-05 vendor ID charon: 05[IKE] received draft-ietf-ipsec-nat-t-ike-04 vendor ID charon: 05[IKE] received draft-ietf-ipsec-nat-t-ike-03 vendor ID charon: 05[IKE] received draft-ietf-ipsec-nat-t-ike-02 vendor ID charon: 05[IKE] received draft-ietf-ipsec-nat-t-ike-02\n vendor ID charon: 05[IKE] received XAuth vendor ID charon: 05[IKE] received Cisco Unity vendor ID charon: 05[IKE] received FRAGMENTATION vendor ID charon: 05[IKE] received DPD vendor ID charon: 05[IKE] 2.3.4.5 is initiating a Main Mode IKE_SA charon: 05[IKE] IKE_SA (unnamed)[7] state change: CREATED => CONNECTING charon: 05[CFG] selecting proposal: charon: 05[CFG] no acceptable ENCRYPTION_ALGORITHM found charon: 05[CFG] selecting proposal: charon: 05[CFG] no acceptable ENCRYPTION_ALGORITHM found charon: 05[CFG] selecting proposal: charon: 05[CFG] no acceptable ENCRYPTION_ALGORITHM found charon: 05[CFG] selecting proposal: charon: 05[CFG] no acceptable ENCRYPTION_ALGORITHM found charon: 05[CFG] selecting proposal: charon: 05[CFG] no acceptable ENCRYPTION_ALGORITHM found charon: 05[CFG] selecting proposal: charon: 05[CFG] no acceptable ENCRYPTION_ALGORITHM found charon: 05[CFG] selecting proposal: charon: 05[CFG] no acceptable ENCRYPTION_ALGORITHM found charon: 05[CFG] selecting proposal: charon: 05[CFG] no acceptable ENCRYPTION_ALGORITHM found charon: 05[CFG] selecting proposal: charon: 05[CFG] no acceptable ENCRYPTION_ALGORITHM found charon: 05[CFG] selecting proposal: charon: 05[CFG] no acceptable DIFFIE_HELLMAN_GROUP found charon: 05[CFG] selecting proposal: charon: 05[CFG] no acceptable PSEUDO_RANDOM_FUNCTION found charon: 05[CFG] selecting proposal: charon: 05[CFG] no acceptable ENCRYPTION_ALGORITHM found charon: 05[CFG] selecting proposal: charon: 05[CFG] no acceptable ENCRYPTION_ALGORITHM found charon: 05[CFG] selecting proposal: charon: 05[CFG] no acceptable ENCRYPTION_ALGORITHM found charon: 05[CFG] selecting proposal: charon: 05[CFG] no acceptable ENCRYPTION_ALGORITHM found charon: 05[CFG] selecting proposal: charon: 05[CFG] no acceptable ENCRYPTION_ALGORITHM found charon: 05[CFG] selecting proposal: charon: 05[CFG] no acceptable ENCRYPTION_ALGORITHM found charon: 05[CFG] selecting proposal: charon: 05[CFG] no acceptable ENCRYPTION_ALGORITHM found charon: 05[CFG] selecting proposal: charon: 05[CFG] no acceptable ENCRYPTION_ALGORITHM found charon: 05[CFG] selecting proposal: charon: 05[CFG] no acceptable ENCRYPTION_ALGORITHM found charon: 05[CFG] selecting proposal: charon: 05[CFG] no acceptable ENCRYPTION_ALGORITHM found charon: 05[CFG] selecting proposal: charon: 05[CFG] no acceptable ENCRYPTION_ALGORITHM found charon: 05[CFG] selecting proposal: charon: 05[CFG] no acceptable ENCRYPTION_ALGORITHM found charon: 05[CFG] selecting proposal: charon: 05[CFG] no acceptable ENCRYPTION_ALGORITHM found charon: 05[CFG] selecting proposal: charon: 05[CFG] no acceptable ENCRYPTION_ALGORITHM found charon: 05[CFG] selecting proposal: charon: 05[CFG] no acceptable ENCRYPTION_ALGORITHM found charon: 05[CFG] selecting proposal: charon: 05[CFG] no acceptable DIFFIE_HELLMAN_GROUP found charon: 05[CFG] selecting proposal: charon: 05[CFG] no acceptable PSEUDO_RANDOM_FUNCTION found charon: 05[CFG] selecting proposal: charon: 05[CFG] no acceptable ENCRYPTION_ALGORITHM found charon: 05[CFG] selecting proposal: charon: 05[CFG] no acceptable ENCRYPTION_ALGORITHM found charon: 05[CFG] selecting proposal: charon: 05[CFG] proposal matches charon: 05[CFG] received proposals: IKE:AES_CBC_256/HMAC_SHA2_256_128/PRF_HMAC_SHA2_256/MODP_2048, IKE:AES_CBC_256/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_2048, IKE:AES_CBC_256/HMAC_MD5_96/PRF_HMAC_MD5/MODP_2048, IKE:AES_CBC_256/HMAC_SHA2_512_256/PRF_HMAC_SHA2_512/MODP_2048, IKE:AES_CBC_256/HMAC_SHA2_256_128/PRF_HMAC_SHA2_256/MODP_1536, IKE:AES_CBC_256/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_1536, IKE:AES_CBC_256/HMAC_MD5_96/PRF_HMAC_MD5/MODP_1536, IKE:AES_CBC_256/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_1024, IKE:AES_CBC_256/HMAC_MD5_96/PRF_HMAC_MD5/MODP_1024, IKE:AES_CBC_128/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_1024, IKE:AES_CBC_128/HMAC_MD5_96/PRF_HMAC_MD5/MODP_1024, IKE:3DES_CBC/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_1024, IKE:3DES_CBC/HMAC_MD5_96/PRF_HMAC_MD5/MODP_1024, IKE:DES_CBC/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_1024, IKE:DES_CBC/HMAC_MD5_96/PRF_HMAC_MD5/MODP_1024 charon: 05[CFG] configured proposals: IKE:AES_CBC_128/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_2048, IKE:3DES_CBC/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_1536, IKE:3DES_CBC/AES_CBC_128/AES_CBC_192/AES_CBC_256/AES_CTR_128/AES_CTR_192/AES_CTR_256/CAMELLIA_CBC_128/CAMELLIA_CBC_192/CAMELLIA_CBC_256/CAMELLIA_CTR_128/CAMELLIA_CTR_192/CAMELLIA_CTR_256/AES_CCM_8_128/AES_CCM_8_192/AES_CCM_8_256/AES_CCM_12_128/AES_CCM_12_192/AES_CCM_12_256/AES_CCM_16_128/AES_CCM_16_192/AES_CCM_16_256/AES_GCM_8_128/AES_GCM_8_192/AES_GCM_8_256/AES_GCM_12_128/AES_GCM_12_192/AES_GCM_12_256/AES_GCM_16_128/AES_GCM_16_192/AES_GCM_16_256/CAMELLIA_CCM_8_128/CAMELLIA_CCM_8_192/CAMELLIA_CCM_8_256/CAMELLIA_CCM_12_128/CAMELLIA_CCM_12_192/CAMELLIA_CCM_12_256/CAMELLIA_CCM_16_128/CAMELLIA_CCM_16_192/CAMELLIA_CCM_16_256/HMAC_MD5_96/HMAC_SHA1_96/AES_XCBC_96/AES_CMAC_96/HMAC_SHA2_256_128/HMAC_SHA2_384_192/HMAC_SHA2_512_256/PRF_HMAC_MD5/PRF_HMAC_SHA1/PRF_AES128_XCBC/PRF_HMAC_SHA2_256/PRF_HMAC_SHA2_384/PRF_HMAC_SHA2_512/PRF_AES128_CMAC/MODP_1024/MODP_1536/MODP_2048/MODP_3072/MODP_4096/MODP_8192/ECP_256/ECP_384/ECP_521/MODP_1024_160/MODP_2048_224/MODP_2048_256/ECP_192/ECP_224/ECP_224_BP/ECP_256_BP/ECP_384_BP/ECP_512_BP charon: 05[CFG] selected proposal: IKE:AES_CBC_256/HMAC_SHA2_256_128/PRF_HMAC_SHA2_256/MODP_2048 charon: 05[IKE] sending XAuth vendor ID charon: 05[IKE] sending DPD vendor ID charon: 05[IKE] sending Cisco Unity vendor ID charon: 05[IKE] sending NAT-T (RFC 3947) vendor ID charon: 05[ENC] generating ID_PROT response 0 [ SA V V V V ] charon: 05[NET] sending packet: from 1.2.3.4[500] to 2.3.4.5[12897] (156 bytes) charon: 10[NET] sending packet: from 1.2.3.4[500] to 2.3.4.5[12897] charon: 09[NET] received packet: from 2.3.4.5[12897] to 1.2.3.4[500] charon: 09[NET] waiting for data on sockets charon: 11[NET] received packet: from 2.3.4.5[12897] to 1.2.3.4[500] (380 bytes) charon: 11[ENC] parsed ID_PROT request 0 [ KE No NAT-D NAT-D ] charon: 11[IKE] local host is behind NAT, sending keep alives charon: 11[IKE] remote host is behind NAT charon: 11[IKE] sending cert request for "C=GB, O=org, CN=org CA" charon: 11[ENC] generating ID_PROT response 0 [ KE No CERTREQ NAT-D NAT-D ] charon: 11[NET] sending packet: from 1.2.3.4[500] to 2.3.4.5[12897] (447 bytes) charon: 10[NET] sending packet: from 1.2.3.4[500] to 2.3.4.5[12897] charon: 09[NET] received packet: from 2.3.4.5[46952] to 1.2.3.4[4500] charon: 09[NET] waiting for data on sockets charon: 12[NET] received packet: from 2.3.4.5[46952] to 1.2.3.4[4500] (1132 bytes) charon: 12[ENC] parsed ID_PROT request 0 [ ID CERT SIG CERTREQ ] charon: 12[IKE] ignoring certificate request without data charon: 12[IKE] received end entity cert "C=GB, O=org, CN=client" charon: 12[CFG] looking for XAuthInitRSA peer configs matching 1.2.3.4...2.3.4.5[C=GB, O=org, CN=client] charon: 12[CFG] candidate "ipsec-l2tp-psk", match: 1/1/24 (me/other/ike) charon: 12[CFG] candidate "ipsec-l2tp-rsa", match: 1/1/24 (me/other/ike) charon: 12[CFG] candidate "ipsec-ikev1-psk", match: 1/1/28 (me/other/ike) charon: 12[CFG] candidate "ipsec-ikev1-rsa", match: 1/20/28 (me/other/ike) charon: 12[CFG] selected peer config "ipsec-ikev1-rsa" charon: 12[CFG] certificate "C=GB, O=org, CN=client" key: 2048 bit RSA charon: 12[CFG] using trusted ca certificate "C=GB, O=org, CN=org CA" charon: 12[CFG] checking certificate status of "C=GB, O=org, CN=client" charon: 12[CFG] ocsp check skipped, no ocsp found charon: 12[CFG] certificate status is not available charon: 12[CFG] certificate "C=GB, O=org, CN=org CA" key: 2048 bit RSA charon: 12[CFG] reached self-signed root ca with a path length of 0 charon: 12[CFG] using trusted certificate "C=GB, O=org, CN=client" charon: 12[IKE] authentication of 'C=GB, O=org, CN=client' with RSA successful charon: 12[IKE] authentication of 'vpn' (myself) successful charon: 12[IKE] queueing XAUTH task charon: 12[IKE] sending end entity cert "C=GB, O=org, CN=vpn" charon: 12[ENC] generating ID_PROT response 0 [ ID CERT SIG ] charon: 12[NET] sending packet: from 1.2.3.4[4500] to 2.3.4.5[46952] (1164 bytes) charon: 10[NET] sending packet: from 1.2.3.4[4500] to 2.3.4.5[46952] charon: 12[IKE] activating new tasks charon: 12[IKE] activating XAUTH task charon: 12[ENC] generating TRANSACTION request 3955598473 [ HASH CPRQ(X_USER X_PWD) ] charon: 12[NET] sending packet: from 1.2.3.4[4500] to 2.3.4.5[46952] (92 bytes) charon: 10[NET] sending packet: from 1.2.3.4[4500] to 2.3.4.5[46952] charon: 09[NET] received packet: from 2.3.4.5[46952] to 1.2.3.4[4500] charon: 09[NET] waiting for data on sockets charon: 13[NET] received packet: from 2.3.4.5[46952] to 1.2.3.4[4500] (92 bytes) charon: 13[ENC] invalid HASH_V1 payload length, decryption failed? charon: 13[ENC] could not decrypt payloads charon: 13[IKE] message parsing failed charon: 13[IKE] ignore malformed INFORMATIONAL request charon: 13[IKE] INFORMATIONAL_V1 request with message ID 2673243766 processing failed charon: 16[IKE] sending retransmit 1 of request message ID 3955598473, seq 1 charon: 16[NET] sending packet: from 1.2.3.4[4500] to 2.3.4.5[46952] (92 bytes) charon: 10[NET] sending packet: from 1.2.3.4[4500] to 2.3.4.5[46952] charon: 04[IKE] sending retransmit 2 of request message ID 3955598473, seq 1 charon: 04[NET] sending packet: from 1.2.3.4[4500] to 2.3.4.5[46952] (92 bytes) charon: 10[NET] sending packet: from 1.2.3.4[4500] to 2.3.4.5[46952]
#7 Updated by Bowen Sun over 9 years ago
Attaching OS X racoon logs
vpnracoon[10077] <Debug>: New IKE-Session to 1.2.3.4[500]. vpnracoon[10077] <Notice>: Connecting. vpnracoon[10077] <Debug>: *** New Phase 1 vpnracoon[10077] <Debug>: ****** state changed to: IKEv1 ident I start vpnracoon[10077] <Debug>: === vpnracoon[10077] <Info>: initiate new phase 1 negotiation: 10.143.187.41[500]<=>1.2.3.4[500] vpnracoon[10077] <Info>: begin Identity Protection mode. vpnracoon[10077] <Notice>: IPSec Phase 1 started (Initiated by me). vpnracoon[10077] <Debug>: new cookie: vpnracoon[10077] <Debug>: add payload of len 540, next type 13 vpnracoon[10077] <Debug>: add payload of len 16, next type 13 vpnracoon[10077] <Debug>: add payload of len 16, next type 13 vpnracoon[10077] <Debug>: add payload of len 16, next type 13 vpnracoon[10077] <Debug>: add payload of len 16, next type 13 vpnracoon[10077] <Debug>: add payload of len 16, next type 13 vpnracoon[10077] <Debug>: add payload of len 16, next type 13 vpnracoon[10077] <Debug>: add payload of len 16, next type 13 vpnracoon[10077] <Debug>: add payload of len 16, next type 13 vpnracoon[10077] <Debug>: add payload of len 16, next type 13 vpnracoon[10077] <Debug>: add payload of len 16, next type 13 vpnracoon[10077] <Debug>: add payload of len 8, next type 13 vpnracoon[10077] <Debug>: add payload of len 16, next type 13 vpnracoon[10077] <Debug>: add payload of len 20, next type 13 vpnracoon[10077] <Debug>: add payload of len 16, next type 0 vpnracoon[10077] <Debug>: 848 bytes from 10.143.187.41[500] to 1.2.3.4[500] vpnracoon[10077] <Debug>: sockname 10.143.187.41[500] vpnracoon[10077] <Debug>: send packet from 10.143.187.41[500] vpnracoon[10077] <Debug>: send packet to 1.2.3.4[500] vpnracoon[10077] <Debug>: @@@@@@ data being sent: vpnracoon[10077] <Debug>: 1 times of 848 bytes message will be sent to 1.2.3.4[500] vpnracoon[10077] <Debug>: Resend Phase 1 packet 25fdff6c38a3a9c8:0000000000000000 vpnracoon[10077] <Debug>: ****** state changed to: IKEv1 ident I msg1 sent vpnracoon[10077] <Notice>: IKE Packet: transmit success. (Initiator, Main-Mode message 1). vpnracoon[10077] <Notice>: >>>>> phase change status = Phase 1 started by us vpnracoon[10077] <Debug>: vpn control writing 20 bytes vpnracoon[10077] <Debug>: @@@@@@ data from readmsg: vpnracoon[10077] <Debug>: @@@@@@ data from readmsg: vpnracoon[10077] <Debug>: 156 bytes message received from 1.2.3.4[500] to 10.143.187.41[500] vpnracoon[10077] <Debug>: start search for IKE-Session. target 1.2.3.4[500]. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[500]. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 1. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: start search for IKE-Session. target 1.2.3.4[500]. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[500]. vpnracoon[10077] <Debug>: Pre-existing IKE-Session to 1.2.3.4[500]. case 1. vpnracoon[10077] <Debug>: begin. vpnracoon[10077] <Debug>: seen nptype=1(sa) vpnracoon[10077] <Debug>: seen nptype=13(vid) vpnracoon[10077] <Debug>: seen nptype=13(vid) vpnracoon[10077] <Debug>: seen nptype=13(vid) vpnracoon[10077] <Debug>: seen nptype=13(vid) vpnracoon[10077] <Debug>: succeed. vpnracoon[10077] <Info>: received Vendor ID: draft-ietf-ipsra-isakmp-xauth-06.txt vpnracoon[10077] <Info>: received Vendor ID: DPD vpnracoon[10077] <Info>: received Vendor ID: CISCO-UNITY vpnracoon[10077] <Info>: received Vendor ID: RFC 3947 vpnracoon[10077] <Info>: Selected NAT-T version: RFC 3947 vpnracoon[10077] <Debug>: begin. vpnracoon[10077] <Debug>: seen nptype=2(prop) vpnracoon[10077] <Debug>: succeed. vpnracoon[10077] <Debug>: proposal #1 len=44 vpnracoon[10077] <Debug>: begin. vpnracoon[10077] <Debug>: seen nptype=3(trns) vpnracoon[10077] <Debug>: succeed. vpnracoon[10077] <Debug>: transform #1 len=36 vpnracoon[10077] <Debug>: type=Encryption Algorithm, flag=0x8000, lorv=AES-CBC vpnracoon[10077] <Debug>: encryption(aes) vpnracoon[10077] <Debug>: type=Key Length, flag=0x8000, lorv=256 vpnracoon[10077] <Debug>: type=Hash Algorithm, flag=0x8000, lorv=SHA256 vpnracoon[10077] <Debug>: hash(sha2_256) vpnracoon[10077] <Debug>: type=Group Description, flag=0x8000, lorv=2048-bit MODP group vpnracoon[10077] <Debug>: hmac(modp2048) vpnracoon[10077] <Debug>: type=Authentication Method, flag=0x8000, lorv=XAuth RSASIG client vpnracoon[10077] <Debug>: type=Life Type, flag=0x8000, lorv=seconds vpnracoon[10077] <Debug>: type=Life Duration, flag=0x8000, lorv=3600 vpnracoon[10077] <Debug>: pair 1: vpnracoon[10077] <Debug>: 0x7fc5c8e35130: next=0x0 tnext=0x0 vpnracoon[10077] <Debug>: proposal #1: 1 transform vpnracoon[10077] <Debug>: prop#=1, prot-id=ISAKMP, spi-size=0, #trns=1 vpnracoon[10077] <Debug>: trns#=1, trns-id=IKE vpnracoon[10077] <Debug>: type=Encryption Algorithm, flag=0x8000, lorv=AES-CBC vpnracoon[10077] <Debug>: type=Key Length, flag=0x8000, lorv=256 vpnracoon[10077] <Debug>: type=Hash Algorithm, flag=0x8000, lorv=SHA256 vpnracoon[10077] <Debug>: type=Group Description, flag=0x8000, lorv=2048-bit MODP group vpnracoon[10077] <Debug>: type=Authentication Method, flag=0x8000, lorv=XAuth RSASIG client vpnracoon[10077] <Debug>: type=Life Type, flag=0x8000, lorv=seconds vpnracoon[10077] <Debug>: type=Life Duration, flag=0x8000, lorv=3600 vpnracoon[10077] <Debug>: Compared: DB:Peer vpnracoon[10077] <Debug>: (version = 0:0) vpnracoon[10077] <Debug>: (lifetime = 3600:3600) vpnracoon[10077] <Debug>: (lifebyte = 0:0) vpnracoon[10077] <Debug>: enctype = AES-CBC:AES-CBC vpnracoon[10077] <Debug>: (encklen = 256:256) vpnracoon[10077] <Debug>: hashtype = SHA256:SHA256 vpnracoon[10077] <Debug>: authmethod = XAuth RSASIG client:XAuth RSASIG client vpnracoon[10077] <Debug>: dh_group = 2048-bit MODP group:2048-bit MODP group vpnracoon[10077] <Debug>: an acceptable proposal found. vpnracoon[10077] <Debug>: hmac(modp2048) vpnracoon[10077] <Debug>: agreed on XAuth RSASIG client auth. vpnracoon[10077] <Debug>: ****** state changed to: IKEv1 ident I msg2 rcvd vpnracoon[10077] <Notice>: >>>>> phase change status = Phase 1 started by peer vpnracoon[10077] <Debug>: vpn control writing 20 bytes vpnracoon[10077] <Notice>: IKE Packet: receive success. (Initiator, Main-Mode message 2). vpnracoon[10077] <Debug>: === vpnracoon[10077] <Debug>: compute DH's private. vpnracoon[10077] <Debug>: compute DH's public. vpnracoon[10077] <Info>: Hashing 1.2.3.4[500] with algo #4 vpnracoon[10077] <Debug>: hash(sha2_256) vpnracoon[10077] <Info>: Hashing 10.143.187.41[500] with algo #4 vpnracoon[10077] <Debug>: hash(sha2_256) vpnracoon[10077] <Info>: Adding remote and local NAT-D payloads. vpnracoon[10077] <Debug>: add payload of len 256, next type 10 vpnracoon[10077] <Debug>: add payload of len 16, next type 20 vpnracoon[10077] <Debug>: add payload of len 32, next type 20 vpnracoon[10077] <Debug>: add payload of len 32, next type 0 vpnracoon[10077] <Debug>: 380 bytes from 10.143.187.41[500] to 1.2.3.4[500] vpnracoon[10077] <Debug>: sockname 10.143.187.41[500] vpnracoon[10077] <Debug>: send packet from 10.143.187.41[500] vpnracoon[10077] <Debug>: send packet to 1.2.3.4[500] vpnracoon[10077] <Debug>: @@@@@@ data being sent: vpnracoon[10077] <Debug>: 1 times of 380 bytes message will be sent to 1.2.3.4[500] vpnracoon[10077] <Debug>: Resend Phase 1 packet 25fdff6c38a3a9c8:8a5d06340be69dad vpnracoon[10077] <Debug>: ****** state changed to: IKEv1 ident I msg3 sent vpnracoon[10077] <Notice>: IKE Packet: transmit success. (Initiator, Main-Mode message 3). vpnracoon[10077] <Debug>: @@@@@@ data from readmsg: vpnracoon[10077] <Debug>: @@@@@@ data from readmsg: vpnracoon[10077] <Debug>: 447 bytes message received from 1.2.3.4[500] to 10.143.187.41[500] vpnracoon[10077] <Debug>: start search for IKE-Session. target 1.2.3.4[500]. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[500]. vpnracoon[10077] <Debug>: Pre-existing IKE-Session to 1.2.3.4[500]. case 1. vpnracoon[10077] <Debug>: begin. vpnracoon[10077] <Debug>: seen nptype=4(ke) vpnracoon[10077] <Debug>: seen nptype=10(nonce) vpnracoon[10077] <Debug>: seen nptype=7(cr) vpnracoon[10077] <Debug>: seen nptype=20(nat-d) vpnracoon[10077] <Debug>: seen nptype=20(nat-d) vpnracoon[10077] <Debug>: succeed. vpnracoon[10077] <Debug>: CR saved vpnracoon[10077] <Info>: Hashing 10.143.187.41[500] with algo #4 vpnracoon[10077] <Debug>: hash(sha2_256) vpnracoon[10077] <Info>: NAT-D payload #0 doesn't match vpnracoon[10077] <Info>: Hashing 1.2.3.4[500] with algo #4 vpnracoon[10077] <Debug>: hash(sha2_256) vpnracoon[10077] <Info>: NAT-D payload #1 doesn't match vpnracoon[10077] <Info>: NAT detected: ME PEER vpnracoon[10077] <Debug>: peer transmitted CR: X.509 Certificate Signature vpnracoon[10077] <Debug>: ****** state changed to: IKEv1 ident I msg4 rcvd vpnracoon[10077] <Notice>: IKE Packet: receive success. (Initiator, Main-Mode message 4). vpnracoon[10077] <Debug>: === vpnracoon[10077] <Debug>: compute DH's shared. vpnracoon[10077] <Debug>: hmac(hmac_sha2_256) vpnracoon[10077] <Debug>: hmac(hmac_sha2_256) vpnracoon[10077] <Debug>: hmac(hmac_sha2_256) vpnracoon[10077] <Debug>: hmac(hmac_sha2_256) vpnracoon[10077] <Debug>: encryption(aes) vpnracoon[10077] <Debug>: hash(sha2_256) vpnracoon[10077] <Debug>: hash(sha2_256) vpnracoon[10077] <Debug>: encryption(aes) vpnracoon[10077] <Debug>: done with chking cert status 0 vpnracoon[10077] <Debug>: created CERT payload vpnracoon[10077] <Debug>: use ID type of DER_ASN1_DN vpnracoon[10077] <Debug>: hmac(hmac_sha2_256) vpnracoon[10077] <Debug>: create my CR: X.509 Certificate Signature vpnracoon[10077] <Debug>: failed to add initial-contact payload: rekey 0, ini-contact 1, contacted 1. vpnracoon[10077] <Debug>: add payload of len 50, next type 6 vpnracoon[10077] <Debug>: add payload of len 770, next type 9 vpnracoon[10077] <Debug>: add payload of len 256, next type 7 vpnracoon[10077] <Debug>: add payload of len 1, next type 0 vpnracoon[10077] <Debug>: Begin encryption. vpnracoon[10077] <Debug>: encryption(aes) vpnracoon[10077] <Debug>: pad length = 11 vpnracoon[10077] <Debug>: About to encrypt 1104 bytes vpnracoon[10077] <Debug>: encryption(aes) vpnracoon[10077] <Debug>: Encrypted. vpnracoon[10077] <Debug>: Adding NON-ESP marker vpnracoon[10077] <Debug>: 1136 bytes from 10.143.187.41[4500] to 1.2.3.4[4500] vpnracoon[10077] <Debug>: sockname 10.143.187.41[4500] vpnracoon[10077] <Debug>: send packet from 10.143.187.41[4500] vpnracoon[10077] <Debug>: send packet to 1.2.3.4[4500] vpnracoon[10077] <Debug>: @@@@@@ data being sent: vpnracoon[10077] <Debug>: 1 times of 1136 bytes message will be sent to 1.2.3.4[4500] vpnracoon[10077] <Debug>: Resend Phase 1 packet 25fdff6c38a3a9c8:8a5d06340be69dad vpnracoon[10077] <Debug>: Adding NON-ESP marker vpnracoon[10077] <Debug>: ****** state changed to: IKEv1 ident I msg5 sent vpnracoon[10077] <Notice>: IKE Packet: transmit success. (Initiator, Main-Mode message 5). vpnracoon[10077] <Debug>: @@@@@@ data from readmsg: vpnracoon[10077] <Debug>: @@@@@@ data from readmsg: vpnracoon[10077] <Debug>: 1164 bytes message received from 1.2.3.4[4500] to 10.143.187.41[4500] vpnracoon[10077] <Debug>: start search for IKE-Session. target 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: Pre-existing IKE-Session to 1.2.3.4[4500]. case 1. vpnracoon[10077] <Debug>: Begin decryption. vpnracoon[10077] <Debug>: encryption(aes) vpnracoon[10077] <Debug>: IV was saved for next processing: vpnracoon[10077] <Debug>: encryption(aes) vpnracoon[10077] <Debug>: decrypted payload by IV: vpnracoon[10077] <Debug>: padding len=0 vpnracoon[10077] <Debug>: skip to trim padding. vpnracoon[10077] <Debug>: decrypted. vpnracoon[10077] <Debug>: begin. vpnracoon[10077] <Debug>: seen nptype=5(id) vpnracoon[10077] <Debug>: seen nptype=6(cert) vpnracoon[10077] <Debug>: seen nptype=9(sig) vpnracoon[10077] <Debug>: succeed. vpnracoon[10077] <Debug>: CERT saved: vpnracoon[10077] <Debug>: *** SIGN passed vpnracoon[10077] <Error>: Error evaluating certificate. vpnracoon[10077] <Debug>: eval result = kSecTrustResultRecoverableTrustFailure. vpnracoon[10077] <Error>: ---------------Returned error strings: ---------------. vpnracoon[10077] <Error>: -----------------------------------------------------. vpnracoon[10077] <Error>: the peer's certificate is not verified. vpnracoon[10077] <Notice>: IKEv1 Phase 1 AUTH: failed. (Initiator, Main-Mode Message 6). vpnracoon[10077] <Debug>: sending vpn_control ike failed message - code=22 from=local. vpnracoon[10077] <Debug>: *** New Phase 2 vpnracoon[10077] <Debug>: ****** state changed to: IKEv1 info vpnracoon[10077] <Debug>: Compute IV for Phase 2 vpnracoon[10077] <Debug>: hash(sha2_256) vpnracoon[10077] <Debug>: encryption(aes) vpnracoon[10077] <Debug>: hmac(hmac_sha2_256) vpnracoon[10077] <Debug>: Begin encryption. vpnracoon[10077] <Debug>: encryption(aes) vpnracoon[10077] <Debug>: pad length = 16 vpnracoon[10077] <Debug>: About to encrypt 64 bytes vpnracoon[10077] <Debug>: encryption(aes) vpnracoon[10077] <Debug>: Encrypted. vpnracoon[10077] <Debug>: Adding NON-ESP marker vpnracoon[10077] <Debug>: 96 bytes from 10.143.187.41[4500] to 1.2.3.4[4500] vpnracoon[10077] <Debug>: sockname 10.143.187.41[4500] vpnracoon[10077] <Debug>: send packet from 10.143.187.41[4500] vpnracoon[10077] <Debug>: send packet to 1.2.3.4[4500] vpnracoon[10077] <Debug>: @@@@@@ data being sent: vpnracoon[10077] <Debug>: 1 times of 96 bytes message will be sent to 1.2.3.4[4500] vpnracoon[10077] <Debug>: sendto Information notify. vpnracoon[10077] <Notice>: IKE Packet: transmit success. (Information message). vpnracoon[10077] <Debug>: IV freed vpnracoon[10077] <Notice>: IKEv1 Information-Notice: transmit success. (ISAKMP-SA). vpnracoon[10077] <Notice>: IKE Packet: receive failed. (Initiator, Main-Mode Message 6). vpnracoon[10077] <Debug>: received disconnect command on vpn control socket. vpnracoon[10077] <Notice>: IPSec disconnecting from server 1.2.3.4 vpnracoon[10077] <Debug>: already stopped ike_session_stopped_by_controller. vpnracoon[10077] <Debug>: already stopped ike_session_stopped_by_controller. vpnracoon[10077] <Debug>: already stopped ike_session_stopped_by_controller. vpnracoon[10077] <Debug>: already stopped ike_session_stopped_by_controller. vpnracoon[10077] <Debug>: already stopped ike_session_stopped_by_controller. vpnracoon[10077] <Debug>: already stopped ike_session_stopped_by_controller. vpnracoon[10077] <Debug>: already stopped ike_session_stopped_by_controller. vpnracoon[10077] <Debug>: already stopped ike_session_stopped_by_controller. vpnracoon[10077] <Debug>: already stopped ike_session_stopped_by_controller. vpnracoon[10077] <Debug>: already stopped ike_session_stopped_by_controller. vpnracoon[10077] <Debug>: already stopped ike_session_stopped_by_controller. vpnracoon[10077] <Debug>: already stopped ike_session_stopped_by_controller. vpnracoon[10077] <Debug>: already stopped ike_session_stopped_by_controller. vpnracoon[10077] <Debug>: already stopped ike_session_stopped_by_controller. vpnracoon[10077] <Debug>: already stopped ike_session_stopped_by_controller. vpnracoon[10077] <Debug>: already stopped ike_session_stopped_by_controller. vpnracoon[10077] <Debug>: already stopped ike_session_stopped_by_controller. vpnracoon[10077] <Debug>: already stopped ike_session_stopped_by_controller. vpnracoon[10077] <Debug>: already stopped ike_session_stopped_by_controller. vpnracoon[10077] <Debug>: already stopped ike_session_stopped_by_controller. vpnracoon[10077] <Debug>: already stopped ike_session_stopped_by_controller. vpnracoon[10077] <Debug>: already stopped ike_session_stopped_by_controller. vpnracoon[10077] <Debug>: already stopped ike_session_stopped_by_controller. vpnracoon[10077] <Debug>: already stopped ike_session_stopped_by_controller. vpnracoon[10077] <Debug>: already stopped ike_session_stopped_by_controller. vpnracoon[10077] <Debug>: already stopped ike_session_stopped_by_controller. vpnracoon[10077] <Debug>: already stopped ike_session_stopped_by_controller. vpnracoon[10077] <Debug>: already stopped ike_session_stopped_by_controller. vpnracoon[10077] <Debug>: already stopped ike_session_stopped_by_controller. vpnracoon[10077] <Debug>: already stopped ike_session_stopped_by_controller. vpnracoon[10077] <Debug>: already stopped ike_session_stopped_by_controller. vpnracoon[10077] <Debug>: already stopped ike_session_stopped_by_controller. vpnracoon[10077] <Debug>: already stopped ike_session_stopped_by_controller. vpnracoon[10077] <Debug>: already stopped ike_session_stopped_by_controller. vpnracoon[10077] <Debug>: already stopped ike_session_stopped_by_controller. vpnracoon[10077] <Debug>: already stopped ike_session_stopped_by_controller. vpnracoon[10077] <Debug>: in ike_session_purgephXbydstaddrwop... purging Phase 1 and related Phase 2 structures vpnracoon[10077] <Info>: ISAKMP-SA expired 10.143.187.41[4500]-1.2.3.4[4500] spi:25fdff6c38a3a9c8:8a5d06340be69dad vpnracoon[10077] <Debug>: ****** state changed to: Phase 1 expired vpnracoon[10077] <Debug>: no ph1bind replacement found. NULL ph1. vpnracoon[10077] <Error>: failed to send vpn_control message: Broken pipe vpnracoon[10077] <Debug>: ==== Got usr1 signal - re-parsing configuration. vpnracoon[10077] <Debug>: ==== flush negotiating sessions. vpnracoon[10077] <Debug>: flushing ph2 handles: ignore_estab_or_assert 1... vpnracoon[10077] <Debug>: Flushing Phase 1 handles: ignore_estab_or_assert 1... vpnracoon[10077] <Debug>: already stopped ike_session_stopped_by_controller. vpnracoon[10077] <Notice>: Disconnecting. (Connection tried to negotiate for, 0.325792 seconds). vpnracoon[10077] <Notice>: IKE Packets Receive Failure-Rate Statistic. (Failure-Rate = 50.000). vpnracoon[10077] <Notice>: IKE Phase 1 Authentication Failure-Rate Statistic. (Failure-Rate = 100.000). vpnracoon[10077] <Debug>: Freeing IKE-Session to 1.2.3.4[4500]. vpnracoon[10077] <Debug>: IV freed vpnracoon[10077] <Debug>: ===== parsing configuration vpnracoon[10077] <Debug>: reading configuration file /etc/racoon/racoon.conf vpnracoon[10077] <Debug>: lifetime = 60 vpnracoon[10077] <Debug>: lifebyte = 0 vpnracoon[10077] <Debug>: encklen=0 vpnracoon[10077] <Debug>: p:1 t:1 vpnracoon[10077] <Debug>: 3DES-CBC(5) vpnracoon[10077] <Debug>: SHA(2) vpnracoon[10077] <Debug>: 1024-bit MODP group(2) vpnracoon[10077] <Debug>: pre-shared key(1) vpnracoon[10077] <Debug>: vpnracoon[10077] <Debug>: hmac(modp1024) vpnracoon[10077] <Debug>: filename: /var/run/racoon/*.conf vpnracoon[10077] <Debug>: reading configuration file /var/run/racoon/fda5:b218:a5c6:dd50:3d18:a795:18af:61bd.conf vpnracoon[10077] <Debug>: lifetime = 900 vpnracoon[10077] <Debug>: lifebyte = 0 vpnracoon[10077] <Debug>: encklen=128 vpnracoon[10077] <Debug>: p:1 t:1 vpnracoon[10077] <Debug>: AES-CBC(7) vpnracoon[10077] <Debug>: SHA256(4) vpnracoon[10077] <Debug>: 1024-bit MODP group(2) vpnracoon[10077] <Debug>: pre-shared key(1) vpnracoon[10077] <Debug>: vpnracoon[10077] <Debug>: lifetime = 900 vpnracoon[10077] <Debug>: lifebyte = 0 vpnracoon[10077] <Debug>: encklen=128 vpnracoon[10077] <Debug>: p:1 t:2 vpnracoon[10077] <Debug>: AES-CBC(7) vpnracoon[10077] <Debug>: SHA(2) vpnracoon[10077] <Debug>: 1024-bit MODP group(2) vpnracoon[10077] <Debug>: pre-shared key(1) vpnracoon[10077] <Debug>: vpnracoon[10077] <Debug>: hmac(modp1024) vpnracoon[10077] <Debug>: parse succeeded. vpnracoon[10077] <Info>: caught signal 13 vpnracoon[10077] <Debug>: @@@@@@ data from readmsg: vpnracoon[10077] <Debug>: @@@@@@ data from readmsg: vpnracoon[10077] <Debug>: 92 bytes message received from 1.2.3.4[4500] to 10.143.187.41[4500] vpnracoon[10077] <Debug>: start search for IKE-Session. target 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 1. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: start search for IKE-Session. target 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 1. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: still search for IKE-Session. this 1.2.3.4[4500]. vpnracoon[10077] <Debug>: still searching. skipping... session to 1.2.3.4[4500] is already stopped, active ph1 0 ph2 0. vpnracoon[10077] <Debug>: New IKE-Session to 1.2.3.4[4500]. vpnracoon[10077] <Notice>: Connecting. vpnracoon[10077] <Error>: mode config 6 from 1.2.3.4[4500], but we have no ISAKMP-SA. vpnracoon[10077] <Debug>: vpn_control socket closed by peer. vpnracoon[10077] <Debug>: received disconnect all command. vpnracoon[10077] <Notice>: IPSec disconnecting from server 1.2.3.4
#8 Updated by Tobias Brunner over 9 years ago
vpnracoon[10077] <Error>: Error evaluating certificate. vpnracoon[10077] <Debug>: eval result = kSecTrustResultRecoverableTrustFailure. vpnracoon[10077] <Error>: ---------------Returned error strings: ---------------. vpnracoon[10077] <Error>: -----------------------------------------------------. vpnracoon[10077] <Error>: the peer's certificate is not verified. vpnracoon[10077] <Notice>: IKEv1 Phase 1 AUTH: failed. (Initiator, Main-Mode Message 6). vpnracoon[10077] <Debug>: sending vpn_control ike failed message - code=22 from=local.
Your client log says it all!