8 Replies Latest reply: Nov 12, 2015 12:15 PM by Pblawrence RSS

    phase 1 ISAKMP failure

    Aaron Francis

      Hey gang I had a site-to-site vpn tunnel drop off all of a sudden and it hasn't come back up yet. I haven't changed anything on the router (or any other piece of hardware at this particular site for that matter) and I would be the only person with access to do anything.

       

      I have rebooted the business cable modem which is providing Internet to no avail. There are two vpn tunnels established on this router and the other tunnel is just fine and has been for awhile, so its just a single vpn tunnel in question. I called the distant end to see if they had done anything and they say no (cloud service provider). They see that their ASA5510 responds back to an initialization packet coning from the sites 2911 ISR router but no communication comes back from the router past that initial packet sent in response. This tunnel had been for for months prior to this drop off. Here is a debug output: (this output cycles again and again)

       


       

      Sep 18 16:32:32.099: ISAKMP:(0):deleting SA reason "Death by retransmission P1" state (I) MM_NO_STATE (peer 50.56.61.241)

      Sep 18 16:32:32.099: ISAKMP:(0):deleting SA reason "Death by retransmission P1" state (I) MM_NO_STATE (peer 50.56.61.241)

      Sep 18 16:32:32.099: ISAKMP: Unlocking peer struct 0x314A9EC8 for isadb_mark_sa_deleted(), count 0

      Sep 18 16:32:32.099: ISAKMP: Deleting peer node by peer_reap for 50.56.61.241: 314A9EC8

      Sep 18 16:32:32.099: ISAKMP:(0):deleting node 2094616066 error FALSE reason "IKE deleted"

      Sep 18 16:32:32.099: ISAKMP:(0):deleting node 1902884115 error FALSE reason "IKE deleted"

      Sep 18 16:32:32.099: ISAKMP:(0):deleting node 1499185217 error FALSE reason "IKE deleted"

      Sep 18 16:32:32.099: ISAKMP:(0):Input = IKE_MESG_INTERNAL, IKE_PHASE1_DEL

      Sep 18 16:32:32.099: ISAKMP:(0):Old State = IKE_I_MM1  New State = IKE_DEST_SA

       

       

      Sep 18 16:32:32.099: ISAKMP:(0): SA request profile is (NULL)

      Sep 18 16:32:32.099: ISAKMP: Created a peer struct for 50.56.61.241, peer port 500

      Sep 18 16:32:32.099: ISAKMP: New peer created peer = 0x314A9EC8 peer_handle = 0x800006F9

      Sep 18 16:32:32.099: ISAKMP: Locking peer struct 0x314A9EC8, refcount 1 for isakmp_initiator

      Sep 18 16:32:32.099: ISAKMP: local port 500, remote port 500

      Sep 18 16:32:32.099: ISAKMP: set new node 0 to QM_IDLE

      Sep 18 16:32:32.099: ISAKMP: Find a dup sa in the avl tree during calling isadb_insert sa = 2B998BB4

      Sep 18 16:32:32.099: ISAKMP:(0):Can not start Aggressive mode, trying Main mode.

      Sep 18 16:32:32.099: ISAKMP:(0):found peer pre-shared key matching 50.56.61.241

      Sep 18 16:32:32.099: ISAKMP:(0): constructed NAT-T vendor-rfc3947 ID

      Sep 18 16:32:32.099: ISAKMP:(0): constructed NAT-T vendor-07 ID

      Sep 18 16:32:32.099: ISAKMP:(0): constructed NAT-T vendor-03 ID

      Sep 18 16:32:32.099: ISAKMP:(0): constructed NAT-T vendor-02 ID

      Sep 18 16:32:32.099: ISAKMP:(0):Input = IKE_MESG_FROM_IPSEC, IKE_SA_REQ_MM

      Sep 18 16:32:32.099: ISAKMP:(0):Old State = IKE_READY  New State = IKE_I_MM1

       

       

      Sep 18 16:32:32.099: ISAKMP:(0): beginning Main Mode exchange

      Sep 18 16:32:32.099: ISAKMP:(0): sending packet to 50.56.61.241 my_port 500 peer_port 500 (I) MM_NO_STATE

      Sep 18 16:32:32.099: ISAKMP:(0):Sending an IKE IPv4 Packet.

      Sep 18 16:32:40.915: ISAKMP: set new node 0 to QM_IDLE

      Sep 18 16:32:40.915: ISAKMP:(0):SA is still budding. Attached new ipsec request to it. (local 75.144.111.193, remote 50.56.61.241)

      Sep 18 16:32:40.915: ISAKMP: Error while processing SA request: Failed to initialize SA

      Sep 18 16:32:40.915: ISAKMP: Error while processing KMI message 0, error 2.

      Sep 18 16:32:42.099: ISAKMP:(0): retransmitting phase 1 MM_NO_STATE...

      Sep 18 16:32:42.099: ISAKMP (0): incrementing error counter on sa, attempt 1 of 5: retransmit phase 1

      Sep 18 16:32:42.099: ISAKMP:(0): retransmitting phase 1 MM_NO_STATE

      Sep 18 16:32:42.099: ISAKMP:(0): sending packet to 50.56.61.241 my_port 500 peer_port 500 (I) MM_NO_STATE

      Sep 18 16:32:42.099: ISAKMP:(0):Sending an IKE IPv4 Packet.

      Sep 18 16:32:52.099: ISAKMP:(0): retransmitting phase 1 MM_NO_STATE...

      Sep 18 16:32:52.099: ISAKMP (0): incrementing error counter on sa, attempt 2 of 5: retransmit phase 1

      Sep 18 16:32:52.099: ISAKMP:(0): retransmitting phase 1 MM_NO_STATE

      Sep 18 16:32:52.099: ISAKMP:(0): sending packet to 50.56.61.241 my_port 500 peer_port 500 (I) MM_NO_STATE

      Sep 18 16:32:52.099: ISAKMP:(0):Sending an IKE IPv4 Packet.

      Sep 18 16:32:54.091: ISAKMP: set new node -94652246 to QM_IDLE

      Sep 18 16:32:54.091: ISAKMP:(1487): sending packet to 50.42.30.26 my_port 500 peer_port 500 (R) QM_IDLE

      Sep 18 16:32:54.091: ISAKMP:(1487):Sending an IKE IPv4 Packet.

      Sep 18 16:32:54.091: ISAKMP:(1487):purging node -94652246

      Sep 18 16:32:54.091: ISAKMP:(1487):Input = IKE_MESG_FROM_IPSEC, IKE_PHASE2_DEL

      Sep 18 16:32:54.091: ISAKMP:(1487):Old State = IKE_P1_COMPLETE  New State = IKE_P1_COMPLETE

       

       

      Sep 18 16:32:54.095: ISAKMP (1487): received packet from 50.42.30.26 dport 500 sport 500 Global (R) QM_IDLE

      Sep 18 16:32:54.095: ISAKMP: set new node -847842933 to QM_IDLE

      Sep 18 16:32:54.095: ISAKMP:(1487): processing HASH payload. message ID = 3447124363

      Sep 18 16:32:54.095: ISAKMP:(1487): processing DELETE payload. message ID = 3447124363

      Sep 18 16:32:54.095: ISAKMP:(1487):peer does not do paranoid keepalives.

       

       

      Sep 18 16:32:54.095: ISAKMP:(1487):deleting node -847842933 error FALSE reason "Informational (in) state 1"

      Sep 18 16:32:56.271: ISAKMP:(1487):purging node -746546077

      Sep 18 16:33:02.099: ISAKMP: set new node 0 to QM_IDLE

      Sep 18 16:33:02.099: ISAKMP:(0):SA is still budding. Attached new ipsec request to it. (local 75.144.111.193, remote 50.56.61.241)

      Sep 18 16:33:02.099: ISAKMP: Error while processing SA request: Failed to initialize SA

      Sep 18 16:33:02.099: ISAKMP: Error while processing KMI message 0, error 2.

      Sep 18 16:33:02.099: ISAKMP:(0): retransmitting phase 1 MM_NO_STATE...

      Sep 18 16:33:02.099: ISAKMP (0): incrementing error counter on sa, attempt 3 of 5: retransmit phase 1

      Sep 18 16:33:02.099: ISAKMP:(0): retransmitting phase 1 MM_NO_STATE

      Sep 18 16:33:02.099: ISAKMP:(0): sending packet to 50.56.61.241 my_port 500 peer_port 500 (I) MM_NO_STATE

      Sep 18 16:33:02.099: ISAKMP:(0):Sending an IKE IPv4 Packet.

      Sep 18 16:33:11.954: ISAKMP: set new node 0 to QM_IDLE

      Sep 18 16:33:11.954: ISAKMP:(0):SA is still budding. Attached new ipsec request to it. (local 75.144.111.193, remote 50.56.61.241)

      Sep 18 16:33:11.954: ISAKMP: Error while processing SA request: Failed to initialize SA

      Sep 18 16:33:11.954: ISAKMP: Error while processing KMI message 0, error 2.

      Sep 18 16:33:12.098: ISAKMP:(0): retransmitting phase 1 MM_NO_STATE...

      Sep 18 16:33:12.098: ISAKMP (0): incrementing error counter on sa, attempt 4 of 5: retransmit phase 1

      Sep 18 16:33:12.098: ISAKMP:(0): retransmitting phase 1 MM_NO_STATE

      Sep 18 16:33:12.098: ISAKMP:(0): sending packet to 50.56.61.241 my_port 500 peer_port 500 (I) MM_NO_STATE

      Sep 18 16:33:12.098: ISAKMP:(0):Sending an IKE IPv4 Packet.

      Sep 18 16:33:22.098: ISAKMP:(0):purging node 2094616066

      Sep 18 16:33:22.098: ISAKMP:(0):purging node 1902884115

      Sep 18 16:33:22.098: ISAKMP:(0):purging node 1499185217

      Sep 18 16:33:22.098: ISAKMP:(0): retransmitting phase 1 MM_NO_STATE...

      Sep 18 16:33:22.098: ISAKMP (0): incrementing error counter on sa, attempt 5 of 5: retransmit phase 1

      Sep 18 16:33:22.098: ISAKMP:(0): retransmitting phase 1 MM_NO_STATE

      Sep 18 16:33:22.098: ISAKMP:(0): sending packet to 50.56.61.241 my_port 500 peer_port 500 (I) MM_NO_STATE

      Sep 18 16:33:22.098: ISAKMP:(0):Sending an IKE IPv4 Packet.

      Sep 18 16:33:32.098: ISAKMP:(0):purging SA., sa=312EAA9C, delme=312EAA9C

      Sep 18 16:33:32.098: ISAKMP:(0): retransmitting phase 1 MM_NO_STATE...

      Sep 18 16:33:32.098: ISAKMP:(0):peer does not do paranoid keepalives.

        • 1. Re: phase 1 ISAKMP failure
          Dan

          I had this same thing happen recently and never did find the root cause.  Best I could guess was an IOS upgrade on one of the ends and the default parameters no longer match.  My scenario was EZVPN using aggressive mode, and switching it to a manual crypto map with parameters I could control fixed it.

           

          One suggestion is use different algorithms, especially if the remote end is not Cisco.  I have seen other vendors mismatch algorithms because the key length doesn't match (like AES <> AES since one end "AES" means 128 bit and the other end "AES" means 192 bit, for example).

           

          Only other suggestion is making sure 4500/udp is open on both ends since NAT-T is detected.

           

          Basically, phase 1 is completing on your router, it tries to notify other peer that it succeeded but that notify never makes it through and the remote end kills the connection.

          • 2. Re: phase 1 ISAKMP failure
            Aaron Francis

            Thanks lot for the reply Dan, i really appreaicte it.

            • 3. Re: phase 1 ISAKMP failure
              Dan

              No problem, glad to help.  Let us know if/when you find a resolution.

              • 4. Re: phase 1 ISAKMP failure
                Aaron Francis

                Will do.

                • 5. Re: phase 1 ISAKMP failure
                  Tahir Mahmood Kamboh

                  A show crypto isakmp sa command shows the ISAKMP SA to be in MM_NO_STATE. This also means that main mode has failed.

                   

                  dst                src        state                         conn-id               slot

                  10.1.1.2  10.1.1.1   MM_NO_STATE              1           0

                  Verify that the phase 1 policy is on both peers, and ensure that all the attributes match.

                   

                  Encryption DES or 3DES

                  Hash MD5 or SHA

                  Diffie-Hellman Group 1 or 2

                  Authentication {rsa-sig | rsa-encr | pre-share  }

                   

                  The following link can also be helpfull in troubleshooting

                  http://cisco.com/en/US/tech/tk583/tk372/technologies_tech_note09186a00800949c5.shtml

                  • 6. Re: phase 1 ISAKMP failure
                    krmidhun

                    I had the same issue with a tunnel between cisco ASA having a static IP and IOS router with dynamic IP. The issue was that the phase 2 security lifetime association was globally configured on the cisco ASA as below:

                    ASA# sh run crypto | i lifetime
                    crypto ipsec security-association lifetime seconds 28800
                    crypto ipsec security-association lifetime kilobytes 4608000

                    On the other side, router had a different value as given below:

                    Router#show crypto ipsec security-association lifetime
                    Security association lifetime: 4608000 kilobytes/3600 seconds

                    I changed the lifetime value under the crypto map configuration on router and that fixed the issue.

                    • 7. Re: phase 1 ISAKMP failure
                      Ismael da Silva Mariano

                          Hi,  Aaron!

                       

                          Could you please send the configuration of both boxes

                       

                          Thank you!

                      • 8. Re: phase 1 ISAKMP failure
                        Pblawrence

                        I had the same issue today...however, mine was a DMVPN connection. Everything was working fine until yesterday. I checked the logs to make sure nobody made any configuration changes (dot your i's).

                         

                        • When I issued the show crytpo isakmp sa command on the spoke router, I realized my connection was flapping

                        IPv4 Crypto ISAKMP SA

                        dst             src             state          conn-id status

                        167.102.x.x  192.168.x.x   MM_KEY_EXCH       8427 ACTIVE

                        167.102.x.x 192.168.x.x   MM_NO_STATE       8425 ACTIVE (deleted)

                        167.102.x.x  192.168.x.x   MM_KEY_EXCH       8428 ACTIVE

                        167.102.x.x  192.168.x.x   MM_NO_STATE       8426 ACTIVE (deleted)

                         

                        • ON the Hub router, I was getting the following response after issuing the command above also

                        dst             src             state          conn-id status

                        10.158.x.x   173.64.x.x    MM_NO_STATE      38769 ACTIVE (deleted)

                         

                        The src in the Hub router table above is the internet IP address of the spoke's ISP. The Hub could see the request come through but it

                        wasn't stable enough to hold a connection, hence dropping back and forth.

                         

                        After running several debug commands, and cross referencing my config, I still couldn't find the problem.

                        Most annoying answer to tshoot issues: I issued the RELOAD command on my Cisco Router. BAM!!! All my connections came back up!!!

                        You don't have to reboot the ISP router.