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

Groups > linux.kernel > #1233623 > unrolled thread

Re: [GIT PULL rcu/urgent] Fix two more 4.3 regressions

Started bySedat Dilek <sedat.dilek@gmail.com>
First post2015-09-27 08:30 +0200
Last post2015-09-27 09:40 +0200
Articles 13 — 3 participants

Back to article view | Back to linux.kernel

Contents

  Re: [GIT PULL rcu/urgent] Fix two more 4.3 regressions Sedat Dilek <sedat.dilek@gmail.com> - 2015-09-27 08:30 +0200
    Re: [GIT PULL rcu/urgent] Fix two more 4.3 regressions Sedat Dilek <sedat.dilek@gmail.com> - 2015-09-27 09:40 +0200
      Re: [GIT PULL rcu/urgent] Fix two more 4.3 regressions "Paul E. McKenney" <paulmck@linux.vnet.ibm.com> - 2015-09-27 17:50 +0200
        Re: [GIT PULL rcu/urgent] Fix two more 4.3 regressions Sedat Dilek <sedat.dilek@gmail.com> - 2015-09-27 18:00 +0200
          Re: [GIT PULL rcu/urgent] Fix two more 4.3 regressions Sedat Dilek <sedat.dilek@gmail.com> - 2015-09-27 18:20 +0200
            Re: [GIT PULL rcu/urgent] Fix two more 4.3 regressions Sedat Dilek <sedat.dilek@gmail.com> - 2015-09-27 18:30 +0200
              Re: [GIT PULL rcu/urgent] Fix two more 4.3 regressions "Paul E. McKenney" <paulmck@linux.vnet.ibm.com> - 2015-09-27 18:50 +0200
          Re: [GIT PULL rcu/urgent] Fix two more 4.3 regressions "Paul E. McKenney" <paulmck@linux.vnet.ibm.com> - 2015-09-27 18:50 +0200
            Re: [GIT PULL rcu/urgent] Fix two more 4.3 regressions Sedat Dilek <sedat.dilek@gmail.com> - 2015-09-27 19:30 +0200
              Re: [GIT PULL rcu/urgent] Fix two more 4.3 regressions "Paul E. McKenney" <paulmck@linux.vnet.ibm.com> - 2015-09-27 19:50 +0200
      Re: [GIT PULL rcu/urgent] Fix two more 4.3 regressions Ingo Molnar <mingo@kernel.org> - 2015-09-28 08:10 +0200
        Re: [GIT PULL rcu/urgent] Fix two more 4.3 regressions Sedat Dilek <sedat.dilek@gmail.com> - 2015-09-28 08:30 +0200
    Re: [GIT PULL rcu/urgent] Fix two more 4.3 regressions "Paul E. McKenney" <paulmck@linux.vnet.ibm.com> - 2015-09-27 09:40 +0200

#1233623 — Re: [GIT PULL rcu/urgent] Fix two more 4.3 regressions

FromSedat Dilek <sedat.dilek@gmail.com>
Date2015-09-27 08:30 +0200
SubjectRe: [GIT PULL rcu/urgent] Fix two more 4.3 regressions
Message-ID<qddDc-7ru-7@gated-at.bofh.it>
Hi,

as I have observed here some lockdep issues (one could be solved in
netdev) I wanted to try this patchset.

Unfortunately, you cannot pull from...

"These changes are available in the git repository at:

  git://git.kernel.org/pub/scm/linux/kernel/git/paulmck/linux-rcu.git for-mingo

for you to fetch changes up to 19a5ecde086a6a5287978b12ae948fa691b197b7:

  rcu: Suppress lockdep false positive for rcp->exp_funnel_mutex
(2015-09-20 21:01:22 -0700)

----------------------------------------------------------------
Oleg Nesterov (1):
      rcu: Change _wait_rcu_gp() to work around GCC bug 67055

Paul E. McKenney (1):
      rcu: Suppress lockdep false positive for rcp->exp_funnel_mutex

 include/linux/rcupdate.h | 11 +++++------
 kernel/rcu/tree.c        |  5 +++++
 2 files changed, 10 insertions(+), 6 deletions(-)"

So, I have stolen them from linux-next.git.

Please look at this, Thanks.

Regards,
- Sedat -

[1] http://marc.info/?l=linux-kernel&m=144332758307978&w=2
[2] http://git.kernel.org/cgit/linux/kernel/git/next/linux-next.git/patch/?id=66e8c57da6bf6b847a48a5a6fda59512f733ed78
[3] http://git.kernel.org/cgit/linux/kernel/git/next/linux-next.git/patch/?id=19a5ecde086a6a5287978b12ae948fa691b197b7
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/

[toc] | [next] | [standalone]

#1233634

FromSedat Dilek <sedat.dilek@gmail.com>
Date2015-09-27 09:40 +0200
Message-ID<qdeIV-vP-7@gated-at.bofh.it>
In reply to#1233623
On Sun, Sep 27, 2015 at 9:32 AM, Paul E. McKenney
<paulmck@linux.vnet.ibm.com> wrote:
> On Sun, Sep 27, 2015 at 08:28:39AM +0200, Sedat Dilek wrote:
>> Hi,
>>
>> as I have observed here some lockdep issues (one could be solved in
>> netdev) I wanted to try this patchset.
>>
>> Unfortunately, you cannot pull from...
>>
>> "These changes are available in the git repository at:
>>
>>   git://git.kernel.org/pub/scm/linux/kernel/git/paulmck/linux-rcu.git for-mingo
>>
>> for you to fetch changes up to 19a5ecde086a6a5287978b12ae948fa691b197b7:
>>
>>   rcu: Suppress lockdep false positive for rcp->exp_funnel_mutex
>> (2015-09-20 21:01:22 -0700)
>>
>> ----------------------------------------------------------------
>> Oleg Nesterov (1):
>>       rcu: Change _wait_rcu_gp() to work around GCC bug 67055
>>
>> Paul E. McKenney (1):
>>       rcu: Suppress lockdep false positive for rcp->exp_funnel_mutex
>>
>>  include/linux/rcupdate.h | 11 +++++------
>>  kernel/rcu/tree.c        |  5 +++++
>>  2 files changed, 10 insertions(+), 6 deletions(-)"
>>
>> So, I have stolen them from linux-next.git.
>>
>> Please look at this, Thanks.
>
> Does it work better now?  (Forgot to actually push the new name...)
>

Hi Paul,

now for-mingo Git branch has this two fixes.
I just booted into my new kernel with the "stolen" rcu.fixes from -next.

For the lockdep problems I will do a CONFIG_DEBUG_LOCKDEP=y to see if
I get some more infos on the workqueue trouble.

[   23.874836] BUG: sleeping function called from invalid context at
kernel/workqueue.c:2678
[   23.874902] in_atomic(): 0, irqs_disabled(): 1, pid: 1411, name: acpid

$ grep LOCKDEP /boot/config-4.3.0-rc2-438.1-llvmlinux-amd64
CONFIG_LOCKDEP_SUPPORT=y
CONFIG_LOCKDEP=y
# CONFIG_DEBUG_LOCKDEP is not set

So, CLANG is a bit different compiler :-).

Thanks for taking care.

Regards,
- Sedat -

>>
>> [1] http://marc.info/?l=linux-kernel&m=144332758307978&w=2
>> [2] http://git.kernel.org/cgit/linux/kernel/git/next/linux-next.git/patch/?id=66e8c57da6bf6b847a48a5a6fda59512f733ed78
>> [3] http://git.kernel.org/cgit/linux/kernel/git/next/linux-next.git/patch/?id=19a5ecde086a6a5287978b12ae948fa691b197b7
>>
>
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/

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

#1233695

From"Paul E. McKenney" <paulmck@linux.vnet.ibm.com>
Date2015-09-27 17:50 +0200
Message-ID<qdmn8-31g-9@gated-at.bofh.it>
In reply to#1233634
On Sun, Sep 27, 2015 at 09:37:05AM +0200, Sedat Dilek wrote:
> On Sun, Sep 27, 2015 at 9:32 AM, Paul E. McKenney
> <paulmck@linux.vnet.ibm.com> wrote:
> > On Sun, Sep 27, 2015 at 08:28:39AM +0200, Sedat Dilek wrote:
> >> Hi,
> >>
> >> as I have observed here some lockdep issues (one could be solved in
> >> netdev) I wanted to try this patchset.
> >>
> >> Unfortunately, you cannot pull from...
> >>
> >> "These changes are available in the git repository at:
> >>
> >>   git://git.kernel.org/pub/scm/linux/kernel/git/paulmck/linux-rcu.git for-mingo
> >>
> >> for you to fetch changes up to 19a5ecde086a6a5287978b12ae948fa691b197b7:
> >>
> >>   rcu: Suppress lockdep false positive for rcp->exp_funnel_mutex
> >> (2015-09-20 21:01:22 -0700)
> >>
> >> ----------------------------------------------------------------
> >> Oleg Nesterov (1):
> >>       rcu: Change _wait_rcu_gp() to work around GCC bug 67055
> >>
> >> Paul E. McKenney (1):
> >>       rcu: Suppress lockdep false positive for rcp->exp_funnel_mutex
> >>
> >>  include/linux/rcupdate.h | 11 +++++------
> >>  kernel/rcu/tree.c        |  5 +++++
> >>  2 files changed, 10 insertions(+), 6 deletions(-)"
> >>
> >> So, I have stolen them from linux-next.git.
> >>
> >> Please look at this, Thanks.
> >
> > Does it work better now?  (Forgot to actually push the new name...)
> 
> Hi Paul,
> 
> now for-mingo Git branch has this two fixes.

Whew!!!  Apologies for the hassle!

> I just booted into my new kernel with the "stolen" rcu.fixes from -next.
> 
> For the lockdep problems I will do a CONFIG_DEBUG_LOCKDEP=y to see if
> I get some more infos on the workqueue trouble.
> 
> [   23.874836] BUG: sleeping function called from invalid context at
> kernel/workqueue.c:2678
> [   23.874902] in_atomic(): 0, irqs_disabled(): 1, pid: 1411, name: acpid

Did you get a stack trace?  There are quite a few potential callers of
start_flush_work() via flush_work().

> $ grep LOCKDEP /boot/config-4.3.0-rc2-438.1-llvmlinux-amd64
> CONFIG_LOCKDEP_SUPPORT=y
> CONFIG_LOCKDEP=y
> # CONFIG_DEBUG_LOCKDEP is not set
> 
> So, CLANG is a bit different compiler :-).

True enough.  Good to have more than one, though.

							Thanx, Paul

> Thanks for taking care.
> 
> Regards,
> - Sedat -
> 
> >>
> >> [1] http://marc.info/?l=linux-kernel&m=144332758307978&w=2
> >> [2] http://git.kernel.org/cgit/linux/kernel/git/next/linux-next.git/patch/?id=66e8c57da6bf6b847a48a5a6fda59512f733ed78
> >> [3] http://git.kernel.org/cgit/linux/kernel/git/next/linux-next.git/patch/?id=19a5ecde086a6a5287978b12ae948fa691b197b7
> >>
> >
> 

--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/

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

#1233697

FromSedat Dilek <sedat.dilek@gmail.com>
Date2015-09-27 18:00 +0200
Message-ID<qdmwO-3cB-11@gated-at.bofh.it>
In reply to#1233695
On Sun, Sep 27, 2015 at 5:49 PM, Paul E. McKenney
<paulmck@linux.vnet.ibm.com> wrote:
> On Sun, Sep 27, 2015 at 09:37:05AM +0200, Sedat Dilek wrote:
>> On Sun, Sep 27, 2015 at 9:32 AM, Paul E. McKenney
>> <paulmck@linux.vnet.ibm.com> wrote:
>> > On Sun, Sep 27, 2015 at 08:28:39AM +0200, Sedat Dilek wrote:
>> >> Hi,
>> >>
>> >> as I have observed here some lockdep issues (one could be solved in
>> >> netdev) I wanted to try this patchset.
>> >>
>> >> Unfortunately, you cannot pull from...
>> >>
>> >> "These changes are available in the git repository at:
>> >>
>> >>   git://git.kernel.org/pub/scm/linux/kernel/git/paulmck/linux-rcu.git for-mingo
>> >>
>> >> for you to fetch changes up to 19a5ecde086a6a5287978b12ae948fa691b197b7:
>> >>
>> >>   rcu: Suppress lockdep false positive for rcp->exp_funnel_mutex
>> >> (2015-09-20 21:01:22 -0700)
>> >>
>> >> ----------------------------------------------------------------
>> >> Oleg Nesterov (1):
>> >>       rcu: Change _wait_rcu_gp() to work around GCC bug 67055
>> >>
>> >> Paul E. McKenney (1):
>> >>       rcu: Suppress lockdep false positive for rcp->exp_funnel_mutex
>> >>
>> >>  include/linux/rcupdate.h | 11 +++++------
>> >>  kernel/rcu/tree.c        |  5 +++++
>> >>  2 files changed, 10 insertions(+), 6 deletions(-)"
>> >>
>> >> So, I have stolen them from linux-next.git.
>> >>
>> >> Please look at this, Thanks.
>> >
>> > Does it work better now?  (Forgot to actually push the new name...)
>>
>> Hi Paul,
>>
>> now for-mingo Git branch has this two fixes.
>
> Whew!!!  Apologies for the hassle!
>
>> I just booted into my new kernel with the "stolen" rcu.fixes from -next.
>>
>> For the lockdep problems I will do a CONFIG_DEBUG_LOCKDEP=y to see if
>> I get some more infos on the workqueue trouble.
>>
>> [   23.874836] BUG: sleeping function called from invalid context at
>> kernel/workqueue.c:2678
>> [   23.874902] in_atomic(): 0, irqs_disabled(): 1, pid: 1411, name: acpid
>
> Did you get a stack trace?  There are quite a few potential callers of
> start_flush_work() via flush_work().
>

Hi Paul :-),

Here is the stack trace.

[   23.045871] BUG: sleeping function called from invalid context at
kernel/workqueue.c:2678
[   23.045982] in_atomic(): 0, irqs_disabled(): 1, pid: 1399, name: acpid
[   23.046064] 3 locks held by acpid/1399:
[   23.046066]  #0:  (&evdev->mutex){+.+...}, at: [<ffffffff8174ac7c>]
evdev_release+0xbc/0xf0
[   23.046081]  #1:  (&dev->mutex#2){+.+...}, at: [<ffffffff81742397>]
input_close_device+0x27/0x70
[   23.046093]  #2:  (hid_open_mut){+.+...}, at: [<ffffffffa0056388>]
usbhid_close+0x28/0xb0 [usbhid]
[   23.046106] irq event stamp: 3306
[   23.046109] hardirqs last  enabled at (3305): [<ffffffff8192ae32>]
_raw_spin_unlock_irq+0x32/0x60
[   23.046115] hardirqs last disabled at (3306): [<ffffffff81121017>]
del_timer_sync+0x37/0x110
[   23.046122] softirqs last  enabled at (2704): [<ffffffff818b12c9>]
local_bh_enable+0x9/0x20
[   23.046128] softirqs last disabled at (2702): [<ffffffff818b12a9>]
local_bh_disable+0x9/0x20
[   23.046136] CPU: 2 PID: 1399 Comm: acpid Not tainted
4.3.0-rc3-3-llvmlinux-amd64 #1
[   23.046139] Hardware name: SAMSUNG ELECTRONICS CO., LTD.
530U3BI/530U4BI/530U4BH/530U3BI/530U4BI/530U4BH, BIOS 13XK 03/28/2013
[   23.046143]  ffff8800d36ee948 0000000000000092 0000000000000000
ffff8800bbacfae8
[   23.046151]  ffffffff8149adad ffff8800bbacfb18 ffffffff810cd1ea
ffffffff81c56f0a
[   23.046158]  ffff8800c22dc400 0000000000000000 0000000000000a76
ffff8800bbacfb58
[   23.046165] Call Trace:
[   23.046172]  [<ffffffff8149adad>] dump_stack+0x7d/0xa0
[   23.046177]  [<ffffffff810cd1ea>] ___might_sleep+0x28a/0x2a0
[   23.046182]  [<ffffffff810cceef>] __might_sleep+0x4f/0xc0
[   23.046187]  [<ffffffff810afbff>] start_flush_work+0x2f/0x290
[   23.046192]  [<ffffffff810afbac>] flush_work+0x5c/0x80
[   23.046195]  [<ffffffff810afb6a>] ? flush_work+0x1a/0x80
[   23.046202]  [<ffffffff810eed0d>] ? trace_hardirqs_off+0xd/0x10
[   23.046206]  [<ffffffff810aecc8>] ? try_to_grab_pending+0x48/0x360
[   23.046211]  [<ffffffff8192ac53>] ? _raw_spin_lock_irqsave+0x73/0x80
[   23.046216]  [<ffffffff810afff9>] __cancel_work_timer+0x179/0x260
[   23.046221]  [<ffffffff8192add2>] ? _raw_spin_unlock_irqrestore+0x52/0x80
[   23.046226]  [<ffffffff81120fcd>] ? try_to_del_timer_sync+0xad/0xc0
[   23.046230]  [<ffffffff810afe78>] cancel_work_sync+0x18/0x20
[   23.046237]  [<ffffffffa00563d5>] usbhid_close+0x75/0xb0 [usbhid]
[   23.046245]  [<ffffffffa00394d1>] hidinput_close+0x31/0x40 [hid]
[   23.046251]  [<ffffffffa00394a0>] ? hidinput_open+0x40/0x40 [hid]
[   23.046256]  [<ffffffff817423b8>] input_close_device+0x48/0x70
[   23.046261]  [<ffffffff8174ac96>] evdev_release+0xd6/0xf0
[   23.046267]  [<ffffffff812728c7>] __fput+0x107/0x240
[   23.046271]  [<ffffffff81272756>] ____fput+0x16/0x20
[   23.046276]  [<ffffffff810b945c>] task_work_run+0x6c/0xe0
[   23.046282]  [<ffffffff81003aa7>] prepare_exit_to_usermode+0x117/0x120
[   23.046287]  [<ffffffff81003ce1>] syscall_return_slowpath+0x231/0x2a0
[   23.046292]  [<ffffffff8126efa5>] ? filp_close+0x65/0x90
[   23.046298]  [<ffffffff810ef1c9>] ? trace_hardirqs_on_caller+0x19/0x290
[   23.046303]  [<ffffffff81003017>] ? trace_hardirqs_on_thunk+0x17/0x19
[   23.046308]  [<ffffffff8192bb62>] int_ret_from_sys_call+0x25/0x9f

Can you give help on how to "debug" this?

I switched from full-dynticks to simple cpu-accounting which did not help.
But this was only a suspicion as Jiri pointed to the possibility
del_timer_sync() could have get some mis-optimization.

So, more empty head here.

- Sedat -

>> $ grep LOCKDEP /boot/config-4.3.0-rc2-438.1-llvmlinux-amd64
>> CONFIG_LOCKDEP_SUPPORT=y
>> CONFIG_LOCKDEP=y
>> # CONFIG_DEBUG_LOCKDEP is not set
>>
>> So, CLANG is a bit different compiler :-).
>
> True enough.  Good to have more than one, though.
>
>                                                         Thanx, Paul
>
>> Thanks for taking care.
>>
>> Regards,
>> - Sedat -
>>
>> >>
>> >> [1] http://marc.info/?l=linux-kernel&m=144332758307978&w=2
>> >> [2] http://git.kernel.org/cgit/linux/kernel/git/next/linux-next.git/patch/?id=66e8c57da6bf6b847a48a5a6fda59512f733ed78
>> >> [3] http://git.kernel.org/cgit/linux/kernel/git/next/linux-next.git/patch/?id=19a5ecde086a6a5287978b12ae948fa691b197b7
>> >>
>> >
>>
>
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/

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

#1233704

FromSedat Dilek <sedat.dilek@gmail.com>
Date2015-09-27 18:20 +0200
Message-ID<qdmQ9-3Ov-11@gated-at.bofh.it>
In reply to#1233697
On Sun, Sep 27, 2015 at 6:02 PM, Sedat Dilek <sedat.dilek@gmail.com> wrote:
> On Sun, Sep 27, 2015 at 5:58 PM, Sedat Dilek <sedat.dilek@gmail.com> wrote:
>> On Sun, Sep 27, 2015 at 5:55 PM, Sedat Dilek <sedat.dilek@gmail.com> wrote:
>>> On Sun, Sep 27, 2015 at 5:49 PM, Paul E. McKenney
>>> <paulmck@linux.vnet.ibm.com> wrote:
>>>> On Sun, Sep 27, 2015 at 09:37:05AM +0200, Sedat Dilek wrote:
>>>>> On Sun, Sep 27, 2015 at 9:32 AM, Paul E. McKenney
>>>>> <paulmck@linux.vnet.ibm.com> wrote:
>>>>> > On Sun, Sep 27, 2015 at 08:28:39AM +0200, Sedat Dilek wrote:
>>>>> >> Hi,
>>>>> >>
>>>>> >> as I have observed here some lockdep issues (one could be solved in
>>>>> >> netdev) I wanted to try this patchset.
>>>>> >>
>>>>> >> Unfortunately, you cannot pull from...
>>>>> >>
>>>>> >> "These changes are available in the git repository at:
>>>>> >>
>>>>> >>   git://git.kernel.org/pub/scm/linux/kernel/git/paulmck/linux-rcu.git for-mingo
>>>>> >>
>>>>> >> for you to fetch changes up to 19a5ecde086a6a5287978b12ae948fa691b197b7:
>>>>> >>
>>>>> >>   rcu: Suppress lockdep false positive for rcp->exp_funnel_mutex
>>>>> >> (2015-09-20 21:01:22 -0700)
>>>>> >>
>>>>> >> ----------------------------------------------------------------
>>>>> >> Oleg Nesterov (1):
>>>>> >>       rcu: Change _wait_rcu_gp() to work around GCC bug 67055
>>>>> >>
>>>>> >> Paul E. McKenney (1):
>>>>> >>       rcu: Suppress lockdep false positive for rcp->exp_funnel_mutex
>>>>> >>
>>>>> >>  include/linux/rcupdate.h | 11 +++++------
>>>>> >>  kernel/rcu/tree.c        |  5 +++++
>>>>> >>  2 files changed, 10 insertions(+), 6 deletions(-)"
>>>>> >>
>>>>> >> So, I have stolen them from linux-next.git.
>>>>> >>
>>>>> >> Please look at this, Thanks.
>>>>> >
>>>>> > Does it work better now?  (Forgot to actually push the new name...)
>>>>>
>>>>> Hi Paul,
>>>>>
>>>>> now for-mingo Git branch has this two fixes.
>>>>
>>>> Whew!!!  Apologies for the hassle!
>>>>
>>>>> I just booted into my new kernel with the "stolen" rcu.fixes from -next.
>>>>>
>>>>> For the lockdep problems I will do a CONFIG_DEBUG_LOCKDEP=y to see if
>>>>> I get some more infos on the workqueue trouble.
>>>>>
>>>>> [   23.874836] BUG: sleeping function called from invalid context at
>>>>> kernel/workqueue.c:2678
>>>>> [   23.874902] in_atomic(): 0, irqs_disabled(): 1, pid: 1411, name: acpid
>>>>
>>>> Did you get a stack trace?  There are quite a few potential callers of
>>>> start_flush_work() via flush_work().
>>>>
>>>
>>> Hi Paul :-),
>>>
>>> Here is the stack trace.
>>>
>>> [   23.045871] BUG: sleeping function called from invalid context at
>>> kernel/workqueue.c:2678
>>> [   23.045982] in_atomic(): 0, irqs_disabled(): 1, pid: 1399, name: acpid
>>> [   23.046064] 3 locks held by acpid/1399:
>>> [   23.046066]  #0:  (&evdev->mutex){+.+...}, at: [<ffffffff8174ac7c>]
>>> evdev_release+0xbc/0xf0
>>> [   23.046081]  #1:  (&dev->mutex#2){+.+...}, at: [<ffffffff81742397>]
>>> input_close_device+0x27/0x70
>>> [   23.046093]  #2:  (hid_open_mut){+.+...}, at: [<ffffffffa0056388>]
>>> usbhid_close+0x28/0xb0 [usbhid]
>>> [   23.046106] irq event stamp: 3306
>>> [   23.046109] hardirqs last  enabled at (3305): [<ffffffff8192ae32>]
>>> _raw_spin_unlock_irq+0x32/0x60
>>> [   23.046115] hardirqs last disabled at (3306): [<ffffffff81121017>]
>>> del_timer_sync+0x37/0x110
>>> [   23.046122] softirqs last  enabled at (2704): [<ffffffff818b12c9>]
>>> local_bh_enable+0x9/0x20
>>> [   23.046128] softirqs last disabled at (2702): [<ffffffff818b12a9>]
>>> local_bh_disable+0x9/0x20
>>> [   23.046136] CPU: 2 PID: 1399 Comm: acpid Not tainted
>>> 4.3.0-rc3-3-llvmlinux-amd64 #1
>>> [   23.046139] Hardware name: SAMSUNG ELECTRONICS CO., LTD.
>>> 530U3BI/530U4BI/530U4BH/530U3BI/530U4BI/530U4BH, BIOS 13XK 03/28/2013
>>> [   23.046143]  ffff8800d36ee948 0000000000000092 0000000000000000
>>> ffff8800bbacfae8
>>> [   23.046151]  ffffffff8149adad ffff8800bbacfb18 ffffffff810cd1ea
>>> ffffffff81c56f0a
>>> [   23.046158]  ffff8800c22dc400 0000000000000000 0000000000000a76
>>> ffff8800bbacfb58
>>> [   23.046165] Call Trace:
>>> [   23.046172]  [<ffffffff8149adad>] dump_stack+0x7d/0xa0
>>> [   23.046177]  [<ffffffff810cd1ea>] ___might_sleep+0x28a/0x2a0
>>> [   23.046182]  [<ffffffff810cceef>] __might_sleep+0x4f/0xc0
>>> [   23.046187]  [<ffffffff810afbff>] start_flush_work+0x2f/0x290
>>> [   23.046192]  [<ffffffff810afbac>] flush_work+0x5c/0x80
>>> [   23.046195]  [<ffffffff810afb6a>] ? flush_work+0x1a/0x80
>>> [   23.046202]  [<ffffffff810eed0d>] ? trace_hardirqs_off+0xd/0x10
>>> [   23.046206]  [<ffffffff810aecc8>] ? try_to_grab_pending+0x48/0x360
>>> [   23.046211]  [<ffffffff8192ac53>] ? _raw_spin_lock_irqsave+0x73/0x80
>>> [   23.046216]  [<ffffffff810afff9>] __cancel_work_timer+0x179/0x260
>>> [   23.046221]  [<ffffffff8192add2>] ? _raw_spin_unlock_irqrestore+0x52/0x80
>>> [   23.046226]  [<ffffffff81120fcd>] ? try_to_del_timer_sync+0xad/0xc0
>>> [   23.046230]  [<ffffffff810afe78>] cancel_work_sync+0x18/0x20
>>> [   23.046237]  [<ffffffffa00563d5>] usbhid_close+0x75/0xb0 [usbhid]
>>> [   23.046245]  [<ffffffffa00394d1>] hidinput_close+0x31/0x40 [hid]
>>> [   23.046251]  [<ffffffffa00394a0>] ? hidinput_open+0x40/0x40 [hid]
>>> [   23.046256]  [<ffffffff817423b8>] input_close_device+0x48/0x70
>>> [   23.046261]  [<ffffffff8174ac96>] evdev_release+0xd6/0xf0
>>> [   23.046267]  [<ffffffff812728c7>] __fput+0x107/0x240
>>> [   23.046271]  [<ffffffff81272756>] ____fput+0x16/0x20
>>> [   23.046276]  [<ffffffff810b945c>] task_work_run+0x6c/0xe0
>>> [   23.046282]  [<ffffffff81003aa7>] prepare_exit_to_usermode+0x117/0x120
>>> [   23.046287]  [<ffffffff81003ce1>] syscall_return_slowpath+0x231/0x2a0
>>> [   23.046292]  [<ffffffff8126efa5>] ? filp_close+0x65/0x90
>>> [   23.046298]  [<ffffffff810ef1c9>] ? trace_hardirqs_on_caller+0x19/0x290
>>> [   23.046303]  [<ffffffff81003017>] ? trace_hardirqs_on_thunk+0x17/0x19
>>> [   23.046308]  [<ffffffff8192bb62>] int_ret_from_sys_call+0x25/0x9f
>>>
>>> Can you give help on how to "debug" this?
>>>
>>> I switched from full-dynticks to simple cpu-accounting which did not help.
>>> But this was only a suspicion as Jiri pointed to the possibility
>>> del_timer_sync() could have get some mis-optimization.
>>>
>>> So, more empty head here.
>>>
>>
>> Forgot to attach dmesg-log and my kernel-config.
>> Sorry about that.
>>
>
> Time for a pause!
>
> Forgot to attach disassembled kernel/workqueue.o.
>

When looking at start_flush_work() in kernel/workqueue.c...
...I remembered the comments of Lai Jiangshan concerning the
might_sleep() check there.

I tried to move the might_sleep() line to __cancel_work_timer() as
requested, but that did not help or narrowed down whatever.

Please see [1] for more details.

- Sedat -

[1] http://marc.info/?l=linux-kernel&m=144184707824750&w=2
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/

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

#1233705

FromSedat Dilek <sedat.dilek@gmail.com>
Date2015-09-27 18:30 +0200
Message-ID<qdmZP-401-3@gated-at.bofh.it>
In reply to#1233704
On Sun, Sep 27, 2015 at 6:16 PM, Sedat Dilek <sedat.dilek@gmail.com> wrote:
> On Sun, Sep 27, 2015 at 6:02 PM, Sedat Dilek <sedat.dilek@gmail.com> wrote:
>> On Sun, Sep 27, 2015 at 5:58 PM, Sedat Dilek <sedat.dilek@gmail.com> wrote:
>>> On Sun, Sep 27, 2015 at 5:55 PM, Sedat Dilek <sedat.dilek@gmail.com> wrote:
>>>> On Sun, Sep 27, 2015 at 5:49 PM, Paul E. McKenney
>>>> <paulmck@linux.vnet.ibm.com> wrote:
>>>>> On Sun, Sep 27, 2015 at 09:37:05AM +0200, Sedat Dilek wrote:
>>>>>> On Sun, Sep 27, 2015 at 9:32 AM, Paul E. McKenney
>>>>>> <paulmck@linux.vnet.ibm.com> wrote:
>>>>>> > On Sun, Sep 27, 2015 at 08:28:39AM +0200, Sedat Dilek wrote:
>>>>>> >> Hi,
>>>>>> >>
>>>>>> >> as I have observed here some lockdep issues (one could be solved in
>>>>>> >> netdev) I wanted to try this patchset.
>>>>>> >>
>>>>>> >> Unfortunately, you cannot pull from...
>>>>>> >>
>>>>>> >> "These changes are available in the git repository at:
>>>>>> >>
>>>>>> >>   git://git.kernel.org/pub/scm/linux/kernel/git/paulmck/linux-rcu.git for-mingo
>>>>>> >>
>>>>>> >> for you to fetch changes up to 19a5ecde086a6a5287978b12ae948fa691b197b7:
>>>>>> >>
>>>>>> >>   rcu: Suppress lockdep false positive for rcp->exp_funnel_mutex
>>>>>> >> (2015-09-20 21:01:22 -0700)
>>>>>> >>
>>>>>> >> ----------------------------------------------------------------
>>>>>> >> Oleg Nesterov (1):
>>>>>> >>       rcu: Change _wait_rcu_gp() to work around GCC bug 67055
>>>>>> >>
>>>>>> >> Paul E. McKenney (1):
>>>>>> >>       rcu: Suppress lockdep false positive for rcp->exp_funnel_mutex
>>>>>> >>
>>>>>> >>  include/linux/rcupdate.h | 11 +++++------
>>>>>> >>  kernel/rcu/tree.c        |  5 +++++
>>>>>> >>  2 files changed, 10 insertions(+), 6 deletions(-)"
>>>>>> >>
>>>>>> >> So, I have stolen them from linux-next.git.
>>>>>> >>
>>>>>> >> Please look at this, Thanks.
>>>>>> >
>>>>>> > Does it work better now?  (Forgot to actually push the new name...)
>>>>>>
>>>>>> Hi Paul,
>>>>>>
>>>>>> now for-mingo Git branch has this two fixes.
>>>>>
>>>>> Whew!!!  Apologies for the hassle!
>>>>>
>>>>>> I just booted into my new kernel with the "stolen" rcu.fixes from -next.
>>>>>>
>>>>>> For the lockdep problems I will do a CONFIG_DEBUG_LOCKDEP=y to see if
>>>>>> I get some more infos on the workqueue trouble.
>>>>>>
>>>>>> [   23.874836] BUG: sleeping function called from invalid context at
>>>>>> kernel/workqueue.c:2678
>>>>>> [   23.874902] in_atomic(): 0, irqs_disabled(): 1, pid: 1411, name: acpid
>>>>>
>>>>> Did you get a stack trace?  There are quite a few potential callers of
>>>>> start_flush_work() via flush_work().
>>>>>
>>>>
>>>> Hi Paul :-),
>>>>
>>>> Here is the stack trace.
>>>>
>>>> [   23.045871] BUG: sleeping function called from invalid context at
>>>> kernel/workqueue.c:2678
>>>> [   23.045982] in_atomic(): 0, irqs_disabled(): 1, pid: 1399, name: acpid
>>>> [   23.046064] 3 locks held by acpid/1399:
>>>> [   23.046066]  #0:  (&evdev->mutex){+.+...}, at: [<ffffffff8174ac7c>]
>>>> evdev_release+0xbc/0xf0
>>>> [   23.046081]  #1:  (&dev->mutex#2){+.+...}, at: [<ffffffff81742397>]
>>>> input_close_device+0x27/0x70
>>>> [   23.046093]  #2:  (hid_open_mut){+.+...}, at: [<ffffffffa0056388>]
>>>> usbhid_close+0x28/0xb0 [usbhid]
>>>> [   23.046106] irq event stamp: 3306
>>>> [   23.046109] hardirqs last  enabled at (3305): [<ffffffff8192ae32>]
>>>> _raw_spin_unlock_irq+0x32/0x60
>>>> [   23.046115] hardirqs last disabled at (3306): [<ffffffff81121017>]
>>>> del_timer_sync+0x37/0x110
>>>> [   23.046122] softirqs last  enabled at (2704): [<ffffffff818b12c9>]
>>>> local_bh_enable+0x9/0x20
>>>> [   23.046128] softirqs last disabled at (2702): [<ffffffff818b12a9>]
>>>> local_bh_disable+0x9/0x20
>>>> [   23.046136] CPU: 2 PID: 1399 Comm: acpid Not tainted
>>>> 4.3.0-rc3-3-llvmlinux-amd64 #1
>>>> [   23.046139] Hardware name: SAMSUNG ELECTRONICS CO., LTD.
>>>> 530U3BI/530U4BI/530U4BH/530U3BI/530U4BI/530U4BH, BIOS 13XK 03/28/2013
>>>> [   23.046143]  ffff8800d36ee948 0000000000000092 0000000000000000
>>>> ffff8800bbacfae8
>>>> [   23.046151]  ffffffff8149adad ffff8800bbacfb18 ffffffff810cd1ea
>>>> ffffffff81c56f0a
>>>> [   23.046158]  ffff8800c22dc400 0000000000000000 0000000000000a76
>>>> ffff8800bbacfb58
>>>> [   23.046165] Call Trace:
>>>> [   23.046172]  [<ffffffff8149adad>] dump_stack+0x7d/0xa0
>>>> [   23.046177]  [<ffffffff810cd1ea>] ___might_sleep+0x28a/0x2a0
>>>> [   23.046182]  [<ffffffff810cceef>] __might_sleep+0x4f/0xc0
>>>> [   23.046187]  [<ffffffff810afbff>] start_flush_work+0x2f/0x290
>>>> [   23.046192]  [<ffffffff810afbac>] flush_work+0x5c/0x80
>>>> [   23.046195]  [<ffffffff810afb6a>] ? flush_work+0x1a/0x80
>>>> [   23.046202]  [<ffffffff810eed0d>] ? trace_hardirqs_off+0xd/0x10
>>>> [   23.046206]  [<ffffffff810aecc8>] ? try_to_grab_pending+0x48/0x360
>>>> [   23.046211]  [<ffffffff8192ac53>] ? _raw_spin_lock_irqsave+0x73/0x80
>>>> [   23.046216]  [<ffffffff810afff9>] __cancel_work_timer+0x179/0x260
>>>> [   23.046221]  [<ffffffff8192add2>] ? _raw_spin_unlock_irqrestore+0x52/0x80
>>>> [   23.046226]  [<ffffffff81120fcd>] ? try_to_del_timer_sync+0xad/0xc0
>>>> [   23.046230]  [<ffffffff810afe78>] cancel_work_sync+0x18/0x20
>>>> [   23.046237]  [<ffffffffa00563d5>] usbhid_close+0x75/0xb0 [usbhid]
>>>> [   23.046245]  [<ffffffffa00394d1>] hidinput_close+0x31/0x40 [hid]
>>>> [   23.046251]  [<ffffffffa00394a0>] ? hidinput_open+0x40/0x40 [hid]
>>>> [   23.046256]  [<ffffffff817423b8>] input_close_device+0x48/0x70
>>>> [   23.046261]  [<ffffffff8174ac96>] evdev_release+0xd6/0xf0
>>>> [   23.046267]  [<ffffffff812728c7>] __fput+0x107/0x240
>>>> [   23.046271]  [<ffffffff81272756>] ____fput+0x16/0x20
>>>> [   23.046276]  [<ffffffff810b945c>] task_work_run+0x6c/0xe0
>>>> [   23.046282]  [<ffffffff81003aa7>] prepare_exit_to_usermode+0x117/0x120
>>>> [   23.046287]  [<ffffffff81003ce1>] syscall_return_slowpath+0x231/0x2a0
>>>> [   23.046292]  [<ffffffff8126efa5>] ? filp_close+0x65/0x90
>>>> [   23.046298]  [<ffffffff810ef1c9>] ? trace_hardirqs_on_caller+0x19/0x290
>>>> [   23.046303]  [<ffffffff81003017>] ? trace_hardirqs_on_thunk+0x17/0x19
>>>> [   23.046308]  [<ffffffff8192bb62>] int_ret_from_sys_call+0x25/0x9f
>>>>
>>>> Can you give help on how to "debug" this?
>>>>
>>>> I switched from full-dynticks to simple cpu-accounting which did not help.
>>>> But this was only a suspicion as Jiri pointed to the possibility
>>>> del_timer_sync() could have get some mis-optimization.
>>>>
>>>> So, more empty head here.
>>>>
>>>
>>> Forgot to attach dmesg-log and my kernel-config.
>>> Sorry about that.
>>>
>>
>> Time for a pause!
>>
>> Forgot to attach disassembled kernel/workqueue.o.
>>
>
> When looking at start_flush_work() in kernel/workqueue.c...
> ...I remembered the comments of Lai Jiangshan concerning the
> might_sleep() check there.
>
> I tried to move the might_sleep() line to __cancel_work_timer() as
> requested, but that did not help or narrowed down whatever.
>
> Please see [1] for more details.
>
> - Sedat -
>
> [1] http://marc.info/?l=linux-kernel&m=144184707824750&w=2

Sorry, before you dig to deeply inside this.

Jiri made a good analysis on the hid side looking at my stack trace... see [2].

- Sedat -

[2] http://marc.info/?l=linux-kernel&m=144308152407025&w=2
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/

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

#1233708

From"Paul E. McKenney" <paulmck@linux.vnet.ibm.com>
Date2015-09-27 18:50 +0200
Message-ID<qdnjb-4n6-9@gated-at.bofh.it>
In reply to#1233705
On Sun, Sep 27, 2015 at 06:25:37PM +0200, Sedat Dilek wrote:
> On Sun, Sep 27, 2015 at 6:16 PM, Sedat Dilek <sedat.dilek@gmail.com> wrote:
> > On Sun, Sep 27, 2015 at 6:02 PM, Sedat Dilek <sedat.dilek@gmail.com> wrote:
> >> On Sun, Sep 27, 2015 at 5:58 PM, Sedat Dilek <sedat.dilek@gmail.com> wrote:
> >>> On Sun, Sep 27, 2015 at 5:55 PM, Sedat Dilek <sedat.dilek@gmail.com> wrote:
> >>>> On Sun, Sep 27, 2015 at 5:49 PM, Paul E. McKenney
> >>>> <paulmck@linux.vnet.ibm.com> wrote:
> >>>>> On Sun, Sep 27, 2015 at 09:37:05AM +0200, Sedat Dilek wrote:
> >>>>>> On Sun, Sep 27, 2015 at 9:32 AM, Paul E. McKenney
> >>>>>> <paulmck@linux.vnet.ibm.com> wrote:
> >>>>>> > On Sun, Sep 27, 2015 at 08:28:39AM +0200, Sedat Dilek wrote:
> >>>>>> >> Hi,
> >>>>>> >>
> >>>>>> >> as I have observed here some lockdep issues (one could be solved in
> >>>>>> >> netdev) I wanted to try this patchset.
> >>>>>> >>
> >>>>>> >> Unfortunately, you cannot pull from...
> >>>>>> >>
> >>>>>> >> "These changes are available in the git repository at:
> >>>>>> >>
> >>>>>> >>   git://git.kernel.org/pub/scm/linux/kernel/git/paulmck/linux-rcu.git for-mingo
> >>>>>> >>
> >>>>>> >> for you to fetch changes up to 19a5ecde086a6a5287978b12ae948fa691b197b7:
> >>>>>> >>
> >>>>>> >>   rcu: Suppress lockdep false positive for rcp->exp_funnel_mutex
> >>>>>> >> (2015-09-20 21:01:22 -0700)
> >>>>>> >>
> >>>>>> >> ----------------------------------------------------------------
> >>>>>> >> Oleg Nesterov (1):
> >>>>>> >>       rcu: Change _wait_rcu_gp() to work around GCC bug 67055
> >>>>>> >>
> >>>>>> >> Paul E. McKenney (1):
> >>>>>> >>       rcu: Suppress lockdep false positive for rcp->exp_funnel_mutex
> >>>>>> >>
> >>>>>> >>  include/linux/rcupdate.h | 11 +++++------
> >>>>>> >>  kernel/rcu/tree.c        |  5 +++++
> >>>>>> >>  2 files changed, 10 insertions(+), 6 deletions(-)"
> >>>>>> >>
> >>>>>> >> So, I have stolen them from linux-next.git.
> >>>>>> >>
> >>>>>> >> Please look at this, Thanks.
> >>>>>> >
> >>>>>> > Does it work better now?  (Forgot to actually push the new name...)
> >>>>>>
> >>>>>> Hi Paul,
> >>>>>>
> >>>>>> now for-mingo Git branch has this two fixes.
> >>>>>
> >>>>> Whew!!!  Apologies for the hassle!
> >>>>>
> >>>>>> I just booted into my new kernel with the "stolen" rcu.fixes from -next.
> >>>>>>
> >>>>>> For the lockdep problems I will do a CONFIG_DEBUG_LOCKDEP=y to see if
> >>>>>> I get some more infos on the workqueue trouble.
> >>>>>>
> >>>>>> [   23.874836] BUG: sleeping function called from invalid context at
> >>>>>> kernel/workqueue.c:2678
> >>>>>> [   23.874902] in_atomic(): 0, irqs_disabled(): 1, pid: 1411, name: acpid
> >>>>>
> >>>>> Did you get a stack trace?  There are quite a few potential callers of
> >>>>> start_flush_work() via flush_work().
> >>>>>
> >>>>
> >>>> Hi Paul :-),
> >>>>
> >>>> Here is the stack trace.
> >>>>
> >>>> [   23.045871] BUG: sleeping function called from invalid context at
> >>>> kernel/workqueue.c:2678
> >>>> [   23.045982] in_atomic(): 0, irqs_disabled(): 1, pid: 1399, name: acpid
> >>>> [   23.046064] 3 locks held by acpid/1399:
> >>>> [   23.046066]  #0:  (&evdev->mutex){+.+...}, at: [<ffffffff8174ac7c>]
> >>>> evdev_release+0xbc/0xf0
> >>>> [   23.046081]  #1:  (&dev->mutex#2){+.+...}, at: [<ffffffff81742397>]
> >>>> input_close_device+0x27/0x70
> >>>> [   23.046093]  #2:  (hid_open_mut){+.+...}, at: [<ffffffffa0056388>]
> >>>> usbhid_close+0x28/0xb0 [usbhid]
> >>>> [   23.046106] irq event stamp: 3306
> >>>> [   23.046109] hardirqs last  enabled at (3305): [<ffffffff8192ae32>]
> >>>> _raw_spin_unlock_irq+0x32/0x60
> >>>> [   23.046115] hardirqs last disabled at (3306): [<ffffffff81121017>]
> >>>> del_timer_sync+0x37/0x110
> >>>> [   23.046122] softirqs last  enabled at (2704): [<ffffffff818b12c9>]
> >>>> local_bh_enable+0x9/0x20
> >>>> [   23.046128] softirqs last disabled at (2702): [<ffffffff818b12a9>]
> >>>> local_bh_disable+0x9/0x20
> >>>> [   23.046136] CPU: 2 PID: 1399 Comm: acpid Not tainted
> >>>> 4.3.0-rc3-3-llvmlinux-amd64 #1
> >>>> [   23.046139] Hardware name: SAMSUNG ELECTRONICS CO., LTD.
> >>>> 530U3BI/530U4BI/530U4BH/530U3BI/530U4BI/530U4BH, BIOS 13XK 03/28/2013
> >>>> [   23.046143]  ffff8800d36ee948 0000000000000092 0000000000000000
> >>>> ffff8800bbacfae8
> >>>> [   23.046151]  ffffffff8149adad ffff8800bbacfb18 ffffffff810cd1ea
> >>>> ffffffff81c56f0a
> >>>> [   23.046158]  ffff8800c22dc400 0000000000000000 0000000000000a76
> >>>> ffff8800bbacfb58
> >>>> [   23.046165] Call Trace:
> >>>> [   23.046172]  [<ffffffff8149adad>] dump_stack+0x7d/0xa0
> >>>> [   23.046177]  [<ffffffff810cd1ea>] ___might_sleep+0x28a/0x2a0
> >>>> [   23.046182]  [<ffffffff810cceef>] __might_sleep+0x4f/0xc0
> >>>> [   23.046187]  [<ffffffff810afbff>] start_flush_work+0x2f/0x290
> >>>> [   23.046192]  [<ffffffff810afbac>] flush_work+0x5c/0x80
> >>>> [   23.046195]  [<ffffffff810afb6a>] ? flush_work+0x1a/0x80
> >>>> [   23.046202]  [<ffffffff810eed0d>] ? trace_hardirqs_off+0xd/0x10
> >>>> [   23.046206]  [<ffffffff810aecc8>] ? try_to_grab_pending+0x48/0x360
> >>>> [   23.046211]  [<ffffffff8192ac53>] ? _raw_spin_lock_irqsave+0x73/0x80
> >>>> [   23.046216]  [<ffffffff810afff9>] __cancel_work_timer+0x179/0x260
> >>>> [   23.046221]  [<ffffffff8192add2>] ? _raw_spin_unlock_irqrestore+0x52/0x80
> >>>> [   23.046226]  [<ffffffff81120fcd>] ? try_to_del_timer_sync+0xad/0xc0
> >>>> [   23.046230]  [<ffffffff810afe78>] cancel_work_sync+0x18/0x20
> >>>> [   23.046237]  [<ffffffffa00563d5>] usbhid_close+0x75/0xb0 [usbhid]
> >>>> [   23.046245]  [<ffffffffa00394d1>] hidinput_close+0x31/0x40 [hid]
> >>>> [   23.046251]  [<ffffffffa00394a0>] ? hidinput_open+0x40/0x40 [hid]
> >>>> [   23.046256]  [<ffffffff817423b8>] input_close_device+0x48/0x70
> >>>> [   23.046261]  [<ffffffff8174ac96>] evdev_release+0xd6/0xf0
> >>>> [   23.046267]  [<ffffffff812728c7>] __fput+0x107/0x240
> >>>> [   23.046271]  [<ffffffff81272756>] ____fput+0x16/0x20
> >>>> [   23.046276]  [<ffffffff810b945c>] task_work_run+0x6c/0xe0
> >>>> [   23.046282]  [<ffffffff81003aa7>] prepare_exit_to_usermode+0x117/0x120
> >>>> [   23.046287]  [<ffffffff81003ce1>] syscall_return_slowpath+0x231/0x2a0
> >>>> [   23.046292]  [<ffffffff8126efa5>] ? filp_close+0x65/0x90
> >>>> [   23.046298]  [<ffffffff810ef1c9>] ? trace_hardirqs_on_caller+0x19/0x290
> >>>> [   23.046303]  [<ffffffff81003017>] ? trace_hardirqs_on_thunk+0x17/0x19
> >>>> [   23.046308]  [<ffffffff8192bb62>] int_ret_from_sys_call+0x25/0x9f
> >>>>
> >>>> Can you give help on how to "debug" this?
> >>>>
> >>>> I switched from full-dynticks to simple cpu-accounting which did not help.
> >>>> But this was only a suspicion as Jiri pointed to the possibility
> >>>> del_timer_sync() could have get some mis-optimization.
> >>>>
> >>>> So, more empty head here.
> >>>>
> >>>
> >>> Forgot to attach dmesg-log and my kernel-config.
> >>> Sorry about that.
> >>>
> >>
> >> Time for a pause!
> >>
> >> Forgot to attach disassembled kernel/workqueue.o.
> >>
> >
> > When looking at start_flush_work() in kernel/workqueue.c...
> > ...I remembered the comments of Lai Jiangshan concerning the
> > might_sleep() check there.
> >
> > I tried to move the might_sleep() line to __cancel_work_timer() as
> > requested, but that did not help or narrowed down whatever.
> >
> > Please see [1] for more details.
> >
> > - Sedat -
> >
> > [1] http://marc.info/?l=linux-kernel&m=144184707824750&w=2
> 
> Sorry, before you dig to deeply inside this.
> 
> Jiri made a good analysis on the hid side looking at my stack trace... see [2].

Good.  Might be that clang/LLVM needs some help here.  ;-)

							Thanx, Paul

> - Sedat -
> 
> [2] http://marc.info/?l=linux-kernel&m=144308152407025&w=2
> 

--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/

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

#1233709

From"Paul E. McKenney" <paulmck@linux.vnet.ibm.com>
Date2015-09-27 18:50 +0200
Message-ID<qdnjb-4n6-11@gated-at.bofh.it>
In reply to#1233697
On Sun, Sep 27, 2015 at 05:55:43PM +0200, Sedat Dilek wrote:
> On Sun, Sep 27, 2015 at 5:49 PM, Paul E. McKenney
> <paulmck@linux.vnet.ibm.com> wrote:
> > On Sun, Sep 27, 2015 at 09:37:05AM +0200, Sedat Dilek wrote:
> >> On Sun, Sep 27, 2015 at 9:32 AM, Paul E. McKenney
> >> <paulmck@linux.vnet.ibm.com> wrote:
> >> > On Sun, Sep 27, 2015 at 08:28:39AM +0200, Sedat Dilek wrote:

[ . . . ]

> Hi Paul :-),
> 
> Here is the stack trace.
> 
> [   23.045871] BUG: sleeping function called from invalid context at
> kernel/workqueue.c:2678
> [   23.045982] in_atomic(): 0, irqs_disabled(): 1, pid: 1399, name: acpid
> [   23.046064] 3 locks held by acpid/1399:
> [   23.046066]  #0:  (&evdev->mutex){+.+...}, at: [<ffffffff8174ac7c>]
> evdev_release+0xbc/0xf0
> [   23.046081]  #1:  (&dev->mutex#2){+.+...}, at: [<ffffffff81742397>]
> input_close_device+0x27/0x70
> [   23.046093]  #2:  (hid_open_mut){+.+...}, at: [<ffffffffa0056388>]
> usbhid_close+0x28/0xb0 [usbhid]
> [   23.046106] irq event stamp: 3306
> [   23.046109] hardirqs last  enabled at (3305): [<ffffffff8192ae32>]
> _raw_spin_unlock_irq+0x32/0x60
> [   23.046115] hardirqs last disabled at (3306): [<ffffffff81121017>]
> del_timer_sync+0x37/0x110
> [   23.046122] softirqs last  enabled at (2704): [<ffffffff818b12c9>]
> local_bh_enable+0x9/0x20
> [   23.046128] softirqs last disabled at (2702): [<ffffffff818b12a9>]
> local_bh_disable+0x9/0x20
> [   23.046136] CPU: 2 PID: 1399 Comm: acpid Not tainted
> 4.3.0-rc3-3-llvmlinux-amd64 #1
> [   23.046139] Hardware name: SAMSUNG ELECTRONICS CO., LTD.
> 530U3BI/530U4BI/530U4BH/530U3BI/530U4BI/530U4BH, BIOS 13XK 03/28/2013
> [   23.046143]  ffff8800d36ee948 0000000000000092 0000000000000000
> ffff8800bbacfae8
> [   23.046151]  ffffffff8149adad ffff8800bbacfb18 ffffffff810cd1ea
> ffffffff81c56f0a
> [   23.046158]  ffff8800c22dc400 0000000000000000 0000000000000a76
> ffff8800bbacfb58
> [   23.046165] Call Trace:
> [   23.046172]  [<ffffffff8149adad>] dump_stack+0x7d/0xa0
> [   23.046177]  [<ffffffff810cd1ea>] ___might_sleep+0x28a/0x2a0
> [   23.046182]  [<ffffffff810cceef>] __might_sleep+0x4f/0xc0
> [   23.046187]  [<ffffffff810afbff>] start_flush_work+0x2f/0x290
> [   23.046192]  [<ffffffff810afbac>] flush_work+0x5c/0x80
> [   23.046195]  [<ffffffff810afb6a>] ? flush_work+0x1a/0x80
> [   23.046202]  [<ffffffff810eed0d>] ? trace_hardirqs_off+0xd/0x10
> [   23.046206]  [<ffffffff810aecc8>] ? try_to_grab_pending+0x48/0x360
> [   23.046211]  [<ffffffff8192ac53>] ? _raw_spin_lock_irqsave+0x73/0x80
> [   23.046216]  [<ffffffff810afff9>] __cancel_work_timer+0x179/0x260
> [   23.046221]  [<ffffffff8192add2>] ? _raw_spin_unlock_irqrestore+0x52/0x80
> [   23.046226]  [<ffffffff81120fcd>] ? try_to_del_timer_sync+0xad/0xc0
> [   23.046230]  [<ffffffff810afe78>] cancel_work_sync+0x18/0x20
> [   23.046237]  [<ffffffffa00563d5>] usbhid_close+0x75/0xb0 [usbhid]
> [   23.046245]  [<ffffffffa00394d1>] hidinput_close+0x31/0x40 [hid]
> [   23.046251]  [<ffffffffa00394a0>] ? hidinput_open+0x40/0x40 [hid]
> [   23.046256]  [<ffffffff817423b8>] input_close_device+0x48/0x70
> [   23.046261]  [<ffffffff8174ac96>] evdev_release+0xd6/0xf0
> [   23.046267]  [<ffffffff812728c7>] __fput+0x107/0x240
> [   23.046271]  [<ffffffff81272756>] ____fput+0x16/0x20
> [   23.046276]  [<ffffffff810b945c>] task_work_run+0x6c/0xe0
> [   23.046282]  [<ffffffff81003aa7>] prepare_exit_to_usermode+0x117/0x120
> [   23.046287]  [<ffffffff81003ce1>] syscall_return_slowpath+0x231/0x2a0
> [   23.046292]  [<ffffffff8126efa5>] ? filp_close+0x65/0x90
> [   23.046298]  [<ffffffff810ef1c9>] ? trace_hardirqs_on_caller+0x19/0x290
> [   23.046303]  [<ffffffff81003017>] ? trace_hardirqs_on_thunk+0x17/0x19
> [   23.046308]  [<ffffffff8192bb62>] int_ret_from_sys_call+0x25/0x9f
> 
> Can you give help on how to "debug" this?
> 
> I switched from full-dynticks to simple cpu-accounting which did not help.
> But this was only a suspicion as Jiri pointed to the possibility
> del_timer_sync() could have get some mis-optimization.
> 
> So, more empty head here.

I am not familiar with the "hardirqs last  enabled" debug output, but
I am guessing that hardirqs are disabled because  the "last disabled"
number is greater than the "last  enabled" number.  So if I understand
correctly, something somewhere up the call stack has irqs disabled,
but is calling a function that needs them enabled.

A quick look at usbhid_close() shows no problem, but then again, I am
looking at the v4.2 version rather than whatever you are testing.
But v4.3-rc2 looks the same.

Looks like you are already in contact with Jiri, which is good.

Another thing to try would be to insert might_sleep() calls, after
usbhid_close(), since it enables irqs explicitly, but before the call
to flush_work().  Jiri's comment can be interpreted as a suggestion
to insert a might_sleep() in try_to_del_timer_sync(), though
__cancel_work_timer() wouldn't be a bad place to try as well,
just before its call to flush_work().

							Thanx, Paul

> - Sedat -
> 
> >> $ grep LOCKDEP /boot/config-4.3.0-rc2-438.1-llvmlinux-amd64
> >> CONFIG_LOCKDEP_SUPPORT=y
> >> CONFIG_LOCKDEP=y
> >> # CONFIG_DEBUG_LOCKDEP is not set
> >>
> >> So, CLANG is a bit different compiler :-).
> >
> > True enough.  Good to have more than one, though.
> >
> >                                                         Thanx, Paul
> >
> >> Thanks for taking care.
> >>
> >> Regards,
> >> - Sedat -
> >>
> >> >>
> >> >> [1] http://marc.info/?l=linux-kernel&m=144332758307978&w=2
> >> >> [2] http://git.kernel.org/cgit/linux/kernel/git/next/linux-next.git/patch/?id=66e8c57da6bf6b847a48a5a6fda59512f733ed78
> >> >> [3] http://git.kernel.org/cgit/linux/kernel/git/next/linux-next.git/patch/?id=19a5ecde086a6a5287978b12ae948fa691b197b7
> >> >>
> >> >
> >>
> >
> 

--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/

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

#1233712

FromSedat Dilek <sedat.dilek@gmail.com>
Date2015-09-27 19:30 +0200
Message-ID<qdnVT-5lj-3@gated-at.bofh.it>
In reply to#1233709
On Sun, Sep 27, 2015 at 6:42 PM, Paul E. McKenney
<paulmck@linux.vnet.ibm.com> wrote:
> On Sun, Sep 27, 2015 at 05:55:43PM +0200, Sedat Dilek wrote:
>> On Sun, Sep 27, 2015 at 5:49 PM, Paul E. McKenney
>> <paulmck@linux.vnet.ibm.com> wrote:
>> > On Sun, Sep 27, 2015 at 09:37:05AM +0200, Sedat Dilek wrote:
>> >> On Sun, Sep 27, 2015 at 9:32 AM, Paul E. McKenney
>> >> <paulmck@linux.vnet.ibm.com> wrote:
>> >> > On Sun, Sep 27, 2015 at 08:28:39AM +0200, Sedat Dilek wrote:
>
> [ . . . ]
>
>> Hi Paul :-),
>>
>> Here is the stack trace.
>>
>> [   23.045871] BUG: sleeping function called from invalid context at
>> kernel/workqueue.c:2678
>> [   23.045982] in_atomic(): 0, irqs_disabled(): 1, pid: 1399, name: acpid
>> [   23.046064] 3 locks held by acpid/1399:
>> [   23.046066]  #0:  (&evdev->mutex){+.+...}, at: [<ffffffff8174ac7c>]
>> evdev_release+0xbc/0xf0
>> [   23.046081]  #1:  (&dev->mutex#2){+.+...}, at: [<ffffffff81742397>]
>> input_close_device+0x27/0x70
>> [   23.046093]  #2:  (hid_open_mut){+.+...}, at: [<ffffffffa0056388>]
>> usbhid_close+0x28/0xb0 [usbhid]
>> [   23.046106] irq event stamp: 3306
>> [   23.046109] hardirqs last  enabled at (3305): [<ffffffff8192ae32>]
>> _raw_spin_unlock_irq+0x32/0x60
>> [   23.046115] hardirqs last disabled at (3306): [<ffffffff81121017>]
>> del_timer_sync+0x37/0x110
>> [   23.046122] softirqs last  enabled at (2704): [<ffffffff818b12c9>]
>> local_bh_enable+0x9/0x20
>> [   23.046128] softirqs last disabled at (2702): [<ffffffff818b12a9>]
>> local_bh_disable+0x9/0x20
>> [   23.046136] CPU: 2 PID: 1399 Comm: acpid Not tainted
>> 4.3.0-rc3-3-llvmlinux-amd64 #1
>> [   23.046139] Hardware name: SAMSUNG ELECTRONICS CO., LTD.
>> 530U3BI/530U4BI/530U4BH/530U3BI/530U4BI/530U4BH, BIOS 13XK 03/28/2013
>> [   23.046143]  ffff8800d36ee948 0000000000000092 0000000000000000
>> ffff8800bbacfae8
>> [   23.046151]  ffffffff8149adad ffff8800bbacfb18 ffffffff810cd1ea
>> ffffffff81c56f0a
>> [   23.046158]  ffff8800c22dc400 0000000000000000 0000000000000a76
>> ffff8800bbacfb58
>> [   23.046165] Call Trace:
>> [   23.046172]  [<ffffffff8149adad>] dump_stack+0x7d/0xa0
>> [   23.046177]  [<ffffffff810cd1ea>] ___might_sleep+0x28a/0x2a0
>> [   23.046182]  [<ffffffff810cceef>] __might_sleep+0x4f/0xc0
>> [   23.046187]  [<ffffffff810afbff>] start_flush_work+0x2f/0x290
>> [   23.046192]  [<ffffffff810afbac>] flush_work+0x5c/0x80
>> [   23.046195]  [<ffffffff810afb6a>] ? flush_work+0x1a/0x80
>> [   23.046202]  [<ffffffff810eed0d>] ? trace_hardirqs_off+0xd/0x10
>> [   23.046206]  [<ffffffff810aecc8>] ? try_to_grab_pending+0x48/0x360
>> [   23.046211]  [<ffffffff8192ac53>] ? _raw_spin_lock_irqsave+0x73/0x80
>> [   23.046216]  [<ffffffff810afff9>] __cancel_work_timer+0x179/0x260
>> [   23.046221]  [<ffffffff8192add2>] ? _raw_spin_unlock_irqrestore+0x52/0x80
>> [   23.046226]  [<ffffffff81120fcd>] ? try_to_del_timer_sync+0xad/0xc0
>> [   23.046230]  [<ffffffff810afe78>] cancel_work_sync+0x18/0x20
>> [   23.046237]  [<ffffffffa00563d5>] usbhid_close+0x75/0xb0 [usbhid]
>> [   23.046245]  [<ffffffffa00394d1>] hidinput_close+0x31/0x40 [hid]
>> [   23.046251]  [<ffffffffa00394a0>] ? hidinput_open+0x40/0x40 [hid]
>> [   23.046256]  [<ffffffff817423b8>] input_close_device+0x48/0x70
>> [   23.046261]  [<ffffffff8174ac96>] evdev_release+0xd6/0xf0
>> [   23.046267]  [<ffffffff812728c7>] __fput+0x107/0x240
>> [   23.046271]  [<ffffffff81272756>] ____fput+0x16/0x20
>> [   23.046276]  [<ffffffff810b945c>] task_work_run+0x6c/0xe0
>> [   23.046282]  [<ffffffff81003aa7>] prepare_exit_to_usermode+0x117/0x120
>> [   23.046287]  [<ffffffff81003ce1>] syscall_return_slowpath+0x231/0x2a0
>> [   23.046292]  [<ffffffff8126efa5>] ? filp_close+0x65/0x90
>> [   23.046298]  [<ffffffff810ef1c9>] ? trace_hardirqs_on_caller+0x19/0x290
>> [   23.046303]  [<ffffffff81003017>] ? trace_hardirqs_on_thunk+0x17/0x19
>> [   23.046308]  [<ffffffff8192bb62>] int_ret_from_sys_call+0x25/0x9f
>>
>> Can you give help on how to "debug" this?
>>
>> I switched from full-dynticks to simple cpu-accounting which did not help.
>> But this was only a suspicion as Jiri pointed to the possibility
>> del_timer_sync() could have get some mis-optimization.
>>
>> So, more empty head here.
>
> I am not familiar with the "hardirqs last  enabled" debug output, but
> I am guessing that hardirqs are disabled because  the "last disabled"
> number is greater than the "last  enabled" number.  So if I understand
> correctly, something somewhere up the call stack has irqs disabled,
> but is calling a function that needs them enabled.
>
> A quick look at usbhid_close() shows no problem, but then again, I am
> looking at the v4.2 version rather than whatever you are testing.
> But v4.3-rc2 looks the same.
>
> Looks like you are already in contact with Jiri, which is good.
>
> Another thing to try would be to insert might_sleep() calls, after
> usbhid_close(), since it enables irqs explicitly, but before the call
> to flush_work().  Jiri's comment can be interpreted as a suggestion
> to insert a might_sleep() in try_to_del_timer_sync(), though
> __cancel_work_timer() wouldn't be a bad place to try as well,
> just before its call to flush_work().

With...

--- a/kernel/time/timer.c
+++ b/kernel/time/timer.c
@@ -1026,6 +1026,8 @@ int try_to_del_timer_sync(struct timer_list *timer)
        unsigned long flags;
        int ret = -1;

+       might_sleep();
+
        debug_assert_init(timer);

        base = lock_timer_base(timer, &flags);

...I get now...

[   53.104411] BUG: sleeping function called from invalid context at
kernel/time/timer.c:1029
[   53.104417] in_atomic(): 0, irqs_disabled(): 1, pid: 2100, name: fusermount
[   53.104419] 1 lock held by fusermount/2100:
[   53.104420]  #0:  (&type->s_umount_key#33){+.+...}, at:
[<ffffffff812746ab>] deactivate_super+0x5b/0x70
[   53.104432] irq event stamp: 3734
[   53.104433] hardirqs last  enabled at (3733): [<ffffffff810aefb8>]
mod_delayed_work_on+0x78/0xa0
[   53.104438] hardirqs last disabled at (3734): [<ffffffff810b045f>]
flush_delayed_work+0x1f/0x70
[   53.104441] softirqs last  enabled at (3730): [<ffffffff81204997>]
wb_shutdown+0x47/0xb0
[   53.104444] softirqs last disabled at (3728): [<ffffffff81204976>]
wb_shutdown+0x26/0xb0
[   53.104449] CPU: 3 PID: 2100 Comm: fusermount Not tainted
4.3.0-rc3-4-llvmlinux-amd64 #2
[   53.104451] Hardware name: SAMSUNG ELECTRONICS CO., LTD.
530U3BI/530U4BI/530U4BH/530U3BI/530U4BI/530U4BH, BIOS 13XK 03/28/2013
[   53.104453]  000000000000000a 0000000000000096 0000000000000000
ffff8800af39bb28
[   53.104457]  ffffffff8149cadd ffff8800af39bb58 ffffffff810cd5aa
ffffffff81c5f2e8
[   53.104461]  ffff8800c5785940 0000000000000000 0000000000000405
ffff8800af39bb98
[   53.104465] Call Trace:
[   53.104470]  [<ffffffff8149cadd>] dump_stack+0x7d/0xa0
[   53.104473]  [<ffffffff810cd5aa>] ___might_sleep+0x28a/0x2a0
[   53.104475]  [<ffffffff810cd2af>] __might_sleep+0x4f/0xc0
[   53.104480]  [<ffffffff81122055>] try_to_del_timer_sync+0x25/0xe0
[   53.104483]  [<ffffffff81122204>] del_timer_sync+0xf4/0x110
[   53.104486]  [<ffffffff8112214b>] ? del_timer_sync+0x3b/0x110
[   53.104497]  [<ffffffff810b0468>] flush_delayed_work+0x28/0x70
[   53.104499]  [<ffffffff812049cb>] wb_shutdown+0x7b/0xb0
[   53.104501]  [<ffffffff812046fd>] bdi_destroy+0x7d/0x2d0
[   53.104505]  [<ffffffff810efe2d>] ? trace_hardirqs_on+0xd/0x10
[   53.104509]  [<ffffffff813b7b08>] fuse_put_super+0xf8/0x140
[   53.104511]  [<ffffffff813b7a10>] ? fuse_evict_inode+0x80/0x80
[   53.104513]  [<ffffffff81274778>] generic_shutdown_super+0x68/0x120
[   53.104515]  [<ffffffff81275a80>] kill_anon_super+0x20/0x70
[   53.104518]  [<ffffffff813b6fcd>] fuse_kill_sb_anon+0x4d/0x60
[   53.104520]  [<ffffffff812745dd>] deactivate_locked_super+0x4d/0xc0
[   53.104522]  [<ffffffff812746b3>] deactivate_super+0x63/0x70
[   53.104525]  [<ffffffff8129fa02>] cleanup_mnt+0xb2/0x140
[   53.104528]  [<ffffffff8129f93a>] __cleanup_mnt+0x1a/0x30
[   53.104531]  [<ffffffff810b97bc>] task_work_run+0x6c/0xe0
[   53.104534]  [<ffffffff81003b8a>] prepare_exit_to_usermode+0x13a/0x140
[   53.104537]  [<ffffffff81003e11>] syscall_return_slowpath+0x281/0x2f0
[   53.104540]  [<ffffffff8129c121>] ? SyS_umount+0x341/0x620
[   53.104542]  [<ffffffff810f02d9>] ? trace_hardirqs_on_caller+0x19/0x290
[   53.104545]  [<ffffffff81003017>] ? trace_hardirqs_on_thunk+0x17/0x19
[   53.104550]  [<ffffffff8192da22>] int_ret_from_sys_call+0x25/0x9f

A problem in fuse?

- Sedat -

>
>                                                         Thanx, Paul
>
>> - Sedat -
>>
>> >> $ grep LOCKDEP /boot/config-4.3.0-rc2-438.1-llvmlinux-amd64
>> >> CONFIG_LOCKDEP_SUPPORT=y
>> >> CONFIG_LOCKDEP=y
>> >> # CONFIG_DEBUG_LOCKDEP is not set
>> >>
>> >> So, CLANG is a bit different compiler :-).
>> >
>> > True enough.  Good to have more than one, though.
>> >
>> >                                                         Thanx, Paul
>> >
>> >> Thanks for taking care.
>> >>
>> >> Regards,
>> >> - Sedat -
>> >>
>> >> >>
>> >> >> [1] http://marc.info/?l=linux-kernel&m=144332758307978&w=2
>> >> >> [2] http://git.kernel.org/cgit/linux/kernel/git/next/linux-next.git/patch/?id=66e8c57da6bf6b847a48a5a6fda59512f733ed78
>> >> >> [3] http://git.kernel.org/cgit/linux/kernel/git/next/linux-next.git/patch/?id=19a5ecde086a6a5287978b12ae948fa691b197b7
>> >> >>
>> >> >
>> >>
>> >
>>
>
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/

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

#1233713

From"Paul E. McKenney" <paulmck@linux.vnet.ibm.com>
Date2015-09-27 19:50 +0200
Message-ID<qdofg-5HU-17@gated-at.bofh.it>
In reply to#1233712
On Sun, Sep 27, 2015 at 07:24:22PM +0200, Sedat Dilek wrote:
> On Sun, Sep 27, 2015 at 6:42 PM, Paul E. McKenney
> <paulmck@linux.vnet.ibm.com> wrote:
> > On Sun, Sep 27, 2015 at 05:55:43PM +0200, Sedat Dilek wrote:
> >> On Sun, Sep 27, 2015 at 5:49 PM, Paul E. McKenney
> >> <paulmck@linux.vnet.ibm.com> wrote:
> >> > On Sun, Sep 27, 2015 at 09:37:05AM +0200, Sedat Dilek wrote:
> >> >> On Sun, Sep 27, 2015 at 9:32 AM, Paul E. McKenney
> >> >> <paulmck@linux.vnet.ibm.com> wrote:
> >> >> > On Sun, Sep 27, 2015 at 08:28:39AM +0200, Sedat Dilek wrote:
> >
> > [ . . . ]
> >
> >> Hi Paul :-),
> >>
> >> Here is the stack trace.
> >>
> >> [   23.045871] BUG: sleeping function called from invalid context at
> >> kernel/workqueue.c:2678
> >> [   23.045982] in_atomic(): 0, irqs_disabled(): 1, pid: 1399, name: acpid
> >> [   23.046064] 3 locks held by acpid/1399:
> >> [   23.046066]  #0:  (&evdev->mutex){+.+...}, at: [<ffffffff8174ac7c>]
> >> evdev_release+0xbc/0xf0
> >> [   23.046081]  #1:  (&dev->mutex#2){+.+...}, at: [<ffffffff81742397>]
> >> input_close_device+0x27/0x70
> >> [   23.046093]  #2:  (hid_open_mut){+.+...}, at: [<ffffffffa0056388>]
> >> usbhid_close+0x28/0xb0 [usbhid]
> >> [   23.046106] irq event stamp: 3306
> >> [   23.046109] hardirqs last  enabled at (3305): [<ffffffff8192ae32>]
> >> _raw_spin_unlock_irq+0x32/0x60
> >> [   23.046115] hardirqs last disabled at (3306): [<ffffffff81121017>]
> >> del_timer_sync+0x37/0x110
> >> [   23.046122] softirqs last  enabled at (2704): [<ffffffff818b12c9>]
> >> local_bh_enable+0x9/0x20
> >> [   23.046128] softirqs last disabled at (2702): [<ffffffff818b12a9>]
> >> local_bh_disable+0x9/0x20
> >> [   23.046136] CPU: 2 PID: 1399 Comm: acpid Not tainted
> >> 4.3.0-rc3-3-llvmlinux-amd64 #1
> >> [   23.046139] Hardware name: SAMSUNG ELECTRONICS CO., LTD.
> >> 530U3BI/530U4BI/530U4BH/530U3BI/530U4BI/530U4BH, BIOS 13XK 03/28/2013
> >> [   23.046143]  ffff8800d36ee948 0000000000000092 0000000000000000
> >> ffff8800bbacfae8
> >> [   23.046151]  ffffffff8149adad ffff8800bbacfb18 ffffffff810cd1ea
> >> ffffffff81c56f0a
> >> [   23.046158]  ffff8800c22dc400 0000000000000000 0000000000000a76
> >> ffff8800bbacfb58
> >> [   23.046165] Call Trace:
> >> [   23.046172]  [<ffffffff8149adad>] dump_stack+0x7d/0xa0
> >> [   23.046177]  [<ffffffff810cd1ea>] ___might_sleep+0x28a/0x2a0
> >> [   23.046182]  [<ffffffff810cceef>] __might_sleep+0x4f/0xc0
> >> [   23.046187]  [<ffffffff810afbff>] start_flush_work+0x2f/0x290
> >> [   23.046192]  [<ffffffff810afbac>] flush_work+0x5c/0x80
> >> [   23.046195]  [<ffffffff810afb6a>] ? flush_work+0x1a/0x80
> >> [   23.046202]  [<ffffffff810eed0d>] ? trace_hardirqs_off+0xd/0x10
> >> [   23.046206]  [<ffffffff810aecc8>] ? try_to_grab_pending+0x48/0x360
> >> [   23.046211]  [<ffffffff8192ac53>] ? _raw_spin_lock_irqsave+0x73/0x80
> >> [   23.046216]  [<ffffffff810afff9>] __cancel_work_timer+0x179/0x260
> >> [   23.046221]  [<ffffffff8192add2>] ? _raw_spin_unlock_irqrestore+0x52/0x80
> >> [   23.046226]  [<ffffffff81120fcd>] ? try_to_del_timer_sync+0xad/0xc0
> >> [   23.046230]  [<ffffffff810afe78>] cancel_work_sync+0x18/0x20
> >> [   23.046237]  [<ffffffffa00563d5>] usbhid_close+0x75/0xb0 [usbhid]
> >> [   23.046245]  [<ffffffffa00394d1>] hidinput_close+0x31/0x40 [hid]
> >> [   23.046251]  [<ffffffffa00394a0>] ? hidinput_open+0x40/0x40 [hid]
> >> [   23.046256]  [<ffffffff817423b8>] input_close_device+0x48/0x70
> >> [   23.046261]  [<ffffffff8174ac96>] evdev_release+0xd6/0xf0
> >> [   23.046267]  [<ffffffff812728c7>] __fput+0x107/0x240
> >> [   23.046271]  [<ffffffff81272756>] ____fput+0x16/0x20
> >> [   23.046276]  [<ffffffff810b945c>] task_work_run+0x6c/0xe0
> >> [   23.046282]  [<ffffffff81003aa7>] prepare_exit_to_usermode+0x117/0x120
> >> [   23.046287]  [<ffffffff81003ce1>] syscall_return_slowpath+0x231/0x2a0
> >> [   23.046292]  [<ffffffff8126efa5>] ? filp_close+0x65/0x90
> >> [   23.046298]  [<ffffffff810ef1c9>] ? trace_hardirqs_on_caller+0x19/0x290
> >> [   23.046303]  [<ffffffff81003017>] ? trace_hardirqs_on_thunk+0x17/0x19
> >> [   23.046308]  [<ffffffff8192bb62>] int_ret_from_sys_call+0x25/0x9f
> >>
> >> Can you give help on how to "debug" this?
> >>
> >> I switched from full-dynticks to simple cpu-accounting which did not help.
> >> But this was only a suspicion as Jiri pointed to the possibility
> >> del_timer_sync() could have get some mis-optimization.
> >>
> >> So, more empty head here.
> >
> > I am not familiar with the "hardirqs last  enabled" debug output, but
> > I am guessing that hardirqs are disabled because  the "last disabled"
> > number is greater than the "last  enabled" number.  So if I understand
> > correctly, something somewhere up the call stack has irqs disabled,
> > but is calling a function that needs them enabled.
> >
> > A quick look at usbhid_close() shows no problem, but then again, I am
> > looking at the v4.2 version rather than whatever you are testing.
> > But v4.3-rc2 looks the same.
> >
> > Looks like you are already in contact with Jiri, which is good.
> >
> > Another thing to try would be to insert might_sleep() calls, after
> > usbhid_close(), since it enables irqs explicitly, but before the call
> > to flush_work().  Jiri's comment can be interpreted as a suggestion
> > to insert a might_sleep() in try_to_del_timer_sync(), though
> > __cancel_work_timer() wouldn't be a bad place to try as well,
> > just before its call to flush_work().
> 
> With...
> 
> --- a/kernel/time/timer.c
> +++ b/kernel/time/timer.c
> @@ -1026,6 +1026,8 @@ int try_to_del_timer_sync(struct timer_list *timer)
>         unsigned long flags;
>         int ret = -1;
> 
> +       might_sleep();
> +
>         debug_assert_init(timer);
> 
>         base = lock_timer_base(timer, &flags);
> 
> ...I get now...
> 
> [   53.104411] BUG: sleeping function called from invalid context at
> kernel/time/timer.c:1029
> [   53.104417] in_atomic(): 0, irqs_disabled(): 1, pid: 2100, name: fusermount
> [   53.104419] 1 lock held by fusermount/2100:
> [   53.104420]  #0:  (&type->s_umount_key#33){+.+...}, at:
> [<ffffffff812746ab>] deactivate_super+0x5b/0x70
> [   53.104432] irq event stamp: 3734
> [   53.104433] hardirqs last  enabled at (3733): [<ffffffff810aefb8>]
> mod_delayed_work_on+0x78/0xa0
> [   53.104438] hardirqs last disabled at (3734): [<ffffffff810b045f>]
> flush_delayed_work+0x1f/0x70
> [   53.104441] softirqs last  enabled at (3730): [<ffffffff81204997>]
> wb_shutdown+0x47/0xb0
> [   53.104444] softirqs last disabled at (3728): [<ffffffff81204976>]
> wb_shutdown+0x26/0xb0
> [   53.104449] CPU: 3 PID: 2100 Comm: fusermount Not tainted
> 4.3.0-rc3-4-llvmlinux-amd64 #2
> [   53.104451] Hardware name: SAMSUNG ELECTRONICS CO., LTD.
> 530U3BI/530U4BI/530U4BH/530U3BI/530U4BI/530U4BH, BIOS 13XK 03/28/2013
> [   53.104453]  000000000000000a 0000000000000096 0000000000000000
> ffff8800af39bb28
> [   53.104457]  ffffffff8149cadd ffff8800af39bb58 ffffffff810cd5aa
> ffffffff81c5f2e8
> [   53.104461]  ffff8800c5785940 0000000000000000 0000000000000405
> ffff8800af39bb98
> [   53.104465] Call Trace:
> [   53.104470]  [<ffffffff8149cadd>] dump_stack+0x7d/0xa0
> [   53.104473]  [<ffffffff810cd5aa>] ___might_sleep+0x28a/0x2a0
> [   53.104475]  [<ffffffff810cd2af>] __might_sleep+0x4f/0xc0
> [   53.104480]  [<ffffffff81122055>] try_to_del_timer_sync+0x25/0xe0
> [   53.104483]  [<ffffffff81122204>] del_timer_sync+0xf4/0x110
> [   53.104486]  [<ffffffff8112214b>] ? del_timer_sync+0x3b/0x110
> [   53.104497]  [<ffffffff810b0468>] flush_delayed_work+0x28/0x70
> [   53.104499]  [<ffffffff812049cb>] wb_shutdown+0x7b/0xb0
> [   53.104501]  [<ffffffff812046fd>] bdi_destroy+0x7d/0x2d0
> [   53.104505]  [<ffffffff810efe2d>] ? trace_hardirqs_on+0xd/0x10
> [   53.104509]  [<ffffffff813b7b08>] fuse_put_super+0xf8/0x140
> [   53.104511]  [<ffffffff813b7a10>] ? fuse_evict_inode+0x80/0x80
> [   53.104513]  [<ffffffff81274778>] generic_shutdown_super+0x68/0x120
> [   53.104515]  [<ffffffff81275a80>] kill_anon_super+0x20/0x70
> [   53.104518]  [<ffffffff813b6fcd>] fuse_kill_sb_anon+0x4d/0x60
> [   53.104520]  [<ffffffff812745dd>] deactivate_locked_super+0x4d/0xc0
> [   53.104522]  [<ffffffff812746b3>] deactivate_super+0x63/0x70
> [   53.104525]  [<ffffffff8129fa02>] cleanup_mnt+0xb2/0x140
> [   53.104528]  [<ffffffff8129f93a>] __cleanup_mnt+0x1a/0x30
> [   53.104531]  [<ffffffff810b97bc>] task_work_run+0x6c/0xe0
> [   53.104534]  [<ffffffff81003b8a>] prepare_exit_to_usermode+0x13a/0x140
> [   53.104537]  [<ffffffff81003e11>] syscall_return_slowpath+0x281/0x2f0
> [   53.104540]  [<ffffffff8129c121>] ? SyS_umount+0x341/0x620
> [   53.104542]  [<ffffffff810f02d9>] ? trace_hardirqs_on_caller+0x19/0x290
> [   53.104545]  [<ffffffff81003017>] ? trace_hardirqs_on_thunk+0x17/0x19
> [   53.104550]  [<ffffffff8192da22>] int_ret_from_sys_call+0x25/0x9f
> 
> A problem in fuse?

Or there is a need to qualify might_sleep() by its caller.  So perhaps
set a per-CPU variable in the caller and only call might_sleep() if that
per-CPU variable is set.  Of course, have the caller clear it on return.

							Thanx, Paul

--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/

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

#1233869

FromIngo Molnar <mingo@kernel.org>
Date2015-09-28 08:10 +0200
Message-ID<qdzNn-5Ey-11@gated-at.bofh.it>
In reply to#1233634
* Sedat Dilek <sedat.dilek@gmail.com> wrote:

> [   23.874836] BUG: sleeping function called from invalid context at
> kernel/workqueue.c:2678
> [   23.874902] in_atomic(): 0, irqs_disabled(): 1, pid: 1411, name: acpid
> 
> $ grep LOCKDEP /boot/config-4.3.0-rc2-438.1-llvmlinux-amd64

Was this kernel built with LLVM?

If yes then please do not report it as 'bugs' to lkml, unless you can also 
reproduce it under GCC. Please bring it up with the LLVM folks.

Thanks,

	Ingo
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/

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

#1233876

FromSedat Dilek <sedat.dilek@gmail.com>
Date2015-09-28 08:30 +0200
Message-ID<qdA6J-613-7@gated-at.bofh.it>
In reply to#1233869
On Mon, Sep 28, 2015 at 8:03 AM, Ingo Molnar <mingo@kernel.org> wrote:
>
> * Sedat Dilek <sedat.dilek@gmail.com> wrote:
>
>> [   23.874836] BUG: sleeping function called from invalid context at
>> kernel/workqueue.c:2678
>> [   23.874902] in_atomic(): 0, irqs_disabled(): 1, pid: 1411, name: acpid
>>
>> $ grep LOCKDEP /boot/config-4.3.0-rc2-438.1-llvmlinux-amd64
>
> Was this kernel built with LLVM?
>
> If yes then please do not report it as 'bugs' to lkml, unless you can also
> reproduce it under GCC. Please bring it up with the LLVM folks.
>

My apologies for flooding the ML.

Yes, this kernel was build with LLVM.

This snippet makes the BUG line go away for me.

--- a/drivers/hid/usbhid/hid-core.c
+++ b/drivers/hid/usbhid/hid-core.c
@@ -731,6 +731,7 @@ void usbhid_close(struct hid_device *hid)
         */
        spin_lock_irq(&usbhid->lock);
        if (!--hid->open) {
+               trace_hardirqs_off();
                spin_unlock_irq(&usbhid->lock);
                hid_cancel_delayed_stuff(usbhid);
                if (!(hid->quirks & HID_QUIRK_ALWAYS_POLL)) {
@@ -1392,6 +1393,8 @@ static void usbhid_disconnect(struct usb_interface *intf)

 static void hid_cancel_delayed_stuff(struct usbhid_device *usbhid)
 {
+       might_sleep();
+
        del_timer_sync(&usbhid->io_retry);
        cancel_work_sync(&usbhid->reset_work);
 }

What does this say to me?
HID problem?
CLANG problem?
Not sure, still digging into it.

- Sedat -
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/

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

#1233635

From"Paul E. McKenney" <paulmck@linux.vnet.ibm.com>
Date2015-09-27 09:40 +0200
Message-ID<qdeIV-vP-9@gated-at.bofh.it>
In reply to#1233623
On Sun, Sep 27, 2015 at 08:28:39AM +0200, Sedat Dilek wrote:
> Hi,
> 
> as I have observed here some lockdep issues (one could be solved in
> netdev) I wanted to try this patchset.
> 
> Unfortunately, you cannot pull from...
> 
> "These changes are available in the git repository at:
> 
>   git://git.kernel.org/pub/scm/linux/kernel/git/paulmck/linux-rcu.git for-mingo
> 
> for you to fetch changes up to 19a5ecde086a6a5287978b12ae948fa691b197b7:
> 
>   rcu: Suppress lockdep false positive for rcp->exp_funnel_mutex
> (2015-09-20 21:01:22 -0700)
> 
> ----------------------------------------------------------------
> Oleg Nesterov (1):
>       rcu: Change _wait_rcu_gp() to work around GCC bug 67055
> 
> Paul E. McKenney (1):
>       rcu: Suppress lockdep false positive for rcp->exp_funnel_mutex
> 
>  include/linux/rcupdate.h | 11 +++++------
>  kernel/rcu/tree.c        |  5 +++++
>  2 files changed, 10 insertions(+), 6 deletions(-)"
> 
> So, I have stolen them from linux-next.git.
> 
> Please look at this, Thanks.

Does it work better now?  (Forgot to actually push the new name...)

							Thanx, Paul

> Regards,
> - Sedat -
> 
> [1] http://marc.info/?l=linux-kernel&m=144332758307978&w=2
> [2] http://git.kernel.org/cgit/linux/kernel/git/next/linux-next.git/patch/?id=66e8c57da6bf6b847a48a5a6fda59512f733ed78
> [3] http://git.kernel.org/cgit/linux/kernel/git/next/linux-next.git/patch/?id=19a5ecde086a6a5287978b12ae948fa691b197b7
> 

--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/

[toc] | [prev] | [standalone]

Back to top | Article view | linux.kernel

csiph-web