ISAKMP Security Association 12.3(3)

[dean.pecorari]

I have an issue relating to the ISAKMP key exchange PHASE 1 process.

The security association is in an MM_SA_SETUP state

Any ideas ??? Debug information below

*****************************************************

Feb 24 15:31:55.409: ISAKMP (0:12): sending packet to 203.17.35.225 my_port 500 peer_port 500

R) MM_SA_SETUP

Feb 24 15:32:04.908: ISAKMP (0:12): received packet from 203.17.35.225 dport 500 sport 500 Glo

al (R) MM_SA_SETUP

Feb 24 15:32:04.908: ISAKMP (0:12): phase 1 packet is a duplicate of a previous packet.

Feb 24 15:32:04.908: ISAKMP (0:12): retransmitting due to retransmit phase 1

Feb 24 15:32:04.908: ISAKMP (0:12): retransmitting phase 1 MM_SA_SETUP...

Feb 24 15:32:05.409: ISAKMP (0:12): retransmitting phase 1 MM_SA_SETUP...

Feb 24 15:32:05.409: ISAKMP (0:12): incrementing error counter on sa: retransmit phase 1

Feb 24 15:32:05.409: ISAKMP (0:12): retransmitting phase 1 MM_SA_SETUP

Feb 24 15:32:05.409: ISAKMP (0:12): sending packet to 203.17.35.225 my_port 500 peer_port 500

R) MM_SA_SETUP

Feb 24 15:32:15.409: ISAKMP (0:12): retransmitting phase 1 MM_SA_SETUP...

Feb 24 15:32:15.409: ISAKMP (0:12): peer does not do paranoid keepalives.

Feb 24 15:32:15.409: ISAKMP (0:12): deleting SA reason "death by retransmission P1" state (R)

M_SA_SETUP (peer 203.17.35.225) input queue 0

Feb 24 15:32:15.409: ISAKMP (0:12): deleting SA reason "death by retransmission P1" state (R)

M_SA_SETUP (peer 203.17.35.225) input queue 0

Feb 24 15:32:15.409: ISAKMP (0:12): Input = IKE_MESG_INTERNAL, IKE_PHASE1_DEL

Feb 24 15:32:15.409: ISAKMP (0:12): Old State = IKE_R_MM2 New State = IKE_DEST_SA

Feb 24 15:33:14.911: ISAKMP (0:0): received packet from 203.17.35.225 dport 500 sport 500 Glob

l (N) NEW SA

Feb 24 15:33:14.911: ISAKMP: local port 500, remote port 500

Feb 24 15:33:14.915: ISAKMP: Find a dup sa in the avl tree during calling isadb_insert sa = 81

EAB94

Feb 24 15:33:14.915: ISAKMP (0:13): Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH

Feb 24 15:33:14.915: ISAKMP (0:13): Old State = IKE_READY New State = IKE_R_MM1

Feb 24 15:33:14.915: ISAKMP (0:13): processing SA payload. message ID = 0

Feb 24 15:33:14.915: ISAKMP (0:13): processing vendor id payload

Feb 24 15:33:14.915: ISAKMP (0:13): vendor ID seems Unity/DPD but major 157 mismatch

Feb 24 15:33:14.915: ISAKMP (0:13): vendor ID is NAT-T v3

Feb 24 15:33:14.915: ISAKMP (0:13): processing vendor id payload

Feb 24 15:33:14.915: ISAKMP (0:13): vendor ID seems Unity/DPD but major 123 mismatch

Feb 24 15:33:14.919: ISAKMP (0:13): vendor ID is NAT-T v2

Feb 24 15:33:14.919: ISAKMP: Looking for a matching key for 203.17.35.225 in default : success

Feb 24 15:33:14.919: ISAKMP (0:13): found peer pre-shared key matching 203.17.35.225

Feb 24 15:33:14.919: ISAKMP (0:13) local preshared key found

Feb 24 15:33:14.919: ISAKMP : Scanning profiles for xauth ...

Feb 24 15:33:14.919: ISAKMP (0:13): Checking ISAKMP transform 1 against priority 10 policy

Feb 24 15:33:14.919: ISAKMP: encryption 3DES-CBC

Feb 24 15:33:14.919: ISAKMP: hash MD5

Feb 24 15:33:14.919: ISAKMP: default group 1

Feb 24 15:33:14.919: ISAKMP: auth pre-share

Feb 24 15:33:14.919: ISAKMP: life type in seconds

Feb 24 15:33:14.919: ISAKMP: life duration (VPI) of 0x0 0x1 0x51 0x80

Feb 24 15:33:14.919: ISAKMP (0:13): atts are acceptable. Next payload is 0

Feb 24 15:33:15.003: ISAKMP (0:13): processing vendor id payload

Feb 24 15:33:15.003: ISAKMP (0:13): vendor ID seems Unity/DPD but major 157 mismatch

Feb 24 15:33:15.003: ISAKMP (0:13): vendor ID is NAT-T v3

Feb 24 15:33:15.003: ISAKMP (0:13): processing vendor id payload

Feb 24 15:33:15.003: ISAKMP (0:13): vendor ID seems Unity/DPD but major 123 mismatch

Feb 24 15:33:15.003: ISAKMP (0:13): vendor ID is NAT-T v2

Feb 24 15:33:15.003: ISAKMP (0:13): Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE

Feb 24 15:33:15.003: ISAKMP (0:13): Old State = IKE_R_MM1 New State = IKE_R_MM1

Feb 24 15:33:15.007: ISAKMP (0:13): constructed NAT-T vendor-03 ID

Feb 24 15:33:15.007: ISAKMP (0:13): sending packet to 203.17.35.225 my_port 500 peer_port 500

R) MM_SA_SETUP

Feb 24 15:33:15.007: ISAKMP (0:13): Input = IKE_MESG_INTERNAL, IKE_PROCESS_COMPLETE

Feb 24 15:33:15.007: ISAKMP (0:13): Old State = IKE_R_MM1 New State = IKE_R_MM2

Feb 24 15:33:15.411: ISAKMP (0:12): purging SA., sa=81DEA510, delme=81DEA510

[gfullage]

Looks like the ISAKMP packets sent by this router aren't making it to 203.17.35.225 for some reason. You can see where this router sends a packet to 203.17.35.225, then 9 SECONDS later it receives a packet which is a duplicate of the previous packet that was sent, this would be because 203.17.35.225 never received the first packet so it retransmitted.

Feb 24 15:31:55.409: ISAKMP (0:12): sending packet to 203.17.35.225 my_port 500 peer_port 500

R) MM_SA_SETUP

Feb 24 15:32:04.908: ISAKMP (0:12): received packet from 203.17.35.225 dport 500 sport 500 Glo

al (R) MM_SA_SETUP

Feb 24 15:32:04.908: ISAKMP (0:12): phase 1 packet is a duplicate of a previous packet.

You need to check the debug on the other router and see what's going on. Check that there isn't a firewall or access-list blocking UDP/500 to that other router.

[dean.pecorari]

I have reloaded the router. It seems that an ISAKMP key exchange occurs. Then a duplicate packet is transmitted by the remote router and the SA is deleted.

****************************************************

Feb 24 16:17:26.389: %SYS-5-RESTART: System restarted --

Cisco Internetwork Operating System Software

IOS (tm) C1700 Software (C1700-K9O3SY7-M), Version 12.3(3), RELEASE SOFTWARE (fc2)

Copyright (c) 1986-2003 by cisco Systems, Inc.

Compiled Tue 19-Aug-03 14:42 by dchih

Feb 24 16:17:26.433: %SNMP-5-COLDSTART: SNMP agent on host RTRQAN02 is undergoing a cold start

Feb 24 16:17:26.609: %LINEPROTO-5-UPDOWN: Line protocol on Interface FastEthernet0/0, changed s

tate to up

Feb 24 16:18:04.427: %LINEPROTO-5-UPDOWN: Line protocol on Interface Serial0/0, changed state t

o down

Feb 24 16:18:34.428: %LINEPROTO-5-UPDOWN: Line protocol on Interface Serial0/0, changed state t

o up

.Feb 24 16:21:07.702: %CRYPTO-4-IKMP_NO_SA: IKE message from 203.17.35.225 has no SA and is n

ot an initialization offer

Feb 24 16:23:31.356: %SEC-6-IPACCESSLOGP: list QANTAS-Inbound denied udp 203.17.35.225(500) ->

172.16.6.2(500), 6 packets

Feb 24 16:25:14.837: ISAKMP (0:0): received packet from 203.17.35.225 dport 500 sport 500 Globa

l (N) NEW SA

Feb 24 16:25:14.841: ISAKMP: local port 500, remote port 500

Feb 24 16:25:14.841: ISAKMP: Find a dup sa in the avl tree during calling isadb_insert sa = 813

05DA4

Feb 24 16:25:14.841: ISAKMP (0:5): Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH

Feb 24 16:25:14.841: ISAKMP (0:5): Old State = IKE_READY New State = IKE_R_MM1

Feb 24 16:25:14.841: ISAKMP (0:5): processing SA payload. message ID = 0

Feb 24 16:25:14.845: ISAKMP (0:5): processing vendor id payload

Feb 24 16:25:14.845: ISAKMP (0:5): vendor ID seems Unity/DPD but major 157 mismatch

Feb 24 16:25:14.845: ISAKMP (0:5): vendor ID is NAT-T v3

Feb 24 16:25:14.845: ISAKMP (0:5): processing vendor id payload

Feb 24 16:25:14.845: ISAKMP (0:5): vendor ID seems Unity/DPD but major 123 mismatch

Feb 24 16:25:14.845: ISAKMP (0:5): vendor ID is NAT-T v2

Feb 24 16:25:14.845: ISAKMP: Looking for a matching key for 203.17.35.225 in default : success

Feb 24 16:25:14.845: ISAKMP (0:5): found peer pre-shared key matching 203.17.35.225

Feb 24 16:25:14.845: ISAKMP (0:5) local preshared key found

Feb 24 16:25:14.845: ISAKMP : Scanning profiles for xauth ...

Feb 24 16:25:14.845: ISAKMP (0:5): Checking ISAKMP transform 1 against priority 10 policy

Feb 24 16:25:14.845: ISAKMP: encryption 3DES-CBC

Feb 24 16:25:14.845: ISAKMP: hash MD5

Feb 24 16:25:14.845: ISAKMP: default group 1

Feb 24 16:25:14.845: ISAKMP: auth pre-share

Feb 24 16:25:14.849: ISAKMP: life type in seconds

Feb 24 16:25:14.849: ISAKMP: life duration (VPI) of 0x0 0x1 0x51 0x80

Feb 24 16:25:14.849: ISAKMP (0:5): atts are acceptable. Next payload is 0

Feb 24 16:25:14.930: ISAKMP (0:5): processing vendor id payload

Feb 24 16:25:14.930: ISAKMP (0:5): vendor ID seems Unity/DPD but major 157 mismatch

Feb 24 16:25:14.930: ISAKMP (0:5): vendor ID is NAT-T v3

Feb 24 16:25:14.930: ISAKMP (0:5): processing vendor id payload

Feb 24 16:25:14.930: ISAKMP (0:5): vendor ID seems Unity/DPD but major 123 mismatch

Feb 24 16:25:14.930: ISAKMP (0:5): vendor ID is NAT-T v2

Feb 24 16:25:14.934: ISAKMP (0:5): Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE

Feb 24 16:25:14.934: ISAKMP (0:5): Old State = IKE_R_MM1 New State = IKE_R_MM1

Feb 24 16:25:14.934: ISAKMP (0:5): constructed NAT-T vendor-03 ID

Feb 24 16:25:14.934: ISAKMP (0:5): sending packet to 203.17.35.225 my_port 500 peer_port 500 (R

) MM_SA_SETUP

Feb 24 16:25:14.934: ISAKMP (0:5): Input = IKE_MESG_INTERNAL, IKE_PROCESS_COMPLETE

Feb 24 16:25:14.934: ISAKMP (0:5): Old State = IKE_R_MM1 New State = IKE_R_MM2

Feb 24 16:25:15.374: ISAKMP (0:4): purging SA., sa=813052F4, delme=813052F4

Feb 24 16:25:24.838: ISAKMP (0:5): received packet from 203.17.35.225 dport 500 sport 500 Globa

l (R) MM_SA_SETUP

Feb 24 16:25:24.838: ISAKMP (0:5): phase 1 packet is a duplicate of a previous packet.

Feb 24 16:25:24.838: ISAKMP (0:5): retransmitting due to retransmit phase 1

Feb 24 16:25:24.838: ISAKMP (0:5): retransmitting phase 1 MM_SA_SETUP...

Feb 24 16:25:25.339: ISAKMP (0:5): retransmitting phase 1 MM_SA_SETUP...

Feb 24 16:25:25.339: ISAKMP (0:5): incrementing error counter on sa: retransmit phase 1

Feb 24 16:25:25.339: ISAKMP (0:5): retransmitting phase 1 MM_SA_SETUP

Feb 24 16:25:25.339: ISAKMP (0:5): sending packet to 203.17.35.225 my_port 500 peer_port 500 (R

) MM_SA_SETUP

Feb 24 16:25:34.838: ISAKMP (0:5): received packet from 203.17.35.225 dport 500 sport 500 Globa

l (R) MM_SA_SETUP

Feb 24 16:25:34.838: ISAKMP (0:5): phase 1 packet is a duplicate of a previous packet.

Feb 24 16:25:34.838: ISAKMP (0:5): retransmitting due to retransmit phase 1

Feb 24 16:25:34.838: ISAKMP (0:5): retransmitting phase 1 MM_SA_SETUP...

Feb 24 16:25:35.339: ISAKMP (0:5): retransmitting phase 1 MM_SA_SETUP...

Feb 24 16:25:35.339: ISAKMP (0:5): incrementing error counter on sa: retransmit phase 1

Feb 24 16:25:35.339: ISAKMP (0:5): retransmitting phase 1 MM_SA_SETUP

Feb 24 16:25:35.339: ISAKMP (0:5): sending packet to 203.17.35.225 my_port 500 peer_port 500 (R

) MM_SA_SETUP

Feb 24 16:25:45.219: ISAKMP (0:5): received packet from 203.17.35.225 dport 500 sport 500 Globa

l (R) MM_SA_SETUP

Feb 24 16:25:45.219: ISAKMP (0:5): phase 1 packet is a duplicate of a previous packet.

Feb 24 16:25:45.219: ISAKMP (0:5): retransmitting due to retransmit phase 1

Feb 24 16:25:45.219: ISAKMP (0:5): retransmitting phase 1 MM_SA_SETUP...

Feb 24 16:25:45.720: ISAKMP (0:5): retransmitting phase 1 MM_SA_SETUP...

Feb 24 16:25:45.720: ISAKMP (0:5): incrementing error counter on sa: retransmit phase 1

Feb 24 16:25:45.720: ISAKMP (0:5): retransmitting phase 1 MM_SA_SETUP

Feb 24 16:25:45.720: ISAKMP (0:5): sending packet to 203.17.35.225 my_port 500 peer_port 500 (R

) MM_SA_SETUP

Feb 24 16:25:54.839: ISAKMP (0:5): received packet from 203.17.35.225 dport 500 sport 500 Globa

l (R) MM_SA_SETUP

[gfullage]

As I said in my first post, the other router is not receiving the ISAKMP packets from this router. The ISAKMP exchange you see is from the first packet we receive from the other router. We verify that everything is OK and the attributes match. We then send a reply here:

Feb 24 16:25:14.934: ISAKMP (0:5): sending packet to 203.17.35.225 my_port 500 peer_port 500 (R) MM_SA_SETUP

Then nothing until 10 seconds later we get this:

Feb 24 16:25:24.838: ISAKMP (0:5): received packet from 203.17.35.225 dport 500 sport 500 Global (R) MM_SA_SETUP

Feb 24 16:25:24.838: ISAKMP (0:5): phase 1 packet is a duplicate of a previous packet.

Which is the same as the first packet that this router sent us. This is because it never received our reply, timed out waiting, and retransmitted.

You have to see why the ISAKMP packets from this router are not reaching the other side. Reloading this router isn't going to do anything I'm afraid.

[dean.pecorari]

I have placed ISAKMP debugging on our other router

and it seems like it receiving the ISAKMP NEW SA request however it seems not to respond.

*****************************************************

Feb 25 09:32:52: ISAKMP (0:7): deleting node -349434646 error FALSE reason "quick mode done (aw

ait()"

Feb 25 09:32:52: ISAKMP (0:7): Node -349434646, Input = IKE_MESG_FROM_PEER, IKE_QM_EXCH

Feb 25 09:32:52: ISAKMP (0:7): Old State = IKE_QM_R_QM2 New State = IKE_QM_PHASE2_COMPLETE

Feb 25 09:32:52: ISAKMP: received ke message (4/1)

Feb 25 09:32:52: ISAKMP: Unlocking IPSEC struct 0x635A3EA8 notified by IPSec, count 1

Feb 25 09:32:53: ISAKMP (0:0): received packet from 172.16.6.1 dport 500 sport 500 (N) NEW SA

Feb 25 09:33:03: ISAKMP (0:0): received packet from 172.16.6.1 dport 500 sport 500 (N) NEW SA

Feb 25 09:33:13: ISAKMP (0:0): received packet from 172.16.6.1 dport 500 sport 500 (N) NEW SA

Feb 25 09:33:13: %CRYPTO-4-IKMP_NO_SA: IKE message from 172.16.6.1 has no SA and is not an

initialization offer

Feb 25 09:33:22: ISAKMP: received ke message (3/2)

Feb 25 09:33:22: ISAKMP: set new node 724013207 to QM_IDLE

Feb 25 09:33:22: ISAKMP (0:7): sending packet to 172.16.6.2 my_port 500 peer_port 500 (R) QM_ID

LE

Feb 25 09:33:22: ISAKMP (0:7): purging node 724013207

Feb 25 09:33:22: ISAKMP (0:7): Input = IKE_MESG_FROM_IPSEC, IKE_PHASE2_DEL

Feb 25 09:33:22: ISAKMP (0:7): Old State = IKE_P1_COMPLETE New State = IKE_P1_COMPLETE

Feb 25 09:33:22: ISAKMP (0:0): received packet from 172.16.6.2 dport 500 sport 500 (N) NEW SA

Feb 25 09:33:33: ISAKMP (0:0): received packet from 172.16.6.2 dport 500 sport 500 (N) NEW SA

Feb 25 09:33:42: ISAKMP (0:7): purging node -349434646

Feb 25 09:33:43: ISAKMP (0:0): received packet from 172.16.6.2 dport 500 sport 500 (N) NEW SA

Feb 25 09:33:53: ISAKMP (0:0): received packet from 172.16.6.2 dport 500 sport 500 (N) NEW SA

Feb 25 09:34:03: ISAKMP (0:0): received packet from 172.16.6.2 dport 500 sport 500 (N) NEW SA

Feb 25 09:34:13: ISAKMP (0:0): received packet from 172.16.6.2 dport 500 sport 500 (N) NEW SA

Feb 25 09:34:13: %CRYPTO-4-IKMP_NO_SA: IKE message from 172.16.6.2 has no SA and is not an

initialization offer

Feb 25 09:34:22: ISAKMP (0:0): received packet from 172.16.6.1 dport 500 sport 500 (N) NEW SA

Feb 25 09:34:33: ISAKMP (0:0): received packet from 172.16.6.1 dport 500 sport 500 (N) NEW SA

Feb 25 09:34:43: ISAKMP (0:0): received packet from 172.16.6.1 dport 500 sport 500 (N) NEW SA

Feb 25 09:34:53: ISAKMP (0:0): received packet from 172.16.6.1 dport 500 sport 500 (N) NEW SA

Feb 25 09:35:03: ISAKMP (0:0): received packet from 172.16.6.1 dport 500 sport 500 (N) NEW SA

Feb 25 09:35:13: ISAKMP (0:0): received packet from 172.16.6.1 dport 500 sport 500 (N) NEW SA

Feb 25 09:35:13: %CRYPTO-4-IKMP_NO_SA: IKE message from 172.16.6.1 has no SA and is not an

initialization offer

Feb 25 09:35:22: ISAKMP (0:0): received packet from 172.16.6.2 dport 500 sport 500 (N) NEW SA

Feb 25 09:35:33: ISAKMP (0:0): received packet from 172.16.6.2 dport 500 sport 500 (N) NEW SA

Feb 25 09:35:43: ISAKMP (0:0): received packet from 172.16.6.2 dport 500 sport 500 (N) NEW SA

Feb 25 09:35:53: ISAKMP (0:0): received packet from 172.16.6.2 dport 500 sport 500 (N) NEW SA

Feb 25 09:36:03: ISAKMP (0:0): received packet from 172.16.6.2 dport 500 sport 500 (N) NEW SA

Feb 25 09:36:13: ISAKMP (0:0): received packet from 172.16.6.2 dport 500 sport 500 (N) NEW SA

Feb 25 09:36:13: %CRYPTO-4-IKMP_NO_SA: IKE message from 172.16.6.2 has no SA and is not an

initialization offer

Feb 25 09:36:22: ISAKMP (0:0): received packet from 172.16.6.1 dport 500 sport 500 (N) NEW SA

Feb 25 09:36:33: ISAKMP (0:0): received packet from 172.16.6.1 dport 500 sport 500 (N) NEW SA

Feb 25 09:36:43: ISAKMP (0:0): received packet from 172.16.6.1 dport 500 sport 500 (N) NEW SA

Feb 25 09:36:53: ISAKMP (0:0): received packet from 172.16.6.1 dport 500 sport 500 (N) NEW SA

Feb 25 09:37:03: ISAKMP (0:0): received packet from 172.16.6.1 dport 500 sport 500 (N) NEW SA

Feb 25 09:37:13: ISAKMP (0:0): received packet from 172.16.6.1 dport 500 sport 500 (N) NEW SA

Feb 25 09:37:13: %CRYPTO-4-IKMP_NO_SA: IKE message from 172.16.6.1 has no SA and is not an

initialization offer

Feb 25 09:37:22: ISAKMP (0:0): received packet from 172.16.6.2 dport 500 sport 500 (N) NEW SA

Feb 25 09:38:22: %CRYPTO-4-IKMP_NO_SA: IKE message from 172.16.6.1 has no SA and is not an

initialization offer

Feb 25 09:39:22: %CRYPTO-4-IKMP_NO_SA: IKE message from 172.16.6.2 has no SA and is not an

initialization offer

Feb 25 09:40:22: %CRYPTO-4-IKMP_NO_SA: IKE message from 172.16.6.1 has no SA and is not an

initialization offer

Feb 25 09:41:22: %CRYPTO-4-IKMP_NO_SA: IKE message from 172.16.6.2 has no SA and is not an

initialization offer

Feb 25 09:42:22: %CRYPTO-4-IKMP_NO_SA: IKE message from 172.16.6.1 has no SA and is not an

initialization offer