netdev.vger.kernel.org archive mirror
 help / color / mirror / Atom feed
* new splat
@ 2025-03-30 23:28 Alexei Starovoitov
  2025-03-31  8:07 ` Paolo Abeni
  0 siblings, 1 reply; 6+ messages in thread
From: Alexei Starovoitov @ 2025-03-30 23:28 UTC (permalink / raw)
  To: bpf, Network Development, Jakub Kicinski

After bpf fast forward we see this new failure:

[  138.359852] BUG: using __this_cpu_read() in preemptible [00000000]
code: test_progs/9368
[  138.362686] caller is lwtunnel_xmit+0x1c/0x2e0
[  138.364363] CPU: 9 UID: 0 PID: 9368 Comm: test_progs Tainted: G
      O        6.14.0-10767-g8be3a12f9f26 #1092 PREEMPT
[  138.364366] Tainted: [O]=OOT_MODULE
[  138.364366] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996),
BIOS rel-1.14.0-0-g155821a1990b-prebuilt.qemu.org 04/01/2014
[  138.364368] Call Trace:
[  138.364370]  <TASK>
[  138.364375]  dump_stack_lvl+0x80/0x90
[  138.364381]  check_preemption_disabled+0xc6/0xe0
[  138.364385]  lwtunnel_xmit+0x1c/0x2e0
[  138.364387]  ip_finish_output2+0x2f9/0x850
[  138.364391]  ? __ip_finish_output+0xa0/0x320
[  138.364394]  ip_send_skb+0x3f/0x90
[  138.364397]  udp_send_skb+0x1a6/0x3d0
[  138.364402]  udp_sendmsg+0x87b/0x1000
[  138.364404]  ? ip_frag_init+0x60/0x60
[  138.364406]  ? reacquire_held_locks+0xcd/0x1f0
[  138.364414]  ? copy_process+0x2ae0/0x2fa0
[  138.364418]  ? inet_autobind+0x41/0x60
[  138.364420]  ? __local_bh_enable_ip+0x79/0xe0
[  138.364422]  ? inet_autobind+0x41/0x60
[  138.364424]  ? inet_send_prepare+0xe7/0x1e0
[  138.364428]  __sock_sendmsg+0x38/0x70
[  138.364432]  ____sys_sendmsg+0x1c9/0x200
[  138.364437]  ___sys_sendmsg+0x73/0xa0
[  138.364444]  ? __fget_files+0xb9/0x180
[  138.364447]  ? lock_release+0x131/0x280
[  138.364450]  ? __fget_files+0xc3/0x180
[  138.364453]  __sys_sendmsg+0x5a/0xa0

and

[  124.853349] BUG: using __this_cpu_read() in preemptible [00000000]
code: ping/9212
[  124.856062] caller is lwtunnel_xmit+0x1c/0x2e0
[  124.857717] CPU: 5 UID: 0 PID: 9212 Comm: ping Tainted: G
O        6.14.0-10767-g8be3a12f9f26 #1092 PREEMPT
[  124.857720] Tainted: [O]=OOT_MODULE
[  124.857721] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996),
BIOS rel-1.14.0-0-g155821a1990b-prebuilt.qemu.org 04/01/2014
[  124.857722] Call Trace:
[  124.857724]  <TASK>
[  124.857726]  dump_stack_lvl+0x80/0x90
[  124.857730]  check_preemption_disabled+0xc6/0xe0
[  124.857734]  lwtunnel_xmit+0x1c/0x2e0
[  124.857736]  ip_finish_output2+0x2f9/0x850
[  124.857740]  ? __ip_finish_output+0xa0/0x320
[  124.857743]  ip_push_pending_frames+0x63/0xb0
[  124.857746]  raw_sendmsg+0x7d8/0x1530

I couldn't find a responsible commit.
Not sure what changed.

^ permalink raw reply	[flat|nested] 6+ messages in thread

* Re: new splat
  2025-03-30 23:28 new splat Alexei Starovoitov
@ 2025-03-31  8:07 ` Paolo Abeni
  2025-04-01  8:44   ` Justin Iurman
  0 siblings, 1 reply; 6+ messages in thread
From: Paolo Abeni @ 2025-03-31  8:07 UTC (permalink / raw)
  To: Alexei Starovoitov, bpf, Network Development, Jakub Kicinski,
	Justin Iurman

Adding Justin.

On 3/31/25 1:28 AM, Alexei Starovoitov wrote:
> After bpf fast forward we see this new failure:
> 
> [  138.359852] BUG: using __this_cpu_read() in preemptible [00000000]
> code: test_progs/9368
> [  138.362686] caller is lwtunnel_xmit+0x1c/0x2e0
> [  138.364363] CPU: 9 UID: 0 PID: 9368 Comm: test_progs Tainted: G
>       O        6.14.0-10767-g8be3a12f9f26 #1092 PREEMPT
> [  138.364366] Tainted: [O]=OOT_MODULE
> [  138.364366] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996),
> BIOS rel-1.14.0-0-g155821a1990b-prebuilt.qemu.org 04/01/2014
> [  138.364368] Call Trace:
> [  138.364370]  <TASK>
> [  138.364375]  dump_stack_lvl+0x80/0x90
> [  138.364381]  check_preemption_disabled+0xc6/0xe0
> [  138.364385]  lwtunnel_xmit+0x1c/0x2e0
> [  138.364387]  ip_finish_output2+0x2f9/0x850
> [  138.364391]  ? __ip_finish_output+0xa0/0x320
> [  138.364394]  ip_send_skb+0x3f/0x90
> [  138.364397]  udp_send_skb+0x1a6/0x3d0
> [  138.364402]  udp_sendmsg+0x87b/0x1000
> [  138.364404]  ? ip_frag_init+0x60/0x60
> [  138.364406]  ? reacquire_held_locks+0xcd/0x1f0
> [  138.364414]  ? copy_process+0x2ae0/0x2fa0
> [  138.364418]  ? inet_autobind+0x41/0x60
> [  138.364420]  ? __local_bh_enable_ip+0x79/0xe0
> [  138.364422]  ? inet_autobind+0x41/0x60
> [  138.364424]  ? inet_send_prepare+0xe7/0x1e0
> [  138.364428]  __sock_sendmsg+0x38/0x70
> [  138.364432]  ____sys_sendmsg+0x1c9/0x200
> [  138.364437]  ___sys_sendmsg+0x73/0xa0
> [  138.364444]  ? __fget_files+0xb9/0x180
> [  138.364447]  ? lock_release+0x131/0x280
> [  138.364450]  ? __fget_files+0xc3/0x180
> [  138.364453]  __sys_sendmsg+0x5a/0xa0

Possibly a decoded stack trace could help.

I think a possible suspect is:

commit 986ffb3a57c5650fb8bf6d59a8f0f07046abfeb6
Author: Justin Iurman <justin.iurman@uliege.be>
Date:   Fri Mar 14 13:00:46 2025 +0100

    net: lwtunnel: fix recursion loops

with dev_xmit_recursion() in lwtunnel_xmit() being called in preemptible
scope.

@Justin, could you please have a look?

Thanks,

Paolo


^ permalink raw reply	[flat|nested] 6+ messages in thread

* Re: new splat
  2025-03-31  8:07 ` Paolo Abeni
@ 2025-04-01  8:44   ` Justin Iurman
  2025-04-01 16:45     ` Stanislav Fomichev
  0 siblings, 1 reply; 6+ messages in thread
From: Justin Iurman @ 2025-04-01  8:44 UTC (permalink / raw)
  To: Paolo Abeni, Alexei Starovoitov, bpf, Network Development,
	Jakub Kicinski

On 3/31/25 10:07, Paolo Abeni wrote:
> Adding Justin.
> 
> On 3/31/25 1:28 AM, Alexei Starovoitov wrote:
>> After bpf fast forward we see this new failure:
>>
>> [  138.359852] BUG: using __this_cpu_read() in preemptible [00000000]
>> code: test_progs/9368
>> [  138.362686] caller is lwtunnel_xmit+0x1c/0x2e0
>> [  138.364363] CPU: 9 UID: 0 PID: 9368 Comm: test_progs Tainted: G
>>        O        6.14.0-10767-g8be3a12f9f26 #1092 PREEMPT
>> [  138.364366] Tainted: [O]=OOT_MODULE
>> [  138.364366] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996),
>> BIOS rel-1.14.0-0-g155821a1990b-prebuilt.qemu.org 04/01/2014
>> [  138.364368] Call Trace:
>> [  138.364370]  <TASK>
>> [  138.364375]  dump_stack_lvl+0x80/0x90
>> [  138.364381]  check_preemption_disabled+0xc6/0xe0
>> [  138.364385]  lwtunnel_xmit+0x1c/0x2e0
>> [  138.364387]  ip_finish_output2+0x2f9/0x850
>> [  138.364391]  ? __ip_finish_output+0xa0/0x320
>> [  138.364394]  ip_send_skb+0x3f/0x90
>> [  138.364397]  udp_send_skb+0x1a6/0x3d0
>> [  138.364402]  udp_sendmsg+0x87b/0x1000
>> [  138.364404]  ? ip_frag_init+0x60/0x60
>> [  138.364406]  ? reacquire_held_locks+0xcd/0x1f0
>> [  138.364414]  ? copy_process+0x2ae0/0x2fa0
>> [  138.364418]  ? inet_autobind+0x41/0x60
>> [  138.364420]  ? __local_bh_enable_ip+0x79/0xe0
>> [  138.364422]  ? inet_autobind+0x41/0x60
>> [  138.364424]  ? inet_send_prepare+0xe7/0x1e0
>> [  138.364428]  __sock_sendmsg+0x38/0x70
>> [  138.364432]  ____sys_sendmsg+0x1c9/0x200
>> [  138.364437]  ___sys_sendmsg+0x73/0xa0
>> [  138.364444]  ? __fget_files+0xb9/0x180
>> [  138.364447]  ? lock_release+0x131/0x280
>> [  138.364450]  ? __fget_files+0xc3/0x180
>> [  138.364453]  __sys_sendmsg+0x5a/0xa0
> 
> Possibly a decoded stack trace could help.
> 
> I think a possible suspect is:
> 
> commit 986ffb3a57c5650fb8bf6d59a8f0f07046abfeb6
> Author: Justin Iurman <justin.iurman@uliege.be>
> Date:   Fri Mar 14 13:00:46 2025 +0100
> 
>      net: lwtunnel: fix recursion loops
> 
> with dev_xmit_recursion() in lwtunnel_xmit() being called in preemptible
> scope.

Correct, I came to the same conclusion based on that trace. However, I 
can't reproduce it with a PREEMPT kernel. It goes through without 
problem and the output is (as expected), i.e., "lwtunnel_xmit(): 
recursion limit reached on datapath".

> @Justin, could you please have a look?

I guess that using preempt_{disable|enable}() would not be enough here, 
so we may s/rcu_read_{lock|unlock}()/rcu_read_{lock|unlock}_bh()/g and 
move the call to rcu_read_lock_bh() before dev_xmit_recursion(). Thoughts?

> Thanks,
> 
> Paolo
> 

^ permalink raw reply	[flat|nested] 6+ messages in thread

* Re: new splat
  2025-04-01  8:44   ` Justin Iurman
@ 2025-04-01 16:45     ` Stanislav Fomichev
  2025-04-01 18:16       ` Justin Iurman
  2025-04-02 16:44       ` Jakub Kicinski
  0 siblings, 2 replies; 6+ messages in thread
From: Stanislav Fomichev @ 2025-04-01 16:45 UTC (permalink / raw)
  To: Justin Iurman
  Cc: Paolo Abeni, Alexei Starovoitov, bpf, Network Development,
	Jakub Kicinski

On 04/01, Justin Iurman wrote:
> On 3/31/25 10:07, Paolo Abeni wrote:
> > Adding Justin.
> > 
> > On 3/31/25 1:28 AM, Alexei Starovoitov wrote:
> > > After bpf fast forward we see this new failure:
> > > 
> > > [  138.359852] BUG: using __this_cpu_read() in preemptible [00000000]
> > > code: test_progs/9368
> > > [  138.362686] caller is lwtunnel_xmit+0x1c/0x2e0
> > > [  138.364363] CPU: 9 UID: 0 PID: 9368 Comm: test_progs Tainted: G
> > >        O        6.14.0-10767-g8be3a12f9f26 #1092 PREEMPT
> > > [  138.364366] Tainted: [O]=OOT_MODULE
> > > [  138.364366] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996),
> > > BIOS rel-1.14.0-0-g155821a1990b-prebuilt.qemu.org 04/01/2014
> > > [  138.364368] Call Trace:
> > > [  138.364370]  <TASK>
> > > [  138.364375]  dump_stack_lvl+0x80/0x90
> > > [  138.364381]  check_preemption_disabled+0xc6/0xe0
> > > [  138.364385]  lwtunnel_xmit+0x1c/0x2e0
> > > [  138.364387]  ip_finish_output2+0x2f9/0x850
> > > [  138.364391]  ? __ip_finish_output+0xa0/0x320
> > > [  138.364394]  ip_send_skb+0x3f/0x90
> > > [  138.364397]  udp_send_skb+0x1a6/0x3d0
> > > [  138.364402]  udp_sendmsg+0x87b/0x1000
> > > [  138.364404]  ? ip_frag_init+0x60/0x60
> > > [  138.364406]  ? reacquire_held_locks+0xcd/0x1f0
> > > [  138.364414]  ? copy_process+0x2ae0/0x2fa0
> > > [  138.364418]  ? inet_autobind+0x41/0x60
> > > [  138.364420]  ? __local_bh_enable_ip+0x79/0xe0
> > > [  138.364422]  ? inet_autobind+0x41/0x60
> > > [  138.364424]  ? inet_send_prepare+0xe7/0x1e0
> > > [  138.364428]  __sock_sendmsg+0x38/0x70
> > > [  138.364432]  ____sys_sendmsg+0x1c9/0x200
> > > [  138.364437]  ___sys_sendmsg+0x73/0xa0
> > > [  138.364444]  ? __fget_files+0xb9/0x180
> > > [  138.364447]  ? lock_release+0x131/0x280
> > > [  138.364450]  ? __fget_files+0xc3/0x180
> > > [  138.364453]  __sys_sendmsg+0x5a/0xa0
> > 
> > Possibly a decoded stack trace could help.
> > 
> > I think a possible suspect is:
> > 
> > commit 986ffb3a57c5650fb8bf6d59a8f0f07046abfeb6
> > Author: Justin Iurman <justin.iurman@uliege.be>
> > Date:   Fri Mar 14 13:00:46 2025 +0100
> > 
> >      net: lwtunnel: fix recursion loops
> > 
> > with dev_xmit_recursion() in lwtunnel_xmit() being called in preemptible
> > scope.
> 
> Correct, I came to the same conclusion based on that trace. However, I can't
> reproduce it with a PREEMPT kernel. It goes through without problem and the
> output is (as expected), i.e., "lwtunnel_xmit(): recursion limit reached on
> datapath".

For me adding the following to the config did the trick:
CONFIG_PREEMPT
CONFIG_DEBUG_PREEMPT

And reverting your patch made it go away.

^ permalink raw reply	[flat|nested] 6+ messages in thread

* Re: new splat
  2025-04-01 16:45     ` Stanislav Fomichev
@ 2025-04-01 18:16       ` Justin Iurman
  2025-04-02 16:44       ` Jakub Kicinski
  1 sibling, 0 replies; 6+ messages in thread
From: Justin Iurman @ 2025-04-01 18:16 UTC (permalink / raw)
  To: Stanislav Fomichev
  Cc: Paolo Abeni, Alexei Starovoitov, bpf, Network Development,
	Jakub Kicinski

On 4/1/25 18:45, Stanislav Fomichev wrote:
> On 04/01, Justin Iurman wrote:
>>
>> Correct, I came to the same conclusion based on that trace. However, I can't
>> reproduce it with a PREEMPT kernel. It goes through without problem and the
>> output is (as expected), i.e., "lwtunnel_xmit(): recursion limit reached on
>> datapath".
> 
> For me adding the following to the config did the trick:
> CONFIG_PREEMPT
> CONFIG_DEBUG_PREEMPT
> 
> And reverting your patch made it go away.

*Sigh* Looks like CONFIG_DEBUG_PREEMPT did the trick... thanks!

@Paolo, I'll provide a fix ASAP.

^ permalink raw reply	[flat|nested] 6+ messages in thread

* Re: new splat
  2025-04-01 16:45     ` Stanislav Fomichev
  2025-04-01 18:16       ` Justin Iurman
@ 2025-04-02 16:44       ` Jakub Kicinski
  1 sibling, 0 replies; 6+ messages in thread
From: Jakub Kicinski @ 2025-04-02 16:44 UTC (permalink / raw)
  To: Stanislav Fomichev
  Cc: Justin Iurman, Paolo Abeni, Alexei Starovoitov, bpf,
	Network Development

On Tue, 1 Apr 2025 09:45:19 -0700 Stanislav Fomichev wrote:
> > Correct, I came to the same conclusion based on that trace. However, I can't
> > reproduce it with a PREEMPT kernel. It goes through without problem and the
> > output is (as expected), i.e., "lwtunnel_xmit(): recursion limit reached on
> > datapath".  
> 
> For me adding the following to the config did the trick:
> CONFIG_PREEMPT
> CONFIG_DEBUG_PREEMPT

Could you send a patch to set these in kernel/configs/debug.config ?

^ permalink raw reply	[flat|nested] 6+ messages in thread

end of thread, other threads:[~2025-04-02 16:44 UTC | newest]

Thread overview: 6+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2025-03-30 23:28 new splat Alexei Starovoitov
2025-03-31  8:07 ` Paolo Abeni
2025-04-01  8:44   ` Justin Iurman
2025-04-01 16:45     ` Stanislav Fomichev
2025-04-01 18:16       ` Justin Iurman
2025-04-02 16:44       ` Jakub Kicinski

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).