<div dir="ltr"><div>Inline responses below ....</div><br><div class="gmail_quote"><div dir="ltr" class="gmail_attr">On Thu, Nov 7, 2019 at 5:53 PM Andrew Cagney <<a href="mailto:cagney@gnu.org">cagney@gnu.org</a>> wrote:<br></div><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex">On Thu, 7 Nov 2019 at 15:54, Alan Szlosek <<a href="mailto:alan@redoxengine.com" target="_blank">alan@redoxengine.com</a>> wrote:<br>
><br>
> You're right, I see 0s:<br>
><br>
> (gdb) p md->hdr.isa_msgid<br>
> $1 = 0<br>
> (gdb) p st->st_v2_msgids<br>
> $2 = {current_request = 0, initiator = {sent = 0, recv = 0}, responder = {sent = 0, recv = 0}}<br>
>pr<br>
> Do you happen to know which commit fixes this? Wondering whether I can easily patch it, and/or how long I might have to wait for 3.30.<br>
<br>
Not really. The commit was:<br>
<br>
commit 0d0a339015e7836c3a120e2d8af18280876b41ee<br>
Author: Andrew Cagney <<a href="mailto:cagney@gnu.org" target="_blank">cagney@gnu.org</a>><br>
Date: Fri May 24 12:15:42 2019 -0400<br>
<br>
state: return {ike,child}_sa from find_v2_{ike,child}_sa*()<br>
<br>
... and pass in the IKE_SA when searching for an SA that is<br>
part of the IKE SA's family.<br>
<br>
Re-order the code looking for a state for a message so that it<br>
first finds the IKE SA and then uses that to find the actual<br>
state.<br>
<br>
but it was part of a whole series of changes.<br></blockquote><div><br></div><div>Ah, yeah if the fix was part of a whole series of changes it'll be too risky to try to bring it in, as other code might cause new issues.</div><div> </div><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex">
<br>
For 3.29 the code looks like:<br>
<br>
/*<br>
* Does the Message ID fall within the IKE SA's<br>
* sliding Message ID window?<br>
*/<br>
struct ike_sa *ike = ike_sa(st);<br>
<br>
Try adding a check for IKE==NULL here and return when it is.<br>
<br>
if (md->hdr.isa_msgid > ike->sa.st_v2_msgids.initiator.sent) {<br></blockquote><div><br></div><div>Sounds like a safe thing to try given there are plenty of early return statements elsewhere in that function. And judging from the function comment it looks like the caller is in charge of freeing md. Are there any other allocations I should free before returning?</div><div><br></div><div>Thanks for the input.</div><div> </div><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex">
<br>
<br>
> Thanks for diving into this with me, Andrew.<br>
><br>
> On Wed, Nov 6, 2019 at 11:53 PM Andrew Cagney <<a href="mailto:andrew.cagney@gmail.com" target="_blank">andrew.cagney@gmail.com</a>> wrote:<br>
>><br>
>> [changing lists]<br>
>><br>
>> On Wed, 6 Nov 2019 at 15:30, Alan Szlosek <<a href="mailto:alan@redoxengine.com" target="_blank">alan@redoxengine.com</a>> wrote:<br>
>> ><br>
>> > Sure, here's everything pertaining to those 2 SAs:<br>
>> ><br>
>> > Oct 16 16:07:08 ip-172-20-116-172 pluto[4703]: packet from NNNNNNNNNN:4500: EXPECTATION FAILED: child state #533502 missing parent state #533497 (in get_ike_sa() at state.c:461)<br>
>><br>
>> I suspect a very small amount of time passes here.<br>
>><br>
>> > Oct 16 16:07:08 ip-172-20-116-172 pluto[4703]: "NNNNNNNN/2x3" #533497: deleting state (STATE_PARENT_R2) aged 4.913s and sending notification<br>
>><br>
>> Like you noted, this happened at the 5s mark so is likely a timeout (idle?).<br>
>><br>
>> If you print:<br>
>> md->hdr.isa_msgid<br>
>> st->st_v2_msgids<br>
>> I suspect both hdr.isa_msgid and st_v2_msgids.initiator.sent will be zero 0.<br>
>><br>
>> It looks like the response to the above notification was incorrectly<br>
>> routed to the still being deleted child SA.<br>
>><br>
>> The current code shouldn't have this bug - it should drop any message<br>
>> with no IKE SA.<br>
>><br>
>> > Oct 16 16:07:03 ip-172-20-116-172 pluto[4703]: "NNNNNNNN/1x2" #533502: STATE_V2_IPSEC_R: IPsec SA established tunnel mode {ESP/NAT=>0xa6587dec <0xb550a3ae xfrm=NNNNNN NATOA=none NATD=NNNNNNNNNNNN:4500 DPD=active}<br>
>> > Oct 16 16:07:03 ip-172-20-116-172 pluto[4703]: "NNNNNNNN/1x2" #533502: negotiated connection ...<br>
>> > Oct 16 16:07:03 ip-172-20-116-172 pluto[4703]: "NNNNNNNN/2x3" #533497: received unsupported NOTIFY v2N_NON_FIRST_FRAGMENTS_ALSO<br>
>> > Oct 16 16:07:03 ip-172-20-116-172 pluto[4703]: "NNNNNNNN/2x3" #533497: proposal 1:ESP:SPI=a6587dec;ENCR=NNNNNN chosen from remote proposals...<br>
>> > Oct 16 16:07:03 ip-172-20-116-172 pluto[4703]: "NNNNNNNN/2x3" #533497: Authenticated using authby=secret<br>
>> > Oct 16 16:07:03 ip-172-20-116-172 pluto[4703]: "NNNNNNNN/2x3" #533497: IKEv2 mode peer ID is ID_IPV4_ADDR: ‘NNNNNN'<br>
>> > Oct 16 16:07:03 ip-172-20-116-172 pluto[4703]: "NNNNNNNN/2x3" #533497: processing decrypted IKE_AUTH request: SK{V,IDi,AUTH,SA,TSi,TSr,N,N,N}<br>
>> > Oct 16 16:07:03 ip-172-20-116-172 pluto[4703]: "NNNNNNNN/2x3" #533497: processing encrypted IKE_AUTH request: SK (message arrived 0 seconds ago)<br>
>> > Oct 16 16:07:03 ip-172-20-116-172 pluto[4703]: "NNNNNNNN/2x3" #533497: STATE_PARENT_R1: received v2I1, sent v2R1 {auth=IKEv2 cipher=NNNNNNNNN}<br>
>> > Oct 16 16:07:03 ip-172-20-116-172 pluto[4703]: "NNNNNNNN/2x3" #533497: proposal 2:IKE:ENCR=...<br>
>> > Oct 16 16:07:03 ip-172-20-116-172 pluto[4703]: "NNNNNNNN/2x3" #533497: processing IKE_SA_INIT request: SA,KE,Ni,V,V,N,N,N,V (message arrived 0 seconds ago)<br>
>> ><br>
>> > On Wed, Nov 6, 2019 at 2:58 PM Andrew Cagney <<a href="mailto:andrew.cagney@gmail.com" target="_blank">andrew.cagney@gmail.com</a>> wrote:<br>
>> >><br>
>> >><br>
>> >><br>
>> >> On Wed, 6 Nov 2019 at 13:12, Alan Szlosek <<a href="mailto:alan@redoxengine.com" target="_blank">alan@redoxengine.com</a>> wrote:<br>
>> >>><br>
>> >>> Can do ....<br>
>> >>><br>
>> >>> The parent was indeed deleted.<br>
>> >>><br>
>> >>> I see this:<br>
>> >>> #533497: received unsupported NOTIFY v2N_NON_FIRST_FRAGMENTS_ALSO<br>
>> >><br>
>> >><br>
>> >> this log message should be changed to ... - ignored<br>
>> >><br>
>> >>> Then 5 seconds later the deletion:<br>
>> >>> #533497: deleting state (STATE_PARENT_R2) aged 4.913s and sending notification<br>
>> >>> Followed immediately by the crash:<br>
>> >>> EXPECTATION FAILED: child state #533502 missing parent state #533497 (in get_ike_sa() at state.c:461)<br>
>> >>><br>
>> >><br>
>> >> so why was the IKE SA deleted?<br>
>> >> perhaps post everything relevant; I'd start with <<grep -v -e '#533497' -e '#533502'>> with anything sensitive stripped out; but keep an eye out for a rekey, history may go back even further<br>
>> >><br>
>> ><br>
>> ><br>
>> > --<br>
>> > Alan Szlosek<br>
>> > Infrastructure Engineer<br>
>> > <a href="http://redoxengine.com" rel="noreferrer" target="_blank">redoxengine.com</a><br>
>> ><br>
>> ><br>
>> > _______________________________________________<br>
>> > Swan mailing list<br>
>> > <a href="mailto:Swan@lists.libreswan.org" target="_blank">Swan@lists.libreswan.org</a><br>
>> > <a href="https://lists.libreswan.org/mailman/listinfo/swan" rel="noreferrer" target="_blank">https://lists.libreswan.org/mailman/listinfo/swan</a><br>
><br>
><br>
><br>
> --<br>
> Alan Szlosek<br>
> Infrastructure Engineer<br>
> <a href="http://redoxengine.com" rel="noreferrer" target="_blank">redoxengine.com</a><br>
><br>
><br>
> _______________________________________________<br>
> Security mailing list<br>
> <a href="mailto:Security@lists.libreswan.org" target="_blank">Security@lists.libreswan.org</a><br>
> <a href="https://lists.libreswan.org/mailman/listinfo/security" rel="noreferrer" target="_blank">https://lists.libreswan.org/mailman/listinfo/security</a><br>
</blockquote></div><br clear="all"><div><br></div>-- <br><div dir="ltr" class="gmail_signature"><div dir="ltr">Alan Szlosek<div>Infrastructure Engineer</div><div><a href="https://www.redoxengine.com" target="_blank">redoxengine.com</a></div></div></div></div>