<div dir="ltr"><div dir="ltr"><div class="gmail_default" style="font-family:verdana,sans-serif;color:#073763">Hi, </div><div class="gmail_default" style="font-family:verdana,sans-serif;color:#073763"><br></div><div class="gmail_default" style="font-family:verdana,sans-serif;color:#073763">In order to add more information.</div><div class="gmail_default" style="font-family:verdana,sans-serif;color:#073763"><br></div><div class="gmail_default" style="font-family:verdana,sans-serif;color:#073763">At this time libreswan is working well, this is a log segment extracted from ipsec status which shows a rightsubnet (vpn/1x9) that is without the phase 2 active but has tried to reconnect at some moment after the subnet phase 2 went down:</div><div class="gmail_default"><blockquote style="color:rgb(7,55,99);margin:0px 0px 0px 40px;border:none;padding:0px"><div class="gmail_default" style="color:rgb(7,55,99)"><font face="monospace">20210615_T14:19:01 - 000 #56: "vpn/1x9":500 STATE_V2_REKEY_CHILD_I0 (STATE_V2_REKEY_CHILD_I0); none in -1s; lastlive=2s; idle; import:admin initiate<br>20210615_T14:20:01 - 000 #56: "vpn/1x9":500 STATE_V2_REKEY_CHILD_I0 (STATE_V2_REKEY_CHILD_I0); none in -1s; lastlive=2s; idle; import:admin initiate<br>20210615_T14:21:01 - 000 #56: "vpn/1x9":500 STATE_V2_REKEY_CHILD_I0 (STATE_V2_REKEY_CHILD_I0); none in -1s; lastlive=22s; idle; import:admin initiate</font></div></blockquote><font color="#073763" face="verdana, sans-serif"><div class="gmail_default"><font color="#073763" face="verdana, sans-serif"><br></font></div>At this point we sent some traffic trying to reconnect the subnet which successfully get the #207 number, but doesn't delete the previous attempt with state </font>STATE_V2_REKEY_CHILD_I0:<font color="#073763" face="verdana, sans-serif"><br></font><blockquote style="color:rgb(7,55,99);margin:0px 0px 0px 40px;border:none;padding:0px"><div class="gmail_default" style="color:rgb(7,55,99)"><font face="monospace">20210615_T14:22:01 - 000 #56: "vpn/1x9":500 STATE_V2_REKEY_CHILD_I0 (STATE_V2_REKEY_CHILD_I0); none in -1s; lastlive=82s; idle; import:admin initiate<br>000 #207: "vpn/1x9":500 STATE_V2_IPSEC_I (IPsec SA established); EVENT_SA_REPLACE in 27920s; newest IPSEC; eroute owner; isakmp#169; idle; import:admin initiate<br>20210615_T14:23:01 - 000 #56: "vpn/1x9":500 STATE_V2_REKEY_CHILD_I0 (STATE_V2_REKEY_CHILD_I0); none in -1s; lastlive=10s; idle; import:admin initiate<br>000 #207: "vpn/1x9":500 STATE_V2_IPSEC_I (IPsec SA established); EVENT_SA_REPLACE in 27860s; newest IPSEC; eroute owner; isakmp#169; idle; import:admin initiate<br>20210615_T14:24:01 - 000 #56: "vpn/1x9":500 STATE_V2_REKEY_CHILD_I0 (STATE_V2_REKEY_CHILD_I0); none in -1s; lastlive=2s; idle; import:admin initiate<br>000 #207: "vpn/1x9":500 STATE_V2_IPSEC_I (IPsec SA established); EVENT_SA_REPLACE in 27800s; newest IPSEC; eroute owner; isakmp#169; idle; import:admin initiate<br>20210615_T14:25:02 - 000 #56: "vpn/1x9":500 STATE_V2_REKEY_CHILD_I0 (STATE_V2_REKEY_CHILD_I0); none in -1s; lastlive=6s; idle; import:admin initiate<br>000 #207: "vpn/1x9":500 STATE_V2_IPSEC_I (IPsec SA established); EVENT_SA_REPLACE in 27740s; newest IPSEC; eroute owner; isakmp#169; idle; import:admin initiate<br>20210615_T14:26:02 - 000 #56: "vpn/1x9":500 STATE_V2_REKEY_CHILD_I0 (STATE_V2_REKEY_CHILD_I0); none in -1s; lastlive=0s; idle; import:admin initiate<br>000 #207: "vpn/1x9":500 STATE_V2_IPSEC_I (IPsec SA established); EVENT_SA_REPLACE in 27680s; newest IPSEC; eroute owner; isakmp#169; idle; import:admin initiate<br>20210615_T14:27:02 - 000 #56: "vpn/1x9":500 STATE_V2_REKEY_CHILD_I0 (STATE_V2_REKEY_CHILD_I0); none in -1s; lastlive=16s; idle; import:admin initiate<br>000 #207: "vpn/1x9":500 STATE_V2_IPSEC_I (IPsec SA established); EVENT_SA_REPLACE in 27620s; newest IPSEC; eroute owner; isakmp#169; idle; import:admin initiate<br>20210615_T14:28:02 - 000 #56: "vpn/1x9":500 STATE_V2_REKEY_CHILD_I0 (STATE_V2_REKEY_CHILD_I0); none in -1s; lastlive=4s; idle; import:admin initiate<br>000 #207: "vpn/1x9":500 STATE_V2_IPSEC_I (IPsec SA established); EVENT_SA_REPLACE in 27560s; newest IPSEC; eroute owner; isakmp#169; idle; import:admin initiate<br>20210615_T14:29:02 - 000 #56: "vpn/1x9":500 STATE_V2_REKEY_CHILD_I0 (STATE_V2_REKEY_CHILD_I0); none in -1s; lastlive=6s; idle; import:admin initiate<br>000 #207: "vpn/1x9":500 STATE_V2_IPSEC_I (IPsec SA established); EVENT_SA_REPLACE in 27500s; newest IPSEC; eroute owner; isakmp#169; idle; import:admin initiate<br>20210615_T14:30:02 - 000 #56: "vpn/1x9":500 STATE_V2_REKEY_CHILD_I0 (STATE_V2_REKEY_CHILD_I0); none in -1s; lastlive=7s; idle; import:admin initiate<br>000 #207: "vpn/1x9":500 STATE_V2_IPSEC_I (IPsec SA established); EVENT_SA_REPLACE in 27439s; newest IPSEC; eroute owner; isakmp#169; idle; import:admin initiate<br>20210615_T14:31:01 - 000 #56: "vpn/1x9":500 STATE_V2_REKEY_CHILD_I0 (STATE_V2_REKEY_CHILD_I0); none in -1s; lastlive=6s; idle; import:admin initiate<br>000 #207: "vpn/1x9":500 STATE_V2_IPSEC_I (IPsec SA established); EVENT_SA_REPLACE in 27380s; newest IPSEC; eroute owner; isakmp#169; idle; import:admin initiate<br>20210615_T14:32:01 - 000 #56: "vpn/1x9":500 STATE_V2_REKEY_CHILD_I0 (STATE_V2_REKEY_CHILD_I0); none in -1s; lastlive=4s; idle; import:admin initiate<br>000 #207: "vpn/1x9":500 STATE_V2_IPSEC_I (IPsec SA established); EVENT_SA_REPLACE in 27320s; newest IPSEC; eroute owner; isakmp#169; idle; import:admin initiate<br>20210615_T14:33:01 - 000 #56: "vpn/1x9":500 STATE_V2_REKEY_CHILD_I0 (STATE_V2_REKEY_CHILD_I0); none in -1s; lastlive=4s; idle; import:admin initiate<br>000 #207: "vpn/1x9":500 STATE_V2_IPSEC_I (IPsec SA established); EVENT_SA_REPLACE in 27260s; newest IPSEC; eroute owner; isakmp#169; idle; import:admin initiate<br>20210615_T14:34:01 - 000 #56: "vpn/1x9":500 STATE_V2_REKEY_CHILD_I0 (STATE_V2_REKEY_CHILD_I0); none in -1s; lastlive=16s; idle; import:admin initiate<br>000 #207: "vpn/1x9":500 STATE_V2_IPSEC_I (IPsec SA established); EVENT_SA_REPLACE in 27200s; newest IPSEC; eroute owner; isakmp#169; idle; import:admin initiate<br>20210615_T14:35:02 - 000 #56: "vpn/1x9":500 STATE_V2_REKEY_CHILD_I0 (STATE_V2_REKEY_CHILD_I0); none in -1s; lastlive=6s; idle; import:admin initiate<br>000 #207: "vpn/1x9":500 STATE_V2_IPSEC_I (IPsec SA established); EVENT_SA_REPLACE in 27140s; newest IPSEC; eroute owner; isakmp#169; idle; import:admin initiate<br>20210615_T14:36:02 - 000 #56: "vpn/1x9":500 STATE_V2_REKEY_CHILD_I0 (STATE_V2_REKEY_CHILD_I0); none in -1s; lastlive=6s; idle; import:admin initiate<br>000 #207: "vpn/1x9":500 STATE_V2_IPSEC_I (IPsec SA established); EVENT_SA_REPLACE in 27080s; newest IPSEC; eroute owner; isakmp#169; idle; import:admin initiate<br>20210615_T14:37:02 - 000 #56: "vpn/1x9":500 STATE_V2_REKEY_CHILD_I0 (STATE_V2_REKEY_CHILD_I0); none in -1s; lastlive=6s; idle; import:admin initiate<br>000 #207: "vpn/1x9":500 STATE_V2_IPSEC_I (IPsec SA established); EVENT_SA_REPLACE in 27020s; newest IPSEC; eroute owner; isakmp#169; idle; import:admin initiate<br>20210615_T14:38:02 - 000 #56: "vpn/1x9":500 STATE_V2_REKEY_CHILD_I0 (STATE_V2_REKEY_CHILD_I0); none in -1s; lastlive=4s; idle; import:admin initiate<br>000 #207: "vpn/1x9":500 STATE_V2_IPSEC_I (IPsec SA established); EVENT_SA_REPLACE in 26960s; newest IPSEC; eroute owner; isakmp#169; idle; import:admin initiate<br>20210615_T14:39:02 - 000 #56: "vpn/1x9":500 STATE_V2_REKEY_CHILD_I0 (STATE_V2_REKEY_CHILD_I0); none in -1s; lastlive=7s; idle; import:admin initiate<br>000 #207: "vpn/1x9":500 STATE_V2_IPSEC_I (IPsec SA established); EVENT_SA_REPLACE in 26899s; newest IPSEC; eroute owner; isakmp#169; idle; import:admin initiate<br>20210615_T14:40:02 - 000 #56: "vpn/1x9":500 STATE_V2_REKEY_CHILD_I0 (STATE_V2_REKEY_CHILD_I0); none in -1s; lastlive=6s; idle; import:admin initiate<br>000 #207: "vpn/1x9":500 STATE_V2_IPSEC_I (IPsec SA established); EVENT_SA_REPLACE in 26840s; newest IPSEC; eroute owner; isakmp#169; idle; import:admin initiate<br>20210615_T14:41:02 - 000 #56: "vpn/1x9":500 STATE_V2_REKEY_CHILD_I0 (STATE_V2_REKEY_CHILD_I0); none in -1s; lastlive=6s; idle; import:admin initiate<br>000 #207: "vpn/1x9":500 STATE_V2_IPSEC_I (IPsec SA established); EVENT_SA_REPLACE in 26780s; newest IPSEC; eroute owner; isakmp#169; idle; import:admin initiate<br>20210615_T14:42:02 - 000 #56: "vpn/1x9":500 STATE_V2_REKEY_CHILD_I0 (STATE_V2_REKEY_CHILD_I0); none in -1s; lastlive=6s; idle; import:admin initiate<br>000 #207: "vpn/1x9":500 STATE_V2_IPSEC_I (IPsec SA established); EVENT_SA_REPLACE in 26719s; newest IPSEC; eroute owner; isakmp#169; idle; import:admin initiate<br>20210615_T14:43:02 - 000 #56: "vpn/1x9":500 STATE_V2_REKEY_CHILD_I0 (STATE_V2_REKEY_CHILD_I0); none in -1s; lastlive=4s; idle; import:admin initiate<br>000 #207: "vpn/1x9":500 STATE_V2_IPSEC_I (IPsec SA established); EVENT_SA_REPLACE in 26659s; newest IPSEC; eroute owner; isakmp#169; idle; import:admin initiate<br>20210615_T14:44:02 - 000 #56: "vpn/1x9":500 STATE_V2_REKEY_CHILD_I0 (STATE_V2_REKEY_CHILD_I0); none in -1s; lastlive=7s; idle; import:admin initiate<br>000 #207: "vpn/1x9":500 STATE_V2_IPSEC_I (IPsec SA established); EVENT_SA_REPLACE in 26599s; newest IPSEC; eroute owner; isakmp#169; idle; import:admin initiate<br>20210615_T14:45:01 - 000 #56: "vpn/1x9":500 STATE_V2_REKEY_CHILD_I0 (STATE_V2_REKEY_CHILD_I0); none in -1s; lastlive=6s; idle; import:admin initiate<br>000 #207: "vpn/1x9":500 STATE_V2_IPSEC_I (IPsec SA established); EVENT_SA_REPLACE in 26540s; newest IPSEC; eroute owner; isakmp#169; idle; import:admin initiate<br>20210615_T14:46:01 - 000 #56: "vpn/1x9":500 STATE_V2_REKEY_CHILD_I0 (STATE_V2_REKEY_CHILD_I0); none in -1s; lastlive=6s; idle; import:admin initiate<br>000 #207: "vpn/1x9":500 STATE_V2_IPSEC_I (IPsec SA established); EVENT_SA_REPLACE in 26480s; newest IPSEC; eroute owner; isakmp#169; idle; import:admin initiate<br>20210615_T14:47:01 - 000 #56: "vpn/1x9":500 STATE_V2_REKEY_CHILD_I0 (STATE_V2_REKEY_CHILD_I0); none in -1s; lastlive=6s; idle; import:admin initiate<br>000 #207: "vpn/1x9":500 STATE_V2_IPSEC_I (IPsec SA established); EVENT_SA_REPLACE in 26420s; newest IPSEC; eroute owner; isakmp#169; idle; import:admin initiate<br>20210615_T14:48:01 - 000 #56: "vpn/1x9":500 STATE_V2_REKEY_CHILD_I0 (STATE_V2_REKEY_CHILD_I0); none in -1s; lastlive=4s; idle; import:admin initiate<br>000 #207: "vpn/1x9":500 STATE_V2_IPSEC_I (IPsec SA established); EVENT_SA_REPLACE in 26360s; newest IPSEC; eroute owner; isakmp#169; idle; import:admin initiate<br>20210615_T14:49:01 - 000 #56: "vpn/1x9":500 STATE_V2_REKEY_CHILD_I0 (STATE_V2_REKEY_CHILD_I0); none in -1s; lastlive=6s; idle; import:admin initiate<br>000 #207: "vpn/1x9":500 STATE_V2_IPSEC_I (IPsec SA established); EVENT_SA_REPLACE in 26300s; newest IPSEC; eroute owner; isakmp#169; idle; import:admin initiate<br>20210615_T14:50:02 - 000 #56: "vpn/1x9":500 STATE_V2_REKEY_CHILD_I0 (STATE_V2_REKEY_CHILD_I0); none in -1s; lastlive=6s; idle; import:admin initiate<br>000 #207: "vpn/1x9":500 STATE_V2_IPSEC_I (IPsec SA established); EVENT_SA_REPLACE in 26240s; newest IPSEC; eroute owner; isakmp#169; idle; import:admin initiate<br>20210615_T14:51:02 - 000 #56: "vpn/1x9":500 STATE_V2_REKEY_CHILD_I0 (STATE_V2_REKEY_CHILD_I0); none in -1s; lastlive=4s; idle; import:admin initiate<br>000 #207: "vpn/1x9":500 STATE_V2_IPSEC_I (IPsec SA established); EVENT_SA_REPLACE in 26180s; newest IPSEC; eroute owner; isakmp#169; idle; import:admin initiate<br>20210615_T14:52:02 - 000 #56: "vpn/1x9":500 STATE_V2_REKEY_CHILD_I0 (STATE_V2_REKEY_CHILD_I0); none in -1s; lastlive=4s; idle; import:admin initiate<br>000 #207: "vpn/1x9":500 STATE_V2_IPSEC_I (IPsec SA established); EVENT_SA_REPLACE in 26119s; newest IPSEC; eroute owner; isakmp#169; idle; import:admin initiate</font></div></blockquote><span style="color:rgb(7,55,99);font-family:verdana,sans-serif"><div class="gmail_default"><span style="color:rgb(7,55,99);font-family:verdana,sans-serif"><br></span></div>After 30 minutes the subnet phase 2 goes down again and retryes using the new #227 which is not successful reconnected. Anyway the old #56 is blocked for some reason:</span><br><blockquote style="color:rgb(7,55,99);margin:0px 0px 0px 40px;border:none;padding:0px"><div class="gmail_default" style="color:rgb(7,55,99)"><font face="monospace">20210615_T14:53:01 - 000 #56: "vpn/1x9":500 STATE_V2_REKEY_CHILD_I0 (STATE_V2_REKEY_CHILD_I0); none in -1s; lastlive=3s; idle; import:admin initiate<br>000 #227: "vpn/1x9":500 STATE_V2_REKEY_CHILD_I0 (STATE_V2_REKEY_CHILD_I0); EVENT_CRYPTO_TIMEOUT in 56s; lastlive=3s; idle; import:admin initiate<br>20210615_T14:54:01 - 000 #56: "vpn/1x9":500 STATE_V2_REKEY_CHILD_I0 (STATE_V2_REKEY_CHILD_I0); none in -1s; lastlive=11s; idle; import:admin initiate<br>20210615_T14:55:01 - 000 #56: "vpn/1x9":500 STATE_V2_REKEY_CHILD_I0 (STATE_V2_REKEY_CHILD_I0); none in -1s; lastlive=2s; idle; import:admin initiate<br>20210615_T14:56:01 - 000 #56: "vpn/1x9":500 STATE_V2_REKEY_CHILD_I0 (STATE_V2_REKEY_CHILD_I0); none in -1s; lastlive=2s; idle; import:admin initiate<br>20210615_T14:57:01 - 000 #56: "vpn/1x9":500 STATE_V2_REKEY_CHILD_I0 (STATE_V2_REKEY_CHILD_I0); none in -1s; lastlive=6s; idle; import:admin initiate<br>20210615_T14:58:01 - 000 #56: "vpn/1x9":500 STATE_V2_REKEY_CHILD_I0 (STATE_V2_REKEY_CHILD_I0); none in -1s; lastlive=2s; idle; import:admin initiate<br>20210615_T14:59:01 - 000 #56: "vpn/1x9":500 STATE_V2_REKEY_CHILD_I0 (STATE_V2_REKEY_CHILD_I0); none in -1s; lastlive=12s; idle; import:admin initiate<br>20210615_T15:00:03 - 000 #56: "vpn/1x9":500 STATE_V2_REKEY_CHILD_I0 (STATE_V2_REKEY_CHILD_I0); none in -1s; lastlive=14s; idle; import:admin initiate </font></div><div class="gmail_default" style="color:rgb(7,55,99)"><font face="monospace"><br></font></div></blockquote><font color="#073763" face="verdana, sans-serif">Other logs from the pluto.log on this events filtering with</font><font color="#073763" face="monospace"> (</font><font face="monospace">grep -e "#56" -e "vpn/1x9" -e "#207" -e "#227") </font><font face="verdana, sans-serif">and omiting repeated lines with</font><font face="monospace"> (...), I hope it helps</font><span style="color:rgb(7,55,99);font-family:monospace">:</span></div><div class="gmail_default"><font color="#073763" face="monospace"><br></font></div><blockquote style="margin:0 0 0 40px;border:none;padding:0px"><div class="gmail_default">  1 Jun 15 14:18:01.044603: | pending review: connection "vpn/1x9" checked<br>  2 Jun 15 14:20:01.047861: | pending review: connection "vpn/1x9" checked<br>  3 Jun 15 14:20:41.789100: |  conn vpn/1x9 mark 0/00000000, 0/00000000<br>  4 ...<br>  5 Jun 15 14:21:12.518678: |  conn vpn/1x9 mark 0/00000000, 0/00000000<br>  6 Jun 15 14:21:21.368267: | find_connection: conn "vpn/1x9" has compatible peers: xxx.xxx.xxx.80/28 -> xxx.xxx.xxx.166/32 [pri: 29425674]<br>  7 Jun 15 14:21:21.368271: | find_connection: first OK "vpn/1x9" [pri:29425674]{0x5631587fe078} (child none)<br>  8 Jun 15 14:21:21.368280: | find_connection: concluding with "vpn/1x9" [pri:29425674]{0x5631587fe078} kind=CK_PERMANENT<br>  9 Jun 15 14:21:21.368292: | priority calculation of connection "vpn/1x9" is 0xfe3df<br> 10 Jun 15 14:21:21.368381: | creating state object #207 at 0x56315882f608<br> 11 Jun 15 14:21:21.368385: | parent state #207: new => STATE_UNDEFINED(ignore)<br> 12 Jun 15 14:21:21.368389: | duplicating state object #169 "vpn/1x18" as #207 for IPSEC SA<br> 13 Jun 15 14:21:21.368405: "vpn/1x9" #207: extra debugging enabled for connection: none<br> 14 Jun 15 14:21:21.368412: | processing: start state #207 connection "vpn/1x9" xxx.xxx.xxx.45:500 (in ikev2_initiate_child_sa() at ikev2_parent.c:6767)<br> 15 Jun 15 14:21:21.368425: | child state #207: STATE_UNDEFINED(ignore) => STATE_V2_CREATE_I0(established-authenticated-ike)<br> 16 Jun 15 14:21:21.368461: | inserting state object #207<br> 17 Jun 15 14:21:21.368466: | serialno list: inserting object 0x56315882f608 (state #207) entry 0x56315882fdb0 into list 0x563157ba4840 (older 0x56315882b050 newer 0x5631588564c0)<br> 18 Jun 15 14:21:21.368471: | serialno list: inserted  object 0x56315882f608 (state #207) entry 0x56315882fdb0 (older 0x56315882b050 newer 0x563157ba4840)<br> 19 Jun 15 14:21:21.368479: | serialno table: inserting object 0x56315882f608 (state #207) entry 0x56315882fdd0 into list 0x563157b99140 (older 0x563157b99140 newer 0x563157b99140)<br> 20 Jun 15 14:21:21.368485: | serialno table: inserted  object 0x56315882f608 (state #207) entry 0x56315882fdd0 (older 0x563157b99140 newer 0x563157b99140)<br> 21 Jun 15 14:21:21.368509: | constructing ESP/AH proposals with default DH MODP2048  for vpn/1x9 (ESP/AH initiator emitting proposals)<br> 22 Jun 15 14:21:21.368529: "vpn/1x9" #207: local ESP/AH proposals for vpn/1x9 (ESP/AH initiator emitting proposals): 1:ESP:ENCR=AES_CBC_256;INTEG=HMAC_SHA2_256_128;DH=MODP2048;ESN=DISABLED<br> 23 Jun 15 14:21:21.368536: | #207 schedule initiate IPsec SA PSK+ENCRYPT+TUNNEL+PFS+UP+IKEV2_ALLOW+IKEV2_PROPOSE+SAREF_TRACK+IKE_FRAG_ALLOW+ESN_NO using IKE# 169 pfs=MODP2048<br> 24 Jun 15 14:21:21.368540: | state #207 requesting to delete non existing event<br> 25 Jun 15 14:21:21.368549: | inserting event EVENT_v2_INITIATE_CHILD, timeout in 0.000 seconds for #207<br> 26 Jun 15 14:21:21.368557: | processing: RESET state #207 connection "vpn/1x9" xxx.xxx.xxx.45:500 (in ikev2_initiate_child_sa() at ikev2_parent.c:6862)<br> 27 Jun 15 14:21:21.368581: | handling event EVENT_v2_INITIATE_CHILD for child state #207<br> 28 Jun 15 14:21:21.368585: "vpn/1x9" #207: extra debugging enabled for connection: none<br> 29 Jun 15 14:21:21.368592: | processing: start state #207 connection "vpn/1x9" xxx.xxx.xxx.45:500 (in timer_event_cb() at timer.c:319)<br> 30 Jun 15 14:21:21.368608: | adding Child Initiator KE and nonce ni work-order 318 for state #207<br> 31 Jun 15 14:21:21.368612: | state #207 requesting to delete non existing event<br> 32 Jun 15 14:21:21.368650: | inserting event EVENT_CRYPTO_TIMEOUT, timeout in 60.000 seconds for #207<br> 33 Jun 15 14:21:21.368656: | backlog: inserting object 0x56315882ffd8 (work-order 318 state #207) entry 0x56315882ffe0 into list 0x563157ba5740 (older 0x563157ba5740 newer 0x563157ba5740)<br> 34 Jun 15 14:21:21.368661: | backlog: inserted  object 0x56315882ffd8 (work-order 318 state #207) entry 0x56315882ffe0 (older 0x563157ba5740 newer 0x563157ba5740)<br> 35 Jun 15 14:21:21.368689: | backlog: removing  object 0x56315882ffd8 (work-order 318 state #207) entry 0x56315882ffe0 (older 0x563157ba5740 newer 0x563157ba5740)<br> 36 Jun 15 14:21:21.368699: | crypto helper 0 starting work-order 318 for state #207<br> 37 Jun 15 14:21:21.370373: | crypto helper 0 sending results from work-order 318 for state #207 to event queue<br> 38 Jun 15 14:21:21.370379: | scheduling now-event sending helper answer for #207<br> 39 Jun 15 14:21:21.370408: | processing: stop state #207 connection "vpn/1x9" xxx.xxx.xxx.45:500 (in timer_event_cb() at timer.c:669)<br> 40 Jun 15 14:21:21.370429: | serialno table: hash serialno #207 to head 0x563157b99140<br> 41 Jun 15 14:21:21.370432: | serialno table: hash serialno #207 to head 0x563157b99140<br> 42 Jun 15 14:21:21.370436: "vpn/1x9" #207: extra debugging enabled for connection: none<br> 43 Jun 15 14:21:21.370441: | processing: start state #207 connection "vpn/1x9" xxx.xxx.xxx.45:500 (in schedule_event_now_cb() at server.c:594)<br> 44 Jun 15 14:21:21.370451: | ikev2_crypto_continue for #207<br> 45 Jun 15 14:21:21.370464: | #207 send new exchange now using parent #169 unacknowledged 0 next message id=73 ike exchange window 1<br> 46 Jun 15 14:21:21.370468: "vpn/1x9" #207: extra debugging enabled for connection: none<br> 47 Jun 15 14:21:21.370473: | processing: [RE]START state #207 connection "vpn/1x9" xxx.xxx.xxx.45:500 (in ikev2_child_out_cont() at ikev2_parent.c:5815)<br> 48 Jun 15 14:21:21.371176: "vpn/1x9" #207: extra debugging enabled for connection: none<br> 49 Jun 15 14:21:21.371181: | processing: [RE]START state #207 connection "vpn/1x9" xxx.xxx.xxx.45:500 (in complete_v2_state_transition() at ikev2.c:2787)<br> 50 Jun 15 14:21:21.371185: | #207 complete v2 state transition from STATE_V2_CREATE_I0 with STF_OK<br> 51 Jun 15 14:21:21.371200: | child state #207: STATE_V2_CREATE_I0(established-authenticated-ike) => STATE_V2_CREATE_I(established-authenticated-ike)<br> 52 Jun 15 14:21:21.371244: | message ID #207 STATE_V2_CREATE_I vpn/1x9 pst #169 st_msgid_nextuse(before=73) 74 st_msgid_lastack 72 st_msgid_lastrecv 4294967295 md is a request<br> 53 Jun 15 14:21:21.371248: "vpn/1x9" #207: STATE_V2_CREATE_I: sent IPsec Child req wait response<br> 54 Jun 15 14:21:21.371385: | state #207 requesting EVENT_CRYPTO_TIMEOUT to be deleted<br> 55 Jun 15 14:21:21.371405: | inserting event EVENT_v2_RETRANSMIT, timeout in 0.500 seconds for #207<br> 56 Jun 15 14:21:21.371411: | #207 STATE_V2_CREATE_I: retransmits: first event in 0.5 seconds; timeout in 60 seconds; limit of 12 retransmits; current time is 1750825.454<br> 57 Jun 15 14:21:21.371417: | processing: stop state #207 connection "vpn/1x9" xxx.xxx.xxx.45:500 (in schedule_event_now_cb() at server.c:597)<br> 58 Jun 15 14:21:21.407522: | v2 peer, cookies and msgid match on #207<br> 59 Jun 15 14:21:21.407526: | v2 state object #207 found, in STATE_V2_CREATE_I<br> 60 Jun 15 14:21:21.407529: | found state #207<br> 61 Jun 15 14:21:21.407534: "vpn/1x9" #207: extra debugging enabled for connection: none<br> 62 Jun 15 14:21:21.407540: | processing: start state #207 connection "vpn/1x9" xxx.xxx.xxx.45:500 (in ikev2_process_packet() at ikev2.c:1538)<br> 63 Jun 15 14:21:21.407543: "vpn/1x9" #207: extra debugging enabled for connection: none<br> 64 Jun 15 14:21:21.407547: | processing: start connection "vpn/1x9" (BACKGROUND) (in ikev2_process_packet() at ikev2.c:1543)<br> 65 Jun 15 14:21:21.407558: | #207 is idle<br> 66 Jun 15 14:21:21.407561: | #207 idle<br> 67 Jun 15 14:21:21.407565: | #207 in state V2_CREATE_I: sent IPsec Child req wait response<br> 68 Jun 15 14:21:21.407793: | #207 ikev2 ISAKMP_v2_CREATE_CHILD_SA decrypt success<br> 69 Jun 15 14:21:21.407932: | "vpn/1x18" #169 received Child SA Response CREATE_CHILD_SA from xxx.xxx.xxx.45:500 Child "vpn/1x9" #207 in STATE_V2_CREATE_I will process it further<br> 70 Jun 15 14:21:21.407935: | switching from parent? #207 to child #207 in FSM processor<br> 71 Jun 15 14:21:21.407947: | message ID #207 STATE_V2_CREATE_I vpn/1x9 pst #169 st_msgid_nextuse(before=74) 74 st_msgid_lastack 73 st_msgid_lastrecv 4294967295 md is a resonse<br> 72 Jun 15 14:21:21.407966: | already determined local ESP/AH proposals for vpn/1x9 (ESP/AH initiator accepting remote proposal)<br> 73 Jun 15 14:21:21.408170: | updating #207's .st_oakley with preserved PRF, but why update?<br> 74 Jun 15 14:21:21.408193: | adding ikev2 Child SA initiator pfs=yes work-order 319 for state #207<br> 75 Jun 15 14:21:21.408197: | state #207 requesting EVENT_v2_RETRANSMIT to be deleted<br> 76 Jun 15 14:21:21.408200: | #207 STATE_V2_CREATE_I: retransmits: cleared<br> 77 Jun 15 14:21:21.408215: | inserting event EVENT_CRYPTO_TIMEOUT, timeout in 60.000 seconds for #207<br> 78 Jun 15 14:21:21.408222: | backlog: inserting object 0x56315882ffd8 (work-order 319 state #207) entry 0x56315882ffe0 into list 0x563157ba5740 (older 0x563157ba5740 newer 0x563157ba5740)<br> 79 Jun 15 14:21:21.408227: | backlog: inserted  object 0x56315882ffd8 (work-order 319 state #207) entry 0x56315882ffe0 (older 0x563157ba5740 newer 0x563157ba5740)<br> 80 Jun 15 14:21:21.408340: | backlog: removing  object 0x56315882ffd8 (work-order 319 state #207) entry 0x56315882ffe0 (older 0x563157ba5740 newer 0x563157ba5740)<br> 81 Jun 15 14:21:21.408381: | crypto helper 1 starting work-order 319 for state #207<br> 82 Jun 15 14:21:21.409780: | crypto helper 1 sending results from work-order 319 for state #207 to event queue<br> 83 Jun 15 14:21:21.409805: | scheduling now-event sending helper answer for #207<br> 84 Jun 15 14:21:21.409850: | suspending state #207 and saving MD<br></div><div class="gmail_default">85 Jun 15 14:21:21.409869: | #207 is busy; has a suspended MD<br> 86 Jun 15 14:21:21.409888: "vpn/1x9" #207: extra debugging enabled for connection: none<br> 87 Jun 15 14:21:21.409909: | processing: [RE]START state #207 connection "vpn/1x9" xxx.xxx.xxx.45:500 (in log_stf_suspend() at ikev2.c:2691)<br> 88 Jun 15 14:21:21.409929: | "vpn/1x9" #207 complete v2 state STATE_V2_CREATE_I transition with STF_SUSPEND suspended from complete_v2_state_transition:2763<br> 89 Jun 15 14:21:21.409968: | processing: stop state #207 connection "vpn/1x9" xxx.xxx.xxx.45:500 (in process_md() at demux.c:396)<br> 90 Jun 15 14:21:21.410023: "vpn/1x9": extra debugging enabled for connection: none<br> 91 Jun 15 14:21:21.410042: | processing: resume connection "vpn/1x9" (in process_md() at demux.c:396)<br> 92 Jun 15 14:21:21.410060: | processing: stop connection "vpn/1x9" (in process_md() at demux.c:397)<br> 93 Jun 15 14:21:21.410107: | serialno table: hash serialno #207 to head 0x563157b99140<br> 94 Jun 15 14:21:21.410125: | serialno table: hash serialno #207 to head 0x563157b99140<br> 95 Jun 15 14:21:21.410143: "vpn/1x9" #207: extra debugging enabled for connection: none<br> 96 Jun 15 14:21:21.410163: | processing: start state #207 connection "vpn/1x9" xxx.xxx.xxx.45:500 (in schedule_event_now_cb() at server.c:594)<br> 97 Jun 15 14:21:21.410217: | ikev2_crypto_continue for #207<br> 98 Jun 15 14:21:21.410727: |   ikev2_evaluate_connection_fit evaluating our conn="vpn/1x9" I=xxx.xxx.xxx.80/28:0/0 R=xxx.xxx.xxx.166/32:0/0  to their:<br> 99 Jun 15 14:21:21.410807: | prefix fitness found a better match c vpn/1x9<br>100 Jun 15 14:21:21.410899: | port fitness found better match c vpn/1x9, tsi[0],tsr[0]<br>101 Jun 15 14:21:21.410990: | protocol fitness found better match c vpn/1x9, tsi[0],tsr[0]<br>102 Jun 15 14:21:21.411447: | install_ipsec_sa() for #207: inbound and outbound<br>103 Jun 15 14:21:21.411473: | could_route called for vpn/1x9 (kind=CK_PERMANENT)<br>104 Jun 15 14:21:21.411493: |  conn vpn/1x9 mark 0/00000000, 0/00000000 vs<br>105 ...<br>106 Jun 15 14:21:21.412124: |  conn vpn/1x9 mark 0/00000000, 0/00000000 vs<br>107 Jun 15 14:21:21.412161: | route owner of "vpn/1x9" prospective erouted: self; eroute owner: self<br>108 Jun 15 14:21:21.412721: | priority calculation of connection "vpn/1x9" is 0xfe3df<br>109 Jun 15 14:21:21.412924: | sr for #207: prospective erouted<br>110 Jun 15 14:21:21.412961: |  conn vpn/1x9 mark 0/00000000, 0/00000000 vs<br>111 ...<br>112 Jun 15 14:21:21.413585: |  conn vpn/1x9 mark 0/00000000, 0/00000000 vs<br>113 Jun 15 14:21:21.413622: | route owner of "vpn/1x9" prospective erouted: self; eroute owner: self<br>114 Jun 15 14:21:21.413642: | route_and_eroute with c: vpn/1x9 (next: none) ero:vpn/1x9 esr:{(nil)} ro:vpn/1x9 rosr:{(nil)} and state: #207<br>115 Jun 15 14:21:21.413661: | priority calculation of connection "vpn/1x9" is 0xfe3df<br>116 Jun 15 14:21:21.413912: | executing up-client: PLUTO_VERB='up-client' PLUTO_VERSION='2.0' PLUTO_CONNECTION='vpn/1x9' PLUTO_INTERFACE='eth0' PLUTO_NEXT_HOP='xxx.xxx.xxx.81' PLUTO_ME='xxx.xxx.xxx.92' PLUTO_MY_ID='54.247.44.120' PLUTO_MY_CLIENT='xxx.xxx.xxx.80/28' PLUTO_MY    _CLIENT_NET='xxx.xxx.xxx.80' PLUTO_MY_CLIENT_MASK='255.255.255.240' PLUTO_MY_PORT='0' PLUTO_MY_PROTOCOL='0' PLUTO_SA_REQID='16420' PLUTO_SA_TYPE='ESP' PLUTO_PEER='xxx.xxx.xxx.45' PLUTO_PEER_ID='xxx.xxx.xxx.45' PLUTO_PEER_CLIENT='xxx.xxx.xxx.166/32' PLUTO_PEER_CLIENT_NET    ='xxx.xxx.xxx.166' PLUTO_PEER_CLIENT_MASK='255.255.255.255' PLUTO_PEER_PORT='0' PLUTO_PEER_PROTOCOL='0' PLUTO_PEER_CA='' PLUTO_STACK='netkey' PLUTO_ADDTIME='1623759681' PLUTO_CONN_POLICY='PSK+ENCRYPT+TUNNEL+PFS+UP+IKEV2_ALLOW+IKEV2_PROPOSE+SAREF_TRACK+IKE_FRAG_ALLOW+ESN    _NO' PLUTO_CONN_KIND='CK_PERMANENT' PLUTO_CONN_ADDRFAMILY='ipv4' XAUTH_FAILED=0 PLUTO_MY_SOURCEIP='xxx.xxx.xxx.92' PLUTO_IS_PEER_CISCO='0' PLUTO_PEER_DNS_INFO='' PLUTO_PEER_DOMAIN_INFO='' PLUTO_PEER_BANNER='' PLUTO_CFG_SERVER='0' PLUTO_CFG_CLIENT='0<br>117 Jun 15 14:21:21.413951: | cmd(   0):PLUTO_VERB='up-client' PLUTO_VERSION='2.0' PLUTO_CONNECTION='vpn/1x9' PLUTO_INTE:<br>118 Jun 15 14:21:21.426748: | route_and_eroute: instance "vpn/1x9", setting eroute_owner {spd=0x5631587fe180,sr=0x5631587fe180} to #207 (was #0) (newest_ipsec_sa=#0)<br>119 Jun 15 14:21:21.426846: | inR2: instance vpn/1x9[0], setting IKEv2 newest_ipsec_sa to #207 (was #0) (spd.eroute=#207) cloned from #169<br>120 Jun 15 14:21:21.426873: | state #207 requesting EVENT_CRYPTO_TIMEOUT to be deleted<br>121 Jun 15 14:21:21.426925: "vpn/1x9" #207: extra debugging enabled for connection: none<br>122 Jun 15 14:21:21.426948: | processing: [RE]START state #207 connection "vpn/1x9" xxx.xxx.xxx.45:500 (in complete_v2_state_transition() at ikev2.c:2787)<br>123 Jun 15 14:21:21.426967: | #207 complete v2 state transition from STATE_V2_CREATE_I with STF_OK<br>124 Jun 15 14:21:21.427038: | child state #207: STATE_V2_CREATE_I(established-authenticated-ike) => STATE_V2_IPSEC_I(authenticated-ipsec)<br>125 Jun 15 14:21:21.427267: | message ID #207 STATE_V2_IPSEC_I vpn/1x9 pst #169 st_msgid_nextuse(before=74) 74 st_msgid_lastack 73 st_msgid_lastrecv 4294967295 md is a resonse<br>126 Jun 15 14:21:21.427287: "vpn/1x9" #207: negotiated connection [xxx.xxx.xxx.80-xxx.xxx.xxx.95:0-65535 0] -> [xxx.xxx.xxx.166-xxx.xxx.xxx.166:0-65535 0]<br>127 Jun 15 14:21:21.427328: "vpn/1x9" #207: STATE_V2_IPSEC_I: IPsec SA established tunnel mode {ESP=>0xd6c50bde <0xe6368e02 xfrm=AES_CBC_256-HMAC_SHA2_256_128-MODP2048 NATOA=none NATD=none DPD=active}<br>128 Jun 15 14:21:21.427347: | releasing whack for #207 (sock=-1)<br>129 Jun 15 14:21:21.427415: | unpending state #169 connection "vpn/1x9"<br>130 Jun 15 14:21:21.427468: | state #207 requesting to delete non existing event<br>131 Jun 15 14:21:21.427512: | inserting event EVENT_SA_REPLACE, timeout in 27961.000 seconds for #207<br>132 Jun 15 14:21:21.427567: | inserting event EVENT_v2_LIVENESS, timeout in 30.000 seconds for #207<br>133 Jun 15 14:21:21.427600: | processing: stop state #207 connection "vpn/1x9" xxx.xxx.xxx.45:500 (in schedule_event_now_cb() at server.c:597)<br>134 Jun 15 14:21:24.052941: | serialno table: hash serialno #207 to head 0x563157b99140<br>135 ...<br>136 Jun 15 14:21:42.901464: | serialno table: hash serialno #207 to head 0x563157b99140<br>137 Jun 15 14:21:42.901483: | serialno table: hash serialno #207 to head 0x563157b99140<br>138 Jun 15 14:21:49.319394: |  conn vpn/1x9 mark 0/00000000, 0/00000000<br>139 Jun 15 14:21:49.320866: |  conn vpn/1x9 mark 0/00000000, 0/00000000<br>140 Jun 15 14:21:51.412791: | handling event EVENT_v2_LIVENESS for child state #207<br>141 Jun 15 14:21:51.412815: "vpn/1x9" #207: extra debugging enabled for connection: none<br>142 Jun 15 14:21:51.412840: | processing: start state #207 connection "vpn/1x9" xxx.xxx.xxx.45:500 (in timer_event_cb() at timer.c:319)<br>143 Jun 15 14:21:51.412861: "vpn/1x9" #207: extra debugging enabled for connection: none<br>144 Jun 15 14:21:51.412881: | processing: [RE]START state #207 connection "vpn/1x9" xxx.xxx.xxx.45:500 (in liveness_check() at timer.c:114)<br>145 Jun 15 14:21:51.412934: | "vpn/1x9" #207 parent connection of this state is diffeent "vpn/1x18" #169<br>146 Jun 15 14:21:51.413031: | processing: stop state #207 connection "vpn/1x9" xxx.xxx.xxx.45:500 (in timer_event_cb() at timer.c:669)<br>147 Jun 15 14:21:54.052550: | serialno table: hash serialno #207 to head 0x563157b99140<br>148 Jun 15 14:21:54.052553: | serialno table: hash serialno #207 to head 0x563157b99140<br></div><div class="gmail_default">149 Jun 15 14:21:57.971455: | serialno table: hash serialno #207 to head 0x563157b99140<br>150 Jun 15 14:21:57.971462: | serialno table: hash serialno #207 to head 0x563157b99140<br>151 Jun 15 14:22:01.054219: | pending review: connection "vpn/1x9" checked<br>152 Jun 15 14:22:01.369389: | serialno table: hash serialno #207 to head 0x563157b99140<br>153 ...<br>154 Jun 15 14:34:31.688150: | serialno table: hash serialno #207 to head 0x563157b99140<br>155 Jun 15 14:34:31.688153: | serialno table: hash serialno #207 to head 0x563157b99140<br>156 Jun 15 14:34:37.344591: "vpn/1x9" #207: extra debugging enabled for connection: none<br>157 Jun 15 14:34:37.344611: | processing: start state #207 connection "vpn/1x9" xxx.xxx.xxx.45:500 (in for_each_state() at state.c:1742)<br>158 Jun 15 14:34:37.344709: | processing: stop state #207 connection "vpn/1x9" xxx.xxx.xxx.45:500 (in for_each_state() at state.c:1742)<br>159 Jun 15 14:34:37.345838: "vpn/1x9" #56: extra debugging enabled for connection: none<br>160 Jun 15 14:34:37.345858: | processing: start state #56 connection "vpn/1x9" xxx.xxx.xxx.45:500 (in for_each_state() at state.c:1742)<br>161 Jun 15 14:34:37.345878: | processing: stop state #56 connection "vpn/1x9" xxx.xxx.xxx.45:500 (in for_each_state() at state.c:1742)<br>162 Jun 15 14:34:39.052934: | serialno table: hash serialno #207 to head 0x563157b99140<br>163 Jun 15 14:34:39.052937: | serialno table: hash serialno #207 to head 0x563157b99140<br>164 Jun 15 14:51:21.641018: | serialno table: hash serialno #207 to head 0x563157b99140<br>165 ...<br>166 Jun 15 14:51:24.053702: | serialno table: hash serialno #207 to head 0x563157b99140<br>167 Jun 15 14:51:24.053706: | serialno table: hash serialno #207 to head 0x563157b99140<br>168 Jun 15 14:51:27.825965: | serialno list: updated newer   object 0x56315882f608 (state #207) entry 0x56315882fdb0 (older 0x56315882a680 newer 0x563158830780)<br>169 Jun 15 14:51:36.717515: | serialno table: hash serialno #207 to head 0x563157b99140<br>170 ...<br>171 Jun 15 14:51:54.052172: | serialno table: hash serialno #207 to head 0x563157b99140<br>172 Jun 15 14:51:57.935511: | serialno list: updated older  object 0x56315882f608 (state #207) entry 0x56315882fdb0 (older 0x56315882a680 newer 0x563158837770)<br>173 Jun 15 14:52:01.145024: | pending review: connection "vpn/1x9" checked<br>174 Jun 15 14:52:01.750287: | serialno table: hash serialno #207 to head 0x563157b99140<br>175 ...<br>176 Jun 15 14:52:24.052144: | serialno table: hash serialno #207 to head 0x563157b99140<br>177 Jun 15 14:52:27.863998: | serialno list: updated older  object 0x56315882f608 (state #207) entry 0x56315882fdb0 (older 0x56315882a680 newer 0x563158838b10)<br>178 Jun 15 14:52:27.899533: | serialno list: updated newer   object 0x56315882f608 (state #207) entry 0x56315882fdb0 (older 0x56315882d940 newer 0x563158838b10)<br>179 Jun 15 14:52:36.999286: | serialno table: hash serialno #207 to head 0x563157b99140<br>180 ...<br>181 Jun 15 14:52:54.052066: | serialno table: hash serialno #207 to head 0x563157b99140<br>182 Jun 15 14:52:57.831870: | serialno list: updated older  object 0x56315882f608 (state #207) entry 0x56315882fdb0 (older 0x56315882d940 newer 0x563158856e90)<br>183 Jun 15 14:52:57.861344: | v2 child state object #207 found, in STATE_V2_IPSEC_I<br>184 Jun 15 14:52:57.861382: "vpn/1x18" #169: received Delete SA payload: replace IPSEC State #207 now<br>185 Jun 15 14:52:57.861401: | state #207 requesting EVENT_SA_REPLACE to be deleted<br>186 Jun 15 14:52:57.861458: | inserting event EVENT_SA_REPLACE, timeout in 0.000 seconds for #207<br>187 Jun 15 14:52:57.862558: | handling event EVENT_SA_REPLACE for child state #207<br>188 Jun 15 14:52:57.862576: "vpn/1x9" #207: extra debugging enabled for connection: none<br>189 Jun 15 14:52:57.862595: | processing: start state #207 connection "vpn/1x9" xxx.xxx.xxx.45:500 (in timer_event_cb() at timer.c:319)<br>190 Jun 15 14:52:57.862613: | EVENT_SA_REPLACE picked newest_ipsec_sa #207<br>191 Jun 15 14:52:57.862672: | creating state object #227 at 0x56315882a8a8<br>192 Jun 15 14:52:57.862691: | parent state #227: new => STATE_UNDEFINED(ignore)<br>193 Jun 15 14:52:57.862708: | duplicating state object #169 "vpn/1x18" as #227 for IPSEC SA<br>194 Jun 15 14:52:57.862728: | processing: suspend state #207 connection "vpn/1x9" xxx.xxx.xxx.45:500 (in ikev2_initiate_child_sa() at ikev2_parent.c:6767)<br>195 Jun 15 14:52:57.862747: "vpn/1x9" #227: extra debugging enabled for connection: none<br>196 Jun 15 14:52:57.862765: | processing: start state #227 connection "vpn/1x9" xxx.xxx.xxx.45:500 (in ikev2_initiate_child_sa() at ikev2_parent.c:6767)<br>197 Jun 15 14:52:57.862783: | serialno table: hash serialno #207 to head 0x563157b99140<br>198 Jun 15 14:52:57.862801: | serialno table: hash serialno #207 to head 0x563157b99140<br>199 Jun 15 14:52:57.862819: | child state #227: STATE_UNDEFINED(ignore) => STATE_V2_REKEY_CHILD_I0(established-authenticated-ike)<br>200 Jun 15 14:52:57.863173: | inserting state object #227<br>201 Jun 15 14:52:57.863192: | serialno list: inserting object 0x56315882a8a8 (state #227) entry 0x56315882b050 into list 0x563157ba4840 (older 0x56315882a680 newer 0x5631588564c0)<br>202 Jun 15 14:52:57.863211: | serialno list: inserted  object 0x56315882a8a8 (state #227) entry 0x56315882b050 (older 0x56315882a680 newer 0x563157ba4840)<br>203 Jun 15 14:52:57.863248: | serialno table: inserting object 0x56315882a8a8 (state #227) entry 0x56315882b070 into list 0x563157b993c0 (older 0x563157b993c0 newer 0x563157b993c0)<br>204 Jun 15 14:52:57.863266: | serialno table: inserted  object 0x56315882a8a8 (state #227) entry 0x56315882b070 (older 0x563157b993c0 newer 0x563157b993c0)<br>205 Jun 15 14:52:57.863305: | serialno table: hash serialno #207 to head 0x563157b99140<br>206 Jun 15 14:52:57.863323: | serialno table: hash serialno #207 to head 0x563157b99140<br>207 Jun 15 14:52:57.863348: | constructing ESP/AH proposals with default DH MODP2048  for vpn/1x9 (ESP/AH initiator emitting proposals)<br>208 Jun 15 14:52:57.863421: "vpn/1x9" #227: local ESP/AH proposals for vpn/1x9 (ESP/AH initiator emitting proposals): 1:ESP:ENCR=AES_CBC_256;INTEG=HMAC_SHA2_256_128;DH=MODP2048;ESN=DISABLED<br>209 Jun 15 14:52:57.863443: | #227 schedule rekey initiate IPsec SA PSK+ENCRYPT+TUNNEL+PFS+UP+IKEV2_ALLOW+IKEV2_PROPOSE+SAREF_TRACK+IKE_FRAG_ALLOW+ESN_NO to replace #207 using IKE# 169 pfs=MODP2048<br>210 Jun 15 14:52:57.863461: | state #227 requesting to delete non existing event<br>211 Jun 15 14:52:57.863498: | inserting event EVENT_v2_INITIATE_CHILD, timeout in 0.000 seconds for #227<br>212 Jun 15 14:52:57.863519: | processing: RESET state #227 connection "vpn/1x9" xxx.xxx.xxx.45:500 (in ikev2_initiate_child_sa() at ikev2_parent.c:6862)<br>213 Jun 15 14:52:57.863556: | state #207 requesting N/A-pe@(nil) be deleted<br>214 Jun 15 14:52:57.863590: | state #207 requesting N/A-pe@(nil) be deleted<br>215 Jun 15 14:52:57.863643: | inserting event EVENT_SA_EXPIRE, timeout in 0.000 seconds for #207<br>216 Jun 15 14:52:57.863756: | handling event EVENT_v2_INITIATE_CHILD for child state #227<br>217 Jun 15 14:52:57.863774: "vpn/1x9" #227: extra debugging enabled for connection: none<br>218 Jun 15 14:52:57.863792: | processing: start state #227 connection "vpn/1x9" xxx.xxx.xxx.45:500 (in timer_event_cb() at timer.c:319)<br>219 Jun 15 14:52:57.863961: | adding Child Rekey Initiator KE and nonce ni work-order 347 for state #227<br>220 Jun 15 14:52:57.863978: | state #227 requesting to delete non existing event<br>221 Jun 15 14:52:57.864025: | inserting event EVENT_CRYPTO_TIMEOUT, timeout in 60.000 seconds for #227<br>222 Jun 15 14:52:57.864046: | backlog: inserting object 0x563158838368 (work-order 347 state #227) entry 0x563158838370 into list 0x563157ba5740 (older 0x563157ba5740 newer 0x563157ba5740)<br></div><div class="gmail_default">223 Jun 15 14:52:57.864065: | backlog: inserted  object 0x563158838368 (work-order 347 state #227) entry 0x563158838370 (older 0x563157ba5740 newer 0x563157ba5740)<br>224 Jun 15 14:52:57.864134: | backlog: removing  object 0x563158838368 (work-order 347 state #227) entry 0x563158838370 (older 0x563157ba5740 newer 0x563157ba5740)<br>225 Jun 15 14:52:57.864171: | crypto helper 1 starting work-order 347 for state #227<br>226 Jun 15 14:52:57.865909: | crypto helper 1 sending results from work-order 347 for state #227 to event queue<br>227 Jun 15 14:52:57.865929: | scheduling now-event sending helper answer for #227<br>228 Jun 15 14:52:57.865999: | processing: stop state #227 connection "vpn/1x9" xxx.xxx.xxx.45:500 (in timer_event_cb() at timer.c:669)<br>229 Jun 15 14:52:57.866070: | handling event EVENT_SA_EXPIRE for child state #207<br>230 Jun 15 14:52:57.866087: "vpn/1x9" #207: extra debugging enabled for connection: none<br>231 Jun 15 14:52:57.866106: | processing: start state #207 connection "vpn/1x9" xxx.xxx.xxx.45:500 (in timer_event_cb() at timer.c:319)<br>232 Jun 15 14:52:57.866193: "vpn/1x9" #207: extra debugging enabled for connection: none<br>233 Jun 15 14:52:57.866212: | processing: [RE]START state #207 connection "vpn/1x9" xxx.xxx.xxx.45:500 (in delete_state() at state.c:1091)<br>234 Jun 15 14:52:57.866229: | serialno table: hash serialno #207 to head 0x563157b99140<br>235 Jun 15 14:52:57.866246: | serialno table: hash serialno #207 to head 0x563157b99140<br>236 Jun 15 14:52:57.866264: "vpn/1x9" #207: deleting state (STATE_V2_IPSEC_I) and NOT sending notification<br>237 Jun 15 14:52:57.866282: | child state #207: STATE_V2_IPSEC_I(authenticated-ipsec) => delete<br>238 Jun 15 14:52:57.866358: "vpn/1x9" #207: ESP traffic information: in=0B out=120B<br>239 Jun 15 14:52:57.866377: | state #207 requesting N/A-pe@(nil) be deleted<br>240 Jun 15 14:52:57.866411: | state #207 requesting N/A-pe@(nil) be deleted<br>241 Jun 15 14:52:57.866445: | state #207 requesting N/A-pe@(nil) be deleted<br>242 Jun 15 14:52:57.866478: | state #207 requesting N/A-pe@(nil) be deleted<br>243 Jun 15 14:52:57.866513: | child state #207: STATE_V2_IPSEC_I(authenticated-ipsec) => STATE_CHILDSA_DEL(informational)<br>244 Jun 15 14:52:57.866699: | state #207 requesting to delete non existing event<br>245 Jun 15 14:52:57.866719: | serialno list: removing  object 0x56315882f608 (state #207) entry 0x56315882fdb0 (older 0x56315882d940 newer 0x563158856e90)<br>246 Jun 15 14:52:57.866777: | serialno table: removing  object 0x56315882f608 (state #207) entry 0x56315882fdd0 (older 0x563157b99140 newer 0x563157b99140)<br>247 Jun 15 14:52:57.867002: | executing down-client: PLUTO_VERB='down-client' PLUTO_VERSION='2.0' PLUTO_CONNECTION='vpn/1x9' PLUTO_INTERFACE='eth0' PLUTO_NEXT_HOP='xxx.xxx.xxx.81' PLUTO_ME='xxx.xxx.xxx.92' PLUTO_MY_ID='54.247.44.120' PLUTO_MY_CLIENT='xxx.xxx.xxx.80/28' PLUT    O_MY_CLIENT_NET='xxx.xxx.xxx.80' PLUTO_MY_CLIENT_MASK='255.255.255.240' PLUTO_MY_PORT='0' PLUTO_MY_PROTOCOL='0' PLUTO_SA_REQID='16420' PLUTO_SA_TYPE='ESP' PLUTO_PEER='xxx.xxx.xxx.45' PLUTO_PEER_ID='xxx.xxx.xxx.45' PLUTO_PEER_CLIENT='xxx.xxx.xxx.166/32' PLUTO_PEER_CLIENT    _NET='xxx.xxx.xxx.166' PLUTO_PEER_CLIENT_MASK='255.255.255.255' PLUTO_PEER_PORT='0' PLUTO_PEER_PROTOCOL='0' PLUTO_PEER_CA='' PLUTO_STACK='netkey' PLUTO_ADDTIME='1623759681' PLUTO_CONN_POLICY='PSK+ENCRYPT+TUNNEL+PFS+UP+IKEV2_ALLOW+IKEV2_PROPOSE+SAREF_TRACK+IKE_FRAG_ALLOW    +ESN_NO' PLUTO_CONN_KIND='CK_PERMANENT' PLUTO_CONN_ADDRFAMILY='ipv4' XAUTH_FAILED=0 PLUTO_MY_SOURCEIP='xxx.xxx.xxx.92' PLUTO_IS_PEER_CISCO='0' PLUTO_PEER_DNS_INFO='' PLUTO_PEER_DOMAIN_INFO='' PLUTO_PEER_BANNER='' PLUTO_CFG_SERVER='0' PLUTO_CFG_CLIEN<br>248 Jun 15 14:52:57.867047: | cmd(   0):PLUTO_VERB='down-client' PLUTO_VERSION='2.0' PLUTO_CONNECTION='vpn/1x9' PLUTO_IN:<br>249 Jun 15 14:52:57.877772: | shunt_eroute() called for connection 'vpn/1x9' to 'replace with shunt' for rt_kind 'prospective erouted' using protoports 0--0->-0<br>250 Jun 15 14:52:57.877848: | priority calculation of connection "vpn/1x9" is 0xfe3df<br>251 Jun 15 14:52:57.878093: | priority calculation of connection "vpn/1x9" is 0xfe3df<br>252 Jun 15 14:52:57.878354: | in connection_discard for connection vpn/1x9<br>253 Jun 15 14:52:57.878372: | child state #207: STATE_CHILDSA_DEL(informational) => STATE_UNDEFINED(ignore)<br>254 Jun 15 14:52:57.878623: | processing: stop state #207 xxx.xxx.xxx.45:500 (in delete_state() at state.c:1326)<br>255 Jun 15 14:52:57.878643: | serialno table: hash serialno #207 to head 0x563157b99140<br>256 Jun 15 14:52:57.878660: | serialno table: hash serialno #207 to head 0x563157b99140<br>257 Jun 15 14:52:57.880360: | serialno table: hash serialno #227 to head 0x563157b993c0<br>258 Jun 15 14:52:57.880378: | serialno table: hash serialno #227 to head 0x563157b993c0<br>259 Jun 15 14:52:57.880397: "vpn/1x9" #227: extra debugging enabled for connection: none<br>260 Jun 15 14:52:57.880417: | processing: start state #227 connection "vpn/1x9" xxx.xxx.xxx.45:500 (in schedule_event_now_cb() at server.c:594)<br>261 Jun 15 14:52:57.880469: | ikev2_crypto_continue for #227<br>262 Jun 15 14:52:57.880527: | #227 send new exchange now using parent #169 unacknowledged 0 next message id=137 ike exchange window 1<br>263 Jun 15 14:52:57.880546: "vpn/1x9" #227: extra debugging enabled for connection: none<br>264 Jun 15 14:52:57.880565: | processing: [RE]START state #227 connection "vpn/1x9" xxx.xxx.xxx.45:500 (in ikev2_child_out_cont() at ikev2_parent.c:5815)<br>265 Jun 15 14:52:57.881770: | serialno table: hash serialno #207 to head 0x563157b99140<br>266 Jun 15 14:52:57.881787: | serialno table: hash serialno #207 to head 0x563157b99140<br>267 Jun 15 14:52:57.881805: "vpn/1x9" #227: Child SA to rekey #207 vanished abort this exchange<br>268 Jun 15 14:52:57.881841: "vpn/1x9" #227: extra debugging enabled for connection: none<br>269 Jun 15 14:52:57.881861: | processing: [RE]START state #227 connection "vpn/1x9" xxx.xxx.xxx.45:500 (in complete_v2_state_transition() at ikev2.c:2787)<br>270 Jun 15 14:52:57.881880: | #227 complete v2 state transition from STATE_V2_REKEY_CHILD_I0 with STF_INTERNAL_ERROR<br>271 Jun 15 14:52:57.882086: | processing: stop state #227 connection "vpn/1x9" xxx.xxx.xxx.45:500 (in schedule_event_now_cb() at server.c:597)<br>272 Jun 15 14:53:57.834975: | serialno list: updated newer   object 0x56315882a8a8 (state #227) entry 0x56315882b050 (older 0x563158853870 newer 0x563157ba4840)<br>273 Jun 15 14:53:57.865909: | handling event EVENT_CRYPTO_TIMEOUT for child state #227<br>274 Jun 15 14:53:57.865931: "vpn/1x9" #227: extra debugging enabled for connection: none<br>275 Jun 15 14:53:57.865954: | processing: start state #227 connection "vpn/1x9" xxx.xxx.xxx.45:500 (in timer_event_cb() at timer.c:319)<br>276 Jun 15 14:53:57.865973: | event crypto_failed on state #227, aborting<br>277 Jun 15 14:53:57.865992: "vpn/1x9" #227: extra debugging enabled for connection: none<br>278 Jun 15 14:53:57.866016: | processing: [RE]START state #227 connection "vpn/1x9" xxx.xxx.xxx.45:500 (in delete_state() at state.c:1091)<br>279 Jun 15 14:53:57.866036: | serialno table: hash serialno #227 to head 0x563157b993c0<br>280 Jun 15 14:53:57.866054: | serialno table: hash serialno #227 to head 0x563157b993c0<br>281 Jun 15 14:53:57.866074: "vpn/1x9" #227: deleting state (STATE_V2_REKEY_CHILD_I0) and NOT sending notification<br>282 Jun 15 14:53:57.866236: | child state #227: STATE_V2_REKEY_CHILD_I0(established-authenticated-ike) => delete<br>283 Jun 15 14:53:57.866316: | state #227 requesting N/A-pe@(nil) be deleted<br>284 Jun 15 14:53:57.866392: | state #227 requesting N/A-pe@(nil) be deleted<br>285 Jun 15 14:53:57.866435: | state #227 requesting N/A-pe@(nil) be deleted<br>286 Jun 15 14:53:57.866470: | state #227 requesting N/A-pe@(nil) be deleted<br>287 Jun 15 14:53:57.866508: | child state #227: STATE_V2_REKEY_CHILD_I0(established-authenticated-ike) => STATE_CHILDSA_DEL(informational)<br>288 Jun 15 14:53:57.866806: | state #227 requesting to delete non existing event<br>289 Jun 15 14:53:57.866826: | serialno list: removing  object 0x56315882a8a8 (state #227) entry 0x56315882b050 (older 0x563158853870 newer 0x563157ba4840)<br>290 Jun 15 14:53:57.866884: | serialno table: removing  object 0x56315882a8a8 (state #227) entry 0x56315882b070 (older 0x563157b993c0 newer 0x563157b993c0)<br>291 Jun 15 14:53:57.867013: | priority calculation of connection "vpn/1x9" is 0xfe3df<br>292 Jun 15 14:53:57.867095: | in connection_discard for connection vpn/1x9<br>293 Jun 15 14:53:57.867114: | child state #227: STATE_CHILDSA_DEL(informational) => STATE_UNDEFINED(ignore)<br>294 Jun 15 14:53:57.867344: | processing: stop state #227 xxx.xxx.xxx.45:500 (in delete_state() at state.c:1326)<br>295 Jun 15 14:53:57.867365: | serialno table: hash serialno #227 to head 0x563157b993c0<br>296 Jun 15 14:53:57.867388: | serialno table: hash serialno #227 to head 0x563157b993c0<br>297 Jun 15 14:54:01.148212: | pending review: connection "vpn/1x9" checked<br>298 ...<br>299 Jun 15 15:02:01.169529: | pending review: connection "vpn/1x9" checked<br>300 Jun 15 15:03:36.458433: "vpn/1x9" #56: extra debugging enabled for connection: none<br>301 Jun 15 15:03:36.458452: | processing: start state #56 connection "vpn/1x9" xxx.xxx.xxx.45:500 (in for_each_state() at state.c:1742)<br>302 Jun 15 15:03:36.458472: | processing: stop state #56 connection "vpn/1x9" xxx.xxx.xxx.45:500 (in for_each_state() at state.c:1742)<br>303 Jun 15 15:04:01.178346: | pending review: connection "vpn/1x9" checked<br></div><div class="gmail_default">304 ...<br>305 Jun 15 15:14:01.199914: | pending review: connection "vpn/1x9" checked<br>306 Jun 15 15:15:42.776002: | investigating connection "vpn/1x9" as a better match<br>307 Jun 15 15:15:42.776020: |   ikev2_evaluate_connection_fit evaluating our conn="vpn/1x9" I=xxx.xxx.xxx.166/32:0/0 R=xxx.xxx.xxx.80/28:0/0  to their:<br>308 Jun 15 15:15:42.776110: | prefix fitness rejected d vpn/1x9<br>309 Jun 15 15:15:42.788257: |  conn vpn/1x9 mark 0/00000000, 0/00000000<br>310 Jun 15 15:15:42.789686: |  conn vpn/1x9 mark 0/00000000, 0/00000000<br>311 Jun 15 15:16:01.206342: | pending review: connection "vpn/1x9" checked<br>312 Jun 15 15:18:01.208991: | pending review: connection "vpn/1x9" checked<br></div><div class="gmail_default"><br></div></blockquote><div class="gmail_default" style="font-family:verdana,sans-serif;color:rgb(7,55,99)">Also I could notice too checking the Libreswan FAQ that there are some data here that I don't know how to manage, even after read this (<a href="https://www.kernel.org/doc/Documentation/networking/xfrm_proc.txt">https://www.kernel.org/doc/Documentation/networking/xfrm_proc.txt</a>):</div><blockquote style="margin:0 0 0 40px;border:none;padding:0px"><div class="gmail_default" style="font-family:verdana,sans-serif;color:rgb(7,55,99)"></div><font face="monospace">cat /proc/net/xfrm_stat<br>XfrmInError                    0<br>XfrmInBufferError         0<br>XfrmInHdrError                  0<br>XfrmInNoStates                  1<br>XfrmInStateProtoError       0<br>XfrmInStateModeError       0<br>XfrmInStateSeqError        0<br>XfrmInStateExpired        0<br>XfrmInStateMismatch        0<br>XfrmInStateInvalid        0<br>XfrmInTmplMismatch        0<br>XfrmInNoPols                   5294<br>XfrmInPolBlock               0<br>XfrmInPolError                  0<br>XfrmOutError                   0<br>XfrmOutBundleGenError       0<br>XfrmOutBundleCheckError      0<br>XfrmOutNoStates          33461<br>XfrmOutStateProtoError          0<br>XfrmOutStateModeError       2<br>XfrmOutStateSeqError       0<br>XfrmOutStateExpired        0<br>XfrmOutPolBlock          0<br>XfrmOutPolDead                  0<br>XfrmOutPolError          0<br>XfrmFwdHdrError          0<br>XfrmOutStateInvalid        0<br>XfrmAcquireError         1</font><br></blockquote><br><div><div class="gmail_default" style="font-family:verdana,sans-serif;color:rgb(7,55,99)">Thanks in advance,</div><div class="gmail_default" style="font-family:verdana,sans-serif;color:rgb(7,55,99)"><br></div><div class="gmail_default" style="font-family:verdana,sans-serif;color:rgb(7,55,99)">Best regards!</div></div></div><br><div class="gmail_quote"><div dir="ltr" class="gmail_attr"><span style="font-family:verdana,sans-serif;color:black">Miguel Ponce Antolín</span><br></div></div>
</div>