lkml.org 
[lkml]   [2011]   [Nov]   [23]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
/
Date
From
SubjectRe: zram deadlock detected
On 11/14/2011 11:41 AM, Jerome Marchand wrote:
> On 11/13/2011 02:16 PM, Witold Baryluk wrote:
>> Hi,
>>
>> just moments after seting size to 256MB (on 512 machine),
>> mkswap /dev/zram0 and swapon -p 10 /dev/zram0 of 256MB zram
>> when system was under high cpu/mem load, I got warning from lockdep.
>> (I was upgrading system, and it was slow because of excessive swaping
>> so I was thinking that enabling zram will help - and it helped, disk swaping
>> stoped and upgrade processed much smoother and faster, maybe 10 times faster),
>>
> Hi Witold,
>
> Thank you for your feedback. It looks to me that we used a GFP_KERNEL allocation
> somewhere when we should have used GFP_NOFS or even GFP_NOIO.

I now think this is a false positive. The mentioned IN-RECLAIM_FS-R lock can only
happen when the device has been swapped on, at which point the initialization of
the device (where the RECLAIM_FS-ON-W is taken) has been already done.
I don't how to shut the warning, though. Lockdep is not that well documented.

On a related note, while investigating this issue, I noticed a suspicious allocation
in zram_init_device():

zram->compress_buffer = (void *)__get_free_pages(__GFP_ZERO, 1);

It does not precise any kind of permission such as GFP_KERNEL. I don't know what
kind of allocation is performed in such a case, but I know it looks wrong.

Thanks,
Jerome

>
> Jerome
>
>>
>> This is part of dmesg
>>
>> [ 4882.866060] Adding 262140k swap on /dev/zram0. Priority:10 extents:1 across:262140k SS
>> [ 4882.910497]
>> [ 4882.910503] =================================
>> [ 4882.910506] [ INFO: inconsistent lock state ]
>> [ 4882.910510] 3.2.0-rc1-t43-devel-smp-00091-g5e442a4-dirty #15
>> [ 4882.910513] ---------------------------------
>> [ 4882.910516] inconsistent {RECLAIM_FS-ON-W} -> {IN-RECLAIM_FS-R} usage.
>> [ 4882.910520] kswapd0/561 [HC0[0]:SC0[0]:HE1:SE1] takes:
>> [ 4882.910524] (&zram->init_lock){+++++-}, at: [<e1948317>] zram_make_request+0x37/0xd0 [zram]
>> [ 4882.910538] {RECLAIM_FS-ON-W} state was registered at:
>> [ 4882.910541] [<c10a2fa6>] mark_held_locks+0x66/0xf0
>> [ 4882.910550] [<c10a306c>] __lockdep_trace_alloc+0x3c/0x70
>> [ 4882.910556] [<c10a374b>] lockdep_trace_alloc+0x4b/0x70
>> [ 4882.910561] [<c111b27b>] __alloc_pages_nodemask+0x5b/0x7d0
>> [ 4882.910568] [<c111ba6c>] __get_free_pages+0x1c/0x30
>> [ 4882.910573] [<c1156339>] kmalloc_order_trace+0x29/0x150
>> [ 4882.910579] [<e1948137>] zram_init_device+0xa7/0x250 [zram]
>> [ 4882.910585] [<e19483a5>] zram_make_request+0xc5/0xd0 [zram]
>> [ 4882.910591] [<c12d465f>] generic_make_request.part.50+0x5f/0x90
>> [ 4882.910598] [<c12d7477>] generic_make_request+0x57/0x60
>> [ 4882.910604] [<c12d74e4>] submit_bio+0x64/0xf0
>> [ 4882.910609] [<c1198201>] submit_bh+0xd1/0x100
>> [ 4882.910615] [<c119ae34>] block_read_full_page+0x254/0x3e0
>> [ 4882.910621] [<c119fa04>] blkdev_readpage+0x14/0x20
>> [ 4882.910626] [<c111daf3>] read_pages+0xc3/0xe0
>> [ 4882.910631] [<c111de44>] __do_page_cache_readahead+0x1b4/0x1e0
>> [ 4882.910636] [<c111def5>] force_page_cache_readahead+0x85/0xb0
>> [ 4882.910642] [<c111e34a>] page_cache_sync_readahead+0x5a/0x70
>> [ 4882.910647] [<c11147f2>] do_generic_file_read.constprop.29+0x322/0x4f0
>> [ 4882.910655] [<c11156d9>] generic_file_aio_read+0xd9/0x290
>> [ 4882.910660] [<c116853c>] do_sync_read+0xac/0xe0
>> [ 4882.910667] [<c116908c>] vfs_read+0x8c/0x160
>> [ 4882.910672] [<c116919d>] sys_read+0x3d/0x70
>> [ 4882.910677] [<c177add8>] sysenter_do_call+0x12/0x38
>> [ 4882.910686] irq event stamp: 10471779
>> [ 4882.910688] hardirqs last enabled at (10471779): [<c1772c16>] _raw_spin_unlock_irqrestore+0x36/0x70
>> [ 4882.910697] hardirqs last disabled at (10471778): [<c17731d9>] _raw_spin_lock_irqsave+0x29/0xa0
>> [ 4882.910703] softirqs last enabled at (10466064): [<c106cefc>] irq_exit+0xac/0xb0
>> [ 4882.910711] softirqs last disabled at (10466063): [<c177b50b>] do_IRQ+0x4b/0xc0
>> [ 4882.910716]
>> [ 4882.910717] other info that might help us debug this:
>> [ 4882.910720] Possible unsafe locking scenario:
>> [ 4882.910721]
>> [ 4882.910724] CPU0
>> [ 4882.910726] ----
>> [ 4882.910728] lock(&zram->init_lock);
>> [ 4882.910732] <Interrupt>
>> [ 4882.910734] lock(&zram->init_lock);
>> [ 4882.910739]
>> [ 4882.910740] *** DEADLOCK ***
>> [ 4882.910741]
>> [ 4882.910744] no locks held by kswapd0/561.
>> [ 4882.910746]
>> [ 4882.910747] stack backtrace:
>> [ 4882.910752] Pid: 561, comm: kswapd0 Tainted: G C 3.2.0-rc1-t43-devel-smp-00091-g5e442a4-dirty #15
>> [ 4882.910756] Call Trace:
>> [ 4882.910763] [<c1759fd2>] ? printk+0x1d/0x1f
>> [ 4882.910768] [<c175ae94>] print_usage_bug+0x150/0x15a
>> [ 4882.910774] [<c10a13d0>] ? print_irq_inversion_bug.part.31+0x1c0/0x1c0
>> [ 4882.910779] [<c175aefc>] mark_lock_irq+0x5e/0x117
>> [ 4882.910784] [<c10a2cc1>] mark_lock+0xe1/0x1c0
>> [ 4882.910790] [<c1091f45>] ? local_clock+0x65/0x70
>> [ 4882.910795] [<c10a2e5d>] mark_irqflags+0xbd/0x1a0
>> [ 4882.910800] [<c10a4cca>] __lock_acquire+0x47a/0x800
>> [ 4882.910805] [<c10a5697>] lock_acquire+0x87/0x1b0
>> [ 4882.910811] [<e1948317>] ? zram_make_request+0x37/0xd0 [zram]
>> [ 4882.910816] [<c12d6ff6>] ? generic_make_request_checks+0xc6/0x4f0
>> [ 4882.910821] [<c1771ac0>] down_read+0x50/0x8a
>> [ 4882.910826] [<e1948317>] ? zram_make_request+0x37/0xd0 [zram]
>> [ 4882.910832] [<e1948317>] zram_make_request+0x37/0xd0 [zram]
>> [ 4882.910837] [<c12d465f>] generic_make_request.part.50+0x5f/0x90
>> [ 4882.910842] [<c12d7477>] generic_make_request+0x57/0x60
>> [ 4882.910847] [<c12d74e4>] submit_bio+0x64/0xf0
>> [ 4882.910852] [<c111bb12>] ? account_page_writeback+0x12/0x20
>> [ 4882.910857] [<c111ca56>] ? test_set_page_writeback+0xc6/0x160
>> [ 4882.910862] [<c1146800>] ? get_swap_bio+0x80/0x80
>> [ 4882.910867] [<c114696a>] swap_writepage+0x6a/0xb0
>> [ 4882.910873] [<c1122c23>] pageout+0x123/0x2d0
>> [ 4882.910879] [<c113f5a2>] ? page_unlock_anon_vma+0x12/0x20
>> [ 4882.910884] [<c11411f5>] ? try_to_unmap_anon+0xc5/0x100
>> [ 4882.910889] [<c1146a6a>] ? __add_to_swap_cache+0x6a/0xa0
>> [ 4882.910894] [<c112591e>] shrink_page_list+0x46e/0x540
>> [ 4882.910899] [<c1125d4d>] shrink_inactive_list+0x12d/0x510
>> [ 4882.910904] [<c10a327b>] ? trace_hardirqs_on+0xb/0x10
>> [ 4882.910910] [<c1123118>] ? get_scan_count+0x208/0x300
>> [ 4882.910914] [<c11261df>] shrink_list+0xaf/0x100
>> [ 4882.910919] [<c11262d1>] shrink_zone+0xa1/0x1a0
>> [ 4882.910924] [<c11267bd>] balance_pgdat+0x3ed/0x580
>> [ 4882.910930] [<c1126a43>] kswapd+0xf3/0x260
>> [ 4882.910934] [<c1126950>] ? balance_pgdat+0x580/0x580
>> [ 4882.910940] [<c108a49d>] kthread+0x6d/0x80
>> [ 4882.910945] [<c108a430>] ? __init_kthread_worker+0x60/0x60
>> [ 4882.910949] [<c177b37a>] kernel_thread_helper+0x6/0x10
>>
>> System works without problem later on. I also disabled
>> later zram (swapoff + rmmod) and enabled it again (modprobe + set size + mkswap + swapon),
>> and also not find any problem.
>>
>> I'm not sure if this is regression, because I run UP kernel without
>> debuging or lockdep normally. I use SMP with full debuging
>> only from time to time.
>>
>> Full dmesg
>> http://smp.if.uj.edu.pl/~baryluk/linux-kernel/2011-11-13/deadlock-zram-3.2.0-rc1-t43-devel-smp-00091-g5e442a4-dirty.txt
>>
>> Full config
>> http://smp.if.uj.edu.pl/~baryluk/linux-kernel/2011-11-13/config-3.2.0-rc1-t43-devel-smp-00091-g5e442a4-dirty
>>
>>
>> It is 32-bit Intel, on Debian GNU/Linux unstable with gcc 4.6.2-4 -march=pentium-m
>> SMP config of course.
>>
>> Any ideas?
>>
>> Regards,
>> Witek
>>
>>
>



\
 
 \ /
  Last update: 2011-11-23 14:23    [W:0.190 / U:0.348 seconds]
©2003-2020 Jasper Spaans|hosted at Digital Ocean and TransIP|Read the blog|Advertise on this site