Project

General

Profile

Issue #3488

Strongswan <> Cisco stopped to work after long time (connection restart doesnt help)

Added by Edvinas Kaikaris about 2 months ago. Updated about 2 months ago.

Status:
Feedback
Priority:
Normal
Assignee:
-
Category:
-
Affected version:
5.7.2
Resolution:

Description

Hello again,

I got quite strange behavior with Strongswan <> Cisco connection. one day it just stopped to work. I though i could be due to duplicate detection and so on. So turned dup detection off and restarted the connection. Still it stucks in Connection mode. It's very strange, other connections to the same nodes work OK. I cant revivee this one.

Here is info on Strongswan Side:

conn net-la2rtr01
    left=37.37.37.37
    leftsubnet=37.37.37.37/32[gre]
    rightsubnet=185.185.185.185/32[gre]
    leftfirewall=no
    ike=aes-sha1-modp1024
    esp=aes128gcm16-modp1024
    right=185.185.185.185
    type=tunnel
    authby=psk
    auto=start
    keyexchange=ikev1

Strongswan statusall:

Security Associations (7 up, 1 connecting):
   (unnamed)[32]: CONNECTING, 37.37.37.37[%any]...185.185.185.185[%any]
   (unnamed)[32]: IKEv1 SPIs: 720a312775195bdd_i 833ab3aff74a727e_r*
   (unnamed)[32]: IKE proposal: AES_CBC_128/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_1024
   (unnamed)[32]: Tasks passive: ISAKMP_VENDOR MAIN_MODE ISAKMP_NATD

Some Strongswan logs:

Jun 22 11:19:31 [localhost] charon: 09[IKE] 185.185.185.185 is initiating a Main Mode IKE_SA
Jun 22 11:19:31 [localhost] charon: 09[NET] sending packet: from 37.37.37.37[500] to 185.185.185.185[500] (136 bytes)
Jun 22 11:19:41 [localhost] charon: 12[NET] received packet: from 185.185.185.185[500] to 37.37.37.37[500] (164 bytes)
Jun 22 11:19:41 [localhost] charon: 12[NET] sending packet: from 37.37.37.37[500] to 185.185.185.185[500] (136 bytes)
Jun 22 11:19:51 [localhost] charon: 06[NET] received packet: from 185.185.185.185[500] to 37.37.37.37[500] (164 bytes)
Jun 22 11:19:51 [localhost] charon: 06[NET] sending packet: from 37.37.37.37[500] to 185.185.185.185[500] (136 bytes)
Jun 22 11:20:01 [localhost] charon: 05[JOB] deleting half open IKE_SA with 185.185.185.185 after timeout
Jun 22 11:20:02 [localhost] charon: 16[NET] received packet: from 185.185.185.185[500] to 37.37.37.37[500] (164 bytes)
Jun 22 11:20:02 [localhost] charon: 16[IKE] 185.185.185.185 is initiating a Main Mode IKE_SA

And also some logs on Cisco side:

Jun 22 09:23:02.886: ISAKMP: (0):retransmitting phase 1 MM_NO_STATE...
Jun 22 09:23:02.886: ISAKMP: (0):peer does not do paranoid keepalives.
Jun 22 09:23:02.886: ISAKMP-ERROR: (0):deleting SA reason "Death by retransmission P1" state (I) MM_NO_STATE (peer 37.37.37.37)
Jun 22 09:23:02.886: ISAKMP-ERROR: (0):deleting SA reason "Death by retransmission P1" state (I) MM_NO_STATE (peer 37.37.37.37) 
Jun 22 09:23:02.886: ISAKMP: (0):Unlocking peer struct 0x80007F2C2634EB20 for isadb_mark_sa_deleted(), count 0
Jun 22 09:23:02.886: ISAKMP: (0):Deleting peer node by peer_reap for 37.37.37.37: 80007F2C2634EB20
Jun 22 09:23:02.887: ISAKMP: (0):deleting node 933492316 error FALSE reason "IKE deleted" 
Jun 22 09:23:02.887: ISAKMP: (0):deleting node 999757834 error FALSE reason "IKE deleted" 
Jun 22 09:23:02.887: ISAKMP: (0):Input = IKE_MESG_INTERNAL, IKE_PHASE1_DEL
Jun 22 09:23:02.887: ISAKMP: (0):Old State = IKE_I_MM1  New State = IKE_DEST_SA 

Jun 22 09:23:02.887: IPSEC(key_engine): got a queue event with 1 KMI message(s)
Jun 22 09:23:03.341: IPSEC:(SESSION ID = 167849) (key_engine) request timer fired: count = 1,
  (identity) local= 185.185.185.185:0, remote= 37.37.37.37:0,
    local_proxy= 185.185.185.185/255.255.255.255/47/0,
    remote_proxy= 37.37.37.37/255.255.255.255/47/0
Jun 22 09:23:03.341: IPSEC(sa_request): ,
  (key eng. msg.) OUTBOUND local= 185.185.185.185:500, remote= 37.37.37.37:500,
    local_proxy= 185.185.185.185/255.255.255.255/47/0,
    remote_proxy= 37.37.37.37/255.255.255.255/47/0,
    protocol= ESP, transform= esp-gcm  (Tunnel), 
    lifedur= 3600s and 4608000kb, 
    spi= 0x0(0), conn_id= 0, keysize= 128, flags= 0x0
Jun 22 09:23:03.341: ISAKMP: (0):SA request profile is (NULL)
Jun 22 09:23:03.341: ISAKMP: (0):Created a peer struct for 37.37.37.37, peer port 500
Jun 22 09:23:03.341: ISAKMP: (0):New peer created peer = 0x80007F2C158BD690 peer_handle = 0x800000008000AC7C
Jun 22 09:23:03.342: ISAKMP: (0):Locking peer struct 0x80007F2C158BD690, refcount 1 for isakmp_initiator
Jun 22 09:23:03.342: ISAKMP: (0):local port 500, remote port 500
Jun 22 09:23:03.342: ISAKMP: (0):set new node 0 to QM_IDLE      
Jun 22 09:23:03.342: ISAKMP: (0):Find a dup sa in the avl tree during calling isadb_insert sa = 80007F2C260DFCA0
Jun 22 09:23:03.342: ISAKMP: (0):Can not start Aggressive mode, trying Main mode.
Jun 22 09:23:03.342: ISAKMP: (0):found peer pre-shared key matching 37.37.37.37
Jun 22 09:23:03.342: ISAKMP: (0):constructed NAT-T vendor-rfc3947 ID
Jun 22 09:23:03.342: ISAKMP: (0):constructed NAT-T vendor-07 ID
Jun 22 09:23:03.342: ISAKMP: (0):constructed NAT-T vendor-03 ID
Jun 22 09:23:03.342: ISAKMP: (0):constructed NAT-T vendor-02 ID
Jun 22 09:23:03.342: ISAKMP: (0):Input = IKE_MESG_FROM_IPSEC, IKE_SA_REQ_MM
Jun 22 09:23:03.342: ISAKMP: (0):Old State = IKE_READY  New State = IKE_I_MM1 

Jun 22 09:23:03.342: ISAKMP: (0):beginning Main Mode exchange
Jun 22 09:23:03.342: ISAKMP-PAK: (0):sending packet to 37.37.37.37 my_port 500 peer_port 500 (I) MM_NO_STATE
Jun 22 09:23:03.342: ISAKMP: (0):Sending an IKE IPv4 Packet.
Jun 22 09:23:13.343: ISAKMP: (0):retransmitting phase 1 MM_NO_STATE...
Jun 22 09:23:13.343: ISAKMP: (0):: incrementing error counter on sa, attempt 1 of 5: retransmit phase 1
Jun 22 09:23:13.343: ISAKMP: (0):retransmitting phase 1 MM_NO_STATE
Jun 22 09:23:13.343: ISAKMP-PAK: (0):sending packet to 37.37.37.37 my_port 500 peer_port 500 (I) MM_NO_STATE
Jun 22 09:23:13.343: ISAKMP: (0):Sending an IKE IPv4 Packet.
LA2RTR01#
Jun 22 09:23:23.344: ISAKMP: (0):retransmitting phase 1 MM_NO_STATE...
Jun 22 09:23:23.344: ISAKMP: (0):: incrementing error counter on sa, attempt 2 of 5: retransmit phase 1
Jun 22 09:23:23.344: ISAKMP: (0):retransmitting phase 1 MM_NO_STATE
Jun 22 09:23:23.344: ISAKMP-PAK: (0):sending packet to 37.37.37.37 my_port 500 peer_port 500 (I) MM_NO_STATE
Jun 22 09:23:23.344: ISAKMP: (0):Sending an IKE IPv4 Packet.
LA2RTR01#
Jun 22 09:23:33.342: IPSEC:(SESSION ID = 167849) (key_engine) request timer fired: count = 2,
  (identity) local= 185.185.185.185:0, remote= 37.37.37.37:0,
    local_proxy= 185.185.185.185/255.255.255.255/47/0,
    remote_proxy= 37.37.37.37/255.255.255.255/47/0
Jun 22 09:23:33.344: ISAKMP: (0):retransmitting phase 1 MM_NO_STATE...
Jun 22 09:23:33.344: ISAKMP: (0):: incrementing error counter on sa, attempt 3 of 5: retransmit phase 1
Jun 22 09:23:33.344: ISAKMP: (0):retransmitting phase 1 MM_NO_STATE
Jun 22 09:23:33.344: ISAKMP-PAK: (0):sending packet to 37.37.37.37 my_port 500 peer_port 500 (I) MM_NO_STATE
Jun 22 09:23:33.344: ISAKMP: (0):Sending an IKE IPv4 Packet.
Jun 22 09:23:33.783: IPSEC(sa_request): ,
  (key eng. msg.) OUTBOUND local= 185.185.185.185:500, remote= 37.37.37.37:500,
    local_proxy= 185.185.185.185/255.255.255.255/47/0,
    remote_proxy= 37.37.37.37/255.255.255.255/47/0,
    protocol= ESP, transform= esp-gcm  (Tunnel), 
    lifedur= 3600s and 4608000kb, 
    spi= 0x0(0), conn_id= 0, keysize= 128, flags= 0x0
Jun 22 09:23:33.783: ISAKMP: (0):set new node 0 to QM_IDLE      
Jun 22 09:23:33.783: ISAKMP-ERROR: (0):SA is still budding. Attached new ipsec request to it. (local 185.185.185.185, remote 37.37.37.37)
Jun 22 09:23:33.783: ISAKMP-ERROR: (0):Error while processing SA request: Failed to initialize SA
Jun 22 09:23:33.783: ISAKMP-ERROR: (0):Error while processing KMI message 0, error 2.
Jun 22 09:23:43.344: ISAKMP: (0):retransmitting phase 1 MM_NO_STATE...
Jun 22 09:23:43.344: ISAKMP: (0):: incrementing error counter on sa, attempt 4 of 5: retransmit phase 1
Jun 22 09:23:43.345: ISAKMP: (0):retransmitting phase 1 MM_NO_STATE
Jun 22 09:23:43.345: ISAKMP-PAK: (0):sending packet to 37.37.37.37 my_port 500 peer_port 500 (I) MM_NO_STATE
Jun 22 09:23:43.345: ISAKMP: (0):Sending an IKE IPv4 Packet.

Maybe you have any comments about it ?

Thank you

History

#1 Updated by Tobias Brunner about 2 months ago

  • Status changed from New to Feedback

It just looks like the the response packets sent by strongSwan get lost somewhere. Where/why, no idea.

Also available in: Atom PDF