Simon Kirby
2013-04-18 21:52:18 UTC
Hello!
Got a lockdep warning on a box running 3.8.0. We were trying zram for
swap to see if btrfsck would then fit ;) :
[12808.907751]
[12808.907784] =================================
[12808.907813] [ INFO: inconsistent lock state ]
[12808.907842] 3.8.0-hw+ #31 Tainted: G C
[12808.907871] ---------------------------------
[12808.907899] inconsistent {RECLAIM_FS-ON-W} -> {IN-RECLAIM_FS-R} usage.
[12808.907933] kswapd0/600 [HC0[0]:SC0[0]:HE1:SE1] takes:
[12808.907963] (&zram->init_lock){+++++-}, at: [<ffffffffa009dd63>] zram_make_request+0x43/0x260 [zram]
[12808.908015] {RECLAIM_FS-ON-W} state was registered at:
[12808.908015] [<ffffffff810a4491>] mark_held_locks+0x91/0x120
[12808.908015] [<ffffffff810a4d90>] lockdep_trace_alloc+0x90/0xf0
[12808.908015] [<ffffffff810fcc27>] __alloc_pages_nodemask+0x87/0x700
[12808.908015] [<ffffffff810fd2b2>] __get_free_pages+0x12/0x50
[12808.908015] [<ffffffff81132b94>] kmalloc_order_trace+0x34/0xb0
[12808.908015] [<ffffffffa009dba8>] zram_init_device+0x78/0x1f0 [zram]
[12808.908015] [<ffffffffa009df6e>] zram_make_request+0x24e/0x260 [zram]
[12808.908015] [<ffffffff813cc882>] generic_make_request+0xc2/0x110
[12808.908015] [<ffffffff813cc937>] submit_bio+0x67/0x130
[12808.908015] [<ffffffff8116886f>] submit_bh+0x10f/0x1e0
[12808.908015] [<ffffffff8116babd>] block_read_full_page+0x23d/0x360
[12808.908015] [<ffffffff8116f4d3>] blkdev_readpage+0x13/0x20
[12808.908015] [<ffffffff81100b2a>] __do_page_cache_readahead+0x2ca/0x2d0
[12808.908015] [<ffffffff81100d89>] force_page_cache_readahead+0x99/0xd0
[12808.908015] [<ffffffff811011d3>] page_cache_sync_readahead+0x43/0x50
[12808.908015] [<ffffffff810f7d10>] generic_file_aio_read+0x4d0/0x740
[12808.908015] [<ffffffff8116f06f>] blkdev_aio_read+0x4f/0x80
[12808.908015] [<ffffffff81138467>] do_sync_read+0xa7/0xe0
[12808.908015] [<ffffffff81138bb3>] vfs_read+0xa3/0x180
[12808.908015] [<ffffffff81138ce0>] sys_read+0x50/0xa0
[12808.908015] [<ffffffff817c14e9>] system_call_fastpath+0x16/0x1b
[12808.908015] irq event stamp: 317239951
[12808.908015] hardirqs last enabled at (317239951): [<ffffffff810a47cc>] debug_check_no_locks_freed+0xac/0x190
[12808.908015] hardirqs last disabled at (317239950): [<ffffffff810a476f>] debug_check_no_locks_freed+0x4f/0x190
[12808.908015] softirqs last enabled at (317239376): [<ffffffff81057945>] __do_softirq+0x145/0x210
[12808.908015] softirqs last disabled at (317239355): [<ffffffff817c283c>] call_softirq+0x1c/0x30
[12808.908015]
[12808.908015] other info that might help us debug this:
[12808.908015] Possible unsafe locking scenario:
[12808.908015]
[12808.908015] CPU0
[12808.908015] ----
[12808.908015] lock(&zram->init_lock);
[12808.908015] <Interrupt>
[12808.908015] lock(&zram->init_lock);
[12808.908015]
[12808.908015] *** DEADLOCK ***
[12808.908015]
[12808.908015] no locks held by kswapd0/600.
[12808.908015]
[12808.908015] stack backtrace:
[12808.908015] Pid: 600, comm: kswapd0 Tainted: G C 3.8.0-hw+ #31
[12808.908015] Call Trace:
[12808.908015] [<ffffffff817adff1>] print_usage_bug.part.36+0x270/0x27f
[12808.908015] [<ffffffff810204fa>] ? save_stack_trace+0x2a/0x50
[12808.908015] [<ffffffff810a32c0>] ? check_usage_backwards+0x140/0x140
[12808.908015] [<ffffffff810a406b>] mark_lock+0x27b/0x610
[12808.908015] [<ffffffff810a66e9>] __lock_acquire+0x5a9/0x1fb0
[12808.908015] [<ffffffff8101a3a9>] ? sched_clock+0x9/0x10
[12808.908015] [<ffffffff81087315>] ? sched_clock_local+0x25/0xa0
[12808.908015] [<ffffffff8101a333>] ? native_sched_clock+0x13/0x80
[12808.908015] [<ffffffff8101a3a9>] ? sched_clock+0x9/0x10
[12808.908015] [<ffffffff81087315>] ? sched_clock_local+0x25/0xa0
[12808.908015] [<ffffffff810874b8>] ? sched_clock_cpu+0xa8/0x120
[12808.908015] [<ffffffff810a8726>] lock_acquire+0xa6/0x120
[12808.908015] [<ffffffffa009dd63>] ? zram_make_request+0x43/0x260 [zram]
[12808.908015] [<ffffffff817b6a49>] down_read+0x39/0x8c
[12808.908015] [<ffffffffa009dd63>] ? zram_make_request+0x43/0x260 [zram]
[12808.908015] [<ffffffffa009dd63>] zram_make_request+0x43/0x260 [zram]
[12808.908015] [<ffffffff817b92fa>] ? _raw_spin_unlock_irqrestore+0x3a/0x70
[12808.908015] [<ffffffff813cc882>] generic_make_request+0xc2/0x110
[12808.908015] [<ffffffff813cc937>] submit_bio+0x67/0x130
[12808.908015] [<ffffffff810fe24b>] ? test_set_page_writeback+0x4b/0x170
[12808.908015] [<ffffffff811293f4>] swap_writepage+0x1a4/0x1f0
[12808.908015] [<ffffffff810874b8>] ? sched_clock_cpu+0xa8/0x120
[12808.908015] [<ffffffff810a1f8d>] ? trace_hardirqs_off+0xd/0x10
[12808.908015] [<ffffffff8108759f>] ? local_clock+0x6f/0x80
[12808.908015] [<ffffffff817b6633>] ? __mutex_unlock_slowpath+0xd3/0x170
[12808.908015] [<ffffffff810a471d>] ? trace_hardirqs_on+0xd/0x10
[12808.908015] [<ffffffff8110a928>] shmem_writepage+0x1a8/0x2d0
[12808.908015] [<ffffffff81107081>] shrink_page_list+0x701/0x8f0
[12808.908015] [<ffffffff81087315>] ? sched_clock_local+0x25/0xa0
[12808.908015] [<ffffffff811077d8>] shrink_inactive_list+0x1f8/0x3c0
[12808.908015] [<ffffffff8108759f>] ? local_clock+0x6f/0x80
[12808.908015] [<ffffffff81107c79>] shrink_lruvec+0x2d9/0x460
[12808.908015] [<ffffffff811087c0>] kswapd+0x570/0x9e0
[12808.908015] [<ffffffff81108250>] ? try_to_free_pages+0x450/0x450
[12808.908015] [<ffffffff81074246>] kthread+0xd6/0xe0
[12808.908015] [<ffffffff81074170>] ? __init_kthread_worker+0x70/0x70
[12808.908015] [<ffffffff817c143c>] ret_from_fork+0x7c/0xb0
[12808.908015] [<ffffffff81074170>] ? __init_kthread_worker+0x70/0x70
It still seems to be working:
procs -----------memory---------- ---swap-- -----io---- -system-- ----cpu----
r b swpd free buff cache si so bi bo in cs us sy id wa
6 9 15879316 2069996 33508 274476 99780 392 106504 392 6477 9537 3 32 14 50
2 9 15863392 1988400 35904 284564 62692 300 72064 300 6535 10861 3 23 12 62
Simon-
Got a lockdep warning on a box running 3.8.0. We were trying zram for
swap to see if btrfsck would then fit ;) :
[12808.907751]
[12808.907784] =================================
[12808.907813] [ INFO: inconsistent lock state ]
[12808.907842] 3.8.0-hw+ #31 Tainted: G C
[12808.907871] ---------------------------------
[12808.907899] inconsistent {RECLAIM_FS-ON-W} -> {IN-RECLAIM_FS-R} usage.
[12808.907933] kswapd0/600 [HC0[0]:SC0[0]:HE1:SE1] takes:
[12808.907963] (&zram->init_lock){+++++-}, at: [<ffffffffa009dd63>] zram_make_request+0x43/0x260 [zram]
[12808.908015] {RECLAIM_FS-ON-W} state was registered at:
[12808.908015] [<ffffffff810a4491>] mark_held_locks+0x91/0x120
[12808.908015] [<ffffffff810a4d90>] lockdep_trace_alloc+0x90/0xf0
[12808.908015] [<ffffffff810fcc27>] __alloc_pages_nodemask+0x87/0x700
[12808.908015] [<ffffffff810fd2b2>] __get_free_pages+0x12/0x50
[12808.908015] [<ffffffff81132b94>] kmalloc_order_trace+0x34/0xb0
[12808.908015] [<ffffffffa009dba8>] zram_init_device+0x78/0x1f0 [zram]
[12808.908015] [<ffffffffa009df6e>] zram_make_request+0x24e/0x260 [zram]
[12808.908015] [<ffffffff813cc882>] generic_make_request+0xc2/0x110
[12808.908015] [<ffffffff813cc937>] submit_bio+0x67/0x130
[12808.908015] [<ffffffff8116886f>] submit_bh+0x10f/0x1e0
[12808.908015] [<ffffffff8116babd>] block_read_full_page+0x23d/0x360
[12808.908015] [<ffffffff8116f4d3>] blkdev_readpage+0x13/0x20
[12808.908015] [<ffffffff81100b2a>] __do_page_cache_readahead+0x2ca/0x2d0
[12808.908015] [<ffffffff81100d89>] force_page_cache_readahead+0x99/0xd0
[12808.908015] [<ffffffff811011d3>] page_cache_sync_readahead+0x43/0x50
[12808.908015] [<ffffffff810f7d10>] generic_file_aio_read+0x4d0/0x740
[12808.908015] [<ffffffff8116f06f>] blkdev_aio_read+0x4f/0x80
[12808.908015] [<ffffffff81138467>] do_sync_read+0xa7/0xe0
[12808.908015] [<ffffffff81138bb3>] vfs_read+0xa3/0x180
[12808.908015] [<ffffffff81138ce0>] sys_read+0x50/0xa0
[12808.908015] [<ffffffff817c14e9>] system_call_fastpath+0x16/0x1b
[12808.908015] irq event stamp: 317239951
[12808.908015] hardirqs last enabled at (317239951): [<ffffffff810a47cc>] debug_check_no_locks_freed+0xac/0x190
[12808.908015] hardirqs last disabled at (317239950): [<ffffffff810a476f>] debug_check_no_locks_freed+0x4f/0x190
[12808.908015] softirqs last enabled at (317239376): [<ffffffff81057945>] __do_softirq+0x145/0x210
[12808.908015] softirqs last disabled at (317239355): [<ffffffff817c283c>] call_softirq+0x1c/0x30
[12808.908015]
[12808.908015] other info that might help us debug this:
[12808.908015] Possible unsafe locking scenario:
[12808.908015]
[12808.908015] CPU0
[12808.908015] ----
[12808.908015] lock(&zram->init_lock);
[12808.908015] <Interrupt>
[12808.908015] lock(&zram->init_lock);
[12808.908015]
[12808.908015] *** DEADLOCK ***
[12808.908015]
[12808.908015] no locks held by kswapd0/600.
[12808.908015]
[12808.908015] stack backtrace:
[12808.908015] Pid: 600, comm: kswapd0 Tainted: G C 3.8.0-hw+ #31
[12808.908015] Call Trace:
[12808.908015] [<ffffffff817adff1>] print_usage_bug.part.36+0x270/0x27f
[12808.908015] [<ffffffff810204fa>] ? save_stack_trace+0x2a/0x50
[12808.908015] [<ffffffff810a32c0>] ? check_usage_backwards+0x140/0x140
[12808.908015] [<ffffffff810a406b>] mark_lock+0x27b/0x610
[12808.908015] [<ffffffff810a66e9>] __lock_acquire+0x5a9/0x1fb0
[12808.908015] [<ffffffff8101a3a9>] ? sched_clock+0x9/0x10
[12808.908015] [<ffffffff81087315>] ? sched_clock_local+0x25/0xa0
[12808.908015] [<ffffffff8101a333>] ? native_sched_clock+0x13/0x80
[12808.908015] [<ffffffff8101a3a9>] ? sched_clock+0x9/0x10
[12808.908015] [<ffffffff81087315>] ? sched_clock_local+0x25/0xa0
[12808.908015] [<ffffffff810874b8>] ? sched_clock_cpu+0xa8/0x120
[12808.908015] [<ffffffff810a8726>] lock_acquire+0xa6/0x120
[12808.908015] [<ffffffffa009dd63>] ? zram_make_request+0x43/0x260 [zram]
[12808.908015] [<ffffffff817b6a49>] down_read+0x39/0x8c
[12808.908015] [<ffffffffa009dd63>] ? zram_make_request+0x43/0x260 [zram]
[12808.908015] [<ffffffffa009dd63>] zram_make_request+0x43/0x260 [zram]
[12808.908015] [<ffffffff817b92fa>] ? _raw_spin_unlock_irqrestore+0x3a/0x70
[12808.908015] [<ffffffff813cc882>] generic_make_request+0xc2/0x110
[12808.908015] [<ffffffff813cc937>] submit_bio+0x67/0x130
[12808.908015] [<ffffffff810fe24b>] ? test_set_page_writeback+0x4b/0x170
[12808.908015] [<ffffffff811293f4>] swap_writepage+0x1a4/0x1f0
[12808.908015] [<ffffffff810874b8>] ? sched_clock_cpu+0xa8/0x120
[12808.908015] [<ffffffff810a1f8d>] ? trace_hardirqs_off+0xd/0x10
[12808.908015] [<ffffffff8108759f>] ? local_clock+0x6f/0x80
[12808.908015] [<ffffffff817b6633>] ? __mutex_unlock_slowpath+0xd3/0x170
[12808.908015] [<ffffffff810a471d>] ? trace_hardirqs_on+0xd/0x10
[12808.908015] [<ffffffff8110a928>] shmem_writepage+0x1a8/0x2d0
[12808.908015] [<ffffffff81107081>] shrink_page_list+0x701/0x8f0
[12808.908015] [<ffffffff81087315>] ? sched_clock_local+0x25/0xa0
[12808.908015] [<ffffffff811077d8>] shrink_inactive_list+0x1f8/0x3c0
[12808.908015] [<ffffffff8108759f>] ? local_clock+0x6f/0x80
[12808.908015] [<ffffffff81107c79>] shrink_lruvec+0x2d9/0x460
[12808.908015] [<ffffffff811087c0>] kswapd+0x570/0x9e0
[12808.908015] [<ffffffff81108250>] ? try_to_free_pages+0x450/0x450
[12808.908015] [<ffffffff81074246>] kthread+0xd6/0xe0
[12808.908015] [<ffffffff81074170>] ? __init_kthread_worker+0x70/0x70
[12808.908015] [<ffffffff817c143c>] ret_from_fork+0x7c/0xb0
[12808.908015] [<ffffffff81074170>] ? __init_kthread_worker+0x70/0x70
It still seems to be working:
procs -----------memory---------- ---swap-- -----io---- -system-- ----cpu----
r b swpd free buff cache si so bi bo in cs us sy id wa
6 9 15879316 2069996 33508 274476 99780 392 106504 392 6477 9537 3 32 14 50
2 9 15863392 1988400 35904 284564 62692 300 72064 300 6535 10861 3 23 12 62
Simon-