oprofile? lockdep warning from 2.6.27-rc1-mm1

oprofile? lockdep warning from 2.6.27-rc1-mm1

[hooanon05]

Hello,

While I was testing my filesystem module on 2.6.27-rc1-mm1, I got this
message from oprofile. Is this a known problem, or did I miss something?
sync_buffer() is the one in drivers/oprofile/buffer_sync.c instead of
fs/buffer.c.


Junjiro R. Okajima

----------------------------------------------------------------------

+ sudo opcontrol --setup --vmlinux=/home/jro/transparent/linux-2.6.27-rc1-mm1/D/vmlinux
+ sudo opcontrol --reset
+ sudo opcontrol --start
Using default event: GLOBAL_POWER_EVENTS:100000:1:1:1
Using 2.6+ OProfile kernel interface.
Reading module info.
Daemon started.

=======================================================
[ INFO: possible circular locking dependency detected ]
2.6.27-rc1-mm1jrousD #1
-------------------------------------------------------
events/0/7 is trying to acquire lock:
 (&mm->mmap_sem){----}, at: [<c02d6500>] sync_buffer+0xe7/0x3c9

but task is already holding lock:
 (buffer_mutex){--..}, at: [<c02d6445>] sync_buffer+0x2c/0x3c9

which lock already depends on the new lock.


the existing dependency chain (in reverse order) is:

-> #3 (buffer_mutex){--..}:
       [<c01427d7>] __lock_acquire+0x1195/0x128d
       [<c014296e>] lock_acquire+0x9f/0xb9
       [<c0369f33>] mutex_lock_nested+0xbd/0x39f
       [<c02d6445>] sync_buffer+0x2c/0x3c9
       [<c02d6170>] wq_sync_buffer+0x3e/0x5c
       [<c012ff4a>] run_workqueue+0x128/0x226
       [<c0130b0c>] worker_thread+0x72/0xa7
       [<c0133217>] kthread+0x37/0x59
       [<c0103e37>] kernel_thread_helper+0x7/0x10
       [<ffffffff>] 0xffffffff

-> #2 (&(&b->work)->work){--..}:
       [<c01427d7>] __lock_acquire+0x1195/0x128d
       [<c014296e>] lock_acquire+0x9f/0xb9
       [<c012ff45>] run_workqueue+0x123/0x226
       [<c0130b0c>] worker_thread+0x72/0xa7
       [<c0133217>] kthread+0x37/0x59
       [<c0103e37>] kernel_thread_helper+0x7/0x10
       [<ffffffff>] 0xffffffff

-> #1 (events){--..}:
       [<c01427d7>] __lock_acquire+0x1195/0x128d
       [<c014296e>] lock_acquire+0x9f/0xb9
       [<c01306ac>] flush_work+0x51/0xd2
       [<c0130bda>] schedule_on_each_cpu+0x99/0xbf
       [<c0166266>] lru_add_drain_all+0xd/0xf
       [<c01703a6>] __mlock_vma_pages_range+0x44/0x294
       [<c01706eb>] mlock_fixup+0xf5/0x1c3
       [<c0170832>] do_mlockall+0x79/0x8d
       [<c0170b7d>] sys_mlockall+0x74/0x9e
       [<c0103151>] sysenter_do_call+0x12/0x31
       [<ffffffff>] 0xffffffff

-> #0 (&mm->mmap_sem){----}:
       [<c01425fa>] __lock_acquire+0xfb8/0x128d
       [<c014296e>] lock_acquire+0x9f/0xb9
       [<c036a77e>] down_read+0x3d/0x74
       [<c02d6500>] sync_buffer+0xe7/0x3c9
       [<c02d6170>] wq_sync_buffer+0x3e/0x5c
       [<c012ff4a>] run_workqueue+0x128/0x226
       [<c0130b0c>] worker_thread+0x72/0xa7
       [<c0133217>] kthread+0x37/0x59
       [<c0103e37>] kernel_thread_helper+0x7/0x10
       [<ffffffff>] 0xffffffff

other info that might help us debug this:

3 locks held by events/0/7:
 #0:  (events){--..}, at: [<c012fefc>] run_workqueue+0xda/0x226
 #1:  (&(&b->work)->work){--..}, at: [<c012ff22>] run_workqueue+0x100/0x226
 #2:  (buffer_mutex){--..}, at: [<c02d6445>] sync_buffer+0x2c/0x3c9

stack backtrace:
Pid: 7, comm: events/0 Not tainted 2.6.27-rc1-mm1jrousD #1
 [<c013fb3b>] print_circular_bug_tail+0x68/0x71
 [<c013f1ce>] ? print_circular_bug_entry+0x43/0x4b
 [<c01425fa>] __lock_acquire+0xfb8/0x128d
 [<c0236cc4>] ? debug_smp_processor_id+0x28/0xdc
 [<c013e7ed>] ? trace_hardirqs_off+0xb/0xd
 [<c014296e>] lock_acquire+0x9f/0xb9
 [<c02d6500>] ? sync_buffer+0xe7/0x3c9
 [<c036a77e>] down_read+0x3d/0x74
 [<c02d6500>] ? sync_buffer+0xe7/0x3c9
 [<c02d6500>] sync_buffer+0xe7/0x3c9
 [<c02d6170>] wq_sync_buffer+0x3e/0x5c
 [<c012ff22>] ? run_workqueue+0x100/0x226
 [<c012ff4a>] run_workqueue+0x128/0x226
 [<c012ff22>] ? run_workqueue+0x100/0x226
 [<c02d6132>] ? wq_sync_buffer+0x0/0x5c
 [<c0130b0c>] worker_thread+0x72/0xa7
 [<c01334d6>] ? autoremove_wake_function+0x0/0x3a
 [<c0130a9a>] ? worker_thread+0x0/0xa7
 [<c0133217>] kthread+0x37/0x59
 [<c01331e0>] ? kthread+0x0/0x59
 [<c0103e37>] kernel_thread_helper+0x7/0x10
 =======================
Using log file /var/lib/oprofile/oprofiled.log
Profiler running.

Re: oprofile? lockdep warning from 2.6.27-rc1-mm1

[hooanon05]

Robert Richter:
> this is new to me. I will take a look at this.

Thanks.
Here is another message at shutdown time.


Junjiro R. Okajima

----------------------------------------------------------------------
BUG: sleeping function called from invalid context at /home/jro/transparent/linux-2.6.27-rc1-mm1/kernel/sched.c:4613
in_atomic():1, irqs_disabled():0
1 lock held by oprofiled/1843:
 #0:  (start_mutex){--..}, at: [<c02d5c77>] oprofile_shutdown+0xf/0x5a
Pid: 1843, comm: oprofiled Not tainted 2.6.27-rc1-mm1jrousD #1
 [<c011ac79>] __might_sleep+0xdf/0x103
 [<c03688a8>] wait_for_common+0x1f/0x140
 [<c036e602>] ? sub_preempt_count+0x62/0xb0
 [<c036bf14>] ? _spin_unlock_irqrestore+0x53/0x69
 [<c0368a4b>] wait_for_completion+0x12/0x14
 [<c01314fe>] synchronize_rcu+0x2d/0x33
 [<c013154b>] ? wakeme_after_rcu+0x0/0xd
 [<c0137cc5>] atomic_notifier_chain_unregister+0x2b/0x32
 [<c0137cdb>] unregister_die_notifier+0xf/0x14
 [<c02d787c>] nmi_shutdown+0x44/0x84
 [<c02d5c94>] oprofile_shutdown+0x2c/0x5a
 [<c02d697c>] event_buffer_release+0x10/0x3c
 [<c01849a8>] __fput+0xc7/0x1b8
 [<c0184e43>] fput+0x22/0x3b
 [<c0181c32>] filp_close+0x43/0x69
 [<c012266f>] ? exit_files+0x30/0x3c
 [<c012261a>] put_files_struct+0xb1/0xd6
 [<c0122676>] exit_files+0x37/0x3c
 [<c0123b21>] do_exit+0x292/0x909
 [<c013e854>] ? put_lock_stats+0x27/0x3a
 [<c013e8b9>] ? lock_release_holdtime+0x52/0x6b
 [<c0173114>] ? sys_munmap+0x3b/0x42
 [<c01241dd>] do_group_exit+0x45/0x9d
 [<c0124244>] sys_exit_group+0xf/0x11
 [<c0103151>] sysenter_do_call+0x12/0x31
 =======================

Re: oprofile? lockdep warning from 2.6.27-rc1-mm1

[Robert Richter]

On 05.08.08 20:29:06, hooanon05@yahoo.co.jp wrote:
> 
> Robert Richter:
> > this is new to me. I will take a look at this.
> 
> Thanks.
> Here is another message at shutdown time.

Junjiro,

I reworked the code around this bug and it is upstream in
v2.6.29-rc1. Could you test with this version and look if the problem
still exists, please?

Thanks,

-Robert

> 
> 
> Junjiro R. Okajima
> 
> ----------------------------------------------------------------------
> BUG: sleeping function called from invalid context at /home/jro/transparent/linux-2.6.27-rc1-mm1/kernel/sched.c:4613
> in_atomic():1, irqs_disabled():0
> 1 lock held by oprofiled/1843:
>  #0:  (start_mutex){--..}, at: [<c02d5c77>] oprofile_shutdown+0xf/0x5a
> Pid: 1843, comm: oprofiled Not tainted 2.6.27-rc1-mm1jrousD #1
>  [<c011ac79>] __might_sleep+0xdf/0x103
>  [<c03688a8>] wait_for_common+0x1f/0x140
>  [<c036e602>] ? sub_preempt_count+0x62/0xb0
>  [<c036bf14>] ? _spin_unlock_irqrestore+0x53/0x69
>  [<c0368a4b>] wait_for_completion+0x12/0x14
>  [<c01314fe>] synchronize_rcu+0x2d/0x33
>  [<c013154b>] ? wakeme_after_rcu+0x0/0xd
>  [<c0137cc5>] atomic_notifier_chain_unregister+0x2b/0x32
>  [<c0137cdb>] unregister_die_notifier+0xf/0x14
>  [<c02d787c>] nmi_shutdown+0x44/0x84
>  [<c02d5c94>] oprofile_shutdown+0x2c/0x5a
>  [<c02d697c>] event_buffer_release+0x10/0x3c
>  [<c01849a8>] __fput+0xc7/0x1b8
>  [<c0184e43>] fput+0x22/0x3b
>  [<c0181c32>] filp_close+0x43/0x69
>  [<c012266f>] ? exit_files+0x30/0x3c
>  [<c012261a>] put_files_struct+0xb1/0xd6
>  [<c0122676>] exit_files+0x37/0x3c
>  [<c0123b21>] do_exit+0x292/0x909
>  [<c013e854>] ? put_lock_stats+0x27/0x3a
>  [<c013e8b9>] ? lock_release_holdtime+0x52/0x6b
>  [<c0173114>] ? sys_munmap+0x3b/0x42
>  [<c01241dd>] do_group_exit+0x45/0x9d
>  [<c0124244>] sys_exit_group+0xf/0x11
>  [<c0103151>] sysenter_do_call+0x12/0x31
>  =======================
> 

-- 
Advanced Micro Devices, Inc.
Operating System Research Center
email: robert.richter@amd.com

Re: oprofile? lockdep warning from 2.6.27-rc1-mm1

[hooanon05]

Robert Richter:
> I reworked the code around this bug and it is upstream in
> v2.6.29-rc1. Could you test with this version and look if the problem
> still exists, please?

Unfortunately, I cannot test it soon. I am afraid it will take a few
months. When I become to be able to test it, I will let you know.

J. R. Okajima