* Panic in udp4_lib_lookup2
@ 2021-05-12 18:21 kapandey
2021-05-13 8:05 ` Paolo Abeni
0 siblings, 1 reply; 7+ messages in thread
From: kapandey @ 2021-05-12 18:21 UTC (permalink / raw)
To: willemb, pabeni, netdev, eric.dumazet, sharathv, subashab
Hi All,
We observed panic in udp_lib_lookup with below call trace:
[136523.743271] (7) Call trace:
[136523.743275] (7) udp4_lib_lookup2+0x88/0x1d8
[136523.743277] (7) __udp4_lib_lookup+0x168/0x194
[136523.743280] (7) udp4_lib_lookup+0x28/0x54
[136523.743285] (7) nf_sk_lookup_slow_v4+0x2b4/0x384
[136523.743289] (7) owner_mt+0xb8/0x248
[136523.743292] (7) ipt_do_table+0x28c/0x6a8
[136523.743295] (7) iptable_filter_hook+0x24/0x30
[136523.743299] (7) nf_hook_slow+0xa8/0x148
[136523.743303] (7) ip_local_deliver+0xa8/0x14c
[136523.743305] (7) ip_rcv+0xe0/0x134
We suspect this might happen due to below sequence:
Time CPU X
CPU Y
t0 inet_release -> udp_lib_close ->
sk_common_release -> udp_lib_unhash
inet_diag_handler_cmd -> udp_diag_destroy -> __udp_diag_destroy ->
udp_lib_rehash
t1 if(sk hashed)
if(sk hashed)
sk_del_node_init_rcu
hlist_del_init_rcu(udp_portaddr_node)
t2
if(hslot2 != nhslot2)
hlist_del_init_rcu(udp_portaddr_node)
hlist_add_head_rcu(udp_portaddr_node)
t3 sk is freed here
After t3 any use of that added udp_portaddr_node will cause panic.
Same happens in udp4_lib_lookup2/udp6_lib_lookup2.
We dont have any reproducer for this, getting hit during random testing.
Pls let us know how this be resolved.
Thanks,
KP
^ permalink raw reply [flat|nested] 7+ messages in thread
* Re: Panic in udp4_lib_lookup2
2021-05-12 18:21 Panic in udp4_lib_lookup2 kapandey
@ 2021-05-13 8:05 ` Paolo Abeni
2021-05-13 19:48 ` Kaustubh Pandey
0 siblings, 1 reply; 7+ messages in thread
From: Paolo Abeni @ 2021-05-13 8:05 UTC (permalink / raw)
To: kapandey, willemb, netdev, eric.dumazet, sharathv, subashab
Hello,
On Wed, 2021-05-12 at 23:51 +0530, kapandey@codeaurora.org wrote:
> We observed panic in udp_lib_lookup with below call trace:
> [136523.743271] (7) Call trace:
> [136523.743275] (7) udp4_lib_lookup2+0x88/0x1d8
> [136523.743277] (7) __udp4_lib_lookup+0x168/0x194
> [136523.743280] (7) udp4_lib_lookup+0x28/0x54
> [136523.743285] (7) nf_sk_lookup_slow_v4+0x2b4/0x384
> [136523.743289] (7) owner_mt+0xb8/0x248
> [136523.743292] (7) ipt_do_table+0x28c/0x6a8
> [136523.743295] (7) iptable_filter_hook+0x24/0x30
> [136523.743299] (7) nf_hook_slow+0xa8/0x148
> [136523.743303] (7) ip_local_deliver+0xa8/0x14c
> [136523.743305] (7) ip_rcv+0xe0/0x134
It would be helpful if you could provide a full, decoded, stack trace
and the relevant kernel version.
> We suspect this might happen due to below sequence:
Some email formatting made the "graph" very hard to read...
> Time CPU X
>
> CPU Y
> t0 inet_release -> udp_lib_close ->
> sk_common_release -> udp_lib_unhash
> inet_diag_handler_cmd -> udp_diag_destroy -> __udp_diag_destroy ->
> udp_lib_rehash
... but it looks like udp_lib_close() is missing a
lock_sock()/release_sock() pair. Something alike:
---
diff --git a/include/net/udp.h b/include/net/udp.h
index 360df454356c..06586b42db3f 100644
--- a/include/net/udp.h
+++ b/include/net/udp.h
@@ -209,7 +209,9 @@ void udp_lib_rehash(struct sock *sk, u16 new_hash);
static inline void udp_lib_close(struct sock *sk, long timeout)
{
+ lock_sock(sk);
sk_common_release(sk);
+ release_sock(sk);
}
int udp_lib_get_port(struct sock *sk, unsigned short snum,
---
could u please give the above a spin in your testbed?
Thanks!
Paolo
^ permalink raw reply related [flat|nested] 7+ messages in thread
* Re: Panic in udp4_lib_lookup2
2021-05-13 8:05 ` Paolo Abeni
@ 2021-05-13 19:48 ` Kaustubh Pandey
2021-05-13 21:18 ` Paolo Abeni
0 siblings, 1 reply; 7+ messages in thread
From: Kaustubh Pandey @ 2021-05-13 19:48 UTC (permalink / raw)
To: Paolo Abeni; +Cc: willemb, netdev, eric.dumazet, sharathv, subashab
On Thu, May 13, 2021 at 10:05:37AM +0200, Paolo Abeni wrote:
> Hello,
>
> On Wed, 2021-05-12 at 23:51 +0530, kapandey@codeaurora.org wrote:
> > We observed panic in udp_lib_lookup with below call trace:
> > [136523.743271] (7) Call trace:
> > [136523.743275] (7) udp4_lib_lookup2+0x88/0x1d8
> > [136523.743277] (7) __udp4_lib_lookup+0x168/0x194
> > [136523.743280] (7) udp4_lib_lookup+0x28/0x54
> > [136523.743285] (7) nf_sk_lookup_slow_v4+0x2b4/0x384
> > [136523.743289] (7) owner_mt+0xb8/0x248
> > [136523.743292] (7) ipt_do_table+0x28c/0x6a8
> > [136523.743295] (7) iptable_filter_hook+0x24/0x30
> > [136523.743299] (7) nf_hook_slow+0xa8/0x148
> > [136523.743303] (7) ip_local_deliver+0xa8/0x14c
> > [136523.743305] (7) ip_rcv+0xe0/0x134
>
> It would be helpful if you could provide a full, decoded, stack trace
> and the relevant kernel version.
>
> > We suspect this might happen due to below sequence:
>
> Some email formatting made the "graph" very hard to read...
>
> > Time CPU X
> >
> > CPU Y
> > t0 inet_release -> udp_lib_close ->
> > sk_common_release -> udp_lib_unhash
> > inet_diag_handler_cmd -> udp_diag_destroy -> __udp_diag_destroy ->
> > udp_lib_rehash
>
> ... but it looks like udp_lib_close() is missing a
> lock_sock()/release_sock() pair. Something alike:
> ---
> diff --git a/include/net/udp.h b/include/net/udp.h
> index 360df454356c..06586b42db3f 100644
> --- a/include/net/udp.h
> +++ b/include/net/udp.h
> @@ -209,7 +209,9 @@ void udp_lib_rehash(struct sock *sk, u16 new_hash);
>
> static inline void udp_lib_close(struct sock *sk, long timeout)
> {
> + lock_sock(sk);
> sk_common_release(sk);
> + release_sock(sk);
> }
>
> int udp_lib_get_port(struct sock *sk, unsigned short snum,
> ---
>
> could u please give the above a spin in your testbed?
>
> Thanks!
>
> Paolo
>
>
Hi Paolo,
Pls find full backtrace:
[136523.743141]Unable to handle kernel paging request at virtual address
00000c08ff000820
[136523.743147]Mem abort info:
[136523.743150] ESR = 0x96000004
[136523.743154] EC = 0x25: DABT (current EL), IL = 32 bits
[136523.743157] SET = 0, FnV = 0
[136523.743159] EA = 0, S1PTW = 0
[136523.743162]Data abort info:
[136523.743164] ISV = 0, ISS = 0x00000004
[136523.743167] CM = 0, WnR = 0
[136523.743170][00000c08ff000820] address between user and kernel
address ranges
[136523.743174]Internal error: Oops: 96000004 [#1] PREEMPT SMP
[136523.743218]pstate: a0c00005 (NzCv daif +PAN +UAO)
[136523.743226]pc : udp4_lib_lookup2+0x88/0x1d8
[136523.743229]lr : __udp4_lib_lookup+0x168/0x194
[136523.743232]sp : ffffffc039a9b600
[136523.743234]x29: ffffffc039a9b610 x28: 0000000000000000
[136523.743237]x27: 0000000000000000 x26: ff000c08ff0007f0
[136523.743239]x25: ffffffe1e2319b40 x24: 0000000073737272
[136523.743242]x23: 0000000000003500 x22: 0000000000000000
[136523.743244]x21: 000000000000a622 x20: 000000000000001a
[136523.743246]x19: 00000000ffffffff x18: ffffffc02b6d7098
[136523.743249]x17: 0000000000000000 x16: 0000000000000000
[136523.743251]x15: 0000000000000000 x14: 0000000000000000
[136523.743254]x13: 0000000000000000 x12: ffffff81d8e30000
[136523.743257]x11: 0000000000000fff x10: ff000c08ff0007f0
[136523.743259]x9 : ff000c08ff000808 x8 : 0000000000000000
[136523.743261]x7 : ffffff81d8e3e6a0 x6 : 0000000000000000
[136523.743263]x5 : 000000000000001a x4 : 000000000000a622
[136523.743266]x3 : 0000000000000000 x2 : 0000000000003500
[136523.743268]x1 : 0000000073737272 x0 : ffffffe1e2319b40
[136523.743271]Call trace:
[136523.743275] udp4_lib_lookup2+0x88/0x1d8
[136523.743277] __udp4_lib_lookup+0x168/0x194
[136523.743280] udp4_lib_lookup+0x28/0x54
[136523.743285] nf_sk_lookup_slow_v4+0x2b4/0x384
[136523.743289] owner_mt+0xb8/0x248
[136523.743292] ipt_do_table+0x28c/0x6a8
[136523.743295] iptable_filter_hook+0x24/0x30
[136523.743299] nf_hook_slow+0xa8/0x148
[136523.743303] ip_local_deliver+0xa8/0x14c
[136523.743305] ip_rcv+0xe0/0x134
[136523.743309] __netif_receive_skb_core+0x9d0/0xd74
[136523.743313] __netif_receive_skb+0x50/0x17c
[136523.743316] netif_receive_skb_internal+0xa0/0xd8
[136523.743318] netif_receive_skb+0xec/0x1e4
Kernel version used is 5.4
Derived from your suggestion I think below change might be more suited
here:
diff --git a/net/core/sock.c b/net/core/sock.c
index f87c9f7..a5dd0e5 100644
--- a/net/core/sock.c
+++ b/net/core/sock.c
@@ -3210,7 +3210,9 @@ void sk_common_release(struct sock *sk)
* A. Remove from hash tables.
*/
+ lock_sock(sk);
sk->sk_prot->unhash(sk);
+ release_sock(sk);
--
Previously I was trying to share this anlaysis:
Time | CPU[X] | CPU[Y]
____________________________________________________________________________
| |
t0 | inet_release | inet_diag_handler_cmd
| udp_lib_close | udp_diag_destroy
| sk_common_release | __udp_diag_destroy
| udp_lib_unhash | udp_lib_rehash
____________________________________________________________________________
t1 | if(sk hashed) | if(sk hashed)
| sk_del_node_init_rcu |
| hlist_del_init_rcu(udp_portaddr_node) |
____________________________________________________________________________
t2 | | if(hslot2 != nhslot2)
| | hlist_del_init_rcu(udp_portaddr_node)
| | hlist_add_head_rcu(udp_portaddr_node)
____________________________________________________________________________
t3 | sk is freed here |
Pls let me know your views on this.
Thanks
KP
^ permalink raw reply related [flat|nested] 7+ messages in thread
* Re: Panic in udp4_lib_lookup2
2021-05-13 19:48 ` Kaustubh Pandey
@ 2021-05-13 21:18 ` Paolo Abeni
2021-05-18 14:20 ` Kaustubh Pandey
0 siblings, 1 reply; 7+ messages in thread
From: Paolo Abeni @ 2021-05-13 21:18 UTC (permalink / raw)
To: Kaustubh Pandey; +Cc: willemb, netdev, eric.dumazet, sharathv, subashab
On Fri, 2021-05-14 at 01:18 +0530, Kaustubh Pandey wrote:
> On Thu, May 13, 2021 at 10:05:37AM +0200, Paolo Abeni wrote:
> > Hello,
> >
> > On Wed, 2021-05-12 at 23:51 +0530, kapandey@codeaurora.org wrote:
> > > We observed panic in udp_lib_lookup with below call trace:
> > > [136523.743271] (7) Call trace:
> > > [136523.743275] (7) udp4_lib_lookup2+0x88/0x1d8
> > > [136523.743277] (7) __udp4_lib_lookup+0x168/0x194
> > > [136523.743280] (7) udp4_lib_lookup+0x28/0x54
> > > [136523.743285] (7) nf_sk_lookup_slow_v4+0x2b4/0x384
> > > [136523.743289] (7) owner_mt+0xb8/0x248
> > > [136523.743292] (7) ipt_do_table+0x28c/0x6a8
> > > [136523.743295] (7) iptable_filter_hook+0x24/0x30
> > > [136523.743299] (7) nf_hook_slow+0xa8/0x148
> > > [136523.743303] (7) ip_local_deliver+0xa8/0x14c
> > > [136523.743305] (7) ip_rcv+0xe0/0x134
> >
> > It would be helpful if you could provide a full, decoded, stack trace
> > and the relevant kernel version.
> >
> > > We suspect this might happen due to below sequence:
> >
> > Some email formatting made the "graph" very hard to read...
> >
> > > Time CPU X
> > >
> > > CPU Y
> > > t0 inet_release -> udp_lib_close ->
> > > sk_common_release -> udp_lib_unhash
> > > inet_diag_handler_cmd -> udp_diag_destroy -> __udp_diag_destroy ->
> > > udp_lib_rehash
> >
> > ... but it looks like udp_lib_close() is missing a
> > lock_sock()/release_sock() pair. Something alike:
> > ---
> > diff --git a/include/net/udp.h b/include/net/udp.h
> > index 360df454356c..06586b42db3f 100644
> > --- a/include/net/udp.h
> > +++ b/include/net/udp.h
> > @@ -209,7 +209,9 @@ void udp_lib_rehash(struct sock *sk, u16 new_hash);
> >
> > static inline void udp_lib_close(struct sock *sk, long timeout)
> > {
> > + lock_sock(sk);
> > sk_common_release(sk);
> > + release_sock(sk);
> > }
> >
> > int udp_lib_get_port(struct sock *sk, unsigned short snum,
> > ---
> >
> > could u please give the above a spin in your testbed?
> >
> > Thanks!
> >
> > Paolo
> >
> >
> Hi Paolo,
>
> Pls find full backtrace:
> [136523.743141]Unable to handle kernel paging request at virtual address
> 00000c08ff000820
>
> [136523.743147]Mem abort info:
> [136523.743150] ESR = 0x96000004
> [136523.743154] EC = 0x25: DABT (current EL), IL = 32 bits
> [136523.743157] SET = 0, FnV = 0
> [136523.743159] EA = 0, S1PTW = 0
> [136523.743162]Data abort info:
> [136523.743164] ISV = 0, ISS = 0x00000004
> [136523.743167] CM = 0, WnR = 0
> [136523.743170][00000c08ff000820] address between user and kernel
> address ranges
> [136523.743174]Internal error: Oops: 96000004 [#1] PREEMPT SMP
> [136523.743218]pstate: a0c00005 (NzCv daif +PAN +UAO)
>
> [136523.743226]pc : udp4_lib_lookup2+0x88/0x1d8
> [136523.743229]lr : __udp4_lib_lookup+0x168/0x194
>
> [136523.743232]sp : ffffffc039a9b600
> [136523.743234]x29: ffffffc039a9b610 x28: 0000000000000000
> [136523.743237]x27: 0000000000000000 x26: ff000c08ff0007f0
> [136523.743239]x25: ffffffe1e2319b40 x24: 0000000073737272
> [136523.743242]x23: 0000000000003500 x22: 0000000000000000
> [136523.743244]x21: 000000000000a622 x20: 000000000000001a
> [136523.743246]x19: 00000000ffffffff x18: ffffffc02b6d7098
> [136523.743249]x17: 0000000000000000 x16: 0000000000000000
> [136523.743251]x15: 0000000000000000 x14: 0000000000000000
> [136523.743254]x13: 0000000000000000 x12: ffffff81d8e30000
> [136523.743257]x11: 0000000000000fff x10: ff000c08ff0007f0
> [136523.743259]x9 : ff000c08ff000808 x8 : 0000000000000000
> [136523.743261]x7 : ffffff81d8e3e6a0 x6 : 0000000000000000
> [136523.743263]x5 : 000000000000001a x4 : 000000000000a622
> [136523.743266]x3 : 0000000000000000 x2 : 0000000000003500
> [136523.743268]x1 : 0000000073737272 x0 : ffffffe1e2319b40
> [136523.743271]Call trace:
> [136523.743275] udp4_lib_lookup2+0x88/0x1d8
> [136523.743277] __udp4_lib_lookup+0x168/0x194
> [136523.743280] udp4_lib_lookup+0x28/0x54
> [136523.743285] nf_sk_lookup_slow_v4+0x2b4/0x384
> [136523.743289] owner_mt+0xb8/0x248
> [136523.743292] ipt_do_table+0x28c/0x6a8
> [136523.743295] iptable_filter_hook+0x24/0x30
> [136523.743299] nf_hook_slow+0xa8/0x148
> [136523.743303] ip_local_deliver+0xa8/0x14c
> [136523.743305] ip_rcv+0xe0/0x134
> [136523.743309] __netif_receive_skb_core+0x9d0/0xd74
> [136523.743313] __netif_receive_skb+0x50/0x17c
> [136523.743316] netif_receive_skb_internal+0xa0/0xd8
> [136523.743318] netif_receive_skb+0xec/0x1e4
>
> Kernel version used is 5.4
>
> Derived from your suggestion I think below change might be more suited
> here:
> diff --git a/net/core/sock.c b/net/core/sock.c
> index f87c9f7..a5dd0e5 100644
> --- a/net/core/sock.c
> +++ b/net/core/sock.c
> @@ -3210,7 +3210,9 @@ void sk_common_release(struct sock *sk)
> * A. Remove from hash tables.
> */
> + lock_sock(sk);
> sk->sk_prot->unhash(sk);
> + release_sock(sk);
The above will cause deadlock on protocol rightfully calling
sk_common_release under the socket lock (e.g. sctp).
Could you please test the change I suggested in your testbed?
Thanks
Paolo
^ permalink raw reply [flat|nested] 7+ messages in thread
* Re: Panic in udp4_lib_lookup2
2021-05-13 21:18 ` Paolo Abeni
@ 2021-05-18 14:20 ` Kaustubh Pandey
2021-05-21 18:18 ` Paolo Abeni
0 siblings, 1 reply; 7+ messages in thread
From: Kaustubh Pandey @ 2021-05-18 14:20 UTC (permalink / raw)
To: Paolo Abeni; +Cc: willemb, netdev, eric.dumazet, sharathv, subashab
On Thu, May 13, 2021 at 11:18:53PM +0200, Paolo Abeni wrote:
> On Fri, 2021-05-14 at 01:18 +0530, Kaustubh Pandey wrote:
> > On Thu, May 13, 2021 at 10:05:37AM +0200, Paolo Abeni wrote:
> > > Hello,
> > >
> > > On Wed, 2021-05-12 at 23:51 +0530, kapandey@codeaurora.org wrote:
> > > > We observed panic in udp_lib_lookup with below call trace:
> > > > [136523.743271] (7) Call trace:
> > > > [136523.743275] (7) udp4_lib_lookup2+0x88/0x1d8
> > > > [136523.743277] (7) __udp4_lib_lookup+0x168/0x194
> > > > [136523.743280] (7) udp4_lib_lookup+0x28/0x54
> > > > [136523.743285] (7) nf_sk_lookup_slow_v4+0x2b4/0x384
> > > > [136523.743289] (7) owner_mt+0xb8/0x248
> > > > [136523.743292] (7) ipt_do_table+0x28c/0x6a8
> > > > [136523.743295] (7) iptable_filter_hook+0x24/0x30
> > > > [136523.743299] (7) nf_hook_slow+0xa8/0x148
> > > > [136523.743303] (7) ip_local_deliver+0xa8/0x14c
> > > > [136523.743305] (7) ip_rcv+0xe0/0x134
> > >
> > > It would be helpful if you could provide a full, decoded, stack trace
> > > and the relevant kernel version.
> > >
> > > > We suspect this might happen due to below sequence:
> > >
> > > Some email formatting made the "graph" very hard to read...
> > >
> > > > Time CPU X
> > > >
> > > > CPU Y
> > > > t0 inet_release -> udp_lib_close ->
> > > > sk_common_release -> udp_lib_unhash
> > > > inet_diag_handler_cmd -> udp_diag_destroy -> __udp_diag_destroy ->
> > > > udp_lib_rehash
> > >
> > > ... but it looks like udp_lib_close() is missing a
> > > lock_sock()/release_sock() pair. Something alike:
> > > ---
> > > diff --git a/include/net/udp.h b/include/net/udp.h
> > > index 360df454356c..06586b42db3f 100644
> > > --- a/include/net/udp.h
> > > +++ b/include/net/udp.h
> > > @@ -209,7 +209,9 @@ void udp_lib_rehash(struct sock *sk, u16 new_hash);
> > >
> > > static inline void udp_lib_close(struct sock *sk, long timeout)
> > > {
> > > + lock_sock(sk);
> > > sk_common_release(sk);
> > > + release_sock(sk);
> > > }
> > >
> > > int udp_lib_get_port(struct sock *sk, unsigned short snum,
> > > ---
> > >
> > > could u please give the above a spin in your testbed?
> > >
> > > Thanks!
> > >
> > > Paolo
> > >
> > >
> > Hi Paolo,
> >
> > Pls find full backtrace:
> > [136523.743141]Unable to handle kernel paging request at virtual address
> > 00000c08ff000820
> >
> > [136523.743147]Mem abort info:
> > [136523.743150] ESR = 0x96000004
> > [136523.743154] EC = 0x25: DABT (current EL), IL = 32 bits
> > [136523.743157] SET = 0, FnV = 0
> > [136523.743159] EA = 0, S1PTW = 0
> > [136523.743162]Data abort info:
> > [136523.743164] ISV = 0, ISS = 0x00000004
> > [136523.743167] CM = 0, WnR = 0
> > [136523.743170][00000c08ff000820] address between user and kernel
> > address ranges
> > [136523.743174]Internal error: Oops: 96000004 [#1] PREEMPT SMP
> > [136523.743218]pstate: a0c00005 (NzCv daif +PAN +UAO)
> >
> > [136523.743226]pc : udp4_lib_lookup2+0x88/0x1d8
> > [136523.743229]lr : __udp4_lib_lookup+0x168/0x194
> >
> > [136523.743232]sp : ffffffc039a9b600
> > [136523.743234]x29: ffffffc039a9b610 x28: 0000000000000000
> > [136523.743237]x27: 0000000000000000 x26: ff000c08ff0007f0
> > [136523.743239]x25: ffffffe1e2319b40 x24: 0000000073737272
> > [136523.743242]x23: 0000000000003500 x22: 0000000000000000
> > [136523.743244]x21: 000000000000a622 x20: 000000000000001a
> > [136523.743246]x19: 00000000ffffffff x18: ffffffc02b6d7098
> > [136523.743249]x17: 0000000000000000 x16: 0000000000000000
> > [136523.743251]x15: 0000000000000000 x14: 0000000000000000
> > [136523.743254]x13: 0000000000000000 x12: ffffff81d8e30000
> > [136523.743257]x11: 0000000000000fff x10: ff000c08ff0007f0
> > [136523.743259]x9 : ff000c08ff000808 x8 : 0000000000000000
> > [136523.743261]x7 : ffffff81d8e3e6a0 x6 : 0000000000000000
> > [136523.743263]x5 : 000000000000001a x4 : 000000000000a622
> > [136523.743266]x3 : 0000000000000000 x2 : 0000000000003500
> > [136523.743268]x1 : 0000000073737272 x0 : ffffffe1e2319b40
> > [136523.743271]Call trace:
> > [136523.743275] udp4_lib_lookup2+0x88/0x1d8
> > [136523.743277] __udp4_lib_lookup+0x168/0x194
> > [136523.743280] udp4_lib_lookup+0x28/0x54
> > [136523.743285] nf_sk_lookup_slow_v4+0x2b4/0x384
> > [136523.743289] owner_mt+0xb8/0x248
> > [136523.743292] ipt_do_table+0x28c/0x6a8
> > [136523.743295] iptable_filter_hook+0x24/0x30
> > [136523.743299] nf_hook_slow+0xa8/0x148
> > [136523.743303] ip_local_deliver+0xa8/0x14c
> > [136523.743305] ip_rcv+0xe0/0x134
> > [136523.743309] __netif_receive_skb_core+0x9d0/0xd74
> > [136523.743313] __netif_receive_skb+0x50/0x17c
> > [136523.743316] netif_receive_skb_internal+0xa0/0xd8
> > [136523.743318] netif_receive_skb+0xec/0x1e4
> >
> > Kernel version used is 5.4
> >
> > Derived from your suggestion I think below change might be more suited
> > here:
> > diff --git a/net/core/sock.c b/net/core/sock.c
> > index f87c9f7..a5dd0e5 100644
> > --- a/net/core/sock.c
> > +++ b/net/core/sock.c
> > @@ -3210,7 +3210,9 @@ void sk_common_release(struct sock *sk)
> > * A. Remove from hash tables.
> > */
> > + lock_sock(sk);
> > sk->sk_prot->unhash(sk);
> > + release_sock(sk);
>
> The above will cause deadlock on protocol rightfully calling
> sk_common_release under the socket lock (e.g. sctp).
>
> Could you please test the change I suggested in your testbed?
>
> Thanks
>
> Paolo
>
Hi Paolo,
I picked up your change and with that it get stuck in udp_destroy_sock
trying to do lock_sock_fast.
Can you guide for next steps here?
Thanks,
KP
^ permalink raw reply [flat|nested] 7+ messages in thread
* Re: Panic in udp4_lib_lookup2
2021-05-18 14:20 ` Kaustubh Pandey
@ 2021-05-21 18:18 ` Paolo Abeni
2021-06-04 14:26 ` Kaustubh Pandey
0 siblings, 1 reply; 7+ messages in thread
From: Paolo Abeni @ 2021-05-21 18:18 UTC (permalink / raw)
To: Kaustubh Pandey; +Cc: willemb, netdev, eric.dumazet, sharathv, subashab
On Tue, 2021-05-18 at 19:50 +0530, Kaustubh Pandey wrote:
> On Thu, May 13, 2021 at 11:18:53PM +0200, Paolo Abeni wrote:
> > On Fri, 2021-05-14 at 01:18 +0530, Kaustubh Pandey wrote:
> > > On Thu, May 13, 2021 at 10:05:37AM +0200, Paolo Abeni wrote:
> > > > Hello,
> > > >
> > > > On Wed, 2021-05-12 at 23:51 +0530, kapandey@codeaurora.org wrote:
> > > > > We observed panic in udp_lib_lookup with below call trace:
> > > > > [136523.743271] (7) Call trace:
> > > > > [136523.743275] (7) udp4_lib_lookup2+0x88/0x1d8
> > > > > [136523.743277] (7) __udp4_lib_lookup+0x168/0x194
> > > > > [136523.743280] (7) udp4_lib_lookup+0x28/0x54
> > > > > [136523.743285] (7) nf_sk_lookup_slow_v4+0x2b4/0x384
> > > > > [136523.743289] (7) owner_mt+0xb8/0x248
> > > > > [136523.743292] (7) ipt_do_table+0x28c/0x6a8
> > > > > [136523.743295] (7) iptable_filter_hook+0x24/0x30
> > > > > [136523.743299] (7) nf_hook_slow+0xa8/0x148
> > > > > [136523.743303] (7) ip_local_deliver+0xa8/0x14c
> > > > > [136523.743305] (7) ip_rcv+0xe0/0x134
> > > >
> > > > It would be helpful if you could provide a full, decoded, stack trace
> > > > and the relevant kernel version.
> > > >
> > > > > We suspect this might happen due to below sequence:
> > > >
> > > > Some email formatting made the "graph" very hard to read...
> > > >
> > > > > Time CPU X
> > > > >
> > > > > CPU Y
> > > > > t0 inet_release -> udp_lib_close ->
> > > > > sk_common_release -> udp_lib_unhash
> > > > > inet_diag_handler_cmd -> udp_diag_destroy -> __udp_diag_destroy ->
> > > > > udp_lib_rehash
> > > >
> > > > ... but it looks like udp_lib_close() is missing a
> > > > lock_sock()/release_sock() pair. Something alike:
> > > > ---
> > > > diff --git a/include/net/udp.h b/include/net/udp.h
> > > > index 360df454356c..06586b42db3f 100644
> > > > --- a/include/net/udp.h
> > > > +++ b/include/net/udp.h
> > > > @@ -209,7 +209,9 @@ void udp_lib_rehash(struct sock *sk, u16 new_hash);
> > > >
> > > > static inline void udp_lib_close(struct sock *sk, long timeout)
> > > > {
> > > > + lock_sock(sk);
> > > > sk_common_release(sk);
> > > > + release_sock(sk);
> > > > }
> > > >
> > > > int udp_lib_get_port(struct sock *sk, unsigned short snum,
> > > > ---
> > > >
> > > > could u please give the above a spin in your testbed?
> > > >
> > > > Thanks!
> > > >
> > > > Paolo
> > > >
> > > >
> > > Hi Paolo,
> > >
> > > Pls find full backtrace:
> > > [136523.743141]Unable to handle kernel paging request at virtual address
> > > 00000c08ff000820
> > >
> > > [136523.743147]Mem abort info:
> > > [136523.743150] ESR = 0x96000004
> > > [136523.743154] EC = 0x25: DABT (current EL), IL = 32 bits
> > > [136523.743157] SET = 0, FnV = 0
> > > [136523.743159] EA = 0, S1PTW = 0
> > > [136523.743162]Data abort info:
> > > [136523.743164] ISV = 0, ISS = 0x00000004
> > > [136523.743167] CM = 0, WnR = 0
> > > [136523.743170][00000c08ff000820] address between user and kernel
> > > address ranges
> > > [136523.743174]Internal error: Oops: 96000004 [#1] PREEMPT SMP
> > > [136523.743218]pstate: a0c00005 (NzCv daif +PAN +UAO)
> > >
> > > [136523.743226]pc : udp4_lib_lookup2+0x88/0x1d8
> > > [136523.743229]lr : __udp4_lib_lookup+0x168/0x194
> > >
> > > [136523.743232]sp : ffffffc039a9b600
> > > [136523.743234]x29: ffffffc039a9b610 x28: 0000000000000000
> > > [136523.743237]x27: 0000000000000000 x26: ff000c08ff0007f0
> > > [136523.743239]x25: ffffffe1e2319b40 x24: 0000000073737272
> > > [136523.743242]x23: 0000000000003500 x22: 0000000000000000
> > > [136523.743244]x21: 000000000000a622 x20: 000000000000001a
> > > [136523.743246]x19: 00000000ffffffff x18: ffffffc02b6d7098
> > > [136523.743249]x17: 0000000000000000 x16: 0000000000000000
> > > [136523.743251]x15: 0000000000000000 x14: 0000000000000000
> > > [136523.743254]x13: 0000000000000000 x12: ffffff81d8e30000
> > > [136523.743257]x11: 0000000000000fff x10: ff000c08ff0007f0
> > > [136523.743259]x9 : ff000c08ff000808 x8 : 0000000000000000
> > > [136523.743261]x7 : ffffff81d8e3e6a0 x6 : 0000000000000000
> > > [136523.743263]x5 : 000000000000001a x4 : 000000000000a622
> > > [136523.743266]x3 : 0000000000000000 x2 : 0000000000003500
> > > [136523.743268]x1 : 0000000073737272 x0 : ffffffe1e2319b40
> > > [136523.743271]Call trace:
> > > [136523.743275] udp4_lib_lookup2+0x88/0x1d8
> > > [136523.743277] __udp4_lib_lookup+0x168/0x194
> > > [136523.743280] udp4_lib_lookup+0x28/0x54
> > > [136523.743285] nf_sk_lookup_slow_v4+0x2b4/0x384
> > > [136523.743289] owner_mt+0xb8/0x248
> > > [136523.743292] ipt_do_table+0x28c/0x6a8
> > > [136523.743295] iptable_filter_hook+0x24/0x30
> > > [136523.743299] nf_hook_slow+0xa8/0x148
> > > [136523.743303] ip_local_deliver+0xa8/0x14c
> > > [136523.743305] ip_rcv+0xe0/0x134
> > > [136523.743309] __netif_receive_skb_core+0x9d0/0xd74
> > > [136523.743313] __netif_receive_skb+0x50/0x17c
> > > [136523.743316] netif_receive_skb_internal+0xa0/0xd8
> > > [136523.743318] netif_receive_skb+0xec/0x1e4
> > >
> > > Kernel version used is 5.4
> > >
> > > Derived from your suggestion I think below change might be more suited
> > > here:
> > > diff --git a/net/core/sock.c b/net/core/sock.c
> > > index f87c9f7..a5dd0e5 100644
> > > --- a/net/core/sock.c
> > > +++ b/net/core/sock.c
> > > @@ -3210,7 +3210,9 @@ void sk_common_release(struct sock *sk)
> > > * A. Remove from hash tables.
> > > */
> > > + lock_sock(sk);
> > > sk->sk_prot->unhash(sk);
> > > + release_sock(sk);
> >
> > The above will cause deadlock on protocol rightfully calling
> > sk_common_release under the socket lock (e.g. sctp).
> >
> > Could you please test the change I suggested in your testbed?
> >
> > Thanks
> >
> > Paolo
> >
> Hi Paolo,
>
> I picked up your change and with that it get stuck in udp_destroy_sock
> trying to do lock_sock_fast.
>
> Can you guide for next steps here?
I'm sorry for the high latency.
It's a bit tricky as we can't easily acquire the socket lock on close
with a wider scope.
Can you please try this one?
Thanks!
Paolo
---
diff --git a/net/ipv4/udp.c b/net/ipv4/udp.c
index 055fceb18bea..0d6205726abf 100644
--- a/net/ipv4/udp.c
+++ b/net/ipv4/udp.c
@@ -2607,6 +2607,7 @@ void udp_destroy_sock(struct sock *sk)
{
struct udp_sock *up = udp_sk(sk);
bool slow = lock_sock_fast(sk);
+ sock_set_flag(sk, SOCK_DEAD);
udp_flush_pending_frames(sk);
unlock_sock_fast(sk, slow);
if (static_branch_unlikely(&udp_encap_needed_key)) {
@@ -2857,10 +2858,17 @@ int udp_abort(struct sock *sk, int err)
{
lock_sock(sk);
+ /* udp{v6}_destroy_sock() sets it under the sk lock, avoid racing
+ * with close()
+ */
+ if (sock_flag(sk, SOCK_DEAD))
+ goto out;
+
sk->sk_err = err;
sk->sk_error_report(sk);
__udp_disconnect(sk, 0);
+out:
release_sock(sk);
return 0;
diff --git a/net/ipv6/udp.c b/net/ipv6/udp.c
index 199b080d418a..2984ec43b9aa 100644
--- a/net/ipv6/udp.c
+++ b/net/ipv6/udp.c
@@ -1598,6 +1598,7 @@ void udpv6_destroy_sock(struct sock *sk)
{
struct udp_sock *up = udp_sk(sk);
lock_sock(sk);
+ sock_set_flag(sk, SOCK_DEAD);
udp_v6_flush_pending_frames(sk);
release_sock(sk);
^ permalink raw reply related [flat|nested] 7+ messages in thread
* Re: Panic in udp4_lib_lookup2
2021-05-21 18:18 ` Paolo Abeni
@ 2021-06-04 14:26 ` Kaustubh Pandey
0 siblings, 0 replies; 7+ messages in thread
From: Kaustubh Pandey @ 2021-06-04 14:26 UTC (permalink / raw)
To: Paolo Abeni; +Cc: willemb, netdev, eric.dumazet, sharathv, subashab
On Fri, May 21, 2021 at 08:18:56PM +0200, Paolo Abeni wrote:
> On Tue, 2021-05-18 at 19:50 +0530, Kaustubh Pandey wrote:
> > On Thu, May 13, 2021 at 11:18:53PM +0200, Paolo Abeni wrote:
> > > On Fri, 2021-05-14 at 01:18 +0530, Kaustubh Pandey wrote:
> > > > On Thu, May 13, 2021 at 10:05:37AM +0200, Paolo Abeni wrote:
> > > > > Hello,
> > > > >
> > > > > On Wed, 2021-05-12 at 23:51 +0530, kapandey@codeaurora.org wrote:
> > > > > > We observed panic in udp_lib_lookup with below call trace:
> > > > > > [136523.743271] (7) Call trace:
> > > > > > [136523.743275] (7) udp4_lib_lookup2+0x88/0x1d8
> > > > > > [136523.743277] (7) __udp4_lib_lookup+0x168/0x194
> > > > > > [136523.743280] (7) udp4_lib_lookup+0x28/0x54
> > > > > > [136523.743285] (7) nf_sk_lookup_slow_v4+0x2b4/0x384
> > > > > > [136523.743289] (7) owner_mt+0xb8/0x248
> > > > > > [136523.743292] (7) ipt_do_table+0x28c/0x6a8
> > > > > > [136523.743295] (7) iptable_filter_hook+0x24/0x30
> > > > > > [136523.743299] (7) nf_hook_slow+0xa8/0x148
> > > > > > [136523.743303] (7) ip_local_deliver+0xa8/0x14c
> > > > > > [136523.743305] (7) ip_rcv+0xe0/0x134
> > > > >
> > > > > It would be helpful if you could provide a full, decoded, stack trace
> > > > > and the relevant kernel version.
> > > > >
> > > > > > We suspect this might happen due to below sequence:
> > > > >
> > > > > Some email formatting made the "graph" very hard to read...
> > > > >
> > > > > > Time CPU X
> > > > > >
> > > > > > CPU Y
> > > > > > t0 inet_release -> udp_lib_close ->
> > > > > > sk_common_release -> udp_lib_unhash
> > > > > > inet_diag_handler_cmd -> udp_diag_destroy -> __udp_diag_destroy ->
> > > > > > udp_lib_rehash
> > > > >
> > > > > ... but it looks like udp_lib_close() is missing a
> > > > > lock_sock()/release_sock() pair. Something alike:
> > > > > ---
> > > > > diff --git a/include/net/udp.h b/include/net/udp.h
> > > > > index 360df454356c..06586b42db3f 100644
> > > > > --- a/include/net/udp.h
> > > > > +++ b/include/net/udp.h
> > > > > @@ -209,7 +209,9 @@ void udp_lib_rehash(struct sock *sk, u16 new_hash);
> > > > >
> > > > > static inline void udp_lib_close(struct sock *sk, long timeout)
> > > > > {
> > > > > + lock_sock(sk);
> > > > > sk_common_release(sk);
> > > > > + release_sock(sk);
> > > > > }
> > > > >
> > > > > int udp_lib_get_port(struct sock *sk, unsigned short snum,
> > > > > ---
> > > > >
> > > > > could u please give the above a spin in your testbed?
> > > > >
> > > > > Thanks!
> > > > >
> > > > > Paolo
> > > > >
> > > > >
> > > > Hi Paolo,
> > > >
> > > > Pls find full backtrace:
> > > > [136523.743141]Unable to handle kernel paging request at virtual address
> > > > 00000c08ff000820
> > > >
> > > > [136523.743147]Mem abort info:
> > > > [136523.743150] ESR = 0x96000004
> > > > [136523.743154] EC = 0x25: DABT (current EL), IL = 32 bits
> > > > [136523.743157] SET = 0, FnV = 0
> > > > [136523.743159] EA = 0, S1PTW = 0
> > > > [136523.743162]Data abort info:
> > > > [136523.743164] ISV = 0, ISS = 0x00000004
> > > > [136523.743167] CM = 0, WnR = 0
> > > > [136523.743170][00000c08ff000820] address between user and kernel
> > > > address ranges
> > > > [136523.743174]Internal error: Oops: 96000004 [#1] PREEMPT SMP
> > > > [136523.743218]pstate: a0c00005 (NzCv daif +PAN +UAO)
> > > >
> > > > [136523.743226]pc : udp4_lib_lookup2+0x88/0x1d8
> > > > [136523.743229]lr : __udp4_lib_lookup+0x168/0x194
> > > >
> > > > [136523.743232]sp : ffffffc039a9b600
> > > > [136523.743234]x29: ffffffc039a9b610 x28: 0000000000000000
> > > > [136523.743237]x27: 0000000000000000 x26: ff000c08ff0007f0
> > > > [136523.743239]x25: ffffffe1e2319b40 x24: 0000000073737272
> > > > [136523.743242]x23: 0000000000003500 x22: 0000000000000000
> > > > [136523.743244]x21: 000000000000a622 x20: 000000000000001a
> > > > [136523.743246]x19: 00000000ffffffff x18: ffffffc02b6d7098
> > > > [136523.743249]x17: 0000000000000000 x16: 0000000000000000
> > > > [136523.743251]x15: 0000000000000000 x14: 0000000000000000
> > > > [136523.743254]x13: 0000000000000000 x12: ffffff81d8e30000
> > > > [136523.743257]x11: 0000000000000fff x10: ff000c08ff0007f0
> > > > [136523.743259]x9 : ff000c08ff000808 x8 : 0000000000000000
> > > > [136523.743261]x7 : ffffff81d8e3e6a0 x6 : 0000000000000000
> > > > [136523.743263]x5 : 000000000000001a x4 : 000000000000a622
> > > > [136523.743266]x3 : 0000000000000000 x2 : 0000000000003500
> > > > [136523.743268]x1 : 0000000073737272 x0 : ffffffe1e2319b40
> > > > [136523.743271]Call trace:
> > > > [136523.743275] udp4_lib_lookup2+0x88/0x1d8
> > > > [136523.743277] __udp4_lib_lookup+0x168/0x194
> > > > [136523.743280] udp4_lib_lookup+0x28/0x54
> > > > [136523.743285] nf_sk_lookup_slow_v4+0x2b4/0x384
> > > > [136523.743289] owner_mt+0xb8/0x248
> > > > [136523.743292] ipt_do_table+0x28c/0x6a8
> > > > [136523.743295] iptable_filter_hook+0x24/0x30
> > > > [136523.743299] nf_hook_slow+0xa8/0x148
> > > > [136523.743303] ip_local_deliver+0xa8/0x14c
> > > > [136523.743305] ip_rcv+0xe0/0x134
> > > > [136523.743309] __netif_receive_skb_core+0x9d0/0xd74
> > > > [136523.743313] __netif_receive_skb+0x50/0x17c
> > > > [136523.743316] netif_receive_skb_internal+0xa0/0xd8
> > > > [136523.743318] netif_receive_skb+0xec/0x1e4
> > > >
> > > > Kernel version used is 5.4
> > > >
> > > > Derived from your suggestion I think below change might be more suited
> > > > here:
> > > > diff --git a/net/core/sock.c b/net/core/sock.c
> > > > index f87c9f7..a5dd0e5 100644
> > > > --- a/net/core/sock.c
> > > > +++ b/net/core/sock.c
> > > > @@ -3210,7 +3210,9 @@ void sk_common_release(struct sock *sk)
> > > > * A. Remove from hash tables.
> > > > */
> > > > + lock_sock(sk);
> > > > sk->sk_prot->unhash(sk);
> > > > + release_sock(sk);
> > >
> > > The above will cause deadlock on protocol rightfully calling
> > > sk_common_release under the socket lock (e.g. sctp).
> > >
> > > Could you please test the change I suggested in your testbed?
> > >
> > > Thanks
> > >
> > > Paolo
> > >
> > Hi Paolo,
> >
> > I picked up your change and with that it get stuck in udp_destroy_sock
> > trying to do lock_sock_fast.
> >
> > Can you guide for next steps here?
>
> I'm sorry for the high latency.
>
> It's a bit tricky as we can't easily acquire the socket lock on close
> with a wider scope.
>
> Can you please try this one?
>
> Thanks!
>
> Paolo
> ---
> diff --git a/net/ipv4/udp.c b/net/ipv4/udp.c
> index 055fceb18bea..0d6205726abf 100644
> --- a/net/ipv4/udp.c
> +++ b/net/ipv4/udp.c
> @@ -2607,6 +2607,7 @@ void udp_destroy_sock(struct sock *sk)
> {
> struct udp_sock *up = udp_sk(sk);
> bool slow = lock_sock_fast(sk);
> + sock_set_flag(sk, SOCK_DEAD);
> udp_flush_pending_frames(sk);
> unlock_sock_fast(sk, slow);
> if (static_branch_unlikely(&udp_encap_needed_key)) {
> @@ -2857,10 +2858,17 @@ int udp_abort(struct sock *sk, int err)
> {
> lock_sock(sk);
>
> + /* udp{v6}_destroy_sock() sets it under the sk lock, avoid racing
> + * with close()
> + */
> + if (sock_flag(sk, SOCK_DEAD))
> + goto out;
> +
> sk->sk_err = err;
> sk->sk_error_report(sk);
> __udp_disconnect(sk, 0);
>
> +out:
> release_sock(sk);
>
> return 0;
> diff --git a/net/ipv6/udp.c b/net/ipv6/udp.c
> index 199b080d418a..2984ec43b9aa 100644
> --- a/net/ipv6/udp.c
> +++ b/net/ipv6/udp.c
> @@ -1598,6 +1598,7 @@ void udpv6_destroy_sock(struct sock *sk)
> {
> struct udp_sock *up = udp_sk(sk);
> lock_sock(sk);
> + sock_set_flag(sk, SOCK_DEAD);
> udp_v6_flush_pending_frames(sk);
> release_sock(sk);
>
>
Hi Paolo,
Apologies for delay.
I picked up this patch and tried reproducing the panic.
I never observed the panic with this patch. Seems to work perfectly
fine.
Can you pls raise a formal patch for this?
Thanks,
KP
^ permalink raw reply [flat|nested] 7+ messages in thread
end of thread, other threads:[~2021-06-04 14:27 UTC | newest]
Thread overview: 7+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2021-05-12 18:21 Panic in udp4_lib_lookup2 kapandey
2021-05-13 8:05 ` Paolo Abeni
2021-05-13 19:48 ` Kaustubh Pandey
2021-05-13 21:18 ` Paolo Abeni
2021-05-18 14:20 ` Kaustubh Pandey
2021-05-21 18:18 ` Paolo Abeni
2021-06-04 14:26 ` Kaustubh Pandey
This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.