* cpufreq/ondemand: unpinning an unpinned lock.
@ 2015-07-15 22:04 Dave Jones
2015-07-16 0:13 ` Rafael J. Wysocki
0 siblings, 1 reply; 6+ messages in thread
From: Dave Jones @ 2015-07-15 22:04 UTC (permalink / raw)
To: Linux Kernel; +Cc: rjw, linux-pm
WARNING: CPU: 1 PID: 29529 at kernel/locking/lockdep.c:3497 lock_unpin_lock+0x109/0x110()
unpinning an unpinned lock
CPU: 1 PID: 29529 Comm: kworker/1:1 Not tainted 4.2.0-rc2-think+ #3
Workqueue: events od_dbs_timer
0000000000000009 ffff880094d5baa8 ffffffffae7f5e6f 0000000000000007
ffff880094d5baf8 ffff880094d5bae8 ffffffffae07b91a 0000000000000118
00000000000000e0 ffff880507bd5c58 0000000000000092 0000000000000004
Call Trace:
[<ffffffffae7f5e6f>] dump_stack+0x4f/0x7b
[<ffffffffae07b91a>] warn_slowpath_common+0x8a/0xc0
[<ffffffffae07b996>] warn_slowpath_fmt+0x46/0x50
[<ffffffffae0d0ec9>] lock_unpin_lock+0x109/0x110
[<ffffffffae7f93cc>] __schedule+0x3ac/0xb60
[<ffffffffae7f9c41>] schedule+0x41/0x90
[<ffffffffae7f9ff8>] schedule_preempt_disabled+0x18/0x30
[<ffffffffae7fbcef>] mutex_lock_nested+0x16f/0x3e0
[<ffffffffae69207f>] ? gov_queue_work+0x2f/0xf0
[<ffffffffae690ec7>] ? od_check_cpu+0x57/0xd0
[<ffffffffae69207f>] ? gov_queue_work+0x2f/0xf0
[<ffffffffae69207f>] gov_queue_work+0x2f/0xf0
[<ffffffffae6918dd>] od_dbs_timer+0xbd/0x150
[<ffffffffae099613>] process_one_work+0x1f3/0x7a0
[<ffffffffae099582>] ? process_one_work+0x162/0x7a0
[<ffffffffae099cb9>] ? worker_thread+0xf9/0x470
[<ffffffffae099c29>] worker_thread+0x69/0x470
[<ffffffffae0ad993>] ? preempt_count_sub+0xa3/0xf0
[<ffffffffae099bc0>] ? process_one_work+0x7a0/0x7a0
[<ffffffffae09fddf>] kthread+0x11f/0x140
[<ffffffffae09fcc0>] ? kthread_create_on_node+0x250/0x250
[<ffffffffae80090f>] ret_from_fork+0x3f/0x70
[<ffffffffae09fcc0>] ? kthread_create_on_node+0x250/0x250
---[ end trace 86cca931caec9193 ]---
^ permalink raw reply [flat|nested] 6+ messages in thread
* Re: cpufreq/ondemand: unpinning an unpinned lock.
2015-07-15 22:04 cpufreq/ondemand: unpinning an unpinned lock Dave Jones
@ 2015-07-16 0:13 ` Rafael J. Wysocki
2015-07-16 5:11 ` Viresh Kumar
0 siblings, 1 reply; 6+ messages in thread
From: Rafael J. Wysocki @ 2015-07-16 0:13 UTC (permalink / raw)
To: Dave Jones; +Cc: Linux Kernel, linux-pm, Viresh Kumar
Cc: Viresh as he's been working on governors recently.
On Wednesday, July 15, 2015 06:04:22 PM Dave Jones wrote:
> WARNING: CPU: 1 PID: 29529 at kernel/locking/lockdep.c:3497 lock_unpin_lock+0x109/0x110()
> unpinning an unpinned lock
> CPU: 1 PID: 29529 Comm: kworker/1:1 Not tainted 4.2.0-rc2-think+ #3
> Workqueue: events od_dbs_timer
> 0000000000000009 ffff880094d5baa8 ffffffffae7f5e6f 0000000000000007
> ffff880094d5baf8 ffff880094d5bae8 ffffffffae07b91a 0000000000000118
> 00000000000000e0 ffff880507bd5c58 0000000000000092 0000000000000004
> Call Trace:
> [<ffffffffae7f5e6f>] dump_stack+0x4f/0x7b
> [<ffffffffae07b91a>] warn_slowpath_common+0x8a/0xc0
> [<ffffffffae07b996>] warn_slowpath_fmt+0x46/0x50
> [<ffffffffae0d0ec9>] lock_unpin_lock+0x109/0x110
> [<ffffffffae7f93cc>] __schedule+0x3ac/0xb60
> [<ffffffffae7f9c41>] schedule+0x41/0x90
> [<ffffffffae7f9ff8>] schedule_preempt_disabled+0x18/0x30
> [<ffffffffae7fbcef>] mutex_lock_nested+0x16f/0x3e0
> [<ffffffffae69207f>] ? gov_queue_work+0x2f/0xf0
> [<ffffffffae690ec7>] ? od_check_cpu+0x57/0xd0
> [<ffffffffae69207f>] ? gov_queue_work+0x2f/0xf0
> [<ffffffffae69207f>] gov_queue_work+0x2f/0xf0
> [<ffffffffae6918dd>] od_dbs_timer+0xbd/0x150
> [<ffffffffae099613>] process_one_work+0x1f3/0x7a0
> [<ffffffffae099582>] ? process_one_work+0x162/0x7a0
> [<ffffffffae099cb9>] ? worker_thread+0xf9/0x470
> [<ffffffffae099c29>] worker_thread+0x69/0x470
> [<ffffffffae0ad993>] ? preempt_count_sub+0xa3/0xf0
> [<ffffffffae099bc0>] ? process_one_work+0x7a0/0x7a0
> [<ffffffffae09fddf>] kthread+0x11f/0x140
> [<ffffffffae09fcc0>] ? kthread_create_on_node+0x250/0x250
> [<ffffffffae80090f>] ret_from_fork+0x3f/0x70
> [<ffffffffae09fcc0>] ? kthread_create_on_node+0x250/0x250
> ---[ end trace 86cca931caec9193 ]---
--
I speak only for myself.
Rafael J. Wysocki, Intel Open Source Technology Center.
^ permalink raw reply [flat|nested] 6+ messages in thread
* Re: cpufreq/ondemand: unpinning an unpinned lock.
2015-07-16 0:13 ` Rafael J. Wysocki
@ 2015-07-16 5:11 ` Viresh Kumar
2015-07-16 12:42 ` Dave Jones
0 siblings, 1 reply; 6+ messages in thread
From: Viresh Kumar @ 2015-07-16 5:11 UTC (permalink / raw)
To: Rafael J. Wysocki; +Cc: Dave Jones, Linux Kernel, linux-pm
On 16-07-15, 02:13, Rafael J. Wysocki wrote:
> Cc: Viresh as he's been working on governors recently.
>
> On Wednesday, July 15, 2015 06:04:22 PM Dave Jones wrote:
> > WARNING: CPU: 1 PID: 29529 at kernel/locking/lockdep.c:3497 lock_unpin_lock+0x109/0x110()
> > unpinning an unpinned lock
> > CPU: 1 PID: 29529 Comm: kworker/1:1 Not tainted 4.2.0-rc2-think+ #3
> > Workqueue: events od_dbs_timer
> > 0000000000000009 ffff880094d5baa8 ffffffffae7f5e6f 0000000000000007
> > ffff880094d5baf8 ffff880094d5bae8 ffffffffae07b91a 0000000000000118
> > 00000000000000e0 ffff880507bd5c58 0000000000000092 0000000000000004
> > Call Trace:
> > [<ffffffffae7f5e6f>] dump_stack+0x4f/0x7b
> > [<ffffffffae07b91a>] warn_slowpath_common+0x8a/0xc0
> > [<ffffffffae07b996>] warn_slowpath_fmt+0x46/0x50
> > [<ffffffffae0d0ec9>] lock_unpin_lock+0x109/0x110
> > [<ffffffffae7f93cc>] __schedule+0x3ac/0xb60
> > [<ffffffffae7f9c41>] schedule+0x41/0x90
> > [<ffffffffae7f9ff8>] schedule_preempt_disabled+0x18/0x30
> > [<ffffffffae7fbcef>] mutex_lock_nested+0x16f/0x3e0
> > [<ffffffffae69207f>] ? gov_queue_work+0x2f/0xf0
> > [<ffffffffae690ec7>] ? od_check_cpu+0x57/0xd0
> > [<ffffffffae69207f>] ? gov_queue_work+0x2f/0xf0
> > [<ffffffffae69207f>] gov_queue_work+0x2f/0xf0
> > [<ffffffffae6918dd>] od_dbs_timer+0xbd/0x150
> > [<ffffffffae099613>] process_one_work+0x1f3/0x7a0
> > [<ffffffffae099582>] ? process_one_work+0x162/0x7a0
> > [<ffffffffae099cb9>] ? worker_thread+0xf9/0x470
> > [<ffffffffae099c29>] worker_thread+0x69/0x470
> > [<ffffffffae0ad993>] ? preempt_count_sub+0xa3/0xf0
> > [<ffffffffae099bc0>] ? process_one_work+0x7a0/0x7a0
> > [<ffffffffae09fddf>] kthread+0x11f/0x140
> > [<ffffffffae09fcc0>] ? kthread_create_on_node+0x250/0x250
> > [<ffffffffae80090f>] ret_from_fork+0x3f/0x70
> > [<ffffffffae09fcc0>] ? kthread_create_on_node+0x250/0x250
> > ---[ end trace 86cca931caec9193 ]---
I don't know why this will happen. Just to confirm, you are getting
this over 4.2-rc(1 or 2)? And you weren't getting these on 4.1 at all?
And its always reproducible? How ?
There have been races in cpufreq core since sometime and what got
pushed in 4.2-rc1 is just half of the fix. The other half is present
here:
http://marc.info/?i=cover.1434713657.git.viresh.kumar%40linaro.org
Please try this and let us know if things work well or not.
--
viresh
^ permalink raw reply [flat|nested] 6+ messages in thread
* Re: cpufreq/ondemand: unpinning an unpinned lock.
2015-07-16 5:11 ` Viresh Kumar
@ 2015-07-16 12:42 ` Dave Jones
2015-07-22 0:46 ` Stephen Boyd
0 siblings, 1 reply; 6+ messages in thread
From: Dave Jones @ 2015-07-16 12:42 UTC (permalink / raw)
To: Viresh Kumar; +Cc: Rafael J. Wysocki, Linux Kernel, linux-pm
On Thu, Jul 16, 2015 at 10:41:50AM +0530, Viresh Kumar wrote:
> > > WARNING: CPU: 1 PID: 29529 at kernel/locking/lockdep.c:3497 lock_unpin_lock+0x109/0x110()
> > > unpinning an unpinned lock
> > > CPU: 1 PID: 29529 Comm: kworker/1:1 Not tainted 4.2.0-rc2-think+ #3
> > > Workqueue: events od_dbs_timer
> > > 0000000000000009 ffff880094d5baa8 ffffffffae7f5e6f 0000000000000007
> > > ffff880094d5baf8 ffff880094d5bae8 ffffffffae07b91a 0000000000000118
> > > 00000000000000e0 ffff880507bd5c58 0000000000000092 0000000000000004
> > > Call Trace:
> > > [<ffffffffae7f5e6f>] dump_stack+0x4f/0x7b
> > > [<ffffffffae07b91a>] warn_slowpath_common+0x8a/0xc0
> > > [<ffffffffae07b996>] warn_slowpath_fmt+0x46/0x50
> > > [<ffffffffae0d0ec9>] lock_unpin_lock+0x109/0x110
> > > [<ffffffffae7f93cc>] __schedule+0x3ac/0xb60
> > > [<ffffffffae7f9c41>] schedule+0x41/0x90
> > > [<ffffffffae7f9ff8>] schedule_preempt_disabled+0x18/0x30
> > > [<ffffffffae7fbcef>] mutex_lock_nested+0x16f/0x3e0
> > > [<ffffffffae69207f>] ? gov_queue_work+0x2f/0xf0
> > > [<ffffffffae690ec7>] ? od_check_cpu+0x57/0xd0
> > > [<ffffffffae69207f>] ? gov_queue_work+0x2f/0xf0
> > > [<ffffffffae69207f>] gov_queue_work+0x2f/0xf0
> > > [<ffffffffae6918dd>] od_dbs_timer+0xbd/0x150
>
> I don't know why this will happen. Just to confirm, you are getting
> this over 4.2-rc(1 or 2)? And you weren't getting these on 4.1 at all?
> And its always reproducible? How ?
I've hit it once, on rc2. I didn't have a lot of time for testing rc1.
> There have been races in cpufreq core since sometime and what got
> pushed in 4.2-rc1 is just half of the fix. The other half is present
> here:
>
> http://marc.info/?i=cover.1434713657.git.viresh.kumar%40linaro.org
>
> Please try this and let us know if things work well or not.
Sure. Though proving the absense of a bug like this is always fun.
Dave
^ permalink raw reply [flat|nested] 6+ messages in thread
* Re: cpufreq/ondemand: unpinning an unpinned lock.
2015-07-16 12:42 ` Dave Jones
@ 2015-07-22 0:46 ` Stephen Boyd
2015-07-22 9:02 ` Peter Zijlstra
0 siblings, 1 reply; 6+ messages in thread
From: Stephen Boyd @ 2015-07-22 0:46 UTC (permalink / raw)
To: Dave Jones, Viresh Kumar, Peter Zijlstra
Cc: Rafael J. Wysocki, Linux Kernel, linux-pm
On 07/16/2015 05:42 AM, Dave Jones wrote:
> On Thu, Jul 16, 2015 at 10:41:50AM +0530, Viresh Kumar wrote:
>
> > > > WARNING: CPU: 1 PID: 29529 at kernel/locking/lockdep.c:3497 lock_unpin_lock+0x109/0x110()
> > > > unpinning an unpinned lock
> > > > CPU: 1 PID: 29529 Comm: kworker/1:1 Not tainted 4.2.0-rc2-think+ #3
> > > > Workqueue: events od_dbs_timer
> > > > 0000000000000009 ffff880094d5baa8 ffffffffae7f5e6f 0000000000000007
> > > > ffff880094d5baf8 ffff880094d5bae8 ffffffffae07b91a 0000000000000118
> > > > 00000000000000e0 ffff880507bd5c58 0000000000000092 0000000000000004
> > > > Call Trace:
> > > > [<ffffffffae7f5e6f>] dump_stack+0x4f/0x7b
> > > > [<ffffffffae07b91a>] warn_slowpath_common+0x8a/0xc0
> > > > [<ffffffffae07b996>] warn_slowpath_fmt+0x46/0x50
> > > > [<ffffffffae0d0ec9>] lock_unpin_lock+0x109/0x110
> > > > [<ffffffffae7f93cc>] __schedule+0x3ac/0xb60
> > > > [<ffffffffae7f9c41>] schedule+0x41/0x90
> > > > [<ffffffffae7f9ff8>] schedule_preempt_disabled+0x18/0x30
> > > > [<ffffffffae7fbcef>] mutex_lock_nested+0x16f/0x3e0
> > > > [<ffffffffae69207f>] ? gov_queue_work+0x2f/0xf0
> > > > [<ffffffffae690ec7>] ? od_check_cpu+0x57/0xd0
> > > > [<ffffffffae69207f>] ? gov_queue_work+0x2f/0xf0
> > > > [<ffffffffae69207f>] gov_queue_work+0x2f/0xf0
> > > > [<ffffffffae6918dd>] od_dbs_timer+0xbd/0x150
> >
> > I don't know why this will happen. Just to confirm, you are getting
> > this over 4.2-rc(1 or 2)? And you weren't getting these on 4.1 at all?
> > And its always reproducible? How ?
>
> I've hit it once, on rc2. I didn't have a lot of time for testing rc1.
Lock pinning is new in v4.2-rc1. Adding Peter just in case there's some
insight.
--
Qualcomm Innovation Center, Inc. is a member of Code Aurora Forum,
a Linux Foundation Collaborative Project
^ permalink raw reply [flat|nested] 6+ messages in thread
* Re: cpufreq/ondemand: unpinning an unpinned lock.
2015-07-22 0:46 ` Stephen Boyd
@ 2015-07-22 9:02 ` Peter Zijlstra
0 siblings, 0 replies; 6+ messages in thread
From: Peter Zijlstra @ 2015-07-22 9:02 UTC (permalink / raw)
To: Stephen Boyd
Cc: Dave Jones, Viresh Kumar, Rafael J. Wysocki, Linux Kernel,
linux-pm
On Tue, Jul 21, 2015 at 05:46:16PM -0700, Stephen Boyd wrote:
> On 07/16/2015 05:42 AM, Dave Jones wrote:
> >On Thu, Jul 16, 2015 at 10:41:50AM +0530, Viresh Kumar wrote:
> >
> > > > > WARNING: CPU: 1 PID: 29529 at kernel/locking/lockdep.c:3497 lock_unpin_lock+0x109/0x110()
> > > > > unpinning an unpinned lock
> > > > > Call Trace:
> > > > > [<ffffffffae0d0ec9>] lock_unpin_lock+0x109/0x110
> > > > > [<ffffffffae7f93cc>] __schedule+0x3ac/0xb60
> > > > > [<ffffffffae7f9c41>] schedule+0x41/0x90
> > > > > [<ffffffffae7f9ff8>] schedule_preempt_disabled+0x18/0x30
> Lock pinning is new in v4.2-rc1. Adding Peter just in case there's some
> insight.
Hmm, weird. I've not seen it happen before.
There's potentially 3 unpin's in __schedule():
- the obvious one in the prev == next case,
- the on in context_switch(),
- the on in try_to_wake_up_local().
All 3 appear to be balanced; the first and second against the pin_lock()
at the start of __schedule() and the third against that and it repins
the lock against the first two.
Most curious.
^ permalink raw reply [flat|nested] 6+ messages in thread
end of thread, other threads:[~2015-07-22 9:03 UTC | newest]
Thread overview: 6+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2015-07-15 22:04 cpufreq/ondemand: unpinning an unpinned lock Dave Jones
2015-07-16 0:13 ` Rafael J. Wysocki
2015-07-16 5:11 ` Viresh Kumar
2015-07-16 12:42 ` Dave Jones
2015-07-22 0:46 ` Stephen Boyd
2015-07-22 9:02 ` Peter Zijlstra
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).