Hello everybody,
our customer has a FirePower 2130 running ASA-OS 9.14(2)18 with hundrets
of S2S-tunnels.
A tunnel (peer 87.129.194.226) is frequently hanging so that only the remote
firewall admin can reset the tunnel to make it transfering fraffic again. A local
reset just terminates the tunnel and it was not re-established even if permanent
pings are running to remote servers.
In the logging I got the following:
4|Mar 15 2024|16:00:58|750003|||||Local:185.247.62.10:500 Remote:87.129.194.226:500 Username:87.129.194.226 IKEv2 Negotiation aborted due to ERROR: Create child exchange failed
7|Mar 15 2024|16:00:58|713906|||||IKE Receiver: Packet received on 185.247.62.10:500 from 87.129.194.226:500
4|Mar 15 2024|16:00:58|750003|||||Local:185.247.62.10:500 Remote:87.129.194.226:500 Username:87.129.194.226 IKEv2 Negotiation aborted due to ERROR: Create child exchange failed
7|Mar 15 2024|16:00:58|713906|||||IKE Receiver: Packet received on 185.247.62.10:500 from 87.129.194.226:500
5|Mar 15 2024|16:00:58|750001|||||Local:185.247.62.10:500 Remote:87.129.194.226:500 Username:Unknown IKEv2 Received request to establish an IPsec tunnel; local traffic selector = Address Range: 185.247.62.225-185.247.62.225 Protocol: 0 Port Range: 0-65535; remote traffic selector = Address Range: 129.2.105.13-129.2.105.13 Protocol: 0 Port Range: 0-65535
5|Mar 15 2024|16:00:58|750001|||||Local:185.247.62.10:500 Remote:87.129.194.226:500 Username:Unknown IKEv2 Received request to establish an IPsec tunnel; local traffic selector = Address Range: 185.247.62.225-185.247.62.225 Protocol: 0 Port Range: 0-65535; remote traffic selector = Address Range: 129.2.105.24-129.2.105.24 Protocol: 0 Port Range: 0-65535
4|Mar 15 2024|16:00:56|750003|||||Local:185.247.62.10:500 Remote:87.129.194.226:500 Username:87.129.194.226 IKEv2 Negotiation aborted due to ERROR: Create child exchange failed
In the debug session I got the following:
IKEv2-PLAT-5: RECV PKT [CREATE_CHILD_SA] [87.129.194.226]:500->[185.247.62.10]:500 InitSPI=0xdacf2a60c40ab89d RespSPI=0x4e1c140c9640f889 MID=00000248
(17607):
IKEv2-PROTO-4: (17607): Received Packet [From 87.129.194.226:500/To 185.247.62.10:500/VRF i0:f0]
(17607): Initiator SPI : DACF2A60C40AB89D - Responder SPI : 4E1C140C9640F889 Message id: 584
(17607): IKEv2 CREATE_CHILD_SA Exchange RESPONSEIKEv2-PROTO-5: (17607): Next payload: ENCR, version: 2.0 (17607): Exchange type: CREATE_CHILD_SA, flags: INITIATOR MSG-RESPONSE (17607): Message id: 584, length: 96(17607):
Payload contents:
IKEv2-PLAT-4: (17607): Decrypt success status returned via ipc 1
IKEv2-PROTO-4: decrypt queued(17607):
(17607): Decrypted packet:(17607): Data: 96 bytes
(17607): REAL Decrypted packet:(17607): Data: 8 bytes
IKEv2-PROTO-7: Parse Notify Payload: TS_UNACCEPTABLE NOTIFY(TS_UNACCEPTABLE) Next payload: NONE, reserved: 0x0, length: 8
Security protocol id: Unknown - 0, spi size: 0, type: TS_UNACCEPTABLE
IKEv2-PROTO-7: (17607): SM Trace-> SA: I_SPI=DACF2A60C40AB89D R_SPI=4E1C140C9640F889 (I) MsgID = 00000248 CurState: CHILD_I_WAIT Event: EV_RECV_CREATE_CHILD
IKEv2-PROTO-7: (17607): Action: Action_Null
IKEv2-PROTO-7: (17607): SM Trace-> SA: I_SPI=DACF2A60C40AB89D R_SPI=4E1C140C9640F889 (I) MsgID = 00000248 CurState: CHILD_I_PROC Event: EV_CHK4_NOTIFY
IKEv2-PROTO-4: (17607): Processing any notify-messages in child SA exchange
IKEv2-PROTO-7: (17607): SM Trace-> SA: I_SPI=DACF2A60C40AB89D R_SPI=4E1C140C9640F889 (I) MsgID = 00000248 CurState: CHILD_I_DONE Event: EV_FAIL
IKEv2-PROTO-2: (17607): Create child exchange failed
IKEv2-PROTO-4: (17607): IPSec SA create failed
IKEv2-PROTO-7: (17607): SM Trace-> SA: I_SPI=DACF2A60C40AB89D R_SPI=4E1C140C9640F889 (I) MsgID = 00000248 CurState: EXIT Event: EV_ABORT
IKEv2-PROTO-7: (17607): Processed response with message id 584, Requests can be sent from range 585 to 585
IKEv2-PROTO-7: (17607): Room in peer window. Request is un-throttled: Current Req = 585 Next Req = 586
IKEv2-PROTO-7: (17607): SM Trace-> SA: I_SPI=DACF2A60C40AB89D R_SPI=4E1C140C9640F889 (I) MsgID = 00000248 CurState: EXIT Event: EV_CHK_PENDING_ABORT
IKEv2-PLAT-7: Negotiating SA request deleted
IKEv2-PLAT-2: Failed to decrement count for incoming negotiating
IKEv2-PROTO-7: (17607): SM Trace-> SA: I_SPI=DACF2A60C40AB89D R_SPI=4E1C140C9640F889 (I) MsgID = 00000248 CurState: EXIT Event: EV_UPDATE_CAC_STATS
IKEv2-PROTO-4: (17607): Abort exchange
IKEv2-PROTO-7: (17607): Deleting negotiation context for my message ID: 0x248
IKEv2-PROTO-7: (17607): SM Trace-> SA: I_SPI=DACF2A60C40AB89D R_SPI=4E1C140C9640F889 (I) MsgID = 00000248 CurState: EXIT Event: EV_FREE_NEG
IKEv2-PROTO-7: (17607): Deleting negotiation context for my message ID: 0x248
IKEv2-PROTO-7: (17607): SM Trace-> SA: I_SPI=DACF2A60C40AB89D R_SPI=4E1C140C9640F889 (I) MsgID = 00000249 CurState: CHILD_I_IPSEC Event: EV_SEND
(17607):
IKEv2-PROTO-4: (17607): Sending Packet [To 87.129.194.226:500/From 185.247.62.10:500/VRF i0:f0]
(17607): Initiator SPI : DACF2A60C40AB89D - Responder SPI : 4E1C140C9640F889 Message id: 585
(17607): IKEv2 CREATE_CHILD_SA Exchange REQUESTIKEv2-PROTO-5: (17607): Next payload: ENCR, version: 2.0 (17607): Exchange type: CREATE_CHILD_SA, flags: RESPONDER (17607): Message id: 585, length: 416(17607):
Payload contents:
(17607): ENCR(17607): Next payload: SA, reserved: 0x0, length: 388
(17607): Encrypted data: 384 bytes
(17607):
IKEv2-PLAT-5: (17607): SENT PKT [CREATE_CHILD_SA] [185.247.62.10]:500->[87.129.194.226]:500 InitSPI=0xdacf2a60c40ab89d RespSPI=0x4e1c140c9640f889 MID=00000249
IKEv2-PROTO-7: (17607): SM Trace-> SA: I_SPI=DACF2A60C40AB89D R_SPI=4E1C140C9640F889 (I) MsgID = 00000249 CurState: CHILD_I_WAIT Event: EV_NO_EVENT
IPSEC: Received a PFKey message from IKE
IPSEC DEBUG: Received a DELETE PFKey message from IKE for an inbound SA (SPI 0x1E33A282)
IPSEC DEBUG: Inbound SA (SPI 0x1E33A282) destroy started, state embryonic
IPSEC: Destroy current inbound SPI: 0x1E33A282
IPSEC DEBUG: Inbound SA (SPI 0x1E33A282) free started, state embryonic
IPSEC DEBUG: Inbound SA (SPI 0x1E33A282, Handle 0x33AA58DF) state change from embryonic to dead
IPSEC INFO: Destroying an IPSec timer of type SA Purge Timer
IPSEC INFO: Setting an IPSec timer of type SA Purge Timer for 30 seconds with a jitter value of 0
IPSEC INFO: IPSec SA PURGE timer started SPI 0x33AA58DF
IPSEC INFO: Destroying an IPSec timer of type SA Purge Timer
IPSEC DEBUG: Inbound SA (SPI 0x1E33A282) free completed
IPSEC DEBUG: Inbound SA (SPI 0x1E33A282) destroy completed
IKEv2-PLAT-4: Received PFKEY delete SA for SPI 0x1E33A282 error FALSE
IKEv2-PLAT-4: PFKEY Delete Ack from IPSec
It looks for me like a problem with the child SA creation.
The tunnel has 63 host IP addresses in the remote protected ACL.
I attach the complete logging, debugging and command outputs of the hanging tunnel.
I can provide the configuration to an engineer who is working on that issue.
What would you do to prevent the tunnel hang happen several
times a day?
Thanks a lot!
Bye
R.
