Flowtable race condition error

Flowtable race condition error

[Sven Auhagen]

Hi,

I have a race condition problem in the flowtable and could
use some hint where to start debugging.

Every now and then a TCP FIN is closing the flowtable with a call
to flow_offload_teardown.

Right after another packet from the reply direction is readding
the connection to the flowtable just before the FIN is actually
transitioning the state from ESTABLISHED to FIN WAIT.

No the FIN WAIT connection is OFFLOADED.
This by itself should work itself out at gc time but
the state is now deleted right away.

Any idea why the state is deleted right away?

Here is the output of the state messages:

    [NEW] tcp      6 120 SYN_SENT src=192.168.97.23 dst=192.168.107.52 sport=63482 dport=443 [UNREPLIED] src=192.168.107.52 dst=192.168.97.23 sport=443 dport=63482 mark=92274785
 [UPDATE] tcp      6 60 SYN_RECV src=192.168.97.23 dst=192.168.107.52 sport=63482 dport=443 src=192.168.107.52 dst=192.168.97.23 sport=443 dport=63482 mark=92274785
 [UPDATE] tcp      6 432000 ESTABLISHED src=192.168.97.23 dst=192.168.107.52 sport=63482 dport=443 src=192.168.107.52 dst=192.168.97.23 sport=443 dport=63482 [OFFLOAD] mark=92274785
 [UPDATE] tcp      6 86400 FIN_WAIT src=192.168.97.23 dst=192.168.107.52 sport=63482 dport=443 src=192.168.107.52 dst=192.168.97.23 sport=443 dport=63482 [OFFLOAD] mark=92274785
[DESTROY] tcp      6 FIN_WAIT src=192.168.97.23 dst=192.168.107.52 sport=63482 dport=443 packets=10 bytes=1415 src=192.168.107.52 dst=192.168.97.23 sport=443 dport=63482 packets=11 bytes=6343 [ASSURED] mark=92274785 delta-time=0

Thanks and best
Sven

Re: Flowtable race condition error

[Florian Westphal]

Sven Auhagen <sven.auhagen@voleatech.de> wrote:
> I have a race condition problem in the flowtable and could
> use some hint where to start debugging.
> 
> Every now and then a TCP FIN is closing the flowtable with a call
> to flow_offload_teardown.

I don't understand why this is done.  It seems buggy to do this.

The skb has not been seen by conntrack yet, so any reply packet coming
in between the flow_offload_teardown() call and the conntrack actually
moving to close state ...

> Right after another packet from the reply direction is readding
> the connection to the flowtable just before the FIN is actually
> transitioning the state from ESTABLISHED to FIN WAIT.

.. will re-add.

> Any idea why the state is deleted right away?

No idea, but it was intentional, see
b6f27d322a0a ("netfilter: nf_flow_table: tear down TCP flows if RST or FIN was seen")

Re: Flowtable race condition error

[Florian Westphal]

Florian Westphal <fw@strlen.de> wrote:
> No idea, but it was intentional, see
> b6f27d322a0a ("netfilter: nf_flow_table: tear down TCP flows if RST or FIN was seen")

Maybe:

diff --git a/net/netfilter/nf_flow_table_ip.c b/net/netfilter/nf_flow_table_ip.c
--- a/net/netfilter/nf_flow_table_ip.c
+++ b/net/netfilter/nf_flow_table_ip.c
@@ -28,10 +28,8 @@ static int nf_flow_state_check(struct flow_offload *flow, int proto,
 		return 0;
 
 	tcph = (void *)(skb_network_header(skb) + thoff);
-	if (unlikely(tcph->fin || tcph->rst)) {
-		flow_offload_teardown(flow);
+	if (unlikely(tcph->fin || tcph->rst))
 		return -1;
-	}
 
 	return 0;
 }

?

This will let gc step clean the entry from the flowtable.

Re: Flowtable race condition error

[Sven Auhagen]

On Wed, Mar 13, 2024 at 04:02:03PM +0100, Florian Westphal wrote:
> Florian Westphal <fw@strlen.de> wrote:
> > No idea, but it was intentional, see
> > b6f27d322a0a ("netfilter: nf_flow_table: tear down TCP flows if RST or FIN was seen")
> 
> Maybe:
> 
> diff --git a/net/netfilter/nf_flow_table_ip.c b/net/netfilter/nf_flow_table_ip.c
> --- a/net/netfilter/nf_flow_table_ip.c
> +++ b/net/netfilter/nf_flow_table_ip.c
> @@ -28,10 +28,8 @@ static int nf_flow_state_check(struct flow_offload *flow, int proto,
>  		return 0;
>  
>  	tcph = (void *)(skb_network_header(skb) + thoff);
> -	if (unlikely(tcph->fin || tcph->rst)) {
> -		flow_offload_teardown(flow);
> +	if (unlikely(tcph->fin || tcph->rst))
>  		return -1;
> -	}
>  
>  	return 0;
>  }
> 
> ?
> 
> This will let gc step clean the entry from the flowtable.
Thanks for your answer.

I double checked and the problem is that the timeout in flow_offload_fixup_ct is set to a very small value
and the state is deleted immediately afterwards.

I will try out this patch tomorrow:

diff --git a/net/netfilter/nf_flow_table_core.c b/net/netfilter/nf_flow_table_core.c
index a7a216fc3207..29c6b9eef50d 100644
--- a/net/netfilter/nf_flow_table_core.c
+++ b/net/netfilter/nf_flow_table_core.c
@@ -195,8 +195,9 @@ static void flow_offload_fixup_ct(struct nf_conn *ct)
 		return;
 	}

-	if (timeout < 0)
-		timeout = 0;
+	// Have at least some time left on the state
+	if (timeout < NF_FLOW_TIMEOUT)
+		timeout = NF_FLOW_TIMEOUT;

 	if (nf_flow_timeout_delta(READ_ONCE(ct->timeout)) > (__s32)timeout)
 		WRITE_ONCE(ct->timeout, nfct_time_stamp + timeout);
--
2.42.0

I was able to mitigate it by setting my TCP_FIN_WAIT timeout to 240 and now the state is not deleted immediately.

I think in general this happens because either the packets come in out of order or there is a double FIN packet.
I am not 100% sure about the cause and it only happens with a small amount of connections when they close.

Best
Sven

Re: Flowtable race condition error

[Florian Westphal]

Sven Auhagen <sven.auhagen@voleatech.de> wrote:
> On Wed, Mar 13, 2024 at 04:02:03PM +0100, Florian Westphal wrote:
> > Florian Westphal <fw@strlen.de> wrote:
> > > No idea, but it was intentional, see
> > > b6f27d322a0a ("netfilter: nf_flow_table: tear down TCP flows if RST or FIN was seen")
> > 
> > Maybe:
> > 
> > diff --git a/net/netfilter/nf_flow_table_ip.c b/net/netfilter/nf_flow_table_ip.c
> > --- a/net/netfilter/nf_flow_table_ip.c
> > +++ b/net/netfilter/nf_flow_table_ip.c
> > @@ -28,10 +28,8 @@ static int nf_flow_state_check(struct flow_offload *flow, int proto,
> >  		return 0;
> >  
> >  	tcph = (void *)(skb_network_header(skb) + thoff);
> > -	if (unlikely(tcph->fin || tcph->rst)) {
> > -		flow_offload_teardown(flow);
> > +	if (unlikely(tcph->fin || tcph->rst))
> >  		return -1;
> > -	}
> >  
> >  	return 0;
> >  }
> > 
> > ?
> > 
> > This will let gc step clean the entry from the flowtable.
> Thanks for your answer.
> 
> I double checked and the problem is that the timeout in flow_offload_fixup_ct is set to a very small value
> and the state is deleted immediately afterwards.

but from where is the call to flow_offload_fixup_ct() made?

I don't think tearing down the flowtable entry on first fin or rst makes
any sense, its racy by design.

Re: Flowtable race condition error

[Sven Auhagen]

On Wed, Mar 13, 2024 at 04:25:28PM +0100, Florian Westphal wrote:
> Sven Auhagen <sven.auhagen@voleatech.de> wrote:
> > On Wed, Mar 13, 2024 at 04:02:03PM +0100, Florian Westphal wrote:
> > > Florian Westphal <fw@strlen.de> wrote:
> > > > No idea, but it was intentional, see
> > > > b6f27d322a0a ("netfilter: nf_flow_table: tear down TCP flows if RST or FIN was seen")
> > > 
> > > Maybe:
> > > 
> > > diff --git a/net/netfilter/nf_flow_table_ip.c b/net/netfilter/nf_flow_table_ip.c
> > > --- a/net/netfilter/nf_flow_table_ip.c
> > > +++ b/net/netfilter/nf_flow_table_ip.c
> > > @@ -28,10 +28,8 @@ static int nf_flow_state_check(struct flow_offload *flow, int proto,
> > >  		return 0;
> > >  
> > >  	tcph = (void *)(skb_network_header(skb) + thoff);
> > > -	if (unlikely(tcph->fin || tcph->rst)) {
> > > -		flow_offload_teardown(flow);
> > > +	if (unlikely(tcph->fin || tcph->rst))
> > >  		return -1;
> > > -	}
> > >  
> > >  	return 0;
> > >  }
> > > 
> > > ?
> > > 
> > > This will let gc step clean the entry from the flowtable.
> > Thanks for your answer.
> > 
> > I double checked and the problem is that the timeout in flow_offload_fixup_ct is set to a very small value
> > and the state is deleted immediately afterwards.
> 
> but from where is the call to flow_offload_fixup_ct() made?

It is coming from nf_flow_state_check so your patch is correct in that sense.
It might still lead to the timeout beeing set to 0 during flowtable gc though if the
state is transitioned to e.g. LAST_ACK before the gc is running even with
your patch applied.

I will also try out your patch and it makes sense that it is a race by design.
I think it should be applied as well.
I guess the question is is it save to send more packets throug the flowtable
even after we have seen a fin or rst?

> 
> I don't think tearing down the flowtable entry on first fin or rst makes
> any sense, its racy by design.

Re: Flowtable race condition error

[Sven Auhagen]

On Wed, Mar 13, 2024 at 04:25:28PM +0100, Florian Westphal wrote:
> Sven Auhagen <sven.auhagen@voleatech.de> wrote:
> > On Wed, Mar 13, 2024 at 04:02:03PM +0100, Florian Westphal wrote:
> > > Florian Westphal <fw@strlen.de> wrote:
> > > > No idea, but it was intentional, see
> > > > b6f27d322a0a ("netfilter: nf_flow_table: tear down TCP flows if RST or FIN was seen")
> > > 
> > > Maybe:
> > > 
> > > diff --git a/net/netfilter/nf_flow_table_ip.c b/net/netfilter/nf_flow_table_ip.c
> > > --- a/net/netfilter/nf_flow_table_ip.c
> > > +++ b/net/netfilter/nf_flow_table_ip.c
> > > @@ -28,10 +28,8 @@ static int nf_flow_state_check(struct flow_offload *flow, int proto,
> > >  		return 0;
> > >  
> > >  	tcph = (void *)(skb_network_header(skb) + thoff);
> > > -	if (unlikely(tcph->fin || tcph->rst)) {
> > > -		flow_offload_teardown(flow);
> > > +	if (unlikely(tcph->fin || tcph->rst))
> > >  		return -1;
> > > -	}
> > >  
> > >  	return 0;
> > >  }
> > > 
> > > ?
> > > 
> > > This will let gc step clean the entry from the flowtable.
> > Thanks for your answer.
> > 
> > I double checked and the problem is that the timeout in flow_offload_fixup_ct is set to a very small value
> > and the state is deleted immediately afterwards.
> 
> but from where is the call to flow_offload_fixup_ct() made?
> 
> I don't think tearing down the flowtable entry on first fin or rst makes
> any sense, its racy by design.

I tested your patch but that leads to other problems.
The ct gc relies on the fact that the flowtable code is setting
the ct timeout to a high value so it is not removed.
With your patch the state for TCP is going into CLOSE while
still beeing offloaded and eventuelly beeing destroyed while
still offloaded. So now bad things happen during flowtable gc
we are accessing the state in there and it has been destroyed already.

So either we need to make the ct gc aware of the offload flag or
need to keep the call to flow_offload_teardown.

Any thoughts?

Re: Flowtable race condition error

[Florian Westphal]

Sven Auhagen <sven.auhagen@voleatech.de> wrote:
> I tested your patch but that leads to other problems.

How can this work then for UDP, which has no fin/rst bits?

Maybe this is needed?  But I really do not understand any of this.

diff --git a/net/netfilter/nf_flow_table_core.c b/net/netfilter/nf_flow_table_core.c
index a0571339239c..aed4994c1b6f 100644
--- a/net/netfilter/nf_flow_table_core.c
+++ b/net/netfilter/nf_flow_table_core.c
@@ -423,6 +423,7 @@ static void nf_flow_offload_gc_step(struct nf_flowtable *flow_table,
 {
        if (nf_flow_has_expired(flow) ||
            nf_ct_is_dying(flow->ct) ||
+           !nf_conntrack_tcp_established(ct) ||
            nf_flow_custom_gc(flow_table, flow))
                flow_offload_teardown(flow);

Re: Flowtable race condition error

[Sven Auhagen]

On Thu, Mar 14, 2024 at 10:25:41AM +0100, Florian Westphal wrote:
> Sven Auhagen <sven.auhagen@voleatech.de> wrote:
> > I tested your patch but that leads to other problems.
> 
> How can this work then for UDP, which has no fin/rst bits?
> 
> Maybe this is needed?  But I really do not understand any of this.

So this is a TCP only issue that I see.
Sorry my comment earlier was not correct the refcount is still +1 as long as
the flowtable entry is active so I take that back.

I will think about it for a bit and get back to you with some ideas.
I think you have a valid point with the not calling flow_offload_teardown but maybe
we need to do something else instead like lower the flowtable entry timeout to trigger a
faster gc for both udp and tcp.

> 
> diff --git a/net/netfilter/nf_flow_table_core.c b/net/netfilter/nf_flow_table_core.c
> index a0571339239c..aed4994c1b6f 100644
> --- a/net/netfilter/nf_flow_table_core.c
> +++ b/net/netfilter/nf_flow_table_core.c
> @@ -423,6 +423,7 @@ static void nf_flow_offload_gc_step(struct nf_flowtable *flow_table,
>  {
>         if (nf_flow_has_expired(flow) ||
>             nf_ct_is_dying(flow->ct) ||
> +           !nf_conntrack_tcp_established(ct) ||
>             nf_flow_custom_gc(flow_table, flow))
>                 flow_offload_teardown(flow);
> 

Re: Flowtable race condition error

[Pablo Neira Ayuso]

Hi Sven,

On Tue, Mar 12, 2024 at 05:29:45PM +0100, Sven Auhagen wrote:
> Hi,
> 
> I have a race condition problem in the flowtable and could
> use some hint where to start debugging.
> 
> Every now and then a TCP FIN is closing the flowtable with a call
> to flow_offload_teardown.
> 
> Right after another packet from the reply direction is readding
> the connection to the flowtable just before the FIN is actually
> transitioning the state from ESTABLISHED to FIN WAIT.
> Now the FIN WAIT connection is OFFLOADED.

Are you restricting your ruleset to only offload new connections?

Or is it conntrack creating a fresh connection that being offloaded
for this terminating TCP traffic what you are observing?

> This by itself should work itself out at gc time but
> the state is now deleted right away.
>
> Any idea why the state is deleted right away?

It might be conntrack which is killing the connection, it would be
good to have a nf_ct_kill_reason(). Last time we talk, NAT can also
kill the conntrack in masquerade scenarios.

> Here is the output of the state messages:
> 
>     [NEW] tcp      6 120 SYN_SENT src=192.168.97.23 dst=192.168.107.52 sport=63482 dport=443 [UNREPLIED] src=192.168.107.52 dst=192.168.97.23 sport=443 dport=63482 mark=92274785
>  [UPDATE] tcp      6 60 SYN_RECV src=192.168.97.23 dst=192.168.107.52 sport=63482 dport=443 src=192.168.107.52 dst=192.168.97.23 sport=443 dport=63482 mark=92274785
>  [UPDATE] tcp      6 432000 ESTABLISHED src=192.168.97.23 dst=192.168.107.52 sport=63482 dport=443 src=192.168.107.52 dst=192.168.97.23 sport=443 dport=63482 [OFFLOAD] mark=92274785
>  [UPDATE] tcp      6 86400 FIN_WAIT src=192.168.97.23 dst=192.168.107.52 sport=63482 dport=443 src=192.168.107.52 dst=192.168.97.23 sport=443 dport=63482 [OFFLOAD] mark=92274785
> [DESTROY] tcp      6 FIN_WAIT src=192.168.97.23 dst=192.168.107.52 sport=63482 dport=443 packets=10 bytes=1415 src=192.168.107.52 dst=192.168.97.23 sport=443 dport=63482 packets=11 bytes=6343 [ASSURED] mark=92274785 delta-time=0

Is there a [NEW] event after this [DESTROY] in FIN_WAIT state to pick
the terminating connection from the middle?

b6f27d322a0a ("netfilter: nf_flow_table: tear down TCP flows if RST or
FIN was seen") to let conntrack close the connection gracefully,
otherwise flowtable becomes stateless and already finished connections
remain in place which affects features such as connlimit.

The intention in that patch is to remove the entry from the flowtable
then hand over back the conntrack to the connection tracking system
following slow path.

Re: Flowtable race condition error

[Florian Westphal]

Sven Auhagen <sven.auhagen@voleatech.de> wrote:
> I think you have a valid point with the not calling flow_offload_teardown but maybe
> we need to do something else instead like lower the flowtable entry timeout to trigger a
> faster gc for both udp and tcp.

conntrack core should receive the fin/rst packet, and should switch the
state entry accordingly, i.e. away from established.

I suspect that gc_worker() "repairs" the timeout to a hige value again
because the OFFLOAD flag is left in place.

However, this change:

> >         if (nf_flow_has_expired(flow) ||
> >             nf_ct_is_dying(flow->ct) ||
> > +           !nf_conntrack_tcp_established(ct) ||
> >             nf_flow_custom_gc(flow_table, flow))
> >                 flow_offload_teardown(flow);

(well, flow->ct, I did not test this at all).

should still make flowtable gc remove the entry.

I think if possible we should get rid of ct/flowtable
entanglements where possible rather than adding more.

F.e. early drop should probably not test or care about
offload flag anymore.

Re: Flowtable race condition error

[Sven Auhagen]

On Thu, Mar 14, 2024 at 12:17:51PM +0100, Pablo Neira Ayuso wrote:
Hi Pablo,

> Hi Sven,
> 
> On Tue, Mar 12, 2024 at 05:29:45PM +0100, Sven Auhagen wrote:
> > Hi,
> > 
> > I have a race condition problem in the flowtable and could
> > use some hint where to start debugging.
> > 
> > Every now and then a TCP FIN is closing the flowtable with a call
> > to flow_offload_teardown.
> > 
> > Right after another packet from the reply direction is readding
> > the connection to the flowtable just before the FIN is actually
> > transitioning the state from ESTABLISHED to FIN WAIT.
> > Now the FIN WAIT connection is OFFLOADED.
> 
> Are you restricting your ruleset to only offload new connections?
> 

It does not work to only use ct state new as we need to see both
directions for the offload and the return packet is in ct state
established at that point.

> Or is it conntrack creating a fresh connection that being offloaded
> for this terminating TCP traffic what you are observing?
> 

I can see a race condition where there is a TCP FIN packet
so flow_offload_teardown is called but before the FIN packet
is going through the slow path and sets the TCP connection to FIN_WAIT
another packet is readding the state to the flowtable.
So I end up with FIN_WAIT and status OFFLOADED.
This only happens every few hunderd connections.

> > This by itself should work itself out at gc time but
> > the state is now deleted right away.
> >
> > Any idea why the state is deleted right away?
> 
> It might be conntrack which is killing the connection, it would be
> good to have a nf_ct_kill_reason(). Last time we talk, NAT can also
> kill the conntrack in masquerade scenarios.
> 

I found this out.
The state is deleted in the end because the flow_offload_fixup_ct
function is pulling the FIN_WAIT timeout and deducts the offload_timeout
from it. This is 0 or very close to 0 and therefore ct gc is deleting the state
more or less right away after the flow_offload_teardown is called
(for the second time).

> > Here is the output of the state messages:
> > 
> >     [NEW] tcp      6 120 SYN_SENT src=192.168.97.23 dst=192.168.107.52 sport=63482 dport=443 [UNREPLIED] src=192.168.107.52 dst=192.168.97.23 sport=443 dport=63482 mark=92274785
> >  [UPDATE] tcp      6 60 SYN_RECV src=192.168.97.23 dst=192.168.107.52 sport=63482 dport=443 src=192.168.107.52 dst=192.168.97.23 sport=443 dport=63482 mark=92274785
> >  [UPDATE] tcp      6 432000 ESTABLISHED src=192.168.97.23 dst=192.168.107.52 sport=63482 dport=443 src=192.168.107.52 dst=192.168.97.23 sport=443 dport=63482 [OFFLOAD] mark=92274785
> >  [UPDATE] tcp      6 86400 FIN_WAIT src=192.168.97.23 dst=192.168.107.52 sport=63482 dport=443 src=192.168.107.52 dst=192.168.97.23 sport=443 dport=63482 [OFFLOAD] mark=92274785
> > [DESTROY] tcp      6 FIN_WAIT src=192.168.97.23 dst=192.168.107.52 sport=63482 dport=443 packets=10 bytes=1415 src=192.168.107.52 dst=192.168.97.23 sport=443 dport=63482 packets=11 bytes=6343 [ASSURED] mark=92274785 delta-time=0
> 
> Is there a [NEW] event after this [DESTROY] in FIN_WAIT state to pick
> the terminating connection from the middle?
> 
> b6f27d322a0a ("netfilter: nf_flow_table: tear down TCP flows if RST or
> FIN was seen") to let conntrack close the connection gracefully,
> otherwise flowtable becomes stateless and already finished connections
> remain in place which affects features such as connlimit.
> 
> The intention in that patch is to remove the entry from the flowtable
> then hand over back the conntrack to the connection tracking system
> following slow path.

So if the machanism is intended as it is then we need to make sure that the
timeout is not so close to 0 and we life with the possible race condition?

Re: Flowtable race condition error

[Pablo Neira Ayuso]

[-- Attachment #1: Type: text/plain, Size: 4611 bytes --]

On Thu, Mar 14, 2024 at 12:30:30PM +0100, Sven Auhagen wrote:
> On Thu, Mar 14, 2024 at 12:17:51PM +0100, Pablo Neira Ayuso wrote:
> Hi Pablo,
> 
> > Hi Sven,
> > 
> > On Tue, Mar 12, 2024 at 05:29:45PM +0100, Sven Auhagen wrote:
> > > Hi,
> > > 
> > > I have a race condition problem in the flowtable and could
> > > use some hint where to start debugging.
> > > 
> > > Every now and then a TCP FIN is closing the flowtable with a call
> > > to flow_offload_teardown.
> > > 
> > > Right after another packet from the reply direction is readding
> > > the connection to the flowtable just before the FIN is actually
> > > transitioning the state from ESTABLISHED to FIN WAIT.
> > > Now the FIN WAIT connection is OFFLOADED.
> > 
> > Are you restricting your ruleset to only offload new connections?
> > 
> 
> It does not work to only use ct state new as we need to see both
> directions for the offload and the return packet is in ct state
> established at that point.

Indeed, we need to see two packets at least, which will be the next
one coming in the opposite that is, the conntrack needs to be
confirmed.

> > Or is it conntrack creating a fresh connection that being offloaded
> > for this terminating TCP traffic what you are observing?
> 
> I can see a race condition where there is a TCP FIN packet
> so flow_offload_teardown is called but before the FIN packet
> is going through the slow path and sets the TCP connection to FIN_WAIT
> another packet is readding the state to the flowtable.
>
> So I end up with FIN_WAIT and status OFFLOADED.
> This only happens every few hunderd connections.
>
> > > This by itself should work itself out at gc time but
> > > the state is now deleted right away.
> > >
> > > Any idea why the state is deleted right away?
> > 
> > It might be conntrack which is killing the connection, it would be
> > good to have a nf_ct_kill_reason(). Last time we talk, NAT can also
> > kill the conntrack in masquerade scenarios.
> > 
> 
> I found this out.
> The state is deleted in the end because the flow_offload_fixup_ct
> function is pulling the FIN_WAIT timeout and deducts the offload_timeout
> from it. This is 0 or very close to 0 and therefore ct gc is deleting the state
> more or less right away after the flow_offload_teardown is called
> (for the second time).

This used to be set to:

        timeout = tn->timeouts[TCP_CONNTRACK_ESTABLISHED];

but after:

commit e5eaac2beb54f0a16ff851125082d9faeb475572
Author: Pablo Neira Ayuso <pablo@netfilter.org>
Date:   Tue May 17 10:44:14 2022 +0200

    netfilter: flowtable: fix TCP flow teardown

it uses the current state.

> > > Here is the output of the state messages:
> > > 
> > >     [NEW] tcp      6 120 SYN_SENT src=192.168.97.23 dst=192.168.107.52 sport=63482 dport=443 [UNREPLIED] src=192.168.107.52 dst=192.168.97.23 sport=443 dport=63482 mark=92274785
> > >  [UPDATE] tcp      6 60 SYN_RECV src=192.168.97.23 dst=192.168.107.52 sport=63482 dport=443 src=192.168.107.52 dst=192.168.97.23 sport=443 dport=63482 mark=92274785
> > >  [UPDATE] tcp      6 432000 ESTABLISHED src=192.168.97.23 dst=192.168.107.52 sport=63482 dport=443 src=192.168.107.52 dst=192.168.97.23 sport=443 dport=63482 [OFFLOAD] mark=92274785
> > >  [UPDATE] tcp      6 86400 FIN_WAIT src=192.168.97.23 dst=192.168.107.52 sport=63482 dport=443 src=192.168.107.52 dst=192.168.97.23 sport=443 dport=63482 [OFFLOAD] mark=92274785
> > > [DESTROY] tcp      6 FIN_WAIT src=192.168.97.23 dst=192.168.107.52 sport=63482 dport=443 packets=10 bytes=1415 src=192.168.107.52 dst=192.168.97.23 sport=443 dport=63482 packets=11 bytes=6343 [ASSURED] mark=92274785 delta-time=0
> > 
> > Is there a [NEW] event after this [DESTROY] in FIN_WAIT state to pick
> > the terminating connection from the middle?
> > 
> > b6f27d322a0a ("netfilter: nf_flow_table: tear down TCP flows if RST or
> > FIN was seen") to let conntrack close the connection gracefully,
> > otherwise flowtable becomes stateless and already finished connections
> > remain in place which affects features such as connlimit.
> > 
> > The intention in that patch is to remove the entry from the flowtable
> > then hand over back the conntrack to the connection tracking system
> > following slow path.
> 
> So if the machanism is intended as it is then we need to make sure that the
> timeout is not so close to 0 and we life with the possible race condition?

Then, this needs a state fix up based on the packet from the flowtable
path to infer the current state.

This patch is not complete, it just restores ct timeout based on
the established state, which has also its own problems.

[-- Attachment #2: x.patch --]
[-- Type: text/x-diff, Size: 929 bytes --]

diff --git a/net/netfilter/nf_flow_table_core.c b/net/netfilter/nf_flow_table_core.c
index a0571339239c..1f6d168e3ce6 100644
--- a/net/netfilter/nf_flow_table_core.c
+++ b/net/netfilter/nf_flow_table_core.c
@@ -182,7 +182,7 @@ static void flow_offload_fixup_ct(struct nf_conn *ct)
 
 		flow_offload_fixup_tcp(&ct->proto.tcp);
 
-		timeout = tn->timeouts[ct->proto.tcp.state];
+		timeout = tn->timeouts[TCP_CONNTRACK_ESTABLISHED];
 		timeout -= tn->offload_timeout;
 	} else if (l4num == IPPROTO_UDP) {
 		struct nf_udp_net *tn = nf_udp_pernet(net);
@@ -346,9 +346,10 @@ static void flow_offload_del(struct nf_flowtable *flow_table,
 
 void flow_offload_teardown(struct flow_offload *flow)
 {
+	flow_offload_fixup_ct(flow->ct);
+	smp_mb__before_atomic();
 	clear_bit(IPS_OFFLOAD_BIT, &flow->ct->status);
 	set_bit(NF_FLOW_TEARDOWN, &flow->flags);
-	flow_offload_fixup_ct(flow->ct);
 }
 EXPORT_SYMBOL_GPL(flow_offload_teardown);
 

Re: Flowtable race condition error

[Sven Auhagen]

On Thu, Mar 14, 2024 at 01:38:54PM +0100, Pablo Neira Ayuso wrote:
> On Thu, Mar 14, 2024 at 12:30:30PM +0100, Sven Auhagen wrote:
> > On Thu, Mar 14, 2024 at 12:17:51PM +0100, Pablo Neira Ayuso wrote:
> > Hi Pablo,
> > 
> > > Hi Sven,
> > > 
> > > On Tue, Mar 12, 2024 at 05:29:45PM +0100, Sven Auhagen wrote:
> > > > Hi,
> > > > 
> > > > I have a race condition problem in the flowtable and could
> > > > use some hint where to start debugging.
> > > > 
> > > > Every now and then a TCP FIN is closing the flowtable with a call
> > > > to flow_offload_teardown.
> > > > 
> > > > Right after another packet from the reply direction is readding
> > > > the connection to the flowtable just before the FIN is actually
> > > > transitioning the state from ESTABLISHED to FIN WAIT.
> > > > Now the FIN WAIT connection is OFFLOADED.
> > > 
> > > Are you restricting your ruleset to only offload new connections?
> > > 
> > 
> > It does not work to only use ct state new as we need to see both
> > directions for the offload and the return packet is in ct state
> > established at that point.
> 
> Indeed, we need to see two packets at least, which will be the next
> one coming in the opposite that is, the conntrack needs to be
> confirmed.
> 
> > > Or is it conntrack creating a fresh connection that being offloaded
> > > for this terminating TCP traffic what you are observing?
> > 
> > I can see a race condition where there is a TCP FIN packet
> > so flow_offload_teardown is called but before the FIN packet
> > is going through the slow path and sets the TCP connection to FIN_WAIT
> > another packet is readding the state to the flowtable.
> >
> > So I end up with FIN_WAIT and status OFFLOADED.
> > This only happens every few hunderd connections.
> >
> > > > This by itself should work itself out at gc time but
> > > > the state is now deleted right away.
> > > >
> > > > Any idea why the state is deleted right away?
> > > 
> > > It might be conntrack which is killing the connection, it would be
> > > good to have a nf_ct_kill_reason(). Last time we talk, NAT can also
> > > kill the conntrack in masquerade scenarios.
> > > 
> > 
> > I found this out.
> > The state is deleted in the end because the flow_offload_fixup_ct
> > function is pulling the FIN_WAIT timeout and deducts the offload_timeout
> > from it. This is 0 or very close to 0 and therefore ct gc is deleting the state
> > more or less right away after the flow_offload_teardown is called
> > (for the second time).
> 
> This used to be set to:
> 
>         timeout = tn->timeouts[TCP_CONNTRACK_ESTABLISHED];
> 
> but after:
> 
> commit e5eaac2beb54f0a16ff851125082d9faeb475572
> Author: Pablo Neira Ayuso <pablo@netfilter.org>
> Date:   Tue May 17 10:44:14 2022 +0200
> 
>     netfilter: flowtable: fix TCP flow teardown
> 
> it uses the current state.

Yes since the TCP state might not be established anymore at that time.
Your patch will work but also give my TCP_FIN a very large timeout.

I have successfully tested this version today:

-	if (timeout < 0)
-		timeout = 0;
+	// Have at least some time left on the state
+	if (timeout < NF_FLOW_TIMEOUT)
+		timeout = NF_FLOW_TIMEOUT;

This makes sure that the timeout is not so big like ESTABLISHED but still enough
so the state does not time out right away.

> 
> > > > Here is the output of the state messages:
> > > > 
> > > >     [NEW] tcp      6 120 SYN_SENT src=192.168.97.23 dst=192.168.107.52 sport=63482 dport=443 [UNREPLIED] src=192.168.107.52 dst=192.168.97.23 sport=443 dport=63482 mark=92274785
> > > >  [UPDATE] tcp      6 60 SYN_RECV src=192.168.97.23 dst=192.168.107.52 sport=63482 dport=443 src=192.168.107.52 dst=192.168.97.23 sport=443 dport=63482 mark=92274785
> > > >  [UPDATE] tcp      6 432000 ESTABLISHED src=192.168.97.23 dst=192.168.107.52 sport=63482 dport=443 src=192.168.107.52 dst=192.168.97.23 sport=443 dport=63482 [OFFLOAD] mark=92274785
> > > >  [UPDATE] tcp      6 86400 FIN_WAIT src=192.168.97.23 dst=192.168.107.52 sport=63482 dport=443 src=192.168.107.52 dst=192.168.97.23 sport=443 dport=63482 [OFFLOAD] mark=92274785
> > > > [DESTROY] tcp      6 FIN_WAIT src=192.168.97.23 dst=192.168.107.52 sport=63482 dport=443 packets=10 bytes=1415 src=192.168.107.52 dst=192.168.97.23 sport=443 dport=63482 packets=11 bytes=6343 [ASSURED] mark=92274785 delta-time=0
> > > 
> > > Is there a [NEW] event after this [DESTROY] in FIN_WAIT state to pick
> > > the terminating connection from the middle?
> > > 
> > > b6f27d322a0a ("netfilter: nf_flow_table: tear down TCP flows if RST or
> > > FIN was seen") to let conntrack close the connection gracefully,
> > > otherwise flowtable becomes stateless and already finished connections
> > > remain in place which affects features such as connlimit.
> > > 
> > > The intention in that patch is to remove the entry from the flowtable
> > > then hand over back the conntrack to the connection tracking system
> > > following slow path.
> > 
> > So if the machanism is intended as it is then we need to make sure that the
> > timeout is not so close to 0 and we life with the possible race condition?
> 
> Then, this needs a state fix up based on the packet from the flowtable
> path to infer the current state.
> 
> This patch is not complete, it just restores ct timeout based on
> the established state, which has also its own problems.

Re: Flowtable race condition error

[Pablo Neira Ayuso]

On Thu, Mar 14, 2024 at 01:43:52PM +0100, Sven Auhagen wrote:
> On Thu, Mar 14, 2024 at 01:38:54PM +0100, Pablo Neira Ayuso wrote:
> > On Thu, Mar 14, 2024 at 12:30:30PM +0100, Sven Auhagen wrote:
[...]
> > > I found this out.
> > > The state is deleted in the end because the flow_offload_fixup_ct
> > > function is pulling the FIN_WAIT timeout and deducts the offload_timeout
> > > from it. This is 0 or very close to 0 and therefore ct gc is deleting the state
> > > more or less right away after the flow_offload_teardown is called
> > > (for the second time).
> > 
> > This used to be set to:
> > 
> >         timeout = tn->timeouts[TCP_CONNTRACK_ESTABLISHED];
> > 
> > but after:
> > 
> > commit e5eaac2beb54f0a16ff851125082d9faeb475572
> > Author: Pablo Neira Ayuso <pablo@netfilter.org>
> > Date:   Tue May 17 10:44:14 2022 +0200
> > 
> >     netfilter: flowtable: fix TCP flow teardown
> > 
> > it uses the current state.
> 
> Yes since the TCP state might not be established anymore at that time.
> Your patch will work but also give my TCP_FIN a very large timeout.

Is that still possible? My patch also fixes up conntrack _before_
the offload flag is cleared, so the packet in the reply direction
either sees the already fixed up conntrack or it follows flowtable
datapath.

> I have successfully tested this version today:
> 
> -	if (timeout < 0)
> -		timeout = 0;
> +	// Have at least some time left on the state
> +	if (timeout < NF_FLOW_TIMEOUT)
> +		timeout = NF_FLOW_TIMEOUT;
>
> This makes sure that the timeout is not so big like ESTABLISHED but still enough
> so the state does not time out right away.

This also seems sensible to me. Currently it is using the last conntrack
state that we have observed when conntrack handed over this flow to the
flowtable, which is inaccurate in any case, and which could still be low
depending on user-defined tcp conntrack timeouts (in case user decided
to tweaks them).

Re: Flowtable race condition error

[Sven Auhagen]

On Thu, Mar 14, 2024 at 01:56:12PM +0100, Pablo Neira Ayuso wrote:
> On Thu, Mar 14, 2024 at 01:43:52PM +0100, Sven Auhagen wrote:
> > On Thu, Mar 14, 2024 at 01:38:54PM +0100, Pablo Neira Ayuso wrote:
> > > On Thu, Mar 14, 2024 at 12:30:30PM +0100, Sven Auhagen wrote:
> [...]
> > > > I found this out.
> > > > The state is deleted in the end because the flow_offload_fixup_ct
> > > > function is pulling the FIN_WAIT timeout and deducts the offload_timeout
> > > > from it. This is 0 or very close to 0 and therefore ct gc is deleting the state
> > > > more or less right away after the flow_offload_teardown is called
> > > > (for the second time).
> > > 
> > > This used to be set to:
> > > 
> > >         timeout = tn->timeouts[TCP_CONNTRACK_ESTABLISHED];
> > > 
> > > but after:
> > > 
> > > commit e5eaac2beb54f0a16ff851125082d9faeb475572
> > > Author: Pablo Neira Ayuso <pablo@netfilter.org>
> > > Date:   Tue May 17 10:44:14 2022 +0200
> > > 
> > >     netfilter: flowtable: fix TCP flow teardown
> > > 
> > > it uses the current state.
> > 
> > Yes since the TCP state might not be established anymore at that time.
> > Your patch will work but also give my TCP_FIN a very large timeout.
> 
> Is that still possible? My patch also fixes up conntrack _before_
> the offload flag is cleared, so the packet in the reply direction
> either sees the already fixed up conntrack or it follows flowtable
> datapath.

Yes, the call to flow_offload_teardown happens in the ingress stage.
When a TCP FIN is going through there and the offload is removed that is fine.
But between the packet now moving from ingress to the normal slow path netfilter
code a reply packet might come in the tcp state is still established
because the FIN is not processed yet and therefore it is offloading the state again.
The FIN is now processed after after re-offload and the state move on to FIN_WAIT.

I do not think there is a way to resolve this problem.
We would need to transition the TCP state right in the flowtable flow_offload_teardown
function to avoid this.

> 
> > I have successfully tested this version today:
> > 
> > -	if (timeout < 0)
> > -		timeout = 0;
> > +	// Have at least some time left on the state
> > +	if (timeout < NF_FLOW_TIMEOUT)
> > +		timeout = NF_FLOW_TIMEOUT;
> >
> > This makes sure that the timeout is not so big like ESTABLISHED but still enough
> > so the state does not time out right away.
> 
> This also seems sensible to me. Currently it is using the last conntrack
> state that we have observed when conntrack handed over this flow to the
> flowtable, which is inaccurate in any case, and which could still be low
> depending on user-defined tcp conntrack timeouts (in case user decided
> to tweaks them).

Re: Flowtable race condition error

[Sven Auhagen]

On Thu, Mar 14, 2024 at 01:56:12PM +0100, Pablo Neira Ayuso wrote:
> On Thu, Mar 14, 2024 at 01:43:52PM +0100, Sven Auhagen wrote:
> > On Thu, Mar 14, 2024 at 01:38:54PM +0100, Pablo Neira Ayuso wrote:
> > > On Thu, Mar 14, 2024 at 12:30:30PM +0100, Sven Auhagen wrote:
> [...]
> > > > I found this out.
> > > > The state is deleted in the end because the flow_offload_fixup_ct
> > > > function is pulling the FIN_WAIT timeout and deducts the offload_timeout
> > > > from it. This is 0 or very close to 0 and therefore ct gc is deleting the state
> > > > more or less right away after the flow_offload_teardown is called
> > > > (for the second time).
> > > 
> > > This used to be set to:
> > > 
> > >         timeout = tn->timeouts[TCP_CONNTRACK_ESTABLISHED];
> > > 
> > > but after:
> > > 
> > > commit e5eaac2beb54f0a16ff851125082d9faeb475572
> > > Author: Pablo Neira Ayuso <pablo@netfilter.org>
> > > Date:   Tue May 17 10:44:14 2022 +0200
> > > 
> > >     netfilter: flowtable: fix TCP flow teardown
> > > 
> > > it uses the current state.
> > 
> > Yes since the TCP state might not be established anymore at that time.
> > Your patch will work but also give my TCP_FIN a very large timeout.
> 
> Is that still possible? My patch also fixes up conntrack _before_
> the offload flag is cleared, so the packet in the reply direction
> either sees the already fixed up conntrack or it follows flowtable
> datapath.
> 
> > I have successfully tested this version today:
> > 
> > -	if (timeout < 0)
> > -		timeout = 0;
> > +	// Have at least some time left on the state
> > +	if (timeout < NF_FLOW_TIMEOUT)
> > +		timeout = NF_FLOW_TIMEOUT;
> >
> > This makes sure that the timeout is not so big like ESTABLISHED but still enough
> > so the state does not time out right away.
> 
> This also seems sensible to me. Currently it is using the last conntrack
> state that we have observed when conntrack handed over this flow to the
> flowtable, which is inaccurate in any case, and which could still be low
> depending on user-defined tcp conntrack timeouts (in case user decided
> to tweaks them).

If I take my patch and the part of your patch that moves up flow_offload_fixup_ct
to the top of the function it works now.
As expected, it still happens that a flow is ending up in FIN_WAIT OFFLOADED but
the state is no longer deleted right away and is eventually removed from the flowoffload
via gc and then goes on until the end.

    [NEW] tcp      6 120 SYN_SENT src=192.168.7.100 dst=17.248.209.132 sport=54774 dport=443 [UNREPLIED] src=17.248.209.132 dst=87.138.198.79 sport=443 dport=30121 mark=25165825
 [UPDATE] tcp      6 60 SYN_RECV src=192.168.7.100 dst=17.248.209.132 sport=54774 dport=443 src=17.248.209.132 dst=87.138.198.79 sport=443 dport=30121 mark=25165825
 [UPDATE] tcp      6 86400 ESTABLISHED src=192.168.7.100 dst=17.248.209.132 sport=54774 dport=443 src=17.248.209.132 dst=87.138.198.79 sport=443 dport=30121 [OFFLOAD] mark=25165825
[DESTROY] tcp      6 TIME_WAIT src=192.168.4.81 dst=192.168.6.8 sport=54774 dport=8080 packets=6 bytes=1388 src=192.168.6.8 dst=192.168.4.81 sport=8080 dport=54774 packets=4 bytes=398 [ASSURED] mark=16777216 delta-time=120
 [UPDATE] tcp      6 120 FIN_WAIT src=192.168.7.100 dst=17.248.209.132 sport=54774 dport=443 src=17.248.209.132 dst=87.138.198.79 sport=443 dport=30121 [OFFLOAD] mark=25165825
 [UPDATE] tcp      6 30 LAST_ACK src=192.168.7.100 dst=17.248.209.132 sport=54774 dport=443 src=17.248.209.132 dst=87.138.198.79 sport=443 dport=30121 [OFFLOAD] mark=25165825
 [UPDATE] tcp      6 10 CLOSE src=192.168.7.100 dst=17.248.209.132 sport=54774 dport=443 src=17.248.209.132 dst=87.138.198.79 sport=443 dport=30121 [ASSURED] mark=25165825
[DESTROY] tcp      6 CLOSE src=192.168.7.100 dst=17.248.209.132 sport=54774 dport=443 packets=31 bytes=5542 src=17.248.209.132 dst=87.138.198.79 sport=443 dport=30121 packets=35 bytes=8168 [ASSURED] mark=25165825 delta-time=50