2.6.21-rc6 + firstfloor patches: BUG: sleeping function called from invalid context at kernel/sched,.c:3643

2.6.21-rc6 + firstfloor patches: BUG: sleeping function called from invalid context at kernel/sched,.c:3643

[Jeremy Fitzhardinge]

I'm seeing this:

Apr 13 21:55:34 localhost kernel: BUG: sleeping function called from invalid context at kernel/sched.c:3643
Apr 13 21:55:34 localhost kernel: in_atomic():1, irqs_disabled():0
Apr 13 21:55:34 localhost kernel: 1 lock held by events/0/8:
Apr 13 21:55:34 localhost kernel:  #0:  (dbs_mutex){--..}, at: [<c032046b>] mutex_lock+0x1f/0x23
Apr 13 21:55:34 localhost kernel:  [<c0106f25>] show_trace_log_lvl+0x1a/0x30
Apr 13 21:55:34 localhost kernel:  [<c0107588>] show_trace+0x12/0x14
Apr 13 21:55:34 localhost kernel:  [<c0107650>] dump_stack+0x16/0x18
Apr 13 21:55:34 localhost kernel:  [<c011a56a>] __might_sleep+0xe5/0xeb
Apr 13 21:55:34 localhost kernel:  [<c031f194>] wait_for_completion+0x1a/0xaa
Apr 13 21:55:34 localhost kernel:  [<c011bea3>] set_cpus_allowed+0x6e/0x8c
Apr 13 21:55:34 localhost kernel:  [<c010f490>] acpi_cpufreq_target+0x18d/0x262
Apr 13 21:55:34 localhost kernel:  [<c02ae6d5>] __cpufreq_driver_target+0x27/0x32
Apr 13 21:55:34 localhost kernel:  [<c02b0d2b>] do_dbs_timer+0x190/0x1d2
Apr 13 21:55:34 localhost kernel:  [<c012ecde>] run_workqueue+0x8f/0x15f
Apr 13 21:55:34 localhost kernel:  [<c012f4ab>] worker_thread+0xf8/0x124
Apr 13 21:55:34 localhost kernel:  [<c0131cf0>] kthread+0xb5/0xe1
Apr 13 21:55:34 localhost kernel:  [<c0106b07>] kernel_thread_helper+0x7/0x10
Apr 13 21:55:34 localhost kernel:  =======================
Apr 13 21:55:34 localhost kernel: BUG: scheduling while atomic: events/0/0x00000002/8
Apr 13 21:55:34 localhost kernel: 1 lock held by events/0/8:
Apr 13 21:55:34 localhost kernel:  #0:  (dbs_mutex){--..}, at: [<c032046b>] mutex_lock+0x1f/0x23
Apr 13 21:55:34 localhost kernel:  [<c0106f25>] show_trace_log_lvl+0x1a/0x30
Apr 13 21:55:34 localhost kernel:  [<c0107588>] show_trace+0x12/0x14
Apr 13 21:55:34 localhost kernel:  [<c0107650>] dump_stack+0x16/0x18
Apr 13 21:55:34 localhost kernel:  [<c031e971>] __sched_text_start+0x79/0x86a
Apr 13 21:55:34 localhost kernel:  [<c031f1ee>] wait_for_completion+0x74/0xaa
Apr 13 21:55:34 localhost kernel:  [<c011bea3>] set_cpus_allowed+0x6e/0x8c
Apr 13 21:55:34 localhost kernel:  [<c010f490>] acpi_cpufreq_target+0x18d/0x262
Apr 13 21:55:34 localhost kernel:  [<c02ae6d5>] __cpufreq_driver_target+0x27/0x32
Apr 13 21:55:34 localhost kernel:  [<c02b0d2b>] do_dbs_timer+0x190/0x1d2
Apr 13 21:55:34 localhost kernel:  [<c012ecde>] run_workqueue+0x8f/0x15f
Apr 13 21:55:34 localhost kernel:  [<c012f4ab>] worker_thread+0xf8/0x124
Apr 13 21:55:34 localhost kernel:  [<c0131cf0>] kthread+0xb5/0xe1
Apr 13 21:55:34 localhost kernel:  [<c0106b07>] kernel_thread_helper+0x7/0x10
[...repeat ad nauseum...]

Re: 2.6.21-rc6 + firstfloor patches: BUG: sleeping function called from invalid context at kernel/sched,.c:3643

[Andi Kleen]

On Saturday 14 April 2007 08:20:50 Jeremy Fitzhardinge wrote:
> I'm seeing this:
> 
> Apr 13 21:55:34 localhost kernel: BUG: sleeping function called from invalid context at kernel/sched.c:3643

Fixed now. The latest sched-clock was leaking preempt counts during
cpu frequency changes.

-Andi

Re: 2.6.21-rc6 + firstfloor patches: BUG: sleeping function called from invalid context at kernel/sched,.c:3643

[Jeremy Fitzhardinge]

Andi Kleen wrote:
> Fixed now. The latest sched-clock was leaking preempt counts during
> cpu frequency changes.
>   

No, that didn't help.  I think its cpufreq:

Apr 14 13:58:29 localhost kernel: BUG: scheduling while atomic: swapper/0x00000002/1
Apr 14 13:58:29 localhost kernel: 2 locks held by swapper/1:
Apr 14 13:58:29 localhost kernel:  #0:  (&per_cpu(cpu_policy_rwsem, cpu)){--..}, at: [<c02af1ec>] lock_policy_rwsem_write
+0x35/0x5f
Apr 14 13:58:29 localhost kernel:  #1:  (userspace_mutex){--..}, at: [<c032046b>] mutex_lock+0x1f/0x23
Apr 14 13:58:29 localhost kernel:  [<c0106f25>] show_trace_log_lvl+0x1a/0x30
Apr 14 13:58:29 localhost kernel:  [<c0107588>] show_trace+0x12/0x14
Apr 14 13:58:29 localhost kernel:  [<c0107650>] dump_stack+0x16/0x18
Apr 14 13:58:29 localhost kernel:  [<c031e971>] __sched_text_start+0x79/0x86a
Apr 14 13:58:29 localhost kernel:  [<c031f1ee>] wait_for_completion+0x74/0xaa
Apr 14 13:58:29 localhost kernel:  [<c011bea3>] set_cpus_allowed+0x6e/0x8c
Apr 14 13:58:29 localhost kernel:  [<c010f490>] acpi_cpufreq_target+0x18d/0x262
Apr 14 13:58:29 localhost kernel:  [<c02ae6d5>] __cpufreq_driver_target+0x27/0x32
Apr 14 13:58:29 localhost kernel:  [<c02aff0b>] cpufreq_governor_userspace+0x120/0x154
Apr 14 13:58:29 localhost kernel:  [<c02ae888>] __cpufreq_governor+0x77/0xab
Apr 14 13:58:29 localhost kernel:  [<c02aee6a>] __cpufreq_set_policy+0x109/0x11a
Apr 14 13:58:29 localhost kernel:  [<c02af32d>] cpufreq_set_policy+0x32/0x6c
Apr 14 13:58:29 localhost kernel:  [<c02afc11>] cpufreq_add_dev+0x347/0x3ea
Apr 14 13:58:29 localhost kernel:  [<c024a15e>] sysdev_driver_register+0x62/0xaf
Apr 14 13:58:29 localhost kernel:  [<c02af85a>] cpufreq_register_driver+0x82/0xf2
Apr 14 13:58:29 localhost kernel:  [<c0454f24>] acpi_cpufreq_init+0x8d/0x93
Apr 14 13:58:29 localhost kernel:  [<c04497c7>] init+0x14b/0x241
Apr 14 13:58:29 localhost kernel:  [<c0106b07>] kernel_thread_helper+0x7/0x10
Apr 14 13:58:29 localhost kernel:  =======================
Apr 14 13:58:29 localhost kernel: initcall at 0xc0454e97: acpi_cpufreq_init+0x0/0x93(): returned with preemption imbalance


    J

Re: 2.6.21-rc6 + firstfloor patches: BUG: sleeping function called from invalid context at kernel/sched,.c:3643

[Andi Kleen]

On Saturday 14 April 2007 23:12:25 Jeremy Fitzhardinge wrote:
> Andi Kleen wrote:
> > Fixed now. The latest sched-clock was leaking preempt counts during
> > cpu frequency changes.
> >   
> 
> No, that didn't help.  I think its cpufreq:

Hmm, are you sure? Can you double check?  With the latest tree?

I could reproduce the problem and my change fixed the problem for me.

-Andi

Re: 2.6.21-rc6 + firstfloor patches: BUG: sleeping function called from invalid context at kernel/sched,.c:3643

[Jeremy Fitzhardinge]

Andi Kleen wrote:
> Hmm, are you sure? Can you double check?  With the latest tree?
>
> I could reproduce the problem and my change fixed the problem for me.
>   

Hm.  Me too.  I just booted 2.6.21-rc7-ff-paravirt, and it seems fine.

    J