[strongSwan] Remote site dies for no reason?

[Rene Maurer]

Hello

We are  using strongSwan U5.4.0/K4.4.107 (embedded device) and making an ipec connection to a remote CISCO system.

 From time to time we see the following behavior (tunnel seams to stop working):

------------------------------------------------------------------------
Oct 20 09:32:33 EGV charon[656]: 13[KNL] creating rekey job for CHILD_SA ESP/0xc5ff03b6/xx.xxx.xxx.xxx
Oct 20 09:32:33 EGV charon[656]: 13[IKE] establishing CHILD_SA one{1}
Oct 20 09:32:33 EGV charon[656]: 13[IKE] establishing CHILD_SA one{1}
Oct 20 09:32:33 EGV charon[656]: 13[ENC] generating CREATE_CHILD_SA request 24388 [ N(REKEY_SA) SA No KE TSi TSr ]
Oct 20 09:32:33 EGV charon[656]: 13[NET] sending packet: from 10.162.225.65[4500] to xx.xxx.xxx.xxx[4500] (309 bytes)
Oct 20 09:32:33 EGV charon[656]: 08[NET] received packet: from xx.xxx.xxx.xxx[4500] to 10.162.225.65[4500] (297 bytes)
Oct 20 09:32:33 EGV charon[656]: 08[ENC] parsed CREATE_CHILD_SA response 24388 [ SA No KE TSi TSr ]
Oct 20 09:32:33 EGV charon[656]: 08[IKE] CHILD_SA one{93} established with SPIs c70a8723_i a5e30c1d_o and TS 10.162.110.160/29 === 10.0.0.0/8
Oct 20 09:32:33 EGV charon[656]: 08[IKE] CHILD_SA one{93} established with SPIs c70a8723_i a5e30c1d_o and TS 10.162.110.160/29 === 10.0.0.0/8
Oct 20 09:32:33 EGV charon[656]: 08[IKE] closing CHILD_SA one{92} with SPIs ca335ba8_i (21496 bytes) c5ff03b6_o (21496 bytes) and TS 10.162.110.160/29 === 10.0.0.0/8
Oct 20 09:32:33 EGV charon[656]: 08[IKE] closing CHILD_SA one{92} with SPIs ca335ba8_i (21496 bytes) c5ff03b6_o (21496 bytes) and TS 10.162.110.160/29 === 10.0.0.0/8
Oct 20 09:32:33 EGV charon[656]: 08[IKE] sending DELETE for ESP CHILD_SA with SPI ca335ba8
Oct 20 09:32:33 EGV charon[656]: 08[ENC] generating INFORMATIONAL request 24389 [ D ]
Oct 20 09:32:33 EGV charon[656]: 08[NET] sending packet: from 10.162.225.65[4500] to xx.xxx.xxx.xxx[4500] (69 bytes)
Oct 20 09:32:33 EGV charon[656]: 14[NET] received packet: from xx.xxx.xxx.xxx[4500] to 10.162.225.65[4500] (69 bytes)
Oct 20 09:32:33 EGV charon[656]: 14[ENC] parsed INFORMATIONAL response 24389 [ D ]
Oct 20 09:32:33 EGV charon[656]: 14[IKE] received DELETE for ESP CHILD_SA with SPI c5ff03b6
Oct 20 09:32:33 EGV charon[656]: 14[IKE] CHILD_SA closed
Oct 20 09:32:37 EGV charon[656]: 10[IKE] sending DPD request
Oct 20 09:32:37 EGV charon[656]: 10[ENC] generating INFORMATIONAL request 24390 [ ]
Oct 20 09:32:37 EGV charon[656]: 10[NET] sending packet: from 10.162.225.65[4500] to xx.xxx.xxx.xxx[4500] (57 bytes)
Oct 20 09:32:37 EGV charon[656]: 16[NET] received packet: from xx.xxx.xxx.xxx[4500] to 10.162.225.65[4500] (57 bytes)
Oct 20 09:32:37 EGV charon[656]: 16[ENC] parsed INFORMATIONAL response 24390 [ ]
Oct 20 09:32:38 EGV charon[656]: 14[NET] received packet: from xx.xxx.xxx.xxx[4500] to 10.162.225.65[4500] (57 bytes)
Oct 20 09:32:38 EGV charon[656]: 14[ENC] parsed INFORMATIONAL request 7089 [ ]
Oct 20 09:32:38 EGV charon[656]: 14[ENC] generating INFORMATIONAL response 7089 [ ]
Oct 20 09:32:38 EGV charon[656]: 14[NET] sending packet: from 10.162.225.65[4500] to xx.xxx.xxx.xxx[4500] (57 bytes)
Oct 20 09:32:40 EGV charon[656]: 08[IKE] sending DPD request
Oct 20 09:32:40 EGV charon[656]: 08[ENC] generating INFORMATIONAL request 24391 [ ]
Oct 20 09:32:40 EGV charon[656]: 08[NET] sending packet: from 10.162.225.65[4500] to xx.xxx.xxx.xxx[4500] (57 bytes)
Oct 20 09:32:40 EGV charon[656]: 06[NET] received packet: from xx.xxx.xxx.xxx[4500] to 10.162.225.65[4500] (57 bytes)
Oct 20 09:32:40 EGV charon[656]: 06[ENC] parsed INFORMATIONAL response 24391 [ ]
Oct 20 09:32:43 EGV charon[656]: 07[IKE] sending DPD request
Oct 20 09:32:43 EGV charon[656]: 07[ENC] generating INFORMATIONAL request 24392 [ ]
Oct 20 09:32:43 EGV charon[656]: 07[NET] sending packet: from 10.162.225.65[4500] to xx.xxx.xxx.xxx[4500] (57 bytes)
Oct 20 09:32:47 EGV charon[656]: 06[IKE] retransmit 1 of request with message ID 24392
Oct 20 09:32:47 EGV charon[656]: 06[NET] sending packet: from 10.162.225.65[4500] to xx.xxx.xxx.xxx[4500] (57 bytes)
Oct 20 09:32:54 EGV charon[656]: 09[IKE] retransmit 2 of request with message ID 24392
Oct 20 09:32:54 EGV charon[656]: 09[NET] sending packet: from 10.162.225.65[4500] to xx.xxx.xxx.xxx[4500] (57 bytes)
Ping::PingHost, send ping to xx.xxx.xxx.xxx, ret 8
Ping::PingHost, ping reply received
Oct 20 09:33:02 EGV charon[656]: 11[NET] received packet: from xx.xxx.xxx.xxx[4500] to 10.162.225.65[4500] (57 bytes)
Oct 20 09:33:02 EGV charon[656]: 11[ENC] parsed INFORMATIONAL request 7090 [ ]
Oct 20 09:33:02 EGV charon[656]: 11[ENC] generating INFORMATIONAL response 7090 [ ]
Oct 20 09:33:02 EGV charon[656]: 11[NET] sending packet: from 10.162.225.65[4500] to xx.xxx.xxx.xxx[4500] (57 bytes)
Oct 20 09:33:02 EGV charon[656]: 13[MGR] ignoring request with ID 7090, already processing
Oct 20 09:33:02 EGV charon[656]: 07[MGR] ignoring request with ID 7090, already processing
Oct 20 09:33:02 EGV charon[656]: 07[MGR] ignoring request with ID 7090, already processing
Oct 20 09:33:07 EGV charon[656]: 15[IKE] retransmit 3 of request with message ID 24392
Oct 20 09:33:07 EGV charon[656]: 15[NET] sending packet: from 10.162.225.65[4500] to xx.xxx.xxx.xxx[4500] (57 bytes)
tunnel ping to 10.162.100.126 failed (1)
tunnel ping to 10.162.100.126 failed (2)
tunnel ping to 10.162.100.126 failed (3)
Oct 20 09:33:30 EGV charon[656]: 15[IKE] retransmit 4 of request with message ID 24392
Oct 20 09:33:30 EGV charon[656]: 15[NET] sending packet: from 10.162.225.65[4500] to xx.xxx.xxx.xxx[4500] (57 bytes)
Ping::PingHost, send ping to xx.xxx.xxx.xxx, ret 8
Ping::PingHost, ping reply received
tunnel ping to 10.162.100.126 failed (1)
tunnel ping to 10.162.100.126 failed (2)
Oct 20 09:34:12 EGV charon[656]: 15[IKE] retransmit 5 of request with message ID 24392
Oct 20 09:34:12 EGV charon[656]: 15[NET] sending packet: from 10.162.225.65[4500] to xx.xxx.xxx.xxx[4500] (57 bytes)
tunnel ping to 10.162.100.126 failed (3)
2022-10-20 09:34:13 restart ipsec
------------------------------------------------------------------------

The remote side is pinged from once per minute, if this fails two consecutive times ipsec is restarted on the local side (this is what you see at the end, we can also remove this).

How should we interpret the log. Does ipsec on the remote side simply no longer respond? Or is that to be understood differently?

What we also do not understand:

We have

   ikelifetime=86400
   keylife=1090
   fragmentation=yes
   mobike=yes
   dpddelay=2
   dpdtimeout=10
   dpdaction=restart
   rekeymargin=3m
   keyingtries=%forever
   keyexchange=ikev2

Why is ipsec not restarted locally with the above dpd-settings?

Best regards
René