Site to site VPN Mtl to Barbade, how to debug/Interpretation of result

Unanswered Question
Mar 18th, 2010

Hello everyone!

I have to support a Site to Site VPN between montreal and Barbados.

This setup work from 2 years without problem,

but from last sunday the VPN does't run anymore.

I'm new in VPN, and if someone have a IOS command and the result interpretation, I have to learn in emergency mode...

I type this command:

MTL#debug crypto isakmp
Crypto ISAKMP debugging is on
MTL#term mon
MTL#
Mar 18 21:13:16.738: ISAKMP:(0): retransmitting phase 1 MM_NO_STATE...
Mar 18 21:13:16.738: ISAKMP (0:0): incrementing error counter on sa, attempt 5 of 5: retransmit phase 1
Mar 18 21:13:16.738: ISAKMP:(0): retransmitting phase 1 MM_NO_STATE
Mar 18 21:13:16.738: ISAKMP:(0): sending packet to 65.xxx.132.xxx my_port 500 peer_port 500 (I) MM_NO_STATE
Mar 18 21:13:16.738: ISAKMP:(0):Sending an IKE IPv4 Packet.
Mar 18 21:13:26.749: ISAKMP:(0): retransmitting phase 1 MM_NO_STATE...
Mar 18 21:13:26.749: ISAKMP:(0):peer does not do paranoid keepalives.

Mar 18 21:13:26.749: ISAKMP:(0):deleting SA reason "Death by retransmission P1"state (I) MM_NO_STATE (peer 65.xxx.132.xxx)
Mar 18 21:13:26.753: ISAKMP:(0):deleting SA reason "Death by retransmission P1"state (I) MM_NO_STATE (peer 65.xxx.132.xxx)
Mar 18 21:13:26.753: ISAKMP: Unlocking peer struct 0x6589088C for isadb_mark_sa_deleted(), count 0
Mar 18 21:13:26.753: ISAKMP: Deleting peer node by peer_reap for 65.xxx.132.xxx:6589088C
Mar 18 21:13:26.753: ISAKMP:(0):deleting node 77717311 error FALSE reason "IKE deleted"
Mar 18 21:13:26.753: ISAKMP:(0):deleting node -494502065 error FALSE reason "IKE deleted"
Mar 18 21:13:26.753: ISAKMP:(0):Input = IKE_MESG_INTERNAL, IKE_PHASE1_DEL
Mar 18 21:13:26.753: ISAKMP:(0):Old State = IKE_I_MM1  New State = IKE_DEST_SA

Mar 18 21:13:39.896: ISAKMP:(0): SA request profile is (NULL)
Mar 18 21:13:39.896: ISAKMP: Created a peer struct for 65.xxx.132.xxx, peer port 500
Mar 18 21:13:39.896: ISAKMP: New peer created peer = 0x649C31F0 peer_handle = 0x80000019
Mar 18 21:13:39.896: ISAKMP: Locking peer struct 0x649C31F0, refcount 1 for isakmp_initiator
Mar 18 21:13:39.896: ISAKMP: local port 500, remote port 500
Mar 18 21:13:39.896: ISAKMP: set new node 0 to QM_IDLE
Mar 18 21:13:39.896: ISAKMP: Find a dup sa in the avl tree during calling isadb_insert sa = 646BE0B0
Mar 18 21:13:39.896: ISAKMP:(0):Can not start Aggressive mode, trying Main mode.
Mar 18 21:13:39.896: ISAKMP:(0):found peer pre-shared key matching 65.xxx.132.xxx
Mar 18 21:13:39.896: ISAKMP:(0): constructed NAT-T vendor-rfc3947 ID
Mar 18 21:13:39.900: ISAKMP:(0): constructed NAT-T vendor-07 ID
Mar 18 21:13:39.900: ISAKMP:(0): constructed NAT-T vendor-03 ID
Mar 18 21:13:39.900: ISAKMP:(0): constructed NAT-T vendor-02 ID
Mar 18 21:13:39.900: ISAKMP:(0):Input = IKE_MESG_FROM_IPSEC, IKE_SA_REQ_MM
Mar 18 21:13:39.900: ISAKMP:(0):Old State = IKE_READY  New State = IKE_I_MM1

Mar 18 21:13:39.900: ISAKMP:(0): beginning Main Mode exchange
Mar 18 21:13:39.900: ISAKMP:(0): sending packet to 65.xxx.132.xxx my_port 500 peer_port 500 (I) MM_NO_STATE
Mar 18 21:13:39.900: ISAKMP:(0):Sending an IKE IPv4 Packet.
Mar 18 21:13:49.899: ISAKMP:(0): retransmitting phase 1 MM_NO_STATE...
Mar 18 21:13:49.899: ISAKMP (0:0): incrementing error counter on sa, attempt 1 of 5: retransmit phase 1
Mar 18 21:13:49.899: ISAKMP:(0): retransmitting phase 1 MM_NO_STATE
Mar 18 21:13:49.899: ISAKMP:(0): sending packet to 65.xxx.132.xxx my_port 500 peer_port 500 (I) MM_NO_STATE
Mar 18 21:13:49.899: ISAKMP:(0):Sending an IKE IPv4 Packet.
Mar 18 21:13:59.898: ISAKMP:(0): retransmitting phase 1 MM_NO_STATE...
Mar 18 21:13:59.898: ISAKMP (0:0): incrementing error counter on sa, attempt 2 of 5: retransmit phase 1
Mar 18 21:13:59.898: ISAKMP:(0): retransmitting phase 1 MM_NO_STATE
Mar 18 21:13:59.898: ISAKMP:(0): sending packet to 65.xxx.132.xxx my_port 500 peer_port 500 (I) MM_NO_STATE
Mar 18 21:13:59.898: ISAKMP:(0):Sending an IKE IPv4 Packet.
Mar 18 21:14:09.893: ISAKMP: set new node 0 to QM_IDLE
Mar 18 21:14:09.893: ISAKMP:(0):SA is still budding. Attached new ipsec request to it. (local 72.10.144.178, remote 65.xxx.132.xxx)
Mar 18 21:14:09.893: ISAKMP: Error while processing SA request: Failed to initialize SA
Mar 18 21:14:09.893: ISAKMP: Error while processing KMI message 0, error 2.
Mar 18 21:14:09.897: ISAKMP:(0): retransmitting phase 1 MM_NO_STATE...
Mar 18 21:14:09.897: ISAKMP (0:0): incrementing error counter on sa, attempt 3 of 5: retransmit phase 1
Mar 18 21:14:09.897: ISAKMP:(0): retransmitting phase 1 MM_NO_STATE
Mar 18 21:14:09.897: ISAKMP:(0): sending packet to 65.xxx.132.xxx my_port 500 peer_port 500 (I) MM_NO_STATE
Mar 18 21:14:09.897: ISAKMP:(0):Sending an IKE IPv4 Packet.
Mar 18 21:14:16.748: ISAKMP:(0):purging node 77717311
Mar 18 21:14:16.748: ISAKMP:(0):purging node -494502065
Mar 18 21:14:19.896: ISAKMP:(0): retransmitting phase 1 MM_NO_STATE...
Mar 18 21:14:19.896: ISAKMP (0:0): incrementing error counter on sa, attempt 4 of 5: retransmit phase 1
Mar 18 21:14:19.896: ISAKMP:(0): retransmitting phase 1 MM_NO_STATE
Mar 18 21:14:19.896: ISAKMP:(0): sending packet to 65.xxx.132.xxx my_port 500 peer_port 500 (I) MM_NO_STATE
Mar 18 21:14:19.896: ISAKMP:(0):Sending an IKE IPv4 Packet.
Mar 18 21:14:26.747: ISAKMP:(0):purging SA., sa=646BEB88, delme=646BEB88
Mar 18 21:14:29.895: ISAKMP:(0): retransmitting phase 1 MM_NO_STATE...
Mar 18 21:14:29.895: ISAKMP (0:0): incrementing error counter on sa, attempt 5 of 5: retransmit phase 1
Mar 18 21:14:29.895: ISAKMP:(0): retransmitting phase 1 MM_NO_STATE
Mar 18 21:14:29.895: ISAKMP:(0): sending packet to 65.xxx.132.xxx my_port 500 peer_port 500 (I) MM_NO_STATE
Mar 18 21:14:29.895: ISAKMP:(0):Sending an IKE IPv4 Packet.
Mar 18 21:14:39.894: ISAKMP:(0): retransmitting phase 1 MM_NO_STATE...
Mar 18 21:14:39.894: ISAKMP:(0):peer does not do paranoid keepalives.

Mar 18 21:14:39.894: ISAKMP:(0):deleting SA reason "Death by retransmission P1" state (I) MM_NO_STATE (peer 65.xxx.132.xxx)

Thank for reading.

Ce message a été modifié par: daniel-mathieu vérification

I have this problem too.
0 votes
  • 1
  • 2
  • 3
  • 4
  • 5
Overall Rating: 0 (0 ratings)
Loading.
Jennifer Halim Thu, 03/18/2010 - 22:42

Hi Daniel,

Doesn't look like Phase 1 negotiation is taking place.

Please send the following debug from both ends:

- debug cry isa

- debug cry sa

Is UDP/500 being blocked along the path between the 2 sites?

After you try to send traffic between the sites, please also send the following output from both sites:

- show cry isa sa

- show cry ipsec sa

Daniel Mathieu Fri, 03/19/2010 - 01:03

Thank!

We have access to one end only! (MTL 1841) for now,

Tommorow morning we use a Webex session and go inside and get control of this router 870

the other end (Brabade)respond to ping and still having access to web, msn.

This one having access to Web by satellite

that will show the status of phase 1


MTL#show crypto isakmp  sa

IPv4 Crypto ISAKMP SA 
dst             src             state            conn-id     slot status 
72.10.144.178   65.xxx.132.xxx   QM_IDLE           2007    0 ACTIVE 
 
IPv6 Crypto ISAKMP SA

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


that will show the status of phase 2, as well as number of encrypted/decrypted packets     
     
     
MTL#sh crypto ipsec sa     
     
interface: FastEthernet0/1     
    Crypto map tag: SDM_CMAP_3, local addr 72.yyy.yyy.178     
     
   protected vrf: (none)     
   local  ident (addr/mask/prot/port): (192.168.104.0/255.255.255.0/0/0)     
   remote ident (addr/mask/prot/port): (192.168.103.64/255.255.255.192/0/0)     
   current_peer 65.xxx.132.xxx port 4500     
     PERMIT, flags={origin_is_acl,}     
    #pkts encaps: 2425, #pkts encrypt: 2425, #pkts digest: 2425     
    #pkts decaps: 57919, #pkts decrypt: 57919, #pkts verify: 57919     
    #pkts compressed: 0, #pkts decompressed: 0     
    #pkts not compressed: 0, #pkts compr. failed: 0     
    #pkts not decompressed: 0, #pkts decompress failed: 0     
    #send errors 67, #recv errors 0     
     
     local crypto endpt.: 72.yyy.144.yyy, remote crypto endpt.: 65.xxx.132.xxx     
     path mtu 1500, ip mtu 1500, ip mtu idb FastEthernet0/1     
     current outbound spi: 0x396BB827(963360807)     
     
     inbound esp sas:     
      spi: 0xC9973951(3382131025)     
        transform: esp-3des esp-sha-hmac ,     
        in use settings ={Tunnel UDP-Encaps, }     
        conn id: 25, flow_id: AIM-VPN/SSL-1:25, crypto map: SDM_CMAP_3     
        sa timing: remaining key lifetime (k/sec): (4438388/2548)     
        IV size: 8 bytes     
        replay detection support: Y     
        Status: ACTIVE     
     
     inbound ah sas:     
     
     inbound pcp sas:     
     
     outbound esp sas:     
      spi: 0x396BB827(963360807)     
        transform: esp-3des esp-sha-hmac ,     
        in use settings ={Tunnel UDP-Encaps, }     
        conn id: 26, flow_id: AIM-VPN/SSL-1:26, crypto map: SDM_CMAP_3     
        sa timing: remaining key lifetime (k/sec): (4438388/2544)     
        IV size: 8 bytes     
        replay detection support: Y     
        Status: ACTIVE     
     
     outbound ah sas:     
     
     outbound pcp sas:    

****


MTL#debug crypto socket
Crypto secure socket events debugging is on
Angelcare-monitor_MTL#term mon
Angelcare-monitor_MTL#
Mar 19 07:48:12.069: ISAKMP:(0):SA is still budding. Attached new ipsec request to it. (local 72.yyy.144.yyy, remote 65.xxx.132.xxx)
Mar 19 07:48:12.069: ISAKMP: Error while processing SA request: Failed to initialize SA
Mar 19 07:48:12.069: ISAKMP: Error while processing KMI message 0, error 2.
Mar 19 07:48:42.067: ISAKMP:(0):deleting SA reason "Death by retransmission P1" state (I) MM_NO_STATE (peer 65.xxx.132.xxx)
Mar 19 07:48:42.067: ISAKMP:(0):deleting SA reason "Death by retransmission P1" state (I) MM_NO_STATE (peer 65.xxx.132.xxx)
Mar 19 07:49:12.520: ISAKMP:(0):SA is still budding. Attached new ipsec request to it. (local 72.yyy.144.yyy, remote 65.xxx.132.xxx)
Mar 19 07:49:12.520: ISAKMP: Error while processing SA request: Failed to initialize SA
Mar 19 07:49:12.520: ISAKMP: Error while processing KMI message 0, error 2.


Crypto ISAKMP debugging is on
MTL#
Mar 19 07:49:32.062: ISAKMP:(0):purging node -1690812137
Mar 19 07:49:32.062: ISAKMP:(0):purging node -128590477
Mar 19 07:49:32.522: ISAKMP:(0): retransmitting phase 1 MM_NO_STATE...
Mar 19 07:49:32.522: ISAKMP (0:0): incrementing error counter on sa, attempt 5 of 5: retransmit phase 1
Mar 19 07:49:32.522: ISAKMP:(0): retransmitting phase 1 MM_NO_STATE
Mar 19 07:49:32.522: ISAKMP:(0): sending packet to 65.xxx.132.xxx my_port 500 peer_port 500 (I) MM_NO_STATE
Mar 19 07:49:32.522: ISAKMP:(0):Sending an IKE IPv4 Packet.
Mar 19 07:49:42.061: ISAKMP:(0):purging SA., sa=649C1E50, delme=649C1E50
Mar 19 07:49:42.521: ISAKMP:(0): retransmitting phase 1 MM_NO_STATE...
Mar 19 07:49:42.521: ISAKMP:(0):peer does not do paranoid keepalives.

Mar 19 07:49:42.521: ISAKMP:(0):deleting SA reason "Death by retransmission P1" state (I) MM_NO_STATE (peer 65.xxx.132.xxx)
Mar 19 07:49:42.521: ISAKMP:(0):deleting SA reason "Death by retransmission P1" state (I) MM_NO_STATE (peer 65.xxx.132.xxx)
Mar 19 07:49:42.521: ISAKMP: Unlocking peer struct 0x649C2878 for isadb_mark_sa_deleted(), count 0
Mar 19 07:49:42.521: ISAKMP: Deleting peer node by peer_reap for 65.xxx.132.xxx: 649C2878
Mar 19 07:49:42.521: ISAKMP:(0):deleting node -398981836 error FALSE reason "IKE deleted"
Mar 19 07:49:42.521: ISAKMP:(0):deleting node -856086478 error FALSE reason "IKE deleted"
Mar 19 07:49:42.521: ISAKMP:(0):Input = IKE_MESG_INTERNAL, IKE_PHASE1_DEL
Mar 19 07:49:42.521: ISAKMP:(0):Old State = IKE_I_MM1  New State = IKE_DEST_SA

Mar 19 07:49:43.417: ISAKMP:(0): SA request profile is (NULL)
Mar 19 07:49:43.417: ISAKMP: Created a peer struct for 65.xxx.132.xxx, peer port 500
Mar 19 07:49:43.417: ISAKMP: New peer created peer = 0x64890B6C peer_handle = 0x8000002C
Mar 19 07:49:43.417: ISAKMP: Locking peer struct 0x64890B6C, refcount 1 for isakmp_initiator
Mar 19 07:49:43.417: ISAKMP: local port 500, remote port 500
Mar 19 07:49:43.417: ISAKMP: set new node 0 to QM_IDLE
Mar 19 07:49:43.417: ISAKMP: Find a dup sa in the avl tree during calling isadb_insert sa = 649C1E50
Mar 19 07:49:43.417: ISAKMP:(0):Can not start Aggressive mode, trying Main mode.
Mar 19 07:49:43.417: ISAKMP:(0):found peer pre-shared key matching 65.xxx.132.xxx
Mar 19 07:49:43.417: ISAKMP:(0): constructed NAT-T vendor-rfc3947 ID
Mar 19 07:49:43.417: ISAKMP:(0): constructed NAT-T vendor-07 ID
Mar 19 07:49:43.417: ISAKMP:(0): constructed NAT-T vendor-03 ID
Mar 19 07:49:43.417: ISAKMP:(0): constructed NAT-T vendor-02 ID
Mar 19 07:49:43.417: ISAKMP:(0):Input = IKE_MESG_FROM_IPSEC, IKE_SA_REQ_MM
Mar 19 07:49:43.417: ISAKMP:(0):Old State = IKE_READY  New State = IKE_I_MM1

Mar 19 07:49:43.417: ISAKMP:(0): beginning Main Mode exchange
Mar 19 07:49:43.417: ISAKMP:(0): sending packet to 65.xxx.132.xxx my_port 500 peer_port 500 (I) MM_NO_STATE
Mar 19 07:49:43.417: ISAKMP:(0):Sending an IKE IPv4 Packet.
Mar 19 07:49:53.420: ISAKMP:(0): retransmitting phase 1 MM_NO_STATE...
Mar 19 07:49:53.420: ISAKMP (0:0): incrementing error counter on sa, attempt 1 of 5: retransmit phase 1
Mar 19 07:49:53.420: ISAKMP:(0): retransmitting phase 1 MM_NO_STATE
Mar 19 07:49:53.420: ISAKMP:(0): sending packet to 65.xxx.132.xxx my_port 500 peer_port 500 (I) MM_NO_STATE
Mar 19 07:49:53.420: ISAKMP:(0):Sending an IKE IPv4 Packet.
Mar 19 07:50:03.419: ISAKMP:(0): retransmitting phase 1 MM_NO_STATE...
Mar 19 07:50:03.419: ISAKMP (0:0): incrementing error counter on sa, attempt 2 of 5: retransmit phase 1
Mar 19 07:50:03.419: ISAKMP:(0): retransmitting phase 1 MM_NO_STATE
Mar 19 07:50:03.419: ISAKMP:(0): sending packet to 65.xxx.132.xxx my_port 500 peer_port 500 (I) MM_NO_STATE
Mar 19 07:50:03.419: ISAKMP:(0):Sending an IKE IPv4 Packet.
Mar 19 07:50:13.414: ISAKMP: set new node 0 to QM_IDLE
Mar 19 07:50:13.414: ISAKMP:(0):SA is still budding. Attached new ipsec request to it. (local 72.yyy.144.yyy, remote 65.xxx.132.xxx)
Mar 19 07:50:13.414: ISAKMP: Error while processing SA request: Failed to initialize SA
Mar 19 07:50:13.414: ISAKMP: Error while processing KMI message 0, error 2.
Mar 19 07:50:13.418: ISAKMP:(0): retransmitting phase 1 MM_NO_STATE...
Mar 19 07:50:13.418: ISAKMP (0:0): incrementing error counter on sa, attempt 3 of 5: retransmit phase 1
Mar 19 07:50:13.418: ISAKMP:(0): retransmitting phase 1 MM_NO_STATE
Mar 19 07:50:13.418: ISAKMP:(0): sending packet to 65.xxx.132.xxx my_port 500 peer_port 500 (I) MM_NO_STATE
Mar 19 07:50:13.418: ISAKMP:(0):Sending an IKE IPv4 Packet.

Jennifer Halim Fri, 03/19/2010 - 02:24

Both phases seem to be UP and Operational as per the output of show commands.

Did you make any changes on the MTL site? is 192.168.104.0/24 subnet directly connected to the router? are you able to ping across the tunnel? can you try to ping from the router sourcing it from the router interface which is in 192.168.104.0 subnet?

Please also share the configuration if you may.

Daniel Mathieu Fri, 03/19/2010 - 02:42

No change about physical and logical config on both side.

Both WAN Ip was able to ping.

From MTL inside Lan ping the WAN IP of Barbade but not inside 192.168.104.x

Config following

About ping trough tunnel, no

Jennifer Halim Fri, 03/19/2010 - 04:18

The ZBFW policy that you have doesn't allow ping from the router towards the LAN.

Can you try to ping from behind MTL LAN towards Barbade LAN (not the router interface IP please).

Daniel Mathieu Fri, 03/19/2010 - 06:24

From behind the router MTL

ping Barbade router WAN interface 100%

ping Barbade router LAN interface 0%

From behind the router Barbade

ping MTL router WAN interface 100%

ping MTL router LAN interface 0%

From remote user

Ping every wan interface, not inside

We replace on both end all product with original config ( physical and logical ).

The situation appear to be the same.

It's possible we are blocked in between

thank

Attachment: 

Actions

This Discussion