Groups | Search | Server Info | Keyboard shortcuts | Login | Register [http] [https] [nntp] [nntps]

Groups > linux.kernel > #1694433 > unrolled thread

Re: [lkp-robot] [x86/refcount] b631e535c6: WARNING:at_net/netlink/af_netlink.c:#netlink_sock_destruct

Started byKees Cook <keescook@chromium.org>
First post2017-07-24 06:00 +0200
Last post2017-07-27 15:40 +0200
Articles 6 — 2 participants

Back to article view | Back to linux.kernel

This discussion starts older than the indexed window; earlier articles aren't shown. The article labeled Started by below is the oldest one visible, not the original post.

Contents

  Re: [lkp-robot] [x86/refcount] b631e535c6: WARNING:at_net/netlink/af_netlink.c:#netlink_sock_destruct Kees Cook <keescook@chromium.org> - 2017-07-24 06:00 +0200
    Re: [lkp-robot] [x86/refcount] b631e535c6:  WARNING:at_net/netlink/af_netlink.c:#netlink_sock_destruct Hans Liljestrand <liljestrandh@gmail.com> - 2017-07-24 15:10 +0200
      Re: [lkp-robot] [x86/refcount] b631e535c6: WARNING:at_net/netlink/af_netlink.c:#netlink_sock_destruct Kees Cook <keescook@chromium.org> - 2017-07-25 05:30 +0200
        Re: [lkp-robot] [x86/refcount] b631e535c6:  WARNING:at_net/netlink/af_netlink.c:#netlink_sock_destruct Hans Liljestrand <liljestrandh@gmail.com> - 2017-07-25 12:50 +0200
          Re: [lkp-robot] [x86/refcount] b631e535c6: WARNING:at_net/netlink/af_netlink.c:#netlink_sock_destruct Kees Cook <keescook@chromium.org> - 2017-07-25 20:40 +0200
            Re: [lkp-robot] [x86/refcount] b631e535c6:  WARNING:at_net/netlink/af_netlink.c:#netlink_sock_destruct Hans Liljestrand <liljestrandh@gmail.com> - 2017-07-27 15:40 +0200

#1694433 — Re: [lkp-robot] [x86/refcount] b631e535c6: WARNING:at_net/netlink/af_netlink.c:#netlink_sock_destruct

FromKees Cook <keescook@chromium.org>
Date2017-07-24 06:00 +0200
SubjectRe: [lkp-robot] [x86/refcount] b631e535c6: WARNING:at_net/netlink/af_netlink.c:#netlink_sock_destruct
Message-ID<u6CHf-7X3-5@gated-at.bofh.it>
Is 14afee4b6092f ("net: convert sock.sk_wmem_alloc from atomic_t to
refcount_t") correct? That looks like a statistics counter, not a
refcounter? I can't quite tell, though...

I think this WARN is from:

WARN_ON(refcount_read(&sk->sk_wmem_alloc));

-Kees

On Sun, Jul 23, 2017 at 7:13 PM, kernel test robot
<xiaolong.ye@intel.com> wrote:
>
> FYI, we noticed the following commit:
>
> commit: b631e535c61d7ddbb7ebac545f729ca9b3b6d70e ("x86/refcount: Implement fast refcount overflow protection")
> https://git.kernel.org/cgit/linux/kernel/git/kees/linux.git kspp/fast-refcount/ud/v6
>
> in testcase: boot
>
> on test machine: qemu-system-x86_64 -enable-kvm -smp 2 -m 512M
>
> caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):
>
>
> +------------------------------------------------------------+------------+------------+
> |                                                            | 561ee9566e | b631e535c6 |
> +------------------------------------------------------------+------------+------------+
> | boot_successes                                             | 37         | 0          |
> | boot_failures                                              | 0          | 4          |
> | WARNING:at_net/netlink/af_netlink.c:#netlink_sock_destruct | 0          | 4          |
> +------------------------------------------------------------+------------+------------+
>
>
>
> [   36.991339] WARNING: CPU: 0 PID: 280 at net/netlink/af_netlink.c:374 netlink_sock_destruct+0x1ea/0x200
> [   36.994035] Modules linked in:
> [   36.994815] CPU: 0 PID: 280 Comm: sh Not tainted 4.13.0-rc1-00003-gb631e53 #1
> [   36.996546] task: ffff88001448c180 task.stack: ffffc900004e0000
> [   36.998006] RIP: 0010:netlink_sock_destruct+0x1ea/0x200
> [   36.999290] RSP: 0018:ffffffff82433de0 EFLAGS: 00010206
> [   37.000591] RAX: ffff88001448c180 RBX: ffff880016a3d000 RCX: 0000000000000000
> [   37.002319] RDX: 0000000000000100 RSI: 0000000000000001 RDI: ffffffff82796f48
> [   37.004061] RBP: ffffffff82433df0 R08: 0000000000000000 R09: 0000000000000000
> [   37.005780] R10: 0000000000000001 R11: 0000000000000001 R12: 0000000000000001
> [   37.007528] R13: ffffffff81cd4a00 R14: 96e49674e09954cf R15: 000000000000001f
> [   37.009261] FS:  0000000000000000(0000) GS:ffffffff82430000(0000) knlGS:0000000000000000
> [   37.011233] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [   37.012629] CR2: 00007f268a96e688 CR3: 00000000159ff000 CR4: 00000000000006b0
> [   37.014212] Call Trace:
> [   37.014745]  <IRQ>
> [   37.015201]  __sk_destruct+0x3a2/0x4c0
> [   37.015994]  sk_destruct+0x3f/0x70
> [   37.016747]  __sk_free+0x10d/0x160
> [   37.017479]  sk_free+0x4a/0x60
> [   37.018127]  deferred_put_nlk_sk+0xd9/0xf0
> [   37.018998]  rcu_process_callbacks+0x766/0x1cb0
> [   37.019944]  ? rcu_process_callbacks+0x643/0x1cb0
> [   37.020960]  __do_softirq+0x10c/0x6b2
> [   37.021749]  irq_exit+0x135/0x140
> [   37.022458]  smp_apic_timer_interrupt+0x3b/0x50
> [   37.023429]  apic_timer_interrupt+0x8e/0xa0
> [   37.024303] RIP: 0010:__sanitizer_cov_trace_pc+0x0/0x60
> [   37.025141] RSP: 0018:ffffc900004e3c10 EFLAGS: 00000246 ORIG_RAX: ffffffffffffff10
> [   37.026605] RAX: ffff88001448c180 RBX: ffffffff82727288 RCX: 0000000000000000
> [   37.028340] RDX: 0000000000000000 RSI: 0000000000000000 RDI: ffffffff82727288
> [   37.030077] RBP: ffffc900004e3c60 R08: 0000000000000000 R09: 0000000000000000
> [   37.031796] R10: 0000000000000000 R11: 0000000000000001 R12: 0000000000000000
> [   37.033546] R13: 0000000000000000 R14: 0000000000000000 R15: 00007f2689f93000
> [   37.035262]  </IRQ>
> [   37.035814]  ? ftrace_likely_update+0x39/0x200
> [   37.036925]  ? vm_normal_page+0xd7/0x1a0
> [   37.037886]  unmap_page_range+0x775/0x14d0
> [   37.038658]  unmap_single_vma+0x158/0x180
> [   37.039403]  unmap_vmas+0x5b/0x80
> [   37.040202]  exit_mmap+0x118/0x220
> [   37.040900]  mmput+0xd5/0x240
> [   37.041479]  do_exit+0xdb6/0x16d0
> [   37.042183]  ? entry_SYSCALL_64_fastpath+0x5/0xbd
> [   37.043365]  do_group_exit+0x8a/0x160
> [   37.044282]  SyS_exit_group+0x1d/0x20
> [   37.045192]  entry_SYSCALL_64_fastpath+0x1f/0xbd
> [   37.046321] RIP: 0033:0x7f268a676408
> [   37.047221] RSP: 002b:00007ffcba052ea8 EFLAGS: 00000246 ORIG_RAX: 00000000000000e7
> [   37.049042] RAX: ffffffffffffffda RBX: 000000000000007f RCX: 00007f268a676408
> [   37.050784] RDX: 000000000000007f RSI: 000000000000003c RDI: 000000000000007f
> [   37.052512] RBP: 00007f268a96e688 R08: 00000000000000e7 R09: ffffffffffffffa0
> [   37.054281] R10: 0000000000000000 R11: 0000000000000246 R12: 00007f268a96ff40
> [   37.056004] R13: 0000000000000001 R14: 0000000000000000 R15: 00000000ffffffff
> [   37.057765] Code: e8 56 14 48 ff eb ca e8 b5 42 4f ff 0f ff 0f 1f 00 eb a7 e8 a9 42 4f ff 0f ff 0f 1f 80 00 00 00 00 e9 48 ff ff ff e8 96 42 4f ff <0f> ff 0f 1f 40 00 e9 e5 fe ff ff 90 66 2e 0f 1f 84 00 00 00 00
> [   37.062621] ---[ end trace db04ba531557bbda ]---
>
>
> To reproduce:
>
>         git clone https://github.com/01org/lkp-tests.git
>         cd lkp-tests
>         bin/lkp qemu -k <bzImage> job-script  # job-script is attached in this email
>
>
>
> Thanks,
> Xiaolong



-- 
Kees Cook
Pixel Security

[toc] | [next] | [standalone]

#1694696 — Re: [lkp-robot] [x86/refcount] b631e535c6: WARNING:at_net/netlink/af_netlink.c:#netlink_sock_destruct

FromHans Liljestrand <liljestrandh@gmail.com>
Date2017-07-24 15:10 +0200
SubjectRe: [lkp-robot] [x86/refcount] b631e535c6: WARNING:at_net/netlink/af_netlink.c:#netlink_sock_destruct
Message-ID<u6Lhw-5ho-31@gated-at.bofh.it>
In reply to#1694433
On Sun, Jul 23, 2017 at 08:52:53PM -0700, Kees Cook wrote:
>Is 14afee4b6092f ("net: convert sock.sk_wmem_alloc from atomic_t to
>refcount_t") correct? That looks like a statistics counter, not a
>refcounter? I can't quite tell, though...

Hmm, yes, it looks a bit weird, but it is used in a refcount fashion here:

void sk_free(struct sock *sk)
{
	/*
	 * We subtract one from sk_wmem_alloc and can know if
	 * some packets are still in some tx queue.
	 * If not null, sock_wfree() will call __sk_free(sk) later
	 */
	if (refcount_dec_and_test(&sk->sk_wmem_alloc))
		__sk_free(sk);
}
http://elixir.free-electrons.com/linux/v4.13-rc1/source/net/core/sock.c#L1605

And here:

	if (refcount_sub_and_test(len, &sk->sk_wmem_alloc))
		__sk_free(sk);
}
http://elixir.free-electrons.com/linux/v4.13-rc1/source/net/core/sock.c#L1798

>
>I think this WARN is from:
>
>WARN_ON(refcount_read(&sk->sk_wmem_alloc));

I looked through the commit and couldn't find any direct conversion issues.  
Although I guess it is debatable whether refcoun_t should be used in this kind 
of less conventional case.

The only potential problem I noticed was that based on the following change 
(or rather the original code) it seems like sk_wmem_alloc could sometimes be 
negative. I'm not familiar enough with the code to say whether that really is 
the case.

--- a/drivers/atm/fore200e.c
+++ b/drivers/atm/fore200e.c
@@ -924,12 +924,7 @@ fore200e_tx_irq(struct fore200e* fore200e)
                else {
                    dev_kfree_skb_any(entry->skb);
                }
-#if 1
-               /* race fixed by the above incarnation mechanism, but... */
-               if (atomic_read(&sk_atm(vcc)->sk_wmem_alloc) < 0) {
-                   atomic_set(&sk_atm(vcc)->sk_wmem_alloc, 0);
-               }
-#endif
+
                /* check error condition */
                if (*entry->status & STATUS_ERROR)
                    atomic_inc(&vcc->stats->tx_err);

But if this is actually supposed to legitimately happen and eventually 
"balance out" refcount_t might not work here. On the other hand this should 
have triggered an earlier WARN_ON already, so it doesn't seem to be the issue 
here?

Regards,
-hans

>
>-Kees
>
>On Sun, Jul 23, 2017 at 7:13 PM, kernel test robot
><xiaolong.ye@intel.com> wrote:
>>
>> FYI, we noticed the following commit:
>>
>> commit: b631e535c61d7ddbb7ebac545f729ca9b3b6d70e ("x86/refcount: Implement fast refcount overflow protection")
>> https://git.kernel.org/cgit/linux/kernel/git/kees/linux.git kspp/fast-refcount/ud/v6
>>
>> in testcase: boot
>>
>> on test machine: qemu-system-x86_64 -enable-kvm -smp 2 -m 512M
>>
>> caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):
>>
>>
>> +------------------------------------------------------------+------------+------------+
>> |                                                            | 561ee9566e | b631e535c6 |
>> +------------------------------------------------------------+------------+------------+
>> | boot_successes                                             | 37         | 0          |
>> | boot_failures                                              | 0          | 4          |
>> | WARNING:at_net/netlink/af_netlink.c:#netlink_sock_destruct | 0          | 4          |
>> +------------------------------------------------------------+------------+------------+
>>
>>
>>
>> [   36.991339] WARNING: CPU: 0 PID: 280 at net/netlink/af_netlink.c:374 netlink_sock_destruct+0x1ea/0x200
>> [   36.994035] Modules linked in:
>> [   36.994815] CPU: 0 PID: 280 Comm: sh Not tainted 4.13.0-rc1-00003-gb631e53 #1
>> [   36.996546] task: ffff88001448c180 task.stack: ffffc900004e0000
>> [   36.998006] RIP: 0010:netlink_sock_destruct+0x1ea/0x200
>> [   36.999290] RSP: 0018:ffffffff82433de0 EFLAGS: 00010206
>> [   37.000591] RAX: ffff88001448c180 RBX: ffff880016a3d000 RCX: 0000000000000000
>> [   37.002319] RDX: 0000000000000100 RSI: 0000000000000001 RDI: ffffffff82796f48
>> [   37.004061] RBP: ffffffff82433df0 R08: 0000000000000000 R09: 0000000000000000
>> [   37.005780] R10: 0000000000000001 R11: 0000000000000001 R12: 0000000000000001
>> [   37.007528] R13: ffffffff81cd4a00 R14: 96e49674e09954cf R15: 000000000000001f
>> [   37.009261] FS:  0000000000000000(0000) GS:ffffffff82430000(0000) knlGS:0000000000000000
>> [   37.011233] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
>> [   37.012629] CR2: 00007f268a96e688 CR3: 00000000159ff000 CR4: 00000000000006b0
>> [   37.014212] Call Trace:
>> [   37.014745]  <IRQ>
>> [   37.015201]  __sk_destruct+0x3a2/0x4c0
>> [   37.015994]  sk_destruct+0x3f/0x70
>> [   37.016747]  __sk_free+0x10d/0x160
>> [   37.017479]  sk_free+0x4a/0x60
>> [   37.018127]  deferred_put_nlk_sk+0xd9/0xf0
>> [   37.018998]  rcu_process_callbacks+0x766/0x1cb0
>> [   37.019944]  ? rcu_process_callbacks+0x643/0x1cb0
>> [   37.020960]  __do_softirq+0x10c/0x6b2
>> [   37.021749]  irq_exit+0x135/0x140
>> [   37.022458]  smp_apic_timer_interrupt+0x3b/0x50
>> [   37.023429]  apic_timer_interrupt+0x8e/0xa0
>> [   37.024303] RIP: 0010:__sanitizer_cov_trace_pc+0x0/0x60
>> [   37.025141] RSP: 0018:ffffc900004e3c10 EFLAGS: 00000246 ORIG_RAX: ffffffffffffff10
>> [   37.026605] RAX: ffff88001448c180 RBX: ffffffff82727288 RCX: 0000000000000000
>> [   37.028340] RDX: 0000000000000000 RSI: 0000000000000000 RDI: ffffffff82727288
>> [   37.030077] RBP: ffffc900004e3c60 R08: 0000000000000000 R09: 0000000000000000
>> [   37.031796] R10: 0000000000000000 R11: 0000000000000001 R12: 0000000000000000
>> [   37.033546] R13: 0000000000000000 R14: 0000000000000000 R15: 00007f2689f93000
>> [   37.035262]  </IRQ>
>> [   37.035814]  ? ftrace_likely_update+0x39/0x200
>> [   37.036925]  ? vm_normal_page+0xd7/0x1a0
>> [   37.037886]  unmap_page_range+0x775/0x14d0
>> [   37.038658]  unmap_single_vma+0x158/0x180
>> [   37.039403]  unmap_vmas+0x5b/0x80
>> [   37.040202]  exit_mmap+0x118/0x220
>> [   37.040900]  mmput+0xd5/0x240
>> [   37.041479]  do_exit+0xdb6/0x16d0
>> [   37.042183]  ? entry_SYSCALL_64_fastpath+0x5/0xbd
>> [   37.043365]  do_group_exit+0x8a/0x160
>> [   37.044282]  SyS_exit_group+0x1d/0x20
>> [   37.045192]  entry_SYSCALL_64_fastpath+0x1f/0xbd
>> [   37.046321] RIP: 0033:0x7f268a676408
>> [   37.047221] RSP: 002b:00007ffcba052ea8 EFLAGS: 00000246 ORIG_RAX: 00000000000000e7
>> [   37.049042] RAX: ffffffffffffffda RBX: 000000000000007f RCX: 00007f268a676408
>> [   37.050784] RDX: 000000000000007f RSI: 000000000000003c RDI: 000000000000007f
>> [   37.052512] RBP: 00007f268a96e688 R08: 00000000000000e7 R09: ffffffffffffffa0
>> [   37.054281] R10: 0000000000000000 R11: 0000000000000246 R12: 00007f268a96ff40
>> [   37.056004] R13: 0000000000000001 R14: 0000000000000000 R15: 00000000ffffffff
>> [   37.057765] Code: e8 56 14 48 ff eb ca e8 b5 42 4f ff 0f ff 0f 1f 00 eb a7 e8 a9 42 4f ff 0f ff 0f 1f 80 00 00 00 00 e9 48 ff ff ff e8 96 42 4f ff <0f> ff 0f 1f 40 00 e9 e5 fe ff ff 90 66 2e 0f 1f 84 00 00 00 00
>> [   37.062621] ---[ end trace db04ba531557bbda ]---
>>
>>
>> To reproduce:
>>
>>         git clone https://github.com/01org/lkp-tests.git
>>         cd lkp-tests
>>         bin/lkp qemu -k <bzImage> job-script  # job-script is attached in this email
>>
>>
>>
>> Thanks,
>> Xiaolong
>
>
>
>-- 
>Kees Cook
>Pixel Security

[toc] | [prev] | [next] | [standalone]

#1695363

FromKees Cook <keescook@chromium.org>
Date2017-07-25 05:30 +0200
Message-ID<u6YHM-5XO-5@gated-at.bofh.it>
In reply to#1694696
On Mon, Jul 24, 2017 at 6:03 AM, Hans Liljestrand
<liljestrandh@gmail.com> wrote:
> On Sun, Jul 23, 2017 at 08:52:53PM -0700, Kees Cook wrote:
>>
>> Is 14afee4b6092f ("net: convert sock.sk_wmem_alloc from atomic_t to
>> refcount_t") correct? That looks like a statistics counter, not a
>> refcounter? I can't quite tell, though...
>
>
> Hmm, yes, it looks a bit weird, but it is used in a refcount fashion here:
>
> void sk_free(struct sock *sk)
> {
>         /*
>          * We subtract one from sk_wmem_alloc and can know if
>          * some packets are still in some tx queue.
>          * If not null, sock_wfree() will call __sk_free(sk) later
>          */
>         if (refcount_dec_and_test(&sk->sk_wmem_alloc))
>                 __sk_free(sk);
> }
> http://elixir.free-electrons.com/linux/v4.13-rc1/source/net/core/sock.c#L1605

Ah yeah, there it is. Hrmpf. Something is triggering WARNs, though...
I wonder if this can get examined more closely?

Also, why not atomic->refcount for sk_rmem_alloc?

-Kees

>
> And here:
>
>         if (refcount_sub_and_test(len, &sk->sk_wmem_alloc))
>                 __sk_free(sk);
> }
> http://elixir.free-electrons.com/linux/v4.13-rc1/source/net/core/sock.c#L1798
>
>>
>> I think this WARN is from:
>>
>> WARN_ON(refcount_read(&sk->sk_wmem_alloc));
>
>
> I looked through the commit and couldn't find any direct conversion issues.
> Although I guess it is debatable whether refcoun_t should be used in this
> kind of less conventional case.
>
> The only potential problem I noticed was that based on the following change
> (or rather the original code) it seems like sk_wmem_alloc could sometimes be
> negative. I'm not familiar enough with the code to say whether that really
> is the case.
>
> --- a/drivers/atm/fore200e.c
> +++ b/drivers/atm/fore200e.c
> @@ -924,12 +924,7 @@ fore200e_tx_irq(struct fore200e* fore200e)
>                else {
>                    dev_kfree_skb_any(entry->skb);
>                }
> -#if 1
> -               /* race fixed by the above incarnation mechanism, but... */
> -               if (atomic_read(&sk_atm(vcc)->sk_wmem_alloc) < 0) {
> -                   atomic_set(&sk_atm(vcc)->sk_wmem_alloc, 0);
> -               }
> -#endif
> +
>                /* check error condition */
>                if (*entry->status & STATUS_ERROR)
>                    atomic_inc(&vcc->stats->tx_err);
>
> But if this is actually supposed to legitimately happen and eventually
> "balance out" refcount_t might not work here. On the other hand this should
> have triggered an earlier WARN_ON already, so it doesn't seem to be the
> issue here?
>
> Regards,
> -hans
>
>
>>
>> -Kees
>>
>> On Sun, Jul 23, 2017 at 7:13 PM, kernel test robot
>> <xiaolong.ye@intel.com> wrote:
>>>
>>>
>>> FYI, we noticed the following commit:
>>>
>>> commit: b631e535c61d7ddbb7ebac545f729ca9b3b6d70e ("x86/refcount:
>>> Implement fast refcount overflow protection")
>>> https://git.kernel.org/cgit/linux/kernel/git/kees/linux.git
>>> kspp/fast-refcount/ud/v6
>>>
>>> in testcase: boot
>>>
>>> on test machine: qemu-system-x86_64 -enable-kvm -smp 2 -m 512M
>>>
>>> caused below changes (please refer to attached dmesg/kmsg for entire
>>> log/backtrace):
>>>
>>>
>>>
>>> +------------------------------------------------------------+------------+------------+
>>> |                                                            | 561ee9566e
>>> | b631e535c6 |
>>>
>>> +------------------------------------------------------------+------------+------------+
>>> | boot_successes                                             | 37
>>> | 0          |
>>> | boot_failures                                              | 0
>>> | 4          |
>>> | WARNING:at_net/netlink/af_netlink.c:#netlink_sock_destruct | 0
>>> | 4          |
>>>
>>> +------------------------------------------------------------+------------+------------+
>>>
>>>
>>>
>>> [   36.991339] WARNING: CPU: 0 PID: 280 at net/netlink/af_netlink.c:374
>>> netlink_sock_destruct+0x1ea/0x200
>>> [   36.994035] Modules linked in:
>>> [   36.994815] CPU: 0 PID: 280 Comm: sh Not tainted
>>> 4.13.0-rc1-00003-gb631e53 #1
>>> [   36.996546] task: ffff88001448c180 task.stack: ffffc900004e0000
>>> [   36.998006] RIP: 0010:netlink_sock_destruct+0x1ea/0x200
>>> [   36.999290] RSP: 0018:ffffffff82433de0 EFLAGS: 00010206
>>> [   37.000591] RAX: ffff88001448c180 RBX: ffff880016a3d000 RCX:
>>> 0000000000000000
>>> [   37.002319] RDX: 0000000000000100 RSI: 0000000000000001 RDI:
>>> ffffffff82796f48
>>> [   37.004061] RBP: ffffffff82433df0 R08: 0000000000000000 R09:
>>> 0000000000000000
>>> [   37.005780] R10: 0000000000000001 R11: 0000000000000001 R12:
>>> 0000000000000001
>>> [   37.007528] R13: ffffffff81cd4a00 R14: 96e49674e09954cf R15:
>>> 000000000000001f
>>> [   37.009261] FS:  0000000000000000(0000) GS:ffffffff82430000(0000)
>>> knlGS:0000000000000000
>>> [   37.011233] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
>>> [   37.012629] CR2: 00007f268a96e688 CR3: 00000000159ff000 CR4:
>>> 00000000000006b0
>>> [   37.014212] Call Trace:
>>> [   37.014745]  <IRQ>
>>> [   37.015201]  __sk_destruct+0x3a2/0x4c0
>>> [   37.015994]  sk_destruct+0x3f/0x70
>>> [   37.016747]  __sk_free+0x10d/0x160
>>> [   37.017479]  sk_free+0x4a/0x60
>>> [   37.018127]  deferred_put_nlk_sk+0xd9/0xf0
>>> [   37.018998]  rcu_process_callbacks+0x766/0x1cb0
>>> [   37.019944]  ? rcu_process_callbacks+0x643/0x1cb0
>>> [   37.020960]  __do_softirq+0x10c/0x6b2
>>> [   37.021749]  irq_exit+0x135/0x140
>>> [   37.022458]  smp_apic_timer_interrupt+0x3b/0x50
>>> [   37.023429]  apic_timer_interrupt+0x8e/0xa0
>>> [   37.024303] RIP: 0010:__sanitizer_cov_trace_pc+0x0/0x60
>>> [   37.025141] RSP: 0018:ffffc900004e3c10 EFLAGS: 00000246 ORIG_RAX:
>>> ffffffffffffff10
>>> [   37.026605] RAX: ffff88001448c180 RBX: ffffffff82727288 RCX:
>>> 0000000000000000
>>> [   37.028340] RDX: 0000000000000000 RSI: 0000000000000000 RDI:
>>> ffffffff82727288
>>> [   37.030077] RBP: ffffc900004e3c60 R08: 0000000000000000 R09:
>>> 0000000000000000
>>> [   37.031796] R10: 0000000000000000 R11: 0000000000000001 R12:
>>> 0000000000000000
>>> [   37.033546] R13: 0000000000000000 R14: 0000000000000000 R15:
>>> 00007f2689f93000
>>> [   37.035262]  </IRQ>
>>> [   37.035814]  ? ftrace_likely_update+0x39/0x200
>>> [   37.036925]  ? vm_normal_page+0xd7/0x1a0
>>> [   37.037886]  unmap_page_range+0x775/0x14d0
>>> [   37.038658]  unmap_single_vma+0x158/0x180
>>> [   37.039403]  unmap_vmas+0x5b/0x80
>>> [   37.040202]  exit_mmap+0x118/0x220
>>> [   37.040900]  mmput+0xd5/0x240
>>> [   37.041479]  do_exit+0xdb6/0x16d0
>>> [   37.042183]  ? entry_SYSCALL_64_fastpath+0x5/0xbd
>>> [   37.043365]  do_group_exit+0x8a/0x160
>>> [   37.044282]  SyS_exit_group+0x1d/0x20
>>> [   37.045192]  entry_SYSCALL_64_fastpath+0x1f/0xbd
>>> [   37.046321] RIP: 0033:0x7f268a676408
>>> [   37.047221] RSP: 002b:00007ffcba052ea8 EFLAGS: 00000246 ORIG_RAX:
>>> 00000000000000e7
>>> [   37.049042] RAX: ffffffffffffffda RBX: 000000000000007f RCX:
>>> 00007f268a676408
>>> [   37.050784] RDX: 000000000000007f RSI: 000000000000003c RDI:
>>> 000000000000007f
>>> [   37.052512] RBP: 00007f268a96e688 R08: 00000000000000e7 R09:
>>> ffffffffffffffa0
>>> [   37.054281] R10: 0000000000000000 R11: 0000000000000246 R12:
>>> 00007f268a96ff40
>>> [   37.056004] R13: 0000000000000001 R14: 0000000000000000 R15:
>>> 00000000ffffffff
>>> [   37.057765] Code: e8 56 14 48 ff eb ca e8 b5 42 4f ff 0f ff 0f 1f 00
>>> eb a7 e8 a9 42 4f ff 0f ff 0f 1f 80 00 00 00 00 e9 48 ff ff ff e8 96 42 4f
>>> ff <0f> ff 0f 1f 40 00 e9 e5 fe ff ff 90 66 2e 0f 1f 84 00 00 00 00
>>> [   37.062621] ---[ end trace db04ba531557bbda ]---
>>>
>>>
>>> To reproduce:
>>>
>>>         git clone https://github.com/01org/lkp-tests.git
>>>         cd lkp-tests
>>>         bin/lkp qemu -k <bzImage> job-script  # job-script is attached in
>>> this email
>>>
>>>
>>>
>>> Thanks,
>>> Xiaolong
>>
>>
>>
>>
>> --
>> Kees Cook
>> Pixel Security



-- 
Kees Cook
Pixel Security

[toc] | [prev] | [next] | [standalone]

#1695613 — Re: [lkp-robot] [x86/refcount] b631e535c6: WARNING:at_net/netlink/af_netlink.c:#netlink_sock_destruct

FromHans Liljestrand <liljestrandh@gmail.com>
Date2017-07-25 12:50 +0200
SubjectRe: [lkp-robot] [x86/refcount] b631e535c6: WARNING:at_net/netlink/af_netlink.c:#netlink_sock_destruct
Message-ID<u75zA-1Fi-31@gated-at.bofh.it>
In reply to#1695363
On Mon, Jul 24, 2017 at 08:21:16PM -0700, Kees Cook wrote:
>On Mon, Jul 24, 2017 at 6:03 AM, Hans Liljestrand
><liljestrandh@gmail.com> wrote:
>> On Sun, Jul 23, 2017 at 08:52:53PM -0700, Kees Cook wrote:
>>>
>>> Is 14afee4b6092f ("net: convert sock.sk_wmem_alloc from atomic_t to
>>> refcount_t") correct? That looks like a statistics counter, not a
>>> refcounter? I can't quite tell, though...
>>
>>
>> Hmm, yes, it looks a bit weird, but it is used in a refcount fashion here:
>>
>> void sk_free(struct sock *sk)
>> {
>>         /*
>>          * We subtract one from sk_wmem_alloc and can know if
>>          * some packets are still in some tx queue.
>>          * If not null, sock_wfree() will call __sk_free(sk) later
>>          */
>>         if (refcount_dec_and_test(&sk->sk_wmem_alloc))
>>                 __sk_free(sk);
>> }
>> http://elixir.free-electrons.com/linux/v4.13-rc1/source/net/core/sock.c#L1605
>
>Ah yeah, there it is. Hrmpf. Something is triggering WARNs, though...
>I wonder if this can get examined more closely?

I tried reproducing the error but I don't seem to know how to use lkp. Got 
lots of permission denied errors and finally ran out of disk space (after 
using up ~50GB).

Maybe I did something wrong?

What I did was: Cloned the related kernel repository, checked out offending 
commit, plopped in config, compiled bzImage. Then I just cloned the lkp repo 
and tried running the provided command line with the bzImage and provided 
script.

I'll take another look once I have the time, might be I missed something 
earlier.

>
>Also, why not atomic->refcount for sk_rmem_alloc?

I couldn't find any similar refcount-like use on sk_rmem_alloc.

And as noted the sk_wmem_alloc thing is also a bit dubious. It looks like it 
serves a dual purpose of actual allocation size and occasional reference 
counter.

Regards,
-hans

>
>-Kees
>
>>
>> And here:
>>
>>         if (refcount_sub_and_test(len, &sk->sk_wmem_alloc))
>>                 __sk_free(sk);
>> }
>> http://elixir.free-electrons.com/linux/v4.13-rc1/source/net/core/sock.c#L1798
>>
>>>
>>> I think this WARN is from:
>>>
>>> WARN_ON(refcount_read(&sk->sk_wmem_alloc));
>>
>>
>> I looked through the commit and couldn't find any direct conversion issues.
>> Although I guess it is debatable whether refcoun_t should be used in this
>> kind of less conventional case.
>>
>> The only potential problem I noticed was that based on the following change
>> (or rather the original code) it seems like sk_wmem_alloc could sometimes be
>> negative. I'm not familiar enough with the code to say whether that really
>> is the case.
>>
>> --- a/drivers/atm/fore200e.c
>> +++ b/drivers/atm/fore200e.c
>> @@ -924,12 +924,7 @@ fore200e_tx_irq(struct fore200e* fore200e)
>>                else {
>>                    dev_kfree_skb_any(entry->skb);
>>                }
>> -#if 1
>> -               /* race fixed by the above incarnation mechanism, but... */
>> -               if (atomic_read(&sk_atm(vcc)->sk_wmem_alloc) < 0) {
>> -                   atomic_set(&sk_atm(vcc)->sk_wmem_alloc, 0);
>> -               }
>> -#endif
>> +
>>                /* check error condition */
>>                if (*entry->status & STATUS_ERROR)
>>                    atomic_inc(&vcc->stats->tx_err);
>>
>> But if this is actually supposed to legitimately happen and eventually
>> "balance out" refcount_t might not work here. On the other hand this should
>> have triggered an earlier WARN_ON already, so it doesn't seem to be the
>> issue here?
>>
>> Regards,
>> -hans
>>
>>
>>>
>>> -Kees
>>>
>>> On Sun, Jul 23, 2017 at 7:13 PM, kernel test robot
>>> <xiaolong.ye@intel.com> wrote:
>>>>
>>>>
>>>> FYI, we noticed the following commit:
>>>>
>>>> commit: b631e535c61d7ddbb7ebac545f729ca9b3b6d70e ("x86/refcount:
>>>> Implement fast refcount overflow protection")
>>>> https://git.kernel.org/cgit/linux/kernel/git/kees/linux.git
>>>> kspp/fast-refcount/ud/v6
>>>>
>>>> in testcase: boot
>>>>
>>>> on test machine: qemu-system-x86_64 -enable-kvm -smp 2 -m 512M
>>>>
>>>> caused below changes (please refer to attached dmesg/kmsg for entire
>>>> log/backtrace):
>>>>
>>>>
>>>>
>>>> +------------------------------------------------------------+------------+------------+
>>>> |                                                            | 561ee9566e
>>>> | b631e535c6 |
>>>>
>>>> +------------------------------------------------------------+------------+------------+
>>>> | boot_successes                                             | 37
>>>> | 0          |
>>>> | boot_failures                                              | 0
>>>> | 4          |
>>>> | WARNING:at_net/netlink/af_netlink.c:#netlink_sock_destruct | 0
>>>> | 4          |
>>>>
>>>> +------------------------------------------------------------+------------+------------+
>>>>
>>>>
>>>>
>>>> [   36.991339] WARNING: CPU: 0 PID: 280 at net/netlink/af_netlink.c:374
>>>> netlink_sock_destruct+0x1ea/0x200
>>>> [   36.994035] Modules linked in:
>>>> [   36.994815] CPU: 0 PID: 280 Comm: sh Not tainted
>>>> 4.13.0-rc1-00003-gb631e53 #1
>>>> [   36.996546] task: ffff88001448c180 task.stack: ffffc900004e0000
>>>> [   36.998006] RIP: 0010:netlink_sock_destruct+0x1ea/0x200
>>>> [   36.999290] RSP: 0018:ffffffff82433de0 EFLAGS: 00010206
>>>> [   37.000591] RAX: ffff88001448c180 RBX: ffff880016a3d000 RCX:
>>>> 0000000000000000
>>>> [   37.002319] RDX: 0000000000000100 RSI: 0000000000000001 RDI:
>>>> ffffffff82796f48
>>>> [   37.004061] RBP: ffffffff82433df0 R08: 0000000000000000 R09:
>>>> 0000000000000000
>>>> [   37.005780] R10: 0000000000000001 R11: 0000000000000001 R12:
>>>> 0000000000000001
>>>> [   37.007528] R13: ffffffff81cd4a00 R14: 96e49674e09954cf R15:
>>>> 000000000000001f
>>>> [   37.009261] FS:  0000000000000000(0000) GS:ffffffff82430000(0000)
>>>> knlGS:0000000000000000
>>>> [   37.011233] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
>>>> [   37.012629] CR2: 00007f268a96e688 CR3: 00000000159ff000 CR4:
>>>> 00000000000006b0
>>>> [   37.014212] Call Trace:
>>>> [   37.014745]  <IRQ>
>>>> [   37.015201]  __sk_destruct+0x3a2/0x4c0
>>>> [   37.015994]  sk_destruct+0x3f/0x70
>>>> [   37.016747]  __sk_free+0x10d/0x160
>>>> [   37.017479]  sk_free+0x4a/0x60
>>>> [   37.018127]  deferred_put_nlk_sk+0xd9/0xf0
>>>> [   37.018998]  rcu_process_callbacks+0x766/0x1cb0
>>>> [   37.019944]  ? rcu_process_callbacks+0x643/0x1cb0
>>>> [   37.020960]  __do_softirq+0x10c/0x6b2
>>>> [   37.021749]  irq_exit+0x135/0x140
>>>> [   37.022458]  smp_apic_timer_interrupt+0x3b/0x50
>>>> [   37.023429]  apic_timer_interrupt+0x8e/0xa0
>>>> [   37.024303] RIP: 0010:__sanitizer_cov_trace_pc+0x0/0x60
>>>> [   37.025141] RSP: 0018:ffffc900004e3c10 EFLAGS: 00000246 ORIG_RAX:
>>>> ffffffffffffff10
>>>> [   37.026605] RAX: ffff88001448c180 RBX: ffffffff82727288 RCX:
>>>> 0000000000000000
>>>> [   37.028340] RDX: 0000000000000000 RSI: 0000000000000000 RDI:
>>>> ffffffff82727288
>>>> [   37.030077] RBP: ffffc900004e3c60 R08: 0000000000000000 R09:
>>>> 0000000000000000
>>>> [   37.031796] R10: 0000000000000000 R11: 0000000000000001 R12:
>>>> 0000000000000000
>>>> [   37.033546] R13: 0000000000000000 R14: 0000000000000000 R15:
>>>> 00007f2689f93000
>>>> [   37.035262]  </IRQ>
>>>> [   37.035814]  ? ftrace_likely_update+0x39/0x200
>>>> [   37.036925]  ? vm_normal_page+0xd7/0x1a0
>>>> [   37.037886]  unmap_page_range+0x775/0x14d0
>>>> [   37.038658]  unmap_single_vma+0x158/0x180
>>>> [   37.039403]  unmap_vmas+0x5b/0x80
>>>> [   37.040202]  exit_mmap+0x118/0x220
>>>> [   37.040900]  mmput+0xd5/0x240
>>>> [   37.041479]  do_exit+0xdb6/0x16d0
>>>> [   37.042183]  ? entry_SYSCALL_64_fastpath+0x5/0xbd
>>>> [   37.043365]  do_group_exit+0x8a/0x160
>>>> [   37.044282]  SyS_exit_group+0x1d/0x20
>>>> [   37.045192]  entry_SYSCALL_64_fastpath+0x1f/0xbd
>>>> [   37.046321] RIP: 0033:0x7f268a676408
>>>> [   37.047221] RSP: 002b:00007ffcba052ea8 EFLAGS: 00000246 ORIG_RAX:
>>>> 00000000000000e7
>>>> [   37.049042] RAX: ffffffffffffffda RBX: 000000000000007f RCX:
>>>> 00007f268a676408
>>>> [   37.050784] RDX: 000000000000007f RSI: 000000000000003c RDI:
>>>> 000000000000007f
>>>> [   37.052512] RBP: 00007f268a96e688 R08: 00000000000000e7 R09:
>>>> ffffffffffffffa0
>>>> [   37.054281] R10: 0000000000000000 R11: 0000000000000246 R12:
>>>> 00007f268a96ff40
>>>> [   37.056004] R13: 0000000000000001 R14: 0000000000000000 R15:
>>>> 00000000ffffffff
>>>> [   37.057765] Code: e8 56 14 48 ff eb ca e8 b5 42 4f ff 0f ff 0f 1f 00
>>>> eb a7 e8 a9 42 4f ff 0f ff 0f 1f 80 00 00 00 00 e9 48 ff ff ff e8 96 42 4f
>>>> ff <0f> ff 0f 1f 40 00 e9 e5 fe ff ff 90 66 2e 0f 1f 84 00 00 00 00
>>>> [   37.062621] ---[ end trace db04ba531557bbda ]---
>>>>
>>>>
>>>> To reproduce:
>>>>
>>>>         git clone https://github.com/01org/lkp-tests.git
>>>>         cd lkp-tests
>>>>         bin/lkp qemu -k <bzImage> job-script  # job-script is attached in
>>>> this email
>>>>
>>>>
>>>>
>>>> Thanks,
>>>> Xiaolong
>>>
>>>
>>>
>>>
>>> --
>>> Kees Cook
>>> Pixel Security
>
>
>
>-- 
>Kees Cook
>Pixel Security

[toc] | [prev] | [next] | [standalone]

#1696022

FromKees Cook <keescook@chromium.org>
Date2017-07-25 20:40 +0200
Message-ID<u7cUp-6m2-7@gated-at.bofh.it>
In reply to#1695613
On Tue, Jul 25, 2017 at 3:43 AM, Hans Liljestrand
<liljestrandh@gmail.com> wrote:
> On Mon, Jul 24, 2017 at 08:21:16PM -0700, Kees Cook wrote:
>>
>> On Mon, Jul 24, 2017 at 6:03 AM, Hans Liljestrand
>> <liljestrandh@gmail.com> wrote:
>>>
>>> On Sun, Jul 23, 2017 at 08:52:53PM -0700, Kees Cook wrote:
>>>>
>>>>
>>>> Is 14afee4b6092f ("net: convert sock.sk_wmem_alloc from atomic_t to
>>>> refcount_t") correct? That looks like a statistics counter, not a
>>>> refcounter? I can't quite tell, though...
>>>
>>>
>>>
>>> Hmm, yes, it looks a bit weird, but it is used in a refcount fashion
>>> here:
>>>
>>> void sk_free(struct sock *sk)
>>> {
>>>         /*
>>>          * We subtract one from sk_wmem_alloc and can know if
>>>          * some packets are still in some tx queue.
>>>          * If not null, sock_wfree() will call __sk_free(sk) later
>>>          */
>>>         if (refcount_dec_and_test(&sk->sk_wmem_alloc))
>>>                 __sk_free(sk);
>>> }
>>>
>>> http://elixir.free-electrons.com/linux/v4.13-rc1/source/net/core/sock.c#L1605
>>
>>
>> Ah yeah, there it is. Hrmpf. Something is triggering WARNs, though...
>> I wonder if this can get examined more closely?
>
>
> I tried reproducing the error but I don't seem to know how to use lkp. Got
> lots of permission denied errors and finally ran out of disk space (after
> using up ~50GB).
>
> Maybe I did something wrong?
>
> What I did was: Cloned the related kernel repository, checked out offending
> commit, plopped in config, compiled bzImage. Then I just cloned the lkp repo
> and tried running the provided command line with the bzImage and provided
> script.
>
> I'll take another look once I have the time, might be I missed something
> earlier.

Yeah, I'm not sure. Seems it was found through trinity? And only after
36 seconds, too.

>> Also, why not atomic->refcount for sk_rmem_alloc?
>
> I couldn't find any similar refcount-like use on sk_rmem_alloc.

Okay, interesting.

> And as noted the sk_wmem_alloc thing is also a bit dubious. It looks like it
> serves a dual purpose of actual allocation size and occasional reference
> counter.

Could you ask net-dev to see what is actually happening here? This
looks like a regression, but also very odd (broken?) refcounting ...

-Kees


-- 
Kees Cook
Pixel Security

[toc] | [prev] | [next] | [standalone]

#1697988 — Re: [lkp-robot] [x86/refcount] b631e535c6: WARNING:at_net/netlink/af_netlink.c:#netlink_sock_destruct

FromHans Liljestrand <liljestrandh@gmail.com>
Date2017-07-27 15:40 +0200
SubjectRe: [lkp-robot] [x86/refcount] b631e535c6: WARNING:at_net/netlink/af_netlink.c:#netlink_sock_destruct
Message-ID<u7Rbb-6Gi-1@gated-at.bofh.it>
In reply to#1696022
On Tue, Jul 25, 2017 at 11:38:30AM -0700, Kees Cook wrote:
>On Tue, Jul 25, 2017 at 3:43 AM, Hans Liljestrand
><liljestrandh@gmail.com> wrote:
>> On Mon, Jul 24, 2017 at 08:21:16PM -0700, Kees Cook wrote:
>>>
>>> On Mon, Jul 24, 2017 at 6:03 AM, Hans Liljestrand
>>> <liljestrandh@gmail.com> wrote:
>>>>
>>>> On Sun, Jul 23, 2017 at 08:52:53PM -0700, Kees Cook wrote:
>>>>>
>>>>>
>>>>> Is 14afee4b6092f ("net: convert sock.sk_wmem_alloc from atomic_t to
>>>>> refcount_t") correct? That looks like a statistics counter, not a
>>>>> refcounter? I can't quite tell, though...
>>>>
>>>>
>>>>
>>>> Hmm, yes, it looks a bit weird, but it is used in a refcount fashion
>>>> here:
>>>>
>>>> void sk_free(struct sock *sk)
>>>> {
>>>>         /*
>>>>          * We subtract one from sk_wmem_alloc and can know if
>>>>          * some packets are still in some tx queue.
>>>>          * If not null, sock_wfree() will call __sk_free(sk) later
>>>>          */
>>>>         if (refcount_dec_and_test(&sk->sk_wmem_alloc))
>>>>                 __sk_free(sk);
>>>> }
>>>>
>>>> http://elixir.free-electrons.com/linux/v4.13-rc1/source/net/core/sock.c#L1605
>>>
>>>
>>> Ah yeah, there it is. Hrmpf. Something is triggering WARNs, though...
>>> I wonder if this can get examined more closely?
>>
>>
>> I tried reproducing the error but I don't seem to know how to use lkp. Got
>> lots of permission denied errors and finally ran out of disk space (after
>> using up ~50GB).
>>
>> Maybe I did something wrong?
>>
>> What I did was: Cloned the related kernel repository, checked out offending
>> commit, plopped in config, compiled bzImage. Then I just cloned the lkp repo
>> and tried running the provided command line with the bzImage and provided
>> script.
>>
>> I'll take another look once I have the time, might be I missed something
>> earlier.
>
>Yeah, I'm not sure. Seems it was found through trinity? And only after
>36 seconds, too.

I think I might have missed something here? I cannot find anything about 
trinity or 36 seconds? Although I either misplaced or didn't get the original 
email, so I'm not sure if it had some other attachments beyond the config and 
script?

>
>>> Also, why not atomic->refcount for sk_rmem_alloc?
>>
>> I couldn't find any similar refcount-like use on sk_rmem_alloc.
>
>Okay, interesting.
>
>> And as noted the sk_wmem_alloc thing is also a bit dubious. It looks like it
>> serves a dual purpose of actual allocation size and occasional reference
>> counter.
>
>Could you ask net-dev to see what is actually happening here? This
>looks like a regression, but also very odd (broken?) refcounting ...

Sure, but I'm unsure of what exactly I should be asking? If you have any more 
information on the trinity results I'd be happy to look at that beforehand?

Thanks,
-hans

>
>-Kees
>
>
>-- 
>Kees Cook
>Pixel Security

[toc] | [prev] | [standalone]

Back to top | Article view | linux.kernel

csiph-web