Menu
▾
▴
[Shorewall-users] Received DELETE before CHILD-SA-REKEY-RESPONSE
|
From: Naveen N. <nav...@gm...> - 2022-07-21 23:14:36
|
Hi All,
I am using strongswan version 5.6.1, I am seeing an issue, where i am
seeing DELETE request for the rekeyed child sa before CHILD-SA rekey
response , however the peer is sending child-sa rekey response first and
than the delete, is it possible because of the network latency issue , if
so how can i have a workaround for this issue. Because of this my
current session is getting destroyed , I have make-before-break enabled as
well.
Also I am using the go vici interface to receive tunnel down events and I
am receiving tunnel_down events.
I would appreciate any workaround or a version that has this issue fixed.
1. Current Active child-sa was SPI ( a2898236_i *c9026a48_o*) was
created
{"_ts":"2022-07-14T05:58:09.681Z","_prog":"charon","_msgid":"10[CHD]
<sl2|18> *SPI 0xc9026a48*, src 12.0.251.146 dst
165.1.201.72","_fac":"local1","_level":"info"}
{"_ts":"2022-07-14T05:58:09.681Z","_prog":"charon","_msgid":"10[IKE]
<sl2|18> inbound CHILD_SA sl2childsa{60} established with SPIs a2898236_i
c9026a48_o and TS 0.0.0.0/0 === 0.0.0.0/0","_fac":"local1","_level":"info"}
{"_ts":"2022-07-14T05:58:09.682Z","_prog":"charon","_msgid":"10[IKE]
<sl2|18> outbound CHILD_SA sl2childsa{60} established with SPIs a2898236_i
c9026a48_o and TS0.0.0.0/0 === 0.0.0.0/0","_fac":"local1","_level":"info"}
2.New Child-SA request was sent from ION
bash-4.3# cat /log/syslog/local1.0 | grep sl2 | grep "2022-07-14T06:4" |
grep -E 'NET|CHILD_SA'
{"_ts":"2022-07-14T06:46:09.682Z","_prog":"charon","_msgid":"11[IKE]
<sl2|18> establishing CHILD_SA sl2childsa{62} reqid
10","_fac":"local1","_level":"info"}
{"_ts":"2022-07-14T06:46:09.686Z","_prog":"charon","_msgid":"11[CHD]
<sl2|18> CHILD_SA sl2childsa{60} state change: INSTALLED =>
REKEYING","_fac":"local1","_level":"info"}
{"_ts":"2022-07-14T06:46:09.688Z","_prog":"charon","_msgid":"11[ENC]
<sl2|18> generating CREATE_CHILD_SA request 4 [ N(REKEY_SA) SA No KE TSi
TSr ]","_fac":"local1","_level":"info"}
*{"_ts":"2022-07-14T06:46:09.711Z","_prog":"charon","_msgid":"11[NET]
<sl2|18> sending packet: from x.x.x.146[4500] to y.y.y..72[4500] (336
bytes)","_fac":"local1","_level":"info"}*
3.received DELETE for current active SA even before the new SA is created .
*{"_ts":"2022-07-14T06:46:09.773Z","_prog":"charon","_msgid":"05[NET]
<sl2|18> received packet: from y.y.y.72[4500] to x.x.x.146[4500] (96
bytes)","_fac":"local1","_level":"info"}*
{"_ts":"2022-07-14T06:46:09.781Z","_prog":"charon","_msgid":"05[ENC]
<sl2|18> parsed INFORMATIONAL request 1 [ D
]","_fac":"local1","_level":"info"}
{"_ts":"2022-07-14T06:46:09.781Z","_prog":"charon","_msgid":"05[IKE]
<sl2|18> received DELETE for ESP CHILD_SA with SPI
c9026a48","_fac":"local1","_level":"info"}
{"_ts":"2022-07-14T06:46:09.781Z","_prog":"charon","_msgid":"05[IKE]
<sl2|18> closing CHILD_SA sl2childsa{60} with SPIs a2898236_i (11064323
bytes) c9026a48_o (12523609 bytes) and TS 0.0.0.0/0 === 0.0.0.0/0
","_fac":"local1","_level":"info"}
{"_ts":"2022-07-14T06:46:09.782Z","_prog":"charon","_msgid":"05[IKE]
<sl2|18> sending DELETE for ESP CHILD_SA with SPI
a2898236","_fac":"local1","_level":"info"}
{"_ts":"2022-07-14T06:46:09.782Z","_prog":"charon","_msgid":"05[CHD]
<sl2|18> CHILD_SA sl2childsa{60} state change: REKEYING =>
DELETING","_fac":"local1","_level":"info"}
{"_ts":"2022-07-14T06:46:09.782Z","_prog":"charon","_msgid":"05[IKE]
<sl2|18> CHILD_SA closed","_fac":"local1","_level":"info"}
{"_ts":"2022-07-14T06:46:09.783Z","_prog":"charon","_msgid":"05[CHD]
<sl2|18> CHILD_SA sl2childsa{60} state change: DELETING =>
DESTROYING","_fac":"local1","_level":"info"}
{"_ts":"2022-07-14T06:46:09.783Z","_prog":"charon","_msgid":"05[IKE]
<sl2|18> queueing CHILD_CREATE task","_fac":"local1","_level":"info"}
{"_ts":"2022-07-14T06:46:09.783Z","_prog":"charon","_msgid":"05[IKE]
<sl2|18> delaying task initiation, CREATE_CHILD_SA exchange in
progress","_fac":"local1","_level":"info"}
{"_ts":"2022-07-14T06:46:09.783Z","_prog":"charon","_msgid":"05[IKE]
<sl2|18> detected CHILD_REKEY collision with
CHILD_DELETE","_fac":"local1","_level":"info"
{"_ts":"2022-07-14T06:46:09.782Z","_prog":"charon","_msgid":"05[IKE]
<sl2|18> sending DELETE for ESP CHILD_SA with SPI
a2898236","_fac":"local1","_level":"info"}
{"_ts":"2022-07-14T06:46:09.782Z","_prog":"charon","_msgid":"05[CHD]
<sl2|18> CHILD_SA sl2childsa{60} state change: REKEYING =>
DELETING","_fac":"local1","_level":"info"}
{"_ts":"2022-07-14T06:46:09.782Z","_prog":"charon","_msgid":"05[IKE]
<sl2|18> CHILD_SA closed","_fac":"local1","_level":"info"}
4.Out of order: ION received CHILD-SA response for the CHILD-SA rekey
request
*{"_ts":"2022-07-14T06:46:09.792Z","_prog":"charon","_msgid":"13[NET]
<sl2|18> received packet: from y.y.y.72[4500] to x.x.x.146[4500] (336
bytes)","_fac":"local1","_level":"info"}*
*{"_ts":"2022-07-14T06:46:09.825Z","_prog":"charon","_msgid":"13[ENC]
<sl2|18> parsed CREATE_CHILD_SA response 4 [ N(ESP_TFC_PAD_N) SA No KE TSi
TSr ]","_fac":"local1","_level":"info"}*
{"_ts":"2022-07-14T06:46:09.829Z","_prog":"charon","_msgid":"13[CHD]
<sl2|18> CHILD_SA sl2childsa{62} state change: CREATED =>
INSTALLING","_fac":"local1","_level":"info"}
{"_ts":"2022-07-14T06:46:09.830Z","_prog":"charon","_msgid":"13[IKE]
<sl2|18> inbound CHILD_SA sl2childsa{62} established with SPIs a9923f5f_i
826ad051_o and TS 0.0.0.0/0 === 0.0.0.0/0","_fac":"local1","_level":"info"}
{"_ts":"2022-07-14T06:46:09.830Z","_prog":"charon","_msgid":"13[CHD]
<sl2|18> CHILD_SA sl2childsa{62} state change: INSTALLING =>
INSTALLED","_fac":"local1","_level":"info"}
{"_ts":"2022-07-14T06:46:09.830Z","_prog":"charon","_msgid":"13[IKE]
<sl2|18> CHILD_SA rekey/delete collision, deleting redundant child
sl2childsa{62}","_fac":"local1","_level":"info"}
{"_ts":"2022-07-14T06:46:09.830Z","_prog":"charon","_msgid":"13[CHD]
<sl2|18> CHILD_SA sl2childsa{62} state change: INSTALLED =>
REKEYED","_fac":"local1","_level":"info"}
{"_ts":"2022-07-14T06:46:09.830Z","_prog":"charon","_msgid":"13[IKE]
<sl2|18> closing CHILD_SA sl2childsa{62} with SPIs a9923f5f_i (0 bytes)
826ad051_o (0 bytes)and TS 0.0.0.0/0 === 0.0.0.0/0
","_fac":"local1","_level":"info"}
{"_ts":"2022-07-14T06:46:09.830Z","_prog":"charon","_msgid":"13[IKE]
<sl2|18> sending DELETE for ESP CHILD_SA with SPI
a9923f5f","_fac":"local1","_level":"info"}
{"_ts":"2022-07-14T06:46:09.830Z","_prog":"charon","_msgid":"13[CHD]
<sl2|18> CHILD_SA sl2childsa{62} state change: REKEYED =>
DELETING","_fac":"local1","_level":"info"}
{"_ts":"2022-07-14T06:46:09.897Z","_prog":"charon","_msgid":"05[IKE]
<sl2|18> received DELETE for ESP CHILD_SA with SPI
826ad051","_fac":"local1","_level":"info"}
{"_ts":"2022-07-14T06:46:09.897Z","_prog":"charon","_msgid":"05[IKE]
<sl2|18> CHILD_SA closed","_fac":"local1","_level":"info"}
{"_ts":"2022-07-14T06:46:09.965Z","_prog":"charon","_msgid":"12[CHD]
<sl2|18> CHILD_SA sl2childsa{62} state change: DELETING =>
DESTROYING","_fac":"local1","_level":"info"}
I would appreciate your response.
Thanks,
Naveen
|
