[strongSwan] Strongswan in vmware

Mon Jul 19 20:05:51 CEST 2010

I believe there is a timing issue, and the extra debug statements slow
it down enough to fix it.

Below is the ipsec statusall when plutodebug=controlmore
It is stuck on STATE_QUICK_I1

000 Status of IKEv1 pluto daemon (strongSwan 4.3.6):
000 interface lo/lo 127.0.0.1:500
000 interface eth0/eth0 192.168.6.82:500
000 interface eth1/eth1 192.168.99.128:500
000 %myid = '%any'
000 loaded plugins: aes des sha1 sha2 md5 random x509 pubkey pkcs1 pgp
dnskey pem hmac gmp 
000 debug options: controlmore
000 
000 "home": 192.168.6.82[C=US, ST=Arizona, L=Scottsdale, O=General,
OU=Devices, OU=HAP, OU=hapr4, OU=VPN,
CN=haphvpn_guest1]...192.168.6.20[CN=192.168.6.20]===0.0.0.0/0;
unrouted; eroute owner: #0
000 "home":   CAs: "DC=local, DC=hapess, CN=NetworkCA"...%any
000 "home":   ike_life: 3600s; ipsec_life: 1200s; rekey_margin: 3s;
rekey_fuzz: 100%; keyingtries: 3
000 "home":   dpd_action: clear; dpd_delay: 30s; dpd_timeout: 20s;
000 "home":   policy: PUBKEY+ENCRYPT+TUNNEL+PFS+UP; prio: 32,0;
interface: eth0; 
000 "home":   newest ISAKMP SA: #1; newest IPsec SA: #0; 
000 "home":   IKE proposal: AES_CBC_256/HMAC_SHA1/MODP_1536
000 
000 #2: "home" STATE_QUICK_I1 (sent QI1, expecting QR1);
EVENT_RETRANSMIT in 5s
000 #1: "home" STATE_MAIN_I4 (ISAKMP SA established); EVENT_SA_REPLACE
in 3530s; newest ISAKMP; DPD active

And if all I do is change the parameter to plutodebug=raw I get the
following successful status

000 Status of IKEv1 pluto daemon (strongSwan 4.3.6):
000 interface lo/lo 127.0.0.1:500
000 interface eth0/eth0 192.168.6.82:500
000 interface eth1/eth1 192.168.99.128:500
000 %myid = '%any'
000 loaded plugins: aes des sha1 sha2 md5 random x509 pubkey pkcs1 pgp
dnskey pem hmac gmp 
000 debug options: raw
000 
000 "home": 192.168.6.82[C=US, ST=Arizona, L=Scottsdale, O=General,
OU=Devices, OU=HAP, OU=hapr4, OU=VPN,
CN=haphvpn_guest1]...192.168.6.20[CN=192.168.6.20]===0.0.0.0/0; erouted;
eroute owner: #2
000 "home":   CAs: "DC=local, DC=hapess, CN=NetworkCA"...%any
000 "home":   ike_life: 3600s; ipsec_life: 1200s; rekey_margin: 3s;
rekey_fuzz: 100%; keyingtries: 3
000 "home":   dpd_action: clear; dpd_delay: 30s; dpd_timeout: 20s;
000 "home":   policy: PUBKEY+ENCRYPT+TUNNEL+PFS+UP; prio: 32,0;
interface: eth0; 
000 "home":   newest ISAKMP SA: #1; newest IPsec SA: #2; 
000 "home":   IKE proposal: AES_CBC_256/HMAC_SHA1/MODP_1536
000 "home":   ESP proposal: AES_CBC_256/HMAC_SHA1/<Phase1>
000 
000 #2: "home" STATE_QUICK_I2 (sent QI2, IPsec SA established);
EVENT_SA_REPLACE in 1021s; newest IPSEC; eroute owner
000 #2: "home" esp.b11b7fa8 at 192.168.6.20 (0 bytes)
esp.2fe6ef27 at 192.168.6.82 (0 bytes); tunnel
000 #1: "home" STATE_MAIN_I4 (ISAKMP SA established); EVENT_SA_REPLACE
in 3421s; newest ISAKMP; DPD active

The log for when the parameter plutodebug=controlmore is shown below

Jul 19 13:06:32 localhost ipsec_starter[10652]: Starting strongSwan
4.3.6 IPsec [starter]...
Jul 19 13:06:32 localhost pluto[10661]: Starting IKEv1 pluto daemon
(strongSwan 4.3.6) THREADS VENDORID
Jul 19 13:06:32 localhost pluto[10661]: loaded plugins: aes des sha1
sha2 md5 random x509 pubkey pkcs1 pgp dnskey pem hmac gmp  
Jul 19 13:06:32 localhost pluto[10661]:   including NAT-Traversal patch
(Version 0.6c) [disabled]
Jul 19 13:06:32 localhost pluto[10661]: Using Linux 2.6 IPsec interface
code
Jul 19 13:06:32 localhost ipsec_starter[10660]: pluto (10661) started
after 20 ms
Jul 19 13:06:32 localhost pluto[10661]: loading ca certificates from
'/etc/ipsec.d/cacerts' 
Jul 19 13:06:32 localhost pluto[10661]:   loaded ca certificate from
'/etc/ipsec.d/cacerts/netca_haphvpn_guest1_cert.pem'
Jul 19 13:06:32 localhost pluto[10661]:   loaded ca certificate from
'/etc/ipsec.d/cacerts/essca_cert.pem'
Jul 19 13:06:32 localhost pluto[10661]: loading aa certificates from
'/etc/ipsec.d/aacerts' 
Jul 19 13:06:32 localhost pluto[10661]: loading ocsp certificates from
'/etc/ipsec.d/ocspcerts' 
Jul 19 13:06:32 localhost pluto[10661]: Changing to directory
'/etc/ipsec.d/crls'
Jul 19 13:06:32 localhost pluto[10661]: loading attribute certificates
from '/etc/ipsec.d/acerts' 
Jul 19 13:06:32 localhost pluto[10661]: listening for IKE messages
Jul 19 13:06:32 localhost pluto[10661]: adding interface eth1/eth1
192.168.99.128:500
Jul 19 13:06:32 localhost pluto[10661]: adding interface eth0/eth0
192.168.6.82:500
Jul 19 13:06:32 localhost pluto[10661]: adding interface lo/lo
127.0.0.1:500
Jul 19 13:06:32 localhost pluto[10661]: loading secrets from
"/etc/ipsec.secrets"
Jul 19 13:06:32 localhost pluto[10661]:   loaded private key from
'hapavpn_key.pem'
Jul 19 13:06:32 localhost pluto[10661]:   loaded host certificate from
'/etc/ipsec.d/certs/hapavpn_cert.pem'
Jul 19 13:06:32 localhost pluto[10661]:   id '%any' not confirmed by
certificate, defaulting to 'C=US, ST=Arizona, L=Scottsdale, O=General,
OU=Devices, OU=HAP, OU=hapr4, OU=VPN, CN=haphvpn_guest1'
Jul 19 13:06:32 localhost pluto[10661]: added connection description
"home"
Jul 19 13:06:32 localhost pluto[10661]: "home" #1: initiating Main Mode
Jul 19 13:06:32 localhost pluto[10661]: "home" #1: ignoring Vendor ID
payload [FRAGMENTATION c0000000]
Jul 19 13:06:32 localhost pluto[10661]: "home" #1: ignoring Vendor ID
payload [Cisco-Unity]
Jul 19 13:06:32 localhost pluto[10661]: "home" #1: received Vendor ID
payload [XAUTH]
Jul 19 13:06:32 localhost pluto[10661]: "home" #1: ignoring Vendor ID
payload [c61dbb7cb3fd45447ea497fb467dfc88]
Jul 19 13:06:32 localhost pluto[10661]: "home" #1: ignoring Vendor ID
payload [Cisco VPN 3000 Series]
Jul 19 13:06:32 localhost pluto[10661]: "home" #1: we have a cert and
are sending it upon request
Jul 19 13:06:33 localhost pluto[10661]: "home" #1: received Vendor ID
payload [Dead Peer Detection]
Jul 19 13:06:33 localhost pluto[10661]: "home" #1: Peer ID is
ID_DER_ASN1_DN: 'CN=192.168.6.20'
Jul 19 13:06:33 localhost pluto[10661]: "home" #1: crl not found
Jul 19 13:06:33 localhost pluto[10661]: "home" #1: certificate status
unknown
Jul 19 13:06:33 localhost pluto[10661]: "home" #1: ISAKMP SA established
Jul 19 13:06:33 localhost pluto[10661]: "home" #2: initiating Quick Mode
PUBKEY+ENCRYPT+TUNNEL+PFS+UP {using isakmp#1}

And the last messages in the log when plutodebug=raw are

Jul 19 13:02:55 localhost pluto[10458]: "home" #1: ISAKMP SA established
Jul 19 13:02:55 localhost pluto[10458]: "home" #2: initiating Quick Mode
PUBKEY+ENCRYPT+TUNNEL+PFS+UP {using isakmp#1}
Jul 19 13:02:55 localhost pluto[10458]: | size of DH secret exponent:
1534 bits 
Jul 19 13:02:55 localhost pluto[10458]: "home" #2: Dead Peer Detection
(RFC 3706) enabled
Jul 19 13:02:55 localhost pluto[10458]: "home" #2: sent QI2, IPsec SA
established {ESP=>0xb11b7fa8 <0x2fe6ef27}

Mark

-----Original Message-----
From: Thomas Jarosch [mailto:thomas.jarosch at intra2net.com] 
Sent: Monday, July 19, 2010 12:16 AM
To: users at lists.strongswan.org
Cc: Andreas Steffen; Marwil, Mark-P63354
Subject: Re: [strongSwan] Strongswan in vmware

On Friday, 16. July 2010 20:43:39 Andreas Steffen wrote:
> the debugging level shouldn't have any influence at all with
> the establishment of the tunnel.

May be a timing issue? The debug stuff usually slows down things a lot.

Cheers,
Thomas