[Openswan Users] pluto crashes (OS:2.6.31 / K:2.6.35-4)

Francis GASCHET fg at numlog.fr
Wed Dec 8 09:30:26 EST 2010


Hello,

We try to upgrade our VPN gateway with OpenSwan 2.6.31 / Kernel 2.6.35.4

The README says :
> To use the Openswan KLIPS IPsec stack (ipsec0 devices) for Linux
> Kernels 2.6.23 and higher, the following steps should work.  From the
> openswan directory:
>
>     make programs
>     make KERNELSRC=/lib/modules/`uname -r`/build module
>     sudo make KERNELSRC=/lib/modules/`uname -r`/build install minstall
So i didn't applied any patch. But nevertheless there is a directory 
patches/kernel/2.6.35 in the tree, which contains the SAref patch....
When I start IPSEC I get that in the log:

With MAST:

> Dec  8 09:37:21 fw1 ipsec__plutorun: Starting Pluto subsystem...
> Dec  8 09:37:21 fw1 pluto[5607]: Starting Pluto (Openswan Version 
> 2.6.31; Vendor ID OE}GnD\177ZAYe[) pid:5607
> Dec  8 09:37:21 fw1 pluto[5607]: LEAK_DETECTIVE support [enabled]
> Dec  8 09:37:21 fw1 pluto[5607]: SAref support [disabled]: Protocol 
> not available
> Dec  8 09:37:21 fw1 pluto[5607]: SAbind support [disabled]: Protocol 
> not available
> Dec  8 09:37:21 fw1 pluto[5607]: NSS support [disabled]
> Dec  8 09:37:21 fw1 pluto[5607]: HAVE_STATSD notification support not 
> compiled in
> Dec  8 09:37:21 fw1 pluto[5607]: Setting NAT-Traversal port-4500 
> floating to on
> Dec  8 09:37:21 fw1 pluto[5607]:    port floating activation criteria 
> nat_t=1/port_float=1
> Dec  8 09:37:21 fw1 pluto[5607]:    NAT-Traversal support  [enabled]
> Dec  8 09:37:21 fw1 pluto[5607]: using /dev/urandom as source of 
> random entropy
> Dec  8 09:37:21 fw1 pluto[5607]: ike_alg_register_enc(): Activating 
> OAKLEY_TWOFISH_CBC_SSH: Ok (ret=0)
> Dec  8 09:37:21 fw1 pluto[5607]: ike_alg_register_enc(): Activating 
> OAKLEY_TWOFISH_CBC: Ok (ret=0)
> Dec  8 09:37:21 fw1 pluto[5607]: ike_alg_register_enc(): Activating 
> OAKLEY_SERPENT_CBC: Ok (ret=0)
> Dec  8 09:37:21 fw1 pluto[5607]: ike_alg_register_enc(): Activating 
> OAKLEY_AES_CBC: Ok (ret=0)
> Dec  8 09:37:21 fw1 pluto[5607]: ike_alg_register_enc(): Activating 
> OAKLEY_BLOWFISH_CBC: Ok (ret=0)
> Dec  8 09:37:21 fw1 pluto[5607]: ike_alg_register_hash(): Activating 
> OAKLEY_SHA2_512: Ok (ret=0)
> Dec  8 09:37:21 fw1 pluto[5607]: ike_alg_register_hash(): Activating 
> OAKLEY_SHA2_256: Ok (ret=0)
> Dec  8 09:37:21 fw1 pluto[5607]: no helpers will be started, all 
> cryptographic operations will be done inline
> Dec  8 09:37:21 fw1 pluto[5607]: Kernel interface auto-pick
> Dec  8 09:37:21 fw1 pluto[5607]: No Kernel NETKEY interface detected
> Dec  8 09:37:21 fw1 pluto[5607]: Using KLIPSng (mast) IPsec interface 
> code on 2.6.35.4-nml

......

Then, it loads the (100+) connections.
At the same time it receives Main mode requests from the other side and 
negotiate it:
> Dec  8 09:38:07 fw1 pluto[9521]: "fw_mcz" #1: responding to Main Mode
> Dec  8 09:38:07 fw1 pluto[9521]: "fw_mcz" #1: transition from state 
> STATE_MAIN_R0 to state STATE_MAIN_R1
> Dec  8 09:38:07 fw1 pluto[9521]: "fw_mcz" #1: STATE_MAIN_R1: sent MR1, 
> expecting MI2
> Dec  8 09:38:07 fw1 pluto[9521]: "fw_mcz" #1: NAT-Traversal: Result 
> using draft-ietf-ipsec-nat-t-ike-02/03: no NAT detected
> Dec  8 09:38:07 fw1 pluto[9521]: "fw_mcz" #1: transition from state 
> STATE_MAIN_R1 to state STATE_MAIN_R2
> Dec  8 09:38:07 fw1 pluto[9521]: "fw_mcz" #1: STATE_MAIN_R2: sent MR2, 
> expecting MI3
> Dec  8 09:38:07 fw1 pluto[9521]: | mast_shunt_eroute called op=1/add
> Dec  8 09:38:07 fw1 pluto[9521]: "fw_mcz" #1: Main mode peer ID is 
> ID_DER_ASN1_DN: 'C=FR, O=ALPH-X, OU=Marchezais, CN=Passerelle VPN'
> Dec  8 09:38:07 fw1 pluto[9521]: "fw_mcz" #1: crl update for "C=FR, 
> O=NUMLOG, OU=CA Trust center, CN=NUMLOG CA Root, 
> E=support.vpn at numlog.fr" is overdue since Apr 07 23:00:07 UTC 2010Dec  
> 8 09:38:07 fw1 pluto[9521]: "fw_mcz" #1: I am sending my cert
> Dec  8 09:38:07 fw1 pluto[9521]: "fw_mcz" #1: transition from state 
> STATE_MAIN_R2 to state STATE_MAIN_R3
> Dec  8 09:38:07 fw1 pluto[9521]: "fw_mcz" #1: STATE_MAIN_R3: sent MR3, 
> ISAKMP SA established {auth=OAKLEY_RSA_SIG cipher=aes_128 
> prf=oakley_sha group=modp1536}
> Dec  8 09:38:07 fw1 pluto[9521]: "fw_mcz" #1: Dead Peer Detection (RFC 
> 3706): enabled
> Dec  8 09:38:07 fw1 pluto[9521]: | mast_shunt_eroute called op=1/add
> Dec  8 09:38:08 fw1 pluto[9521]: "fw_mcz" #1: the peer proposed: 
> 192.168.13.0/24:0/0 -> 192.168.255.110/32:0/0
> Dec  8 09:38:08 fw1 pluto[9521]: "fw_mcz" #2: responding to Quick Mode 
> proposal {msgid:d7d91ac0}
> Dec  8 09:38:08 fw1 pluto[9521]: "fw_mcz" #2:     us: 
> 192.168.13.0/24===83.167.148.245[C=FR, O=NUMLOG, OU=Internet, CN=VPN 
> SERVER,+S=C]
> Dec  8 09:38:08 fw1 pluto[9521]: "fw_mcz" #2:   them: 
> 83.167.148.123<83.167.148.123>[C=FR, O=ALPH-X, OU=Marchezais, 
> CN=Passerelle VPN,+S=C]===192.168.255.110/32
> Dec  8 09:38:08 fw1 pluto[9521]: | mast_raw_eroute called op=4 
> said=tun.1002 at 83.167.148.245
> Dec  8 09:38:08 fw1 pluto[9521]: "fw_mcz" #2: transition from state 
> STATE_QUICK_R0 to state STATE_QUICK_R1
> Dec  8 09:38:08 fw1 pluto[9521]: "fw_mcz" #2: STATE_QUICK_R1: sent 
> QR1, inbound IPsec SA installed, expecting QI2
> Dec  8 09:38:08 fw1 pluto[9521]: "fw_mcz" #1: the peer proposed: 
> 192.168.13.0/24:0/0 -> 192.168.20.108/30:0/0
....
> Dec  8 09:38:08 fw1 pluto[9521]: "fw_mcz" #2: spdadd-client output: 
> SAref table initialisation left to third party
> Dec  8 09:38:08 fw1 pluto[9521]: "fw_mcz" #2: spdadd-client output: 
> SAref tracking left to third party
> Dec  8 09:38:08 fw1 pluto[9521]: "fw_mcz" #2: Dead Peer Detection (RFC 
> 3706): enabled
> Dec  8 09:38:08 fw1 pluto[9521]: "fw_mcz" #2: transition from state 
> STATE_QUICK_R1 to state STATE_QUICK_R2
> Dec  8 09:38:08 fw1 pluto[9521]: "fw_mcz" #2: STATE_QUICK_R2: IPsec SA 
> established tunnel mode {ESP=>0x65ee429e <0x05f417b4 
> xfrm=AES_128-HMAC_SHA1 IPCOMP=>0x00007856 <0x00003a17 NATOA=none 
> NATD=none DPD=enabl}

SAref ??? Should i install the patch?

Then later, it tries to initiate Quick mode and it produces an 
"ASSERTION FAILED":
> Dec  8 09:38:30 fw1 pluto[9521]: "fw_mcz" #31: initiating Quick Mode 
> RSASIG+ENCRYPT+COMPRESS+TUNNEL+PFS+UP+IKEv2ALLOW {using isakmp#1 
> msgid:c871de7e proposal=AES(12)_256-SHA1(2)_160, 
> AES(12)_128-SHA1(2)_160, 3DES(3)_192-SHA1(2)_160, 
> 3DES(3)_192-MD5(1)_128 pfsgroup=OAKLEY_GROUP_MODP1536}
> Dec  8 09:38:30 fw1 pluto[9521]: "fw_mcz" #31: ASSERTION FAILED at 
> /usr/src/openswan-2.6.31/lib/libopenswan/alloc.c:135: p->i.magic == 
> LEAK_MAGIC
> Dec  8 09:38:30 fw1 pluto[9521]: "fw_mcz" #31: using kernel interface: 
> mast
> Dec  8 09:38:30 fw1 pluto[9521]: "fw_mcz" #31: interface mast0/eth0 
> 192.168.13.251
> Dec  8 09:38:30 fw1 pluto[9521]: "fw_mcz" #31: interface mast0/eth0 
> 192.168.13.251
> Dec  8 09:38:30 fw1 pluto[9521]: "fw_mcz" #31: interface mast0/eth0:0 
> 192.168.13.254
> Dec  8 09:38:30 fw1 pluto[9521]: "fw_mcz" #31: interface mast0/eth0:0 
> 192.168.13.254
> Dec  8 09:38:30 fw1 pluto[9521]: "fw_mcz" #31: interface mast0/eth3 
> 192.168.255.21
> Dec  8 09:38:30 fw1 pluto[9521]: "fw_mcz" #31: interface mast0/eth3 
> 192.168.255.21
> Dec  8 09:38:30 fw1 pluto[9521]: "fw_mcz" #31: interface mast0/eth3:0 
> 194.98.81.41
> Dec  8 09:38:30 fw1 pluto[9521]: "fw_mcz" #31: interface mast0/eth3:0 
> 194.98.81.41
> Dec  8 09:38:30 fw1 pluto[9521]: "fw_mcz" #31: interface mast0/eth3:1 
> 192.168.255.6
> Dec  8 09:38:30 fw1 pluto[9521]: "fw_mcz" #31: interface mast0/eth3:1 
> 192.168.255.6
> Dec  8 09:38:30 fw1 pluto[9521]: "fw_mcz" #31: interface mast0/eth4 
> 192.168.20.1
> Dec  8 09:38:30 fw1 pluto[9521]: "fw_mcz" #31: interface mast0/eth4 
> 192.168.20.1
> Dec  8 09:38:30 fw1 pluto[9521]: "fw_mcz" #31: interface mast0/tapnet 
> 83.167.148.245
> Dec  8 09:38:30 fw1 pluto[9521]: "fw_mcz" #31: interface mast0/tapnet 
> 83.167.148.245
> Dec  8 09:38:30 fw1 pluto[9521]: "fw_mcz" #31: interface 
> mast0/tapnet:0 83.167.148.127
> Dec  8 09:38:30 fw1 pluto[9521]: "fw_mcz" #31: interface 
> mast0/tapnet:0 83.167.148.127
> Dec  8 09:38:30 fw1 pluto[9521]: "fw_mcz" #31: %myid = (none)Dec  8 
> 09:38:30 fw1 pluto[9521]: "fw_mcz" #31: debug none
> Dec  8 09:38:30 fw1 pluto[9521]: "fw_mcz" #31:
> Dec  8 09:38:30 fw1 pluto[9521]: "fw_mcz" #31: virtual_private (%priv):
> Dec  8 09:38:30 fw1 pluto[9521]: "fw_mcz" #31: - allowed 3 subnets: 
> 10.0.0.0/8, 192.168.0.0/16, 172.16.0.0/12
> Dec  8 09:38:30 fw1 pluto[9521]: "fw_mcz" #31: - disallowed 1 subnet: 
> 192.168.13.0/24
> Dec  8 09:38:30 fw1 pluto[9521]: "fw_mcz" #31:
> Dec  8 09:38:30 fw1 pluto[9521]: "fw_mcz" #31: algorithm ESP encrypt: 
> id=3, name=ESP_3DES, ivlen=64, keysizemin=192, keysizemax=192
> Dec  8 09:38:30 fw1 pluto[9521]: "fw_mcz" #31: algorithm ESP encrypt: 
> id=12, name=ESP_AES, ivlen=128, keysizemin=128, keysizemax=256
> Dec  8 09:38:30 fw1 pluto[9521]: "fw_mcz" #31: algorithm ESP auth 
> attr: id=1, name=AUTH_ALGORITHM_HMAC_MD5, keysizemin=128, keysizemax=128
> Dec  8 09:38:30 fw1 pluto[9521]: "fw_mcz" #31: algorithm ESP auth 
> attr: id=2, name=AUTH_ALGORITHM_HMAC_SHA1, keysizemin=160, keysizemax=160
> Dec  8 09:38:30 fw1 pluto[9521]: "fw_mcz" #31:
> Dec  8 09:38:30 fw1 pluto[9521]: "fw_mcz" #31: algorithm IKE encrypt: 
> id=3, name=OAKLEY_BLOWFISH_CBC, blocksize=8, keydeflen=128
> Dec  8 09:38:30 fw1 pluto[9521]: "fw_mcz" #31: algorithm IKE encrypt: 
> id=5, name=OAKLEY_3DES_CBC, blocksize=8, keydeflen=192
> Dec  8 09:38:30 fw1 pluto[9521]: "fw_mcz" #31: algorithm IKE encrypt: 
> id=7, name=OAKLEY_AES_CBC, blocksize=16, keydeflen=128
> Dec  8 09:38:30 fw1 pluto[9521]: "fw_mcz" #31: algorithm IKE encrypt: 
> id=65004, name=OAKLEY_SERPENT_CBC, blocksize=16, keydeflen=128
> Dec  8 09:38:30 fw1 pluto[9521]: "fw_mcz" #31: algorithm IKE encrypt: 
> id=65005, name=OAKLEY_TWOFISH_CBC, blocksize=16, keydeflen=128
> Dec  8 09:38:30 fw1 pluto[9521]: "fw_mcz" #31: algorithm IKE encrypt: 
> id=65289, name=OAKLEY_TWOFISH_CBC_SSH, blocksize=16, keydeflen=128
> Dec  8 09:38:30 fw1 pluto[9521]: "fw_mcz" #31: algorithm IKE hash: 
> id=1, name=OAKLEY_MD5, hashsize=16
> Dec  8 09:38:30 fw1 pluto[9521]: "fw_mcz" #31: algorithm IKE hash: 
> id=2, name=OAKLEY_SHA1, hashsize=20
> Dec  8 09:38:30 fw1 pluto[9521]: "fw_mcz" #31: algorithm IKE hash: 
> id=4, name=OAKLEY_SHA2_256, hashsize=32
> Dec  8 09:38:30 fw1 pluto[9521]: "fw_mcz" #31: algorithm IKE hash: 
> id=6, name=OAKLEY_SHA2_512, hashsize=64
> Dec  8 09:38:30 fw1 pluto[9521]: "fw_mcz" #31: algorithm IKE dh group: 
> id=2, name=OAKLEY_GROUP_MODP1024, bits=1024
> Dec  8 09:38:30 fw1 pluto[9521]: "fw_mcz" #31: algorithm IKE dh group: 
> id=5, name=OAKLEY_GROUP_MODP1536, bits=1536
> Dec  8 09:38:30 fw1 pluto[9521]: "fw_mcz" #31: algorithm IKE dh group: 
> id=14, name=OAKLEY_GROUP_MODP2048, bits=2048
> Dec  8 09:38:30 fw1 pluto[9521]: "fw_mcz" #31: algorithm IKE dh group: 
> id=15, name=OAKLEY_GROUP_MODP3072, bits=3072
> Dec  8 09:38:30 fw1 pluto[9521]: "fw_mcz" #31: algorithm IKE dh group: 
> id=16, name=OAKLEY_GROUP_MODP4096, bits=4096
> Dec  8 09:38:30 fw1 pluto[9521]: "fw_mcz" #31: algorithm IKE dh group: 
> id=17, name=OAKLEY_GROUP_MODP6144, bits=6144
> Dec  8 09:38:30 fw1 pluto[9521]: "fw_mcz" #31: algorithm IKE dh group: 
> id=18, name=OAKLEY_GROUP_MODP8192, bits=8192
> Dec  8 09:38:30 fw1 pluto[9521]: "fw_mcz" #31:
> Dec  8 09:38:30 fw1 pluto[9521]: "fw_mcz" #31: stats db_ops: 
> {curr_cnt, total_cnt, maxsz} :context={0,2,36} trans={0,2,72} 
> attrs={0,2,96}
> Dec  8 09:38:30 fw1 pluto[9521]: "fw_mcz" #31:

And then it starts showing all the others connections (like the result 
we get with "ipsec auto --status", but with a double tag:

> Dec  8 09:38:30 fw1 pluto[9521]: "fw_mcz" #31: "enx_2mi": 
> 192.168.13.0/24===83.167.148.245[C=FR, O=NUMLOG, OU=Internet, CN=VPN 
> SERVER,+S=C]...149.6.162.148<149.6.162.148>[C=FR, ST=X, L=X, O=NUMLOG, 
> OU=HEBERGEMENT, CN=ENX VELIZY,+S=C]===81.252.60.16/28; prospective 
> erouted; eroute owner: #0
> Dec  8 09:38:30 fw1 pluto[9521]: "fw_mcz" #31: "enx_2mi":     
> myip=192.168.13.254; hisip=unset; mycert=numlog_VPNSRV.pem;
> Dec  8 09:38:30 fw1 pluto[9521]: "fw_mcz" #31: "enx_2mi":   CAs: 
> 'C=FR, O=NUMLOG, OU=CA Trust center, CN=NUMLOG CA Root, 
> E=support.vpn at numlog.fr'...'%any'
> Dec  8 09:38:30 fw1 pluto[9521]: "fw_mcz" #31: "enx_2mi":   ike_life: 
> 3600s; ipsec_life: 28800s; rekey_margin: 540s; rekey_fuzz: 100%; 
> keyingtries: 0
>
then all the "STATE_QUICK_R2 (IPsec SA established)" lines
and right afterwards:
> Dec  8 09:38:30 fw1 pluto[9521]: "fw_mcz" #31:
> Dec  8 09:38:30 fw1 pluto[9521]: "fw_mcz" #31: ABORT at 
> /usr/src/openswan-2.6.31/lib/libopenswan/alloc.c:135
> Dec  8 09:38:30 fw1 pluto[9521]: "fw_mcz" #31: ABORT at 
> /usr/src/openswan-2.6.31/lib/libopenswan/alloc.c:135
> Dec  8 09:38:50 fw1 ipsec__plutorun: Starting Pluto subsystem...
> Dec  8 09:38:50 fw1 pluto[13416]: Starting Pluto (Openswan Version 
> 2.6.31; Vendor ID OE}GnD\177ZAYe[) pid:13416
> Dec  8 09:38:50 fw1 pluto[13416]: LEAK_DETECTIVE support [enabled]
and so on...


With KLIPS :

> Dec  8 13:49:26 fw1 ipsec__plutorun: Starting Pluto subsystem...
> Dec  8 13:49:26 fw1 pluto[4720]: Starting Pluto (Openswan Version 
> 2.6.31; Vendor ID OE}GnD\177ZAYe[) pid:4720
> Dec  8 13:49:26 fw1 pluto[4720]: LEAK_DETECTIVE support [enabled]
> Dec  8 13:49:26 fw1 pluto[4720]: SAref support [disabled]: Protocol 
> not available
> Dec  8 13:49:26 fw1 pluto[4720]: SAbind support [disabled]: Protocol 
> not available
> Dec  8 13:49:26 fw1 pluto[4720]: NSS support [disabled]
> Dec  8 13:49:26 fw1 pluto[4720]: HAVE_STATSD notification support not 
> compiled in
> Dec  8 13:49:26 fw1 pluto[4720]: Setting NAT-Traversal port-4500 
> floating to on
> Dec  8 13:49:26 fw1 pluto[4720]:    port floating activation criteria 
> nat_t=1/port_float=1
> Dec  8 13:49:26 fw1 pluto[4720]:    NAT-Traversal support  [enabled]
> Dec  8 13:49:26 fw1 pluto[4720]: using /dev/urandom as source of 
> random entropy
> Dec  8 13:49:26 fw1 pluto[4720]: ike_alg_register_enc(): Activating 
> OAKLEY_TWOFISH_CBC_SSH: Ok (ret=0)
> Dec  8 13:49:26 fw1 pluto[4720]: ike_alg_register_enc(): Activating 
> OAKLEY_TWOFISH_CBC: Ok (ret=0)
> Dec  8 13:49:26 fw1 pluto[4720]: ike_alg_register_enc(): Activating 
> OAKLEY_SERPENT_CBC: Ok (ret=0)
> Dec  8 13:49:26 fw1 pluto[4720]: ike_alg_register_enc(): Activating 
> OAKLEY_AES_CBC: Ok (ret=0)
> Dec  8 13:49:26 fw1 pluto[4720]: ike_alg_register_enc(): Activating 
> OAKLEY_BLOWFISH_CBC: Ok (ret=0)
> Dec  8 13:49:26 fw1 pluto[4720]: ike_alg_register_hash(): Activating 
> OAKLEY_SHA2_512: Ok (ret=0)
> Dec  8 13:49:26 fw1 pluto[4720]: ike_alg_register_hash(): Activating 
> OAKLEY_SHA2_256: Ok (ret=0)
> Dec  8 13:49:26 fw1 pluto[4720]: no helpers will be started, all 
> cryptographic operations will be done inline
> Dec  8 13:49:26 fw1 pluto[4720]: Using KLIPS IPsec interface code on 
> 2.6.35.4-nml

Then it loads all the connections and certificates and private key.
then it tries initiating main mode:
> Dec  8 13:49:53 fw1 pluto[4720]: "fw_mcz" #1: initiating Main Mode
> Dec  8 13:49:53 fw1 pluto[4720]: "fw_mcz" #1: received Vendor ID 
> payload [draft-ietf-ipsec-nat-t-ike-03] method set to=108
> Dec  8 13:49:53 fw1 pluto[4720]: "fw_mcz" #1: received Vendor ID 
> payload [Dead Peer Detection]
> Dec  8 13:49:53 fw1 pluto[4720]: "fw_mcz" #1: enabling possible 
> NAT-traversal with method draft-ietf-ipsec-nat-t-ike-05
> Dec  8 13:49:53 fw1 pluto[4720]: "fw_mcz" #1: transition from state 
> STATE_MAIN_I1 to state STATE_MAIN_I2
> Dec  8 13:49:53 fw1 pluto[4720]: "fw_mcz" #1: STATE_MAIN_I2: sent MI2, 
> expecting MR2
> Dec  8 13:49:53 fw1 pluto[4720]: "enx_akka" #2: initiating Main Mode
> Dec  8 13:49:53 fw1 pluto[4720]: "enx_akka" #2: received Vendor ID 
> payload [draft-ietf-ipsec-nat-t-ike-03] method set to=108
> Dec  8 13:49:53 fw1 pluto[4720]: "enx_akka" #2: enabling possible 
> NAT-traversal with method draft-ietf-ipsec-nat-t-ike-05
> Dec  8 13:49:53 fw1 pluto[4720]: "enx_akka" #2: transition from state 
> STATE_MAIN_I1 to state STATE_MAIN_I2
> Dec  8 13:49:53 fw1 pluto[4720]: "enx_akka" #2: STATE_MAIN_I2: sent 
> MI2, expecting MR2
> Dec  8 13:49:53 fw1 pluto[4720]: "fw_mcz" #1: NAT-Traversal: Result 
> using draft-ietf-ipsec-nat-t-ike-02/03: no NAT detected
> Dec  8 13:49:53 fw1 pluto[4720]: "fw_mcz" #1: I am sending my certDec  
> 8 13:49:53 fw1 pluto[4720]: "fw_mcz" #1: transition from state 
> STATE_MAIN_I2 to state STATE_MAIN_I3
> Dec  8 13:49:53 fw1 pluto[4720]: "fw_mcz" #1: STATE_MAIN_I3: sent MI3, 
> expecting MR3
> Dec  8 13:49:53 fw1 pluto[4720]: "enx_akka" #2: NAT-Traversal: Result 
> using draft-ietf-ipsec-nat-t-ike-02/03: no NAT detected
> Dec  8 13:49:53 fw1 pluto[4720]: "enx_akka" #2: I am sending my cert
> Dec  8 13:49:53 fw1 pluto[4720]: "enx_akka" #2: I am sending a 
> certificate request
> Dec  8 13:49:53 fw1 pluto[4720]: "enx_akka" #2: transition from state 
> STATE_MAIN_I2 to state STATE_MAIN_I3
> Dec  8 13:49:53 fw1 pluto[4720]: "enx_akka" #2: STATE_MAIN_I3: sent 
> MI3, expecting MR3
> Dec  8 13:49:53 fw1 pluto[4720]: "enx_akka" #2: Main mode peer ID is 
> ID_DER_ASN1_DN: 'C=FR, O=NUMLOG, OU=Portail, CN=Firewall'
> Dec  8 13:49:53 fw1 pluto[4720]: "enx_akka" #2: crl update for "C=FR, 
> O=NUMLOG, OU=CA Trust center, CN=NUMLOG CA Root, 
> E=support.vpn at numlog.fr" is overdue since Apr 07 23:00:07 UTC 2010
> Dec  8 13:49:53 fw1 pluto[4720]: "enx_akka" #2: transition from state 
> STATE_MAIN_I3 to state STATE_MAIN_I4
> Dec  8 13:49:53 fw1 pluto[4720]: "enx_akka" #2: STATE_MAIN_I4: ISAKMP 
> SA established {auth=OAKLEY_RSA_SIG cipher=aes_128 prf=oakley_sha 
> group=modp2048}
>
Then surprisingly:
> Dec  8 13:49:53 fw1 pluto[4720]: "enx_automotive_plast" #3: initiating 
> Quick Mode RSASIG+ENCRYPT+COMPRESS+TUNNEL+PFS+UP+IKEv2ALLOW {using 
> isakmp#2 msgid:618a856d proposal=AES(12)_256-SHA1(2)_160, 
> AES(12)_128-SHA1(2)_160, 3DES(3)_192-SHA1(2)_160, 
> 3DES(3)_192-MD5(1)_128 pfsgroup=OAKLEY_GROUP_MODP2048}
> Dec  8 13:49:53 fw1 pluto[4720]: "enx_automotive_plast" #3: ASSERTION 
> FAILED at /usr/src/openswan-2.6.31/lib/libopenswan/alloc.c:135: 
> p->i.magic == LEAK_MAGIC
Why initiate Quickmode before Main mode for this connection  ????????
Then:
> Dec  8 13:49:53 fw1 pluto[4720]: "enx_automotive_plast" #3: using 
> kernel interface: klips
> Dec  8 13:49:53 fw1 pluto[4720]: "enx_automotive_plast" #3: interface 
> ipsec0/tapnet 83.167.148.245
> Dec  8 13:49:53 fw1 pluto[4720]: "enx_automotive_plast" #3: interface 
> ipsec0/tapnet 83.167.148.245
> Dec  8 13:49:53 fw1 pluto[4720]: "enx_automotive_plast" #3: %myid = (none)
> Dec  8 13:49:53 fw1 pluto[4720]: "enx_automotive_plast" #3: debug none
> Dec  8 13:49:53 fw1 pluto[4720]: "enx_automotive_plast" #3:
> Dec  8 13:49:53 fw1 pluto[4720]: "enx_automotive_plast" #3: 
> virtual_private (%priv):
> Dec  8 13:49:53 fw1 pluto[4720]: "enx_automotive_plast" #3: - allowed 
> 3 subnets: 10.0.0.0/8, 192.168.0.0/16, 172.16.0.0/12
> Dec  8 13:49:53 fw1 pluto[4720]: "enx_automotive_plast" #3: - 
> disallowed 1 subnet: 192.168.13.0/24
> Dec  8 13:49:53 fw1 pluto[4720]: "enx_automotive_plast" #3:
> Dec  8 13:49:53 fw1 pluto[4720]: "enx_automotive_plast" #3: algorithm 
> ESP encrypt: id=3, name=ESP_3DES, ivlen=64, keysizemin=192, keysizemax=192
> Dec  8 13:49:53 fw1 pluto[4720]: "enx_automotive_plast" #3: algorithm 
> ESP encrypt: id=12, name=ESP_AES, ivlen=128, keysizemin=128, 
> keysizemax=256
> Dec  8 13:49:53 fw1 pluto[4720]: "enx_automotive_plast" #3: algorithm 
> ESP auth attr: id=1, name=AUTH_ALGORITHM_HMAC_MD5, keysizemin=128, 
> keysizemax=128
> Dec  8 13:49:53 fw1 pluto[4720]: "enx_automotive_plast" #3: algorithm 
> ESP auth attr: id=2, name=AUTH_ALGORITHM_HMAC_SHA1, keysizemin=160, 
> keysizemax=160
> Dec  8 13:49:53 fw1 pluto[4720]: "enx_automotive_plast" #3:
> Dec  8 13:49:53 fw1 pluto[4720]: "enx_automotive_plast" #3: algorithm 
> IKE encrypt: id=3, name=OAKLEY_BLOWFISH_CBC, blocksize=8, keydeflen=128
> Dec  8 13:49:53 fw1 pluto[4720]: "enx_automotive_plast" #3: algorithm 
> IKE encrypt: id=5, name=OAKLEY_3DES_CBC, blocksize=8, keydeflen=192
> Dec  8 13:49:53 fw1 pluto[4720]: "enx_automotive_plast" #3: algorithm 
> IKE encrypt: id=7, name=OAKLEY_AES_CBC, blocksize=16, 
> keydeflen=128Dec  8 13:49:53 fw1 pluto[4720]: "enx_automotive_plast" 
> #3: algorithm IKE encrypt: id=65004, name=OAKLEY_SERPENT_CBC, 
> blocksize=16, keydeflen=128
> Dec  8 13:49:53 fw1 pluto[4720]: "enx_automotive_plast" #3: algorithm 
> IKE encrypt: id=65005, name=OAKLEY_TWOFISH_CBC, blocksize=16, 
> keydeflen=128
> Dec  8 13:49:53 fw1 pluto[4720]: "enx_automotive_plast" #3: algorithm 
> IKE encrypt: id=65289, name=OAKLEY_TWOFISH_CBC_SSH, blocksize=16, 
> keydeflen=128
> Dec  8 13:49:53 fw1 pluto[4720]: "enx_automotive_plast" #3: algorithm 
> IKE hash: id=1, name=OAKLEY_MD5, hashsize=16
> Dec  8 13:49:53 fw1 pluto[4720]: "enx_automotive_plast" #3: algorithm 
> IKE hash: id=2, name=OAKLEY_SHA1, hashsize=20
> Dec  8 13:49:53 fw1 pluto[4720]: "enx_automotive_plast" #3: algorithm 
> IKE hash: id=4, name=OAKLEY_SHA2_256, hashsize=32
> Dec  8 13:49:53 fw1 pluto[4720]: "enx_automotive_plast" #3: algorithm 
> IKE hash: id=6, name=OAKLEY_SHA2_512, hashsize=64
> Dec  8 13:49:53 fw1 pluto[4720]: "enx_automotive_plast" #3: algorithm 
> IKE dh group: id=2, name=OAKLEY_GROUP_MODP1024, bits=1024
> Dec  8 13:49:53 fw1 pluto[4720]: "enx_automotive_plast" #3: algorithm 
> IKE dh group: id=5, name=OAKLEY_GROUP_MODP1536, bits=1536
> Dec  8 13:49:53 fw1 pluto[4720]: "enx_automotive_plast" #3: algorithm 
> IKE dh group: id=14, name=OAKLEY_GROUP_MODP2048, bits=2048
> Dec  8 13:49:53 fw1 pluto[4720]: "enx_automotive_plast" #3: algorithm 
> IKE dh group: id=15, name=OAKLEY_GROUP_MODP3072, bits=3072
> Dec  8 13:49:53 fw1 pluto[4720]: "enx_automotive_plast" #3: algorithm 
> IKE dh group: id=16, name=OAKLEY_GROUP_MODP4096, bits=4096
> Dec  8 13:49:53 fw1 pluto[4720]: "enx_automotive_plast" #3: algorithm 
> IKE dh group: id=17, name=OAKLEY_GROUP_MODP6144, bits=6144
> Dec  8 13:49:53 fw1 pluto[4720]: "enx_automotive_plast" #3: algorithm 
> IKE dh group: id=18, name=OAKLEY_GROUP_MODP8192, bits=8192
> Dec  8 13:49:53 fw1 pluto[4720]: "enx_automotive_plast" #3:
> Dec  8 13:49:53 fw1 pluto[4720]: "enx_automotive_plast" #3: stats 
> db_ops: {curr_cnt, total_cnt, maxsz} :context={0,7,36} trans={0,7,72} 
> attrs={0,7,96}
> Dec  8 13:49:53 fw1 pluto[4720]: "enx_automotive_plast" #3:
Then it starts showing the connections with a double tag:
> Dec  8 13:49:53 fw1 pluto[4720]: "enx_automotive_plast" #3: "enx_2mi": 
> 192.168.13.0/24===83.167.148.245[C=FR, O=NUMLOG, OU=Internet, CN=VPN 
> SERVER,+S=C]...149.6.162.148<149.6.162.148>[C=FR, ST=X, L=X, O=NUMLOG, 
> OU=HEBERGEMENT, CN=ENX VELIZY,+S=C]===81.252.60.16/28; prospective 
> erouted; eroute owner: #0
> Dec  8 13:49:53 fw1 pluto[4720]: "enx_automotive_plast" #3: 
> "enx_2mi":     myip=192.168.13.254; hisip=unset; mycert=numlog_VPNSRV.pem;
> Dec  8 13:49:53 fw1 pluto[4720]: "enx_automotive_plast" #3: 
> "enx_2mi":   CAs: 'C=FR, O=NUMLOG, OU=CA Trust center, CN=NUMLOG CA 
> Root, E=support.vpn at numlog.fr'...'%any'
> Dec  8 13:49:53 fw1 pluto[4720]: "enx_automotive_plast" #3: 
> "enx_2mi":   ike_life: 3600s; ipsec_life: 28800s; rekey_margin: 540s; 
> rekey_fuzz: 100%; keyingtries: 0
> Dec  8 13:49:53 fw1 pluto[4720]: "enx_automotive_plast" #3: 
> "enx_2mi":   policy: RSASIG+ENCRYPT+COMPRESS+TUNNEL+PFS+IKEv2ALLOW; 
> prio: 24,28; interface: tapnet;
> Dec  8 13:49:53 fw1 pluto[4720]: "enx_automotive_plast" #3: 
> "enx_2mi":   newest ISAKMP SA: #0; newest IPsec SA: #0;
> Dec  8 13:49:53 fw1 pluto[4720]: "enx_automotive_plast" #3: 
> "enx_2mi":   ESP algorithms wanted: AES(12)_256-SHA1(2)_000, 
> AES(12)_128-SHA1(2)_000, 3DES(3)_000-SHA1(2)_000, 
> 3DES(3)_000-MD5(1)_000; flags=-strict
> Dec  8 13:49:53 fw1 pluto[4720]: "enx_automotive_plast" #3: 
> "enx_2mi":   ESP algorithms loaded: AES(12)_256-SHA1(2)_160, 
> AES(12)_128-SHA1(2)_160, 3DES(3)_192-SHA1(2)_160, 3DES(3)_192-MD5(1)_128
> Dec  8 13:49:53 fw1 pluto[4720]: "enx_automotive_plast" #3: 
> "enx_akka": 192.168.13.0/24===83.167.148.245[C=FR, O=NUMLOG, 
> OU=Internet, CN=VPN SERVER,+S=C]...213.246.46.30<213.246.46.30>[C=FR, 
> O=NUMLOG, OU=Portail, CN=Firewall,+S=C]===194.206.68.48/28; 
> prospective erouted; eroute owner: #0
>
.....

and it finishes with:
> Dec  8 13:49:53 fw1 pluto[4720]: "enx_automotive_plast" #3:
> Dec  8 13:49:53 fw1 pluto[4720]: "enx_automotive_plast" #3: #2: 
> "enx_akka":500 STATE_MAIN_I4 (ISAKMP SA established); EVENT_SA_REPLACE 
> in 2651s; newest ISAKMP; nodpd; idle; import:admin initiate
> Dec  8 13:49:53 fw1 pluto[4720]: "enx_automotive_plast" #3: #2: 
> pending Phase 2 for "enx_automotive_plast" replacing #0
> Dec  8 13:49:53 fw1 pluto[4720]: "enx_automotive_plast" #3: #2: 
> pending Phase 2 for "enx_amstutz" replacing #0
> Dec  8 13:49:53 fw1 pluto[4720]: "enx_automotive_plast" #3: #2: 
> pending Phase 2 for "enx_allevard" replacing #0
> Dec  8 13:49:53 fw1 pluto[4720]: "enx_automotive_plast" #3: #2: 
> pending Phase 2 for "enx_akka" replacing #0
> Dec  8 13:49:53 fw1 pluto[4720]: "enx_automotive_plast" #3: #3: 
> "enx_automotive_plast":500 STATE_QUICK_I1 (sent QI1, expecting QR1); 
> EVENT_SO_DISCARD in 0s; nodpd; idle; import:admin initiate
> Dec  8 13:49:53 fw1 pluto[4720]: "enx_automotive_plast" #3: #1: 
> "fw_mcz":500 STATE_MAIN_I3 (sent MI3, expecting MR3); EVENT_RETRANSMIT 
> in 10s; lastdpd=-1s(seq in:0 out:0); idle; import:admin initiate
> Dec  8 13:49:53 fw1 pluto[4720]: "enx_automotive_plast" #3: #1: 
> pending Phase 2 for "mcz" replacing #0
> Dec  8 13:49:53 fw1 pluto[4720]: "enx_automotive_plast" #3: #1: 
> pending Phase 2 for "fw_mcz" replacing #0
> Dec  8 13:49:53 fw1 pluto[4720]: "enx_automotive_plast" #3:
> Dec  8 13:49:53 fw1 pluto[4720]: "enx_automotive_plast" #3: ABORT at 
> /usr/src/openswan-2.6.31/lib/libopenswan/alloc.c:135
> Dec  8 13:49:53 fw1 pluto[4720]: "enx_automotive_plast" #3: ABORT at 
> /usr/src/openswan-2.6.31/lib/libopenswan/alloc.c:135
> Dec  8 13:50:13 fw1 ipsec__plutorun: Starting Pluto subsystem...
> Dec  8 13:50:13 fw1 pluto[10021]: Starting Pluto (Openswan Version 
> 2.6.31; Vendor ID OE}GnD\177ZAYe[) pid:10021

The same configuration was working smoothly with OpenSwan 2.4.7 and a 
kernel 2.6.17....
 
Is all of that due to the lack of SAref patch ?
How did it work before that patch exists?

Thanks for any help!

Best regards,

-- 
Francis GASCHET / NUMLOG
http://www.numlog.fr
Tel.: +33 (0) 130 791 616
Fax.: +33 (0) 130 819 286




More information about the Users mailing list