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-next>] [day] [month] [year] [list]
Message-ID: <CA+icZUUCNAUDVqg1D-brJtZ2_QRxW_2s+jv0T5MPpCE9Y-auvg@mail.gmail.com>
Date:	Tue, 1 Mar 2016 11:05:42 +0100
From:	Sedat Dilek <sedat.dilek@...il.com>
To:	Steven Rostedt <rostedt@...dmis.org>,
	Jiri Kosina <jikos@...nel.org>, Tejun Heo <tj@...nel.org>
Cc:	Lai Jiangshan <jiangshanlai@...il.com>,
	Benjamin Tissoires <benjamin.tissoires@...hat.com>,
	Paul McKenney <paulmck@...ux.vnet.ibm.com>,
	Andy Lutomirski <luto@...nel.org>,
	LKML <linux-kernel@...r.kernel.org>, linux-usb@...r.kernel.org,
	Greg Kroah-Hartman <gregkh@...uxfoundation.org>,
	Alan Stern <stern@...land.harvard.edu>,
	Felipe Balbi <balbi@...com>,
	Peter Zijlstra <peterz@...radead.org>,
	Ingo Molnar <mingo@...hat.com>
Subject: Re: [PATCH] usbhid: Fix lockdep unannotated irqs-off warning

On Tue, Oct 13, 2015 at 2:57 AM, Steven Rostedt <rostedt@...dmis.org> wrote:
> On Sat, 3 Oct 2015 12:05:42 +0200
> Sedat Dilek <sedat.dilek@...il.com> wrote:
>
>> So, at the beginning... dunno WTF is causing the problems - no
>> workaround for CLANG.
>
> Probably need to compile with gcc and with clang and look at the binary
> differences. Or at least what objdump shows.
>

[ Hope to address this issue to the correct people - CCed some people
I taped on their nerves ]

Not sure if I should open a new thread?
Please, some clear statements on this.
Thanks.

The issue is still visible and alive.

I switched over to Linux v4.4.y LTS and CLANG v3.8 (currently "rc3").
My GCC is still v4.9.2.
CONFIG_PARAVIRT=n as suggested by Steven is the only difference when
using CLANG.

I have seen those bug-lines first with Linux v4.2.y.
BTW, my recent testing was done with Linux v4.5-rc6 and my llvmlinux
patchset (see file attachments).

Plugging my Logitech mouse to a USB 2.0 or 3.0 port does not matter.

[ FACT #1: LOG-FILES  ]

The simple fact, the bug-lines/outputs are only visible with
CLANG-compiled Linux-kernel but not GCC-compiled ones.
Folks tend to speculate on a compiler-bug - I am not sure, really.

[ FACT #2: TEST-CASE #1 ]

Doing wild cut-n-paste in Firefox crashed all my Linux v4.4.3 kernels
- CLANG and GCC (!) compiled.
Means restarting my X/desktop and landing in LightDM login-manager
here on Ubuntu/precise AMD64.

[ FACT #3: TEST-CASE #2 ]

The most reliable test-case is to simply unplug my external Logitech
USB mouse - saw this by accident.
YES, it was so simple.

--- dmesg_4.5.0-rc6-2-llvmlinux-amd64.txt       2016-02-29
21:23:56.399691975 +0100
+++ dmesg_4.5.0-rc6-2-llvmlinux-amd64_usbmouse-unplugged.txt
2016-02-29 21:28:14.401832240 +0100
@@ -832,3 +832,75 @@
 [   66.529779] PPP BSD Compression module registered
 [   66.563013] PPP Deflate Compression module registered
 [   66.978977] usb 2-1.5: USB disconnect, device number 4
+[  321.937369] usb 2-1.4: USB disconnect, device number 3
+[  321.950810] BUG: sleeping function called from invalid context at
kernel/workqueue.c:2785
+[  321.950816] in_atomic(): 0, irqs_disabled(): 1, pid: 44, name: kworker/2:1
+[  321.950819] 9 locks held by kworker/2:1/44:
+[  321.950820]  #0:  ("usb_hub_wq"){.+.+.+}, at: [<ffffffff810a7c5f>]
process_one_work+0x30f/0x8d0
+[  321.950830]  #1:  ((&hub->events)){+.+.+.}, at:
[<ffffffff810a7c8c>] process_one_work+0x33c/0x8d0
+[  321.950836]  #2:  (&dev->mutex){......}, at: [<ffffffff816fb0e0>]
hub_event+0x50/0x15b0
+[  321.950844]  #3:  (&dev->mutex){......}, at: [<ffffffff816f686f>]
usb_disconnect+0x5f/0x2c0
+[  321.950849]  #4:  (&dev->mutex){......}, at: [<ffffffff816245a2>]
device_release_driver+0x22/0x40
+[  321.950856]  #5:  (&dev->mutex){......}, at: [<ffffffff816245a2>]
device_release_driver+0x22/0x40
+[  321.950862]  #6:  (input_mutex){+.+.+.}, at: [<ffffffff8175171a>]
__input_unregister_device+0x9a/0x190
+[  321.950869]  #7:  (&dev->mutex#2){+.+...}, at:
[<ffffffff8174fe27>] input_close_device+0x27/0x70
+[  321.950875]  #8:  (hid_open_mut){+.+...}, at: [<ffffffffa0057388>]
usbhid_close+0x28/0xb0 [usbhid]
+[  321.950883] irq event stamp: 47770
+[  321.950885] hardirqs last  enabled at (47769):
[<ffffffff819426a2>] _raw_spin_unlock_irq+0x32/0x60
+[  321.950889] hardirqs last disabled at (47770):
[<ffffffff81115bdc>] del_timer_sync+0x3c/0x110
+[  321.950894] softirqs last  enabled at (47112):
[<ffffffff810871a2>] __do_softirq+0x5a2/0x610
+[  321.950898] softirqs last disabled at (47097):
[<ffffffff8108747c>] irq_exit+0x9c/0x120
+[  321.950903] CPU: 2 PID: 44 Comm: kworker/2:1 Not tainted
4.5.0-rc6-2-llvmlinux-amd64 #1
+[  321.950905] Hardware name: SAMSUNG ELECTRONICS CO., LTD.
530U3BI/530U4BI/530U4BH/530U3BI/530U4BI/530U4BH, BIOS 13XK 03/28/2013
+[  321.950908] Workqueue: usb_hub_wq hub_event
+[  321.950911]  ffff8800d3326948 0000000000000092 0000000000000000
ffff8800d4347568
+[  321.950915]  ffffffff814ba7d4 ffff8800d43474f8 ffff8800d4340cc0
ffff8800d4347568
+[  321.950919]  ffffffff810e28fd 0000000000000092 0000000000000096
ffff8800d43475a8
+[  321.950923] Call Trace:
+[  321.950927]  [<ffffffff814ba7d4>] dump_stack+0xa4/0xf0
+[  321.950931]  [<ffffffff810e28fd>] ? print_irqtrace_events+0xcd/0xe0
+[  321.950936]  [<ffffffff810bf495>] ___might_sleep+0x295/0x2b0
+[  321.950939]  [<ffffffff810bf18f>] __might_sleep+0x4f/0xc0
+[  321.950943]  [<ffffffff810a12ef>] start_flush_work+0x2f/0x2a0
+[  321.950946]  [<ffffffff810a129c>] flush_work+0x5c/0x80
+[  321.950949]  [<ffffffff810a125a>] ? flush_work+0x1a/0x80
+[  321.950953]  [<ffffffff810e247d>] ? trace_hardirqs_off+0xd/0x10
+[  321.950956]  [<ffffffff810a032a>] ? try_to_grab_pending+0x4a/0x260
+[  321.950960]  [<ffffffff810a1717>] __cancel_work_timer+0x197/0x290
+[  321.950963]  [<ffffffff81115b8d>] ? try_to_del_timer_sync+0xad/0xc0
+[  321.950966]  [<ffffffff810a1578>] cancel_work_sync+0x18/0x20
+[  321.950970]  [<ffffffffa00573d5>] usbhid_close+0x75/0xb0 [usbhid]
+[  321.950977]  [<ffffffffa003a481>] hidinput_close+0x31/0x40 [hid]
+[  321.950982]  [<ffffffffa003a450>] ? hidinput_open+0x40/0x40 [hid]
+[  321.950985]  [<ffffffff8174fe48>] input_close_device+0x48/0x70
+[  321.950988]  [<ffffffff81757f85>] evdev_cleanup+0xd5/0xe0
+[  321.950990]  [<ffffffff81757b0c>] evdev_disconnect+0x2c/0x60
+[  321.950993]  [<ffffffff8175173e>] __input_unregister_device+0xbe/0x190
+[  321.950996]  [<ffffffff8175164a>] input_unregister_device+0x4a/0x80
+[  321.951001]  [<ffffffffa003a29f>] hidinput_disconnect+0x8f/0xc0 [hid]
+[  321.951007]  [<ffffffffa0034a30>] hid_device_remove+0xb0/0x130 [hid]
+[  321.951010]  [<ffffffff816246bd>] __device_release_driver+0xfd/0x190
+[  321.951014]  [<ffffffff816245aa>] device_release_driver+0x2a/0x40
+[  321.951017]  [<ffffffff816224a3>] bus_remove_device+0x153/0x190
+[  321.951020]  [<ffffffff8161f5fb>] device_del+0x1db/0x2b0
+[  321.951025]  [<ffffffffa0033c1c>] hid_destroy_device+0x2c/0x60 [hid]
+[  321.951029]  [<ffffffffa0058537>] usbhid_disconnect+0x67/0x90 [usbhid]
+[  321.951033]  [<ffffffff81706ebf>] usb_unbind_interface+0xbf/0x2b0
+[  321.951037]  [<ffffffff816246bd>] __device_release_driver+0xfd/0x190
+[  321.951040]  [<ffffffff816245aa>] device_release_driver+0x2a/0x40
+[  321.951043]  [<ffffffff816224a3>] bus_remove_device+0x153/0x190
+[  321.951046]  [<ffffffff8161f5fb>] device_del+0x1db/0x2b0
+[  321.951048]  [<ffffffff8161f6fc>] ? device_unregister+0x2c/0x40
+[  321.951051]  [<ffffffff81704f6b>] usb_disable_device+0x10b/0x3b0
+[  321.951054]  [<ffffffff816f6904>] usb_disconnect+0xf4/0x2c0
+[  321.951057]  [<ffffffff816fbc3d>] hub_event+0xbad/0x15b0
+[  321.951060]  [<ffffffff819426a2>] ? _raw_spin_unlock_irq+0x32/0x60
+[  321.951063]  [<ffffffff810a7e0e>] process_one_work+0x4be/0x8d0
+[  321.951065]  [<ffffffff810a7c8c>] ? process_one_work+0x33c/0x8d0
+[  321.951068]  [<ffffffff810a757b>] worker_thread+0x5cb/0x750
+[  321.951071]  [<ffffffff810a6fb0>] ? destroy_worker+0x110/0x110
+[  321.951074]  [<ffffffff810ae1c5>] kthread+0x115/0x120
+[  321.951077]  [<ffffffff810e248d>] ? trace_hardirqs_on+0xd/0x10
+[  321.951080]  [<ffffffff810ae0b0>] ? flush_kthread_worker+0x80/0x80
+[  321.951084]  [<ffffffff819435ff>] ret_from_fork+0x3f/0x70
+[  321.951087]  [<ffffffff810ae0b0>] ? flush_kthread_worker+0x80/0x80

As this touches workqueue and usb_hub_wq...

[ drivers/usb/core/hub.c ]

5214:    hub_wq = alloc_workqueue("usb_hub_wq", WQ_FREEZABLE, 0);

...see...

+[  321.950908] Workqueue: usb_hub_wq hub_event

...I have CCed USB core maintainers ans folks I know they can help.

Here some Linux kernel-config I have enabled to investigate the issue...

[ LINUX-CONFIG ]

$ egrep 'CONFIG_TRACING=|TRACE_IRQFLAGS|IRQSOFF_TRACER|CONTEXT_TRACKING|LOCKDEP=|PROVE_LOCKING'
/tmp/config-4.5.0-rc6-2-llvmlinux-amd64
CONFIG_CONTEXT_TRACKING=y
# CONFIG_CONTEXT_TRACKING_FORCE is not set
CONFIG_HAVE_CONTEXT_TRACKING=y
CONFIG_TRACE_IRQFLAGS_SUPPORT=y
CONFIG_PROVE_LOCKING=y
CONFIG_LOCKDEP=y
CONFIG_DEBUG_LOCKDEP=y
CONFIG_TRACE_IRQFLAGS=y
CONFIG_TRACING=y
CONFIG_IRQSOFF_TRACER=y

For more details please, see attached files!

Sorry, this is far beyond a cool bug-report, but I could do it like
this for the moment.

Hope this helps to get some interesting and new ideas.

- Sedat -

View attachment "dmesg_4.5.0-rc6-2-llvmlinux-amd64_usbmouse-unplugged.txt" of type "text/plain" (63090 bytes)

Download attachment "config-4.5.0-rc6-2-llvmlinux-amd64" of type "application/octet-stream" (132070 bytes)

View attachment "4.5.0-rc6-2-llvmlinux-amd64.patch" of type "text/x-diff" (29257 bytes)

Powered by blists - more mailing lists

Powered by Openwall GNU/*/Linux Powered by OpenVZ