netdev - Re: Long stalls creating a new netns after a netns with a SMB client exits

lists.openwall.net		lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC
Open Source and information security mailing list archives

Hash Suite: Windows password security audit tool. GUI, reports in PDF.

[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]

Message-ID: <CA+pO-2c+uR_3bfEkNAErJp9H4ngwMjeWp=rSKFJxPrgXZpD38g@mail.gmail.com>
Date:   Mon, 31 Jul 2017 17:22:03 +0100
From:   Rolf Neugebauer <rolf.neugebauer@...ker.com>
To:     David Ahern <dsahern@...il.com>
Cc:     Cong Wang <xiyou.wangcong@...il.com>,
        Linux Kernel Network Developers <netdev@...r.kernel.org>,
        Rolf Neugebauer <rolf.neugebauer@...ker.com>
Subject: Re: Long stalls creating a new netns after a netns with a SMB client exits

On Fri, Jul 28, 2017 at 8:16 PM, David Ahern <dsahern@...il.com> wrote:
> On 7/28/17 12:58 PM, Rolf Neugebauer wrote:
>>>> I can readily reproduce this on 4.9.39, 4.11.12 and another user
>>>> repro-ed it on 4.12.3. It seems to happen every time. At least one
>>>> user reported issues with NFS mounts as well, but we were not able to
>>>> reproduce it. It's not clear to me if this is directly related to
>>>> 'mount.cifs' or if that just happens to reliably repro it.
>>>
>>> OK, so commit d747a7a51b00984127a88113c does not help this case
>>> either.
>>
>> d747a7a51b009("tcp: reset sk_rx_dst in tcp_disconnect()") indeed seems
>> a different issue. As I understand that actually caused the ref count
>> never to get decremented, while here eventually some cleanup kicks in
>> after a long timeout.
>
> It could be a dst is cached on a socket and does not get cleared until
> the socket time outs are done.
>
> Test that theory by something like this for IPv4 TCP (similar change for
> UDP if the client is UDP based):
>
> diff --git a/net/ipv4/tcp_ipv4.c b/net/ipv4/tcp_ipv4.c
> index 3a19ea28339f..37db087b6c97 100644
> --- a/net/ipv4/tcp_ipv4.c
> +++ b/net/ipv4/tcp_ipv4.c
> @@ -1855,7 +1855,7 @@ void inet_sk_rx_dst_set(struct sock *sk, const
> struct sk_buff *skb)
>  {
>         struct dst_entry *dst = skb_dst(skb);
>
> -       if (dst && dst_hold_safe(dst)) {
> +       if (0 && dst && dst_hold_safe(dst)) {
>                 sk->sk_rx_dst = dst;
>                 inet_sk(sk)->rx_dst_ifindex = skb->skb_iif;
>         }


This removes the 200s stall (the test is IPv4/TCP based)

>
>>
>> I'll also try if I can get some traces out of dev_hold()/dev_put().
>
>
> Attached patch puts tracepoints in dev_hold / dev_put; very useful for
> debugging cases like this. Use perf record and perf script.

I extended the patch to also print out the ifindex and the nd_net to
make it easier to distinguish the different lo interfaces.

I've attached two perf traces, stall.script.txt is with the issue
present and nostall-sleep.script.txt is the same setup but with a
"sleep 1" after the executing the mount/ls/umount in the name space
and before deleting the network namespace. In the latter case there is
*no* stall for 200s.

In  stall.script.txt the "struct net *" of the interfaces in question
is net=0xffff897c6a86c080 and in nostall-sleep.script.txt it is
net=0xffff897c6a8a4100.

The two traces start diverging wrt to the reference counts on lo after
the reference count reaches 5 when deleting the namespace (timestamp
138.709884 in stall.script.txt and 550.856279 in
nostall-sleep.script.txt). In the trace where the stalls are, the
trace point of last decrement is:
kworker/0:1    20 [000]   361.938911:  net:dev_put: dev=lo[1]
net=0xffff897c6a86c080 refcnt 1
        ffffffffad704f6c perf_trace_dev_put+0xa3 ([kernel.kallsyms])
        ffffffffad6dc90e dev_put+0x111 ([kernel.kallsyms])
        ffffffffad6ec5df dst_destroy+0x4b ([kernel.kallsyms])
        ffffffffad6ec70c dst_gc_task+0xbe ([kernel.kallsyms])
        ffffffffad102bf8 process_one_work+0x276 ([kernel.kallsyms])
        ffffffffad103374 worker_thread+0x1eb ([kernel.kallsyms])
        ffffffffad1082d2 kthread+0xe3 ([kernel.kallsyms])
        ffffffffad8b947a ret_from_fork+0x2a ([kernel.kallsyms])


Let me know if there is additional data needed

Rolf

View attachment "stall.script.txt" of type "text/plain" (739486 bytes)

Download attachment "0001-Add-tracepoints-to-dev_hold-and-dev_put.patch" of type "application/octet-stream" (3404 bytes)

View attachment "nostall-sleep.script.txt" of type "text/plain" (264747 bytes)