Solved: IKE Phase 2 SA expires immediately - site 2 site ipsec over gre

Philippe Latu · ‎12-12-2012

Hello,

I am migration an IPsec site to site VPN config to a new ASR1001 router «facing» a Linux box (ipsec-tools + racoon).

As the Debian Linux does not offer VTI, I am using a crypto map.

The working config is given below with the corresponding logs on the Linux side.

When I try to apply this previously working config to the ASR1001, I get the following error :

000855: *Dec 12 18:28:21.859 UTC: %ACE-3-TRANSERR: IOSXE-ESP(14): IKEA trans 0x1350; opcode 0x60; param 0x2EE; error 0x5; retry cnt 0

Any hint on the error code 0x5 ?

The Linux side logs show timing problems ...

Dec 12 18:50:19 FAKE-AUCH-GW racoon: INFO: initiate new phase 1 negotiation: 194.214.196.2[500]<=>130.120.124.8[500]

Dec 12 18:50:19 FAKE-AUCH-GW racoon: INFO: begin Identity Protection mode.

Dec 12 18:50:19 FAKE-AUCH-GW racoon: INFO: received Vendor ID: CISCO-UNITY

Dec 12 18:50:19 FAKE-AUCH-GW racoon: INFO: received Vendor ID: DPD

Dec 12 18:50:19 FAKE-AUCH-GW racoon: INFO: received Vendor ID: draft-ietf-ipsra-isakmp-xauth-06.txt

Dec 12 18:50:19 FAKE-AUCH-GW racoon: INFO: ISAKMP-SA established 194.214.196.2[500]-130.120.124.8[500] spi:5f8e6339fb954d45:e513d25e42e19d11

Dec 12 18:50:20 FAKE-AUCH-GW racoon: INFO: initiate new phase 2 negotiation: 194.214.196.2[500]<=>130.120.124.8[500]

Dec 12 18:50:39 FAKE-AUCH-GW racoon: INFO: respond new phase 2 negotiation: 194.214.196.2[500]<=>130.120.124.8[500]

Dec 12 18:50:50 FAKE-AUCH-GW racoon: NOTIFY: the packet is retransmitted by 130.120.124.8[500] (1).

Dec 12 18:50:50 FAKE-AUCH-GW racoon: INFO: IPsec-SA expired: ESP/Transport 130.120.124.8[500]->194.214.196.2[500] spi=30866420(0x1d6fbf4)

Dec 12 18:50:50 FAKE-AUCH-GW racoon: WARNING: PF_KEY EXPIRE message received from kernel for SA being negotiated. Stopping negotiation.

Dec 12 18:50:50 FAKE-AUCH-GW racoon: INFO: IPsec-SA expired: AH/Transport 130.120.124.8[500]->194.214.196.2[500] spi=258959(0x3f38f)

Dec 12 18:50:59 FAKE-AUCH-GW racoon: INFO: initiate new phase 2 negotiation: 194.214.196.2[500]<=>130.120.124.8[500]

Dec 12 18:51:00 FAKE-AUCH-GW racoon: NOTIFY: the packet is retransmitted by 130.120.124.8[500] (1).

Dec 12 18:51:09 FAKE-AUCH-GW racoon: INFO: IPsec-SA expired: ESP/Transport 130.120.124.8[500]->194.214.196.2[500] spi=95427747(0x5b01ca3)

Dec 12 18:51:09 FAKE-AUCH-GW racoon: WARNING: PF_KEY EXPIRE message received from kernel for SA being negotiated. Stopping negotiation.

Dec 12 18:51:09 FAKE-AUCH-GW racoon: INFO: IPsec-SA expired: AH/Transport 130.120.124.8[500]->194.214.196.2[500] spi=159198575(0x97d2d6f)

Dec 12 18:51:09 FAKE-AUCH-GW racoon: INFO: respond new phase 2 negotiation: 194.214.196.2[500]<=>130.120.124.8[500]

Dec 12 18:51:10 FAKE-AUCH-GW racoon: NOTIFY: the packet is retransmitted by 130.120.124.8[500] (1).

!###########################################

! IOS Running config

!

crypto isakmp policy 10

encr aes 256

hash md5

authentication pre-share

group 2

crypto isakmp key MY-0WN-T3RR1F1C-PR35H4R3D-K3Y address 192.0.2.66 no-xauth

!

crypto ipsec transform-set MY-0WN-TS-MD5 ah-md5-hmac esp-aes 256 esp-md5-hmac

mode transport

!

crypto map MY-0WN-MAP 1 ipsec-isakmp

set peer 192.0.2.66

set transform-set MY-0WN-TS-MD5

set pfs group2

match address 120

!

interface Tunnel0

bandwidth 45000

ip address 198.51.100.1 255.255.255.252

no ip redirects

no ip proxy-arp

ip mtu 1400

ip virtual-reassembly in

ip tcp adjust-mss 1360

tunnel source GigabitEthernet0/0

tunnel destination 192.0.2.66

tunnel path-mtu-discovery

tunnel bandwidth transmit 45000

tunnel bandwidth receive 45000

!

interface GigabitEthernet0/0

ip address 192.0.2.34 255.255.255.224

no ip redirects

no ip proxy-arp

ip virtual-reassembly in

duplex full

speed 1000

media-type gbic

negotiation auto

crypto map MY-0WN-MAP

###########################################

Linux side logs

Dec 12 08:18:30 GLA racoon: INFO: ISAKMP-SA expired 192.0.2.66[500]-192.0.2.34[500] spi:88ed3c49ea8ffe38:e568a2dd27cbec5d

Dec 12 08:18:30 GLA racoon: INFO: ISAKMP-SA deleted 192.0.2.66[500]-192.0.2.34[500] spi:88ed3c49ea8ffe38:e568a2dd27cbec5d

Dec 12 08:18:31 GLA racoon: INFO: respond new phase 1 negotiation: 192.0.2.66[500]<=>192.0.2.34[500]

Dec 12 08:18:31 GLA racoon: INFO: begin Identity Protection mode.

Dec 12 08:18:31 GLA racoon: INFO: received Vendor ID: RFC 3947

Dec 12 08:18:31 GLA racoon: INFO: received Vendor ID: draft-ietf-ipsec-nat-t-ike-07

Dec 12 08:18:31 GLA racoon: INFO: received Vendor ID: draft-ietf-ipsec-nat-t-ike-03

Dec 12 08:18:31 GLA racoon: INFO: received Vendor ID: draft-ietf-ipsec-nat-t-ike-02#012

Dec 12 08:18:31 GLA racoon: INFO: received Vendor ID: DPD

Dec 12 08:18:31 GLA racoon: INFO: received Vendor ID: draft-ietf-ipsra-isakmp-xauth-06.txt

Dec 12 08:18:31 GLA racoon: [192.0.2.34] INFO: received INITIAL-CONTACT

Dec 12 08:18:31 GLA racoon: INFO: ISAKMP-SA established 192.0.2.66[500]-192.0.2.34[500] spi:88ed3c49e027808c:b17ba35c5b7f1e82

Dec 12 08:18:31 GLA racoon: INFO: respond new phase 2 negotiation: 192.0.2.66[500]<=>192.0.2.34[500]

Dec 12 08:18:31 GLA racoon: INFO: Update the generated policy : 192.0.2.34/32[0] 192.0.2.66/32[0] proto=any dir=in

Dec 12 08:18:31 GLA racoon: INFO: IPsec-SA established: AH/Transport 192.0.2.66[500]->192.0.2.34[500] spi=88493238(0x5464cb6)

Dec 12 08:18:31 GLA racoon: INFO: IPsec-SA established: ESP/Transport 192.0.2.66[500]->192.0.2.34[500] spi=21367141(0x1460965)

Dec 12 08:18:31 GLA racoon: INFO: IPsec-SA established: AH/Transport 192.0.2.66[500]->192.0.2.34[500] spi=1579505880(0x5e2558d8)

Dec 12 08:18:31 GLA racoon: INFO: IPsec-SA established: ESP/Transport 192.0.2.66[500]->192.0.2.34[500] spi=838280164(0x31f723e4)

Gabriel Hill · ‎12-13-2012

Could you adjust your transform set?

Right now you have: crypto ipsec transform-set MY-0WN-TS-MD5 ah-md5-hmac esp-aes 256 esp-md5-hmac

Could you change this to strictly ESP or AH on both sides instead of mixing them.

There is a known issue with the ASR and mixing AH/ESP in the ipsec config. I will post it below:

CSCtb60545 / CSCsv96390

Mixing AH and ESP in transform set on ASR might not work. This is an enhancement request to introduce support for this.

Symptoms:

Router may display following messages continuously on the console:
%ACE-3-TRANSERR: ASR1000-ESP(14): IKEA trans 0x27E; opcode 0x60; param 0x2A;
error 0x5; retry cnt 0
Conditions:
This symptom is observed on a Cisco ASR1000 series router when functions as a IPSec
end-point, and when nested SA transformation is applied, such as:
crypto ipsec transform-set transform-1 ah-sha-hmac esp-3des esp-md5-hmac
crypto ipsec transform-set transform-1 ah-md5-hmac esp-3des esp-md5-hmac
Workaround:
Remove unsupported configuration.

View solution in original post

Gabriel Hill · ‎12-12-2012

Would it be possible for you to paste the output of a "debug crypto ipsec" on the ASR after restarting the racoon service on the Debian box (/etc/init.d/racoon restart)?

Philippe Latu · ‎12-12-2012

Here it is ... in the attached text file.

Gabriel Hill · ‎12-12-2012

Just for verification could you post your ipsec-tools.conf - it should be in the /etc folder.

Also can you post the following from the ASR:

show version
show crypto ace spi (you may have to type this command out as it may be hidden, also be sure to do this when interestingt traffic is going between the ASR and linux box.)

Philippe Latu · ‎12-13-2012

Hello,

Here are the requested informations.

As a proof of interesting trafic, I can only show the access list matches

~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~

asr1001-gw#sh ip access-lists 120

Extended IP access list 120

10 permit ip host 130.120.124.8 host 194.214.196.2 (3960 matches)

~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~

asr1001-gw#sh crypto ace spi

SPI in use ........................... 0

Normal SPI allocated ................. 67

HA SPI in allocated .................. 0

Free via flow id ..................... 0

Free via SPI ......................... 0

Errors

------

Duplicate free ....................... 0

Set in-use SPI to SPI table .......... 0

Clear in-use SPI from SPI table ...... 0

Free in-use SPI................ ...... 0

~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~

asr1001-gw#sh crypto session

Crypto session current status

Interface: GigabitEthernet0/0/0.2

Session status: UP-IDLE

Peer: 194.214.196.2 port 500

IKEv1 SA: local 130.120.124.8/500 remote 194.214.196.2/500 Active

IPSEC FLOW: permit ip host 130.120.124.8 host 194.214.196.2

Active SAs: 0, origin: crypto map

~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~

On the Linux side :

# setkey -DP

(per-socket policy)

out(socket) none

created: Dec 12 23:27:15 2012 lastused: Dec 13 09:06:14 2012

lifetime: 0(s) validtime: 0(s)

spid=340 seq=1 pid=5037

refcnt=1

(per-socket policy)

in(socket) none

created: Dec 12 23:27:15 2012 lastused: Dec 13 09:06:14 2012

lifetime: 0(s) validtime: 0(s)

spid=331 seq=2 pid=5037

refcnt=1

194.214.196.2[any] 130.120.124.8[any] 255

out prio def ipsec

ah/transport//require

esp/transport//require

created: Dec 12 08:34:14 2012 lastused:

lifetime: 0(s) validtime: 0(s)

spid=161 seq=3 pid=5037

refcnt=5

130.120.124.8[any] 194.214.196.2[any] 255

fwd prio def ipsec

ah/transport//require

esp/transport//require

created: Dec 12 08:34:14 2012 lastused:

lifetime: 0(s) validtime: 0(s)

spid=154 seq=4 pid=5037

refcnt=1

130.120.124.8[any] 194.214.196.2[any] 255

in prio def ipsec

ah/transport//require

esp/transport//require

created: Dec 12 08:34:14 2012 lastused: Dec 12 23:27:15 2012

lifetime: 0(s) validtime: 0(s)

spid=144 seq=0 pid=5037

refcnt=1

# setkey -Dp

130.120.124.8[0] 194.214.196.2[0]

ah mode=transport spi=6347238(0x0060d9e6) reqid=0(0x00000000)

seq=0x00000000 replay=0 flags=0x00000000 state=larval

created: Dec 13 09:07:22 2012 current: Dec 13 09:07:27 2012

diff: 5(s) hard: 30(s) soft: 0(s)

last: hard: 0(s) soft: 0(s)

current: 0(bytes) hard: 0(bytes) soft: 0(bytes)

allocated: 0 hard: 0 soft: 0

sadb_seq=1 pid=5038 refcnt=0

130.120.124.8[0] 194.214.196.2[0]

esp mode=transport spi=73839316(0x0466b2d4) reqid=0(0x00000000)

seq=0x00000000 replay=0 flags=0x00000000 state=larval

created: Dec 13 09:07:22 2012 current: Dec 13 09:07:27 2012

diff: 5(s) hard: 30(s) soft: 0(s)

last: hard: 0(s) soft: 0(s)

current: 0(bytes) hard: 0(bytes) soft: 0(bytes)

allocated: 0 hard: 0 soft: 0

sadb_seq=2 pid=5038 refcnt=0

194.214.196.2[0] 130.120.124.8[0]

ah mode=transport spi=0(0x00000000) reqid=0(0x00000000)

seq=0x00000000 replay=0 flags=0x00000000 state=larval

created: Dec 13 09:07:22 2012 current: Dec 13 09:07:27 2012

diff: 5(s) hard: 30(s) soft: 0(s)

last: hard: 0(s) soft: 0(s)

current: 0(bytes) hard: 0(bytes) soft: 0(bytes)

allocated: 0 hard: 0 soft: 0

sadb_seq=3 pid=5038 refcnt=0

130.120.124.8[0] 194.214.196.2[0]

ah mode=transport spi=33128108(0x01f97eac) reqid=0(0x00000000)

seq=0x00000000 replay=0 flags=0x00000000 state=larval

created: Dec 13 09:07:09 2012 current: Dec 13 09:07:27 2012

diff: 18(s) hard: 30(s) soft: 0(s)

last: hard: 0(s) soft: 0(s)

current: 0(bytes) hard: 0(bytes) soft: 0(bytes)

allocated: 0 hard: 0 soft: 0

sadb_seq=4 pid=5038 refcnt=0

130.120.124.8[0] 194.214.196.2[0]

esp mode=transport spi=226399628(0x0d7e958c) reqid=0(0x00000000)

seq=0x00000000 replay=0 flags=0x00000000 state=larval

created: Dec 13 09:07:09 2012 current: Dec 13 09:07:27 2012

diff: 18(s) hard: 30(s) soft: 0(s)

last: hard: 0(s) soft: 0(s)

current: 0(bytes) hard: 0(bytes) soft: 0(bytes)

allocated: 0 hard: 0 soft: 0

sadb_seq=0 pid=5038 refcnt=0

Gabriel Hill · ‎12-13-2012

Could you adjust your transform set?

Right now you have: crypto ipsec transform-set MY-0WN-TS-MD5 ah-md5-hmac esp-aes 256 esp-md5-hmac

Could you change this to strictly ESP or AH on both sides instead of mixing them.

There is a known issue with the ASR and mixing AH/ESP in the ipsec config. I will post it below:

CSCtb60545 / CSCsv96390

Mixing AH and ESP in transform set on ASR might not work. This is an enhancement request to introduce support for this.

Symptoms:

Router may display following messages continuously on the console:
%ACE-3-TRANSERR: ASR1000-ESP(14): IKEA trans 0x27E; opcode 0x60; param 0x2A;
error 0x5; retry cnt 0
Conditions:
This symptom is observed on a Cisco ASR1000 series router when functions as a IPSec
end-point, and when nested SA transformation is applied, such as:
crypto ipsec transform-set transform-1 ah-sha-hmac esp-3des esp-md5-hmac
crypto ipsec transform-set transform-1 ah-md5-hmac esp-3des esp-md5-hmac
Workaround:
Remove unsupported configuration.

Philippe Latu · ‎12-13-2012

Hello,

That's it ! A big thank you for your time

Following your advice, I set up a new ESP only transform set and both IKE phases worked perfectly.

It seems the issue you mentionned is independant of any hash or encryption algorithm and ASR1k IOS XE 3.8 doesn't support AH+ESP (yet ...).

crypto ipsec transform-set AUCH-TS-ESP esp-aes 256 esp-md5-hmac

mode transport

!

crypto map AUCH-CRYPTO-MAP 1 ipsec-isakmp

set peer 194.214.196.2

set transform-set AUCH-TS-ESP

set pfs group5

match address 120

On the Linux side, the racoon process restart gives the following logs which end by IPsec-SA established (phase 2 up) :

Dec 13 23:00:25 FAKE-AUCH-GW racoon: INFO: @(#)ipsec-tools 0.8.0 (http://ipsec-tools.sourceforge.net)

Dec 13 23:00:25 FAKE-AUCH-GW racoon: INFO: @(#)This product linked OpenSSL 1.0.1c 10 May 2012 (http://www.openssl.org/)

Dec 13 23:00:25 FAKE-AUCH-GW racoon: INFO: Reading configuration from "/etc/racoon/racoon.conf"

Dec 13 23:00:25 FAKE-AUCH-GW racoon: INFO: 194.214.196.2[500] used for NAT-T

Dec 13 23:00:25 FAKE-AUCH-GW racoon: INFO: 194.214.196.2[500] used as isakmp port (fd=8)

Dec 13 23:00:34 FAKE-AUCH-GW racoon: INFO: respond new phase 1 negotiation: 194.214.196.2[500]<=>130.120.124.8[500]

Dec 13 23:00:34 FAKE-AUCH-GW racoon: INFO: begin Identity Protection mode.

Dec 13 23:00:34 FAKE-AUCH-GW racoon: INFO: received Vendor ID: RFC 3947

Dec 13 23:00:34 FAKE-AUCH-GW racoon: INFO: received Vendor ID: draft-ietf-ipsec-nat-t-ike-07

Dec 13 23:00:34 FAKE-AUCH-GW racoon: INFO: received Vendor ID: draft-ietf-ipsec-nat-t-ike-03

Dec 13 23:00:34 FAKE-AUCH-GW racoon: INFO: received Vendor ID: draft-ietf-ipsec-nat-t-ike-02#012

Dec 13 23:00:34 FAKE-AUCH-GW racoon: INFO: received Vendor ID: DPD

Dec 13 23:00:34 FAKE-AUCH-GW racoon: INFO: received Vendor ID: draft-ietf-ipsra-isakmp-xauth-06.txt

Dec 13 23:00:34 FAKE-AUCH-GW racoon: [130.120.124.8] INFO: received INITIAL-CONTACT

Dec 13 23:00:34 FAKE-AUCH-GW racoon: INFO: ISAKMP-SA established 194.214.196.2[500]-130.120.124.8[500] spi:bb2143ada18ff382:4ec392f1578eac7c

Dec 13 23:00:34 FAKE-AUCH-GW racoon: INFO: respond new phase 2 negotiation: 194.214.196.2[500]<=>130.120.124.8[500]

Dec 13 23:00:34 FAKE-AUCH-GW racoon: INFO: Update the generated policy : 130.120.124.8/32[0] 194.214.196.2/32[0] proto=any dir=in

Dec 13 23:00:34 FAKE-AUCH-GW racoon: INFO: respond new phase 2 negotiation: 194.214.196.2[500]<=>130.120.124.8[500]

Dec 13 23:00:34 FAKE-AUCH-GW racoon: INFO: Update the generated policy : 130.120.124.8/32[0] 194.214.196.2/32[0] proto=any dir=in

Dec 13 23:00:34 FAKE-AUCH-GW racoon: INFO: IPsec-SA established: ESP/Transport 194.214.196.2[500]->130.120.124.8[500] spi=94595988(0x5a36b94)

Dec 13 23:00:34 FAKE-AUCH-GW racoon: INFO: IPsec-SA established: ESP/Transport 194.214.196.2[500]->130.120.124.8[500] spi=3846049996(0xe53e10cc)

Dec 13 23:00:34 FAKE-AUCH-GW racoon: INFO: IPsec-SA established: ESP/Transport 194.214.196.2[500]->130.120.124.8[500] spi=53239394(0x32c5e62)

Dec 13 23:00:34 FAKE-AUCH-GW racoon: INFO: IPsec-SA established: ESP/Transport 194.214.196.2[500]->130.120.124.8[500] spi=3071153643(0xb70e15eb

hppp66400 · ‎03-12-2013

Hello,

I can connect my debian with my cisco. I download you ipsec-tools.conf for compare with my but can you put you

/etc/racoon/racoon.conf ?

thank you very much.

Philippe Latu · ‎03-13-2013

Hello,

If you can read french or read through automated translation (which can be quite funny), I started a documentation at the following page : http://www.inetdoc.net/articles/site2site-ipsecvpn/

Here is a sample racoon.conf :

#
# Please read racoon.conf(5) for details, and read also setkey(8).
#
log info;
path pre_shared_key "/etc/racoon/psk.txt";

padding {
  strict_check on;
}

listen {
  isakmp 192.0.2.66;
}

remote 192.0.2.34 {
  my_identifier address 192.0.2.66;
  exchange_mode main;
  proposal_check obey;

  proposal {
    lifetime time 86400 secs;
    encryption_algorithm aes 256;
    hash_algorithm md5;
    authentication_method pre_shared_key;
    dh_group 14;
  }

  generate_policy on;
  initial_contact on;
}

sainfo anonymous {
  lifetime time 3600 secs;
  pfs_group 14;
  encryption_algorithm aes 256;
  authentication_algorithm hmac_md5;
  compression_algorithm deflate;
}