On 3/1/16, Peter Zijlstra <peterz@xxxxxxxxxxxxx> wrote:
> On Tue, Mar 01, 2016 at 10:07:40AM -0500, Steven Rostedt wrote:
>> On Tue, 1 Mar 2016 11:05:42 +0100
>> Sedat Dilek <sedat.dilek@xxxxxxxxx> wrote:
>>
>>
>> > [ 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.
>>
>> Just to clarify, this happens on gcc and clang?
>
> Just clang from what I gather.
>
YES, gcc, but I can crash my Xorg, but do not see a pile of nothing in
my dmesg-log.
>> > --- 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
>>
>> According to lockdep, interrupts were last disabled in del_timer_sync,
>> and they were never enabled. The numbers in parenthesis show the order
>> of events. _raw_spin_unlock_irq() at 47769, then del_timer_sync at
>> 47770.
>>
>> But why did they not get enabled again? We have:
>>
>> local_irq_save(flags);
>> lock_map_acquire(&timer->lockdep_map);
>> lock_map_release(&timer->lockdep_map);
>> local_irq_restore(flags);
>>
>> If this caused an issue, then you would have a lockdep splat. But
>> perhaps something corrupted "flags", and interrupts were not re-enabled?
>
> Right, most odd. Sedat, could you provide objdump -D of the relevant
> sections of vmlinux ?
>
Can you give some clear instructions - for what shall I look for in special?
I can send you a 300MiB mail-bomb if you like :-).
$ cd linux-git
$ objdump -D vmlinux > ../objdump-D_vmlinux.txt
$ du -m ../objdump-D_vmlinux.txt
294 ../objdump-D_vmlinux.txt
I have now built with the same kernel-config for gcc and clang and
archived the most interesting stuff.
Before sending the stuff out, I would like to have some clear instructions.
Thanks.
- Sedat -
--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html
