ASA VPN Tunnel log interpretation

sasa.popravak · ‎08-17-2011

Hello guys!

Can somebody please interpret this log for me:

%ASA-5-713050: Group = a.b.c.d, IP = a.b.c.d, Connection terminated for peer a.b.c.d. Reason: Peer Terminate Remote Proxy 192.168.171.0, Local Proxy 172.27.114.0

%ASA-5-713050: Group = a.b.c.d, IP = a.b.c.d, Connection terminated for peer a.b.c.d. Reason: Peer Terminate Remote Proxy 195.188.162.0, Local Proxy 172.27.114.0

%ASA-5-713259: Group = a.b.c.d, IP = a.b.c.d, Session is being torn down. Reason: User Requested

%ASA-4-113019: Group = a.b.c.d, Username = a.b.c.d, IP = a.b.c.d, Session disconnected. Session Type: IPsec, Duration: 12h:00m:12s, Bytes xmt: 16238872, Bytes rcv: 90368909, Reason: User Requested

%ASA-5-713904: IP = a.b.c.d, Received encrypted packet with no matching SA, dropping

%ASA-5-713119: Group = a.b.c.d, IP = a.b.c.d, PHASE 1 COMPLETED

%ASA-5-713049: Group = a.b.c.d, IP = a.b.c.d, Security negotiation complete for LAN-to-LAN Group (a.b.c.d) Responder, Inbound SPI = 0x36fd3602, Outbound SPI = 0x4d0c4534

%ASA-5-713120: Group = a.b.c.d, IP = a.b.c.d, PHASE 2 COMPLETED (msgid=e22ccfce)

%ASA-5-713049: Group = a.b.c.d, IP = a.b.c.d, Security negotiation complete for LAN-to-LAN Group (a.b.c.d) Responder, Inbound SPI = 0x7d75a0c0, Outbound SPI = 0x6fbf43d9

%ASA-5-713120: Group = a.b.c.d, IP = a.b.c.d, PHASE 2 COMPLETED (msgid=cf7b5095)

I would like to know what "Reason: User Requested" means and why it happens every 12 hrs and tears down the tunnel when IKE lifetime is 24 hrs and IPSec lifetime is 8 hrs

and none should break the tunnel. This is NOT a rekeying. Rekeying is working as expected at different times and does not break the connection.

Here are the details about this tunnel:

Session Type: LAN-to-LAN Detailed

Connection : a.b.c.d

Index : 27124 IP Addr : a.b.c.d

Protocol : IKE IPsec

Encryption : AES256 Hashing : SHA1

Bytes Tx : 6680929 Bytes Rx : 18117532

Login Time : 07:28:44 CEST Wed Aug 17 2011

Duration : 3h:51m:13s

IKE Tunnels: 1

IPsec Tunnels: 2

IKE:

Tunnel ID : 27124.1

UDP Src Port : 500 UDP Dst Port : 500

IKE Neg Mode : Main Auth Mode : preSharedKeys

Encryption : AES256 Hashing : SHA1

Rekey Int (T): 86400 Seconds Rekey Left(T): 72526 Seconds

D/H Group : 2

Filter Name :

IPsec:

Tunnel ID : 27124.2

Local Addr : 172.27.114.0/255.255.255.0/0/0

Remote Addr : 192.168.171.0/255.255.255.0/0/0

Encryption : AES256 Hashing : SHA1

Encapsulation: Tunnel PFS Group : 2

Rekey Int (T): 28800 Seconds Rekey Left(T): 14924 Seconds

Idle Time Out: 30 Minutes Idle TO Left : 30 Minutes

Bytes Tx : 5055121 Bytes Rx : 3277228

Pkts Tx : 47400 Pkts Rx : 47789

IPsec:

Tunnel ID : 27124.3

Local Addr : 172.27.114.0/255.255.255.0/0/0

Remote Addr : 195.188.162.0/255.255.255.0/0/0

Encryption : AES256 Hashing : SHA1

Encapsulation: Tunnel PFS Group : 2

Rekey Int (T): 28800 Seconds Rekey Left(T): 14936 Seconds

Idle Time Out: 30 Minutes Idle TO Left : 29 Minutes

Bytes Tx : 1625969 Bytes Rx : 14840553

Pkts Tx : 11044 Pkts Rx : 15776

NAC:

Reval Int (T): 0 Seconds Reval Left(T): 0 Seconds

SQ Int (T) : 0 Seconds EoU Age(T) : 13877 Seconds

Hold Left (T): 0 Seconds Posture Token:

Redirect URL :

Thanks

Sasa

Marcin Latosiewicz · ‎08-18-2011

Hi Sasa,

The most likely flow of events is that the ASA received a delete notification from other side (for whatever reason).

The ASA proceeds with clearing the active SAs.

At the same time the other side keeps sending packets encryped.

I would check debugs on both sides (debug crypto isakmp 127 on ASA side should suffice) to understand why and what-for the other side is sending the delete.

Marcin

sasa.popravak · ‎08-18-2011

Hi Marcin!

Thanks for reply. I would like to know what "wahtever reason" is. Is it triggered by some monitorring application or is it result of some timeout value (not the IKE or IPSec timeout, though).

Regs,

Sasa

Marcin Latosiewicz · ‎08-18-2011

Sasa,

Since it's exactly 12 hours I would say it's timer driven.

As for actual reason behind it ... well check debugs on other end and compare to your end.

It might be the case that other peer operates in dangling mode, while ASA operates in continuous channel mode (i.e. if you delete phase 1 all phase 2 SAs are removed).

Marcin

Samy Mezache · ‎02-07-2012

Hi,

I am having a similar issue where a rekeying of Phase I is taking place which seems to cause the SA to be dropped shortly after. Here are some logs and was wondering if it had to do with either timers or DPD. I checked with the vendor (the other end of the tunnel [checkpoint]) and the lifetimes are identical for phase 1 and 2.

Jan 30 21:28:36 w.x.y.z local6:notice Jan 30 2012 21:28:36: %ASA-5-713041: IP = a.b.c.d, IKE Initiator: Rekeying Phase 1, Intf Vlan_26, IKE Peer a.b.c.d local Proxy Address N/A, remote Proxy Address N/A, Crypto map (N/A)

Jan 30 21:28:36 w.x.y.z local6:warn|warning Jan 30 2012 21:28:36: %ASA-4-713903: Group = a.b.c.d, IP = a.b.c.d, Freeing previously allocated memory for authorization-dn-attributes

Jan 30 21:28:36 w.x.y.z local6:notice Jan 30 2012 21:28:36: %ASA-5-713119: Group = a.b.c.d, IP = a.b.c.d, PHASE 1 COMPLETED

Jan 30 21:28:36 w.x.y.z local6:notice Jan 30 2012 21:28:36: %ASA-5-713201: Group = a.b.c.d, IP = a.b.c.d, Duplicate Phase 1 packet detected. No last packet to retransmit.

Jan 30 21:28:37 w.x.y.z local6:notice Jan 30 2012 21:28:37: %ASA-5-713201: Group = a.b.c.d, IP = a.b.c.d, Duplicate Phase 1 packet detected. No last packet to retransmit.

Jan 30 21:30:19 w.x.y.z local6:notice Jan 30 2012 21:30:19: %ASA-5-713050: Group = a.b.c.d, IP = a.b.c.d, Connection terminated for peer a.b.c.d. Reason: Peer Terminate Remote Proxy 1.2.3.4, Local Proxy 5.6.7.8

Jan 30 21:30:19 w.x.y.z local6:info Jan 30 2012 21:30:19: %ASA-6-602304: IPSEC: An inbound LAN-to-LAN SA (SPI= 0x0FF2877D) between x.x.x.x and a.b.c.d (user= a.b.c.d) has been deleted.

Jan 30 21:30:19 w.x.y.z local6:info Jan 30 2012 21:30:19: %ASA-6-602304: IPSEC: An outbound LAN-to-LAN SA (SPI= 0x619FFA6A) between x.x.x.x and a.b.c.d (user= a.b.c.d) has been deleted.

Jan 30 21:30:23 w.x.y.z local6:notice Jan 30 2012 21:30:23: %ASA-5-713041: Group = a.b.c.d, IP = a.b.c.d, IKE Initiator: New Phase 2, Intf Vlan_26, IKE Peer a.b.c.d local Proxy Address 5.6.7.8, remote Proxy Address 1.2.3.4, Crypto map (GODIVA-L2LVPN)

Jan 30 21:30:23 w.x.y.z local6:info Jan 30 2012 21:30:23: %ASA-6-602303: IPSEC: An outbound LAN-to-LAN SA (SPI= 0xFC87B58C) between x.x.x.x and a.b.c.d (user= a.b.c.d) has been created.

Jan 30 21:30:23 w.x.y.z local6:notice Jan 30 2012 21:30:23: %ASA-5-713049: Group = a.b.c.d, IP = a.b.c.d, Security negotiation complete for LAN-to-LAN Group (a.b.c.d) Initiator, Inbound SPI = 0xa9e30909, Outbound SPI = 0xfc87b58c

Jan 30 21:30:23 w.x.y.z local6:info Jan 30 2012 21:30:23: %ASA-6-602303: IPSEC: An inbound LAN-to-LAN SA (SPI= 0xA9E30909) between x.x.x.x and a.b.c.d (user= a.b.c.d) has been created.

Jan 30 21:30:23 w.x.y.z local6:notice Jan 30 2012 21:30:23: %ASA-5-713120: Group = a.b.c.d, IP = a.b.c.d, PHASE 2 COMPLETED (msgid=d77831eb)

Jan 30 21:30:25 w.x.y.z local6:notice Jan 30 2012 21:30:25: %ASA-5-713050: Group = a.b.c.d, IP = a.b.c.d, Connection terminated for peer a.b.c.d. Reason: Peer Terminate Remote Proxy 1.2.3.4, Local Proxy 5.6.7.8

Could you let me know if your issue was resolved and if so what you found to be the root cause and fix?

Thanks