* 3.1-rc9: BUG: soft lockup in find_get_pages+0x4e/0x140 @ 2011-10-16 0:06 Justin Piszcz 2011-10-18 4:09 ` Hugh Dickins 0 siblings, 1 reply; 3+ messages in thread From: Justin Piszcz @ 2011-10-16 0:06 UTC (permalink / raw) To: linux-kernel; +Cc: linux-mm Hi, With 3.1-rc9 during a filesystem dump, this occurred, I thought a previous patch fixed this but it did not, it occurs MUCH less (first time in a couple of weeks) but the problem still occurs. Thoughts? [675100.763357] BUG: soft lockup - CPU#0 stuck for 22s! [dump:11066] [675100.763361] CPU 0 [675100.763364] Pid: 11066, comm: dump Not tainted 3.1.0-rc9 #1 Supermicro X8DTH-i/6/iF/6F/X8DTH [675100.763368] RIP: 0010:[<ffffffff81078eee>] [<ffffffff81078eee>] find_get_pages+0x4e/0x140 [675100.763375] RSP: 0018:ffff8806e6603d28 EFLAGS: 00000246 [675100.763377] RAX: ffff880019a0a210 RBX: ffffea0028a65820 RCX: 000000000000000e [675100.763379] RDX: 0000000000000000 RSI: 0000000000000000 RDI: ffffea0029e0faf0 [675100.763381] RBP: 0000000001200ae9 R08: 0000000000000000 R09: ffff8806e6603ce8 [675100.763383] R10: 0000000001200b03 R11: 0000000000000002 R12: ffffffff810805a4 [675100.763386] R13: ffff880c3fffae00 R14: ffff880c3fffae00 R15: ffff8806e6603db8 [675100.763392] FS: 00007fe9b56cc760(0000) GS:ffff88063fc00000(0000) knlGS:0000000000000000 [675100.763395] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [675100.763397] CR2: 00007f2da3718fa8 CR3: 0000000c22da4000 CR4: 00000000000006f0 [675100.763400] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000 [675100.763402] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400 [675100.763405] Process dump (pid: 11066, threadinfo ffff8806e6602000, task ffff880c21c931a0) [675100.763407] Stack: [675100.763408] ffff8800398aaa88 0000000000000000 ffff88063fc0d560 0000000000000005 [675100.763415] ffff880c270652d8 ffff8806e6603da8 00000000000067b5 ffffffffffffffff [675100.763421] ffff880c270652d8 ffffea0028a65820 000000000000000d ffffffff81083d15 [675100.763427] Call Trace: [675100.763433] [<ffffffff81083d15>] ? pagevec_lookup+0x15/0x20 [675100.763437] [<ffffffff810843c6>] ? invalidate_mapping_pages+0x66/0x170 [675100.763442] [<ffffffff812bc841>] ? blkdev_ioctl+0x6b1/0x700 [675100.763451] [<ffffffff810e405b>] ? block_ioctl+0x3b/0x50 [675100.763455] [<ffffffff810c692e>] ? do_vfs_ioctl+0x8e/0x4f0 [675100.763459] [<ffffffff810c6dd9>] ? sys_ioctl+0x49/0x80 [675100.763464] [<ffffffff8168b17b>] ? system_call_fastpath+0x16/0x1b [675100.763466] Code: 48 89 de 4c 89 ef e8 72 37 25 00 85 c0 89 c1 0f 84 a8 00 00 00 49 89 df 31 d2 31 f6 45 31 f6 66 0f 1f 44 00 00 49 8b 07 48 8b 38 [675100.763484] 85 ff 74 3e 40 f6 c7 03 75 5e 44 8b 47 1c 45 85 c0 74 ec 45 [675100.763497] Call Trace: [675100.763500] [<ffffffff81083d15>] ? pagevec_lookup+0x15/0x20 [675100.763503] [<ffffffff810843c6>] ? invalidate_mapping_pages+0x66/0x170 [675100.763507] [<ffffffff812bc841>] ? blkdev_ioctl+0x6b1/0x700 [675100.763510] [<ffffffff810e405b>] ? block_ioctl+0x3b/0x50 [675100.763513] [<ffffffff810c692e>] ? do_vfs_ioctl+0x8e/0x4f0 [675100.763516] [<ffffffff810c6dd9>] ? sys_ioctl+0x49/0x80 [675100.763519] [<ffffffff8168b17b>] ? system_call_fastpath+0x16/0x1b [675101.484164] BUG: soft lockup - CPU#10 stuck for 23s! [dump:11068] [675101.484167] CPU 10 [675101.484170] Pid: 11068, comm: dump Not tainted 3.1.0-rc9 #1 Supermicro X8DTH-i/6/iF/6F/X8DTH [675101.484173] RIP: 0010:[<ffffffff81078eee>] [<ffffffff81078eee>] find_get_pages+0x4e/0x140 [675101.484180] RSP: 0018:ffff880bf713dd28 EFLAGS: 00000246 [675101.484182] RAX: ffff8800ae90af00 RBX: ffffea00190d1288 RCX: 000000000000000e [675101.484183] RDX: 0000000000000000 RSI: 0000000000000000 RDI: ffffea0019046600 [675101.484185] RBP: 0000000000900eef R08: 0000000000000000 R09: ffff880bf713dce8 [675101.484186] R10: 0000000000900efd R11: 000000000000000d R12: ffffffff810805a4 [675101.484188] R13: ffff880c3fffae00 R14: ffff880c3fffae00 R15: ffff880bf713ddb8 [675101.484190] FS: 00007fe9b56cc760(0000) GS:ffff880c3fc80000(0000) knlGS:0000000000000000 [675101.484192] CS: 0010 DS: 0000 ES: 0000 CR0: 000000008005003b [675101.484193] CR2: 00007f1577baefc8 CR3: 0000000bc3458000 CR4: 00000000000006e0 [675101.484195] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000 [675101.484196] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400 [675101.484198] Process dump (pid: 11068, threadinfo ffff880bf713c000, task ffff880c25b2e310) [675101.484199] Stack: [675101.484201] ffff88003b6f6bc0 000000000000000a ffff880c3fc8d560 0000000000000005 [675101.484204] ffff880c270652d8 ffff880bf713dda8 00000000000009f2 ffffffffffffffff [675101.484208] ffff880c270652d8 ffffea00190d1288 000000000000000d ffffffff81083d15 [675101.484211] Call Trace: [675101.484217] [<ffffffff81083d15>] ? pagevec_lookup+0x15/0x20 [675101.484220] [<ffffffff810843c6>] ? invalidate_mapping_pages+0x66/0x170 [675101.484226] [<ffffffff812bc841>] ? blkdev_ioctl+0x6b1/0x700 [675101.484230] [<ffffffff810e405b>] ? block_ioctl+0x3b/0x50 [675101.484234] [<ffffffff810c692e>] ? do_vfs_ioctl+0x8e/0x4f0 [675101.484238] [<ffffffff810c6dd9>] ? sys_ioctl+0x49/0x80 [675101.484242] [<ffffffff8168b17b>] ? system_call_fastpath+0x16/0x1b [675101.484243] Code: 48 89 de 4c 89 ef e8 72 37 25 00 85 c0 89 c1 0f 84 a8 00 00 00 49 89 df 31 d2 31 f6 45 31 f6 66 0f 1f 44 00 00 49 8b 07 48 8b 38 [675101.484257] 85 ff 74 3e 40 f6 c7 03 75 5e 44 8b 47 1c 45 85 c0 74 ec 45 [675101.484263] Call Trace: [675101.484266] [<ffffffff81083d15>] ? pagevec_lookup+0x15/0x20 [675101.484268] [<ffffffff810843c6>] ? invalidate_mapping_pages+0x66/0x170 [675101.484272] [<ffffffff812bc841>] ? blkdev_ioctl+0x6b1/0x700 [675101.484275] [<ffffffff810e405b>] ? block_ioctl+0x3b/0x50 [675101.484277] [<ffffffff810c692e>] ? do_vfs_ioctl+0x8e/0x4f0 [675101.484279] [<ffffffff810c6dd9>] ? sys_ioctl+0x49/0x80 [675101.484282] [<ffffffff8168b17b>] ? system_call_fastpath+0x16/0x1b Justin. ^ permalink raw reply [flat|nested] 3+ messages in thread
* Re: 3.1-rc9: BUG: soft lockup in find_get_pages+0x4e/0x140 2011-10-16 0:06 3.1-rc9: BUG: soft lockup in find_get_pages+0x4e/0x140 Justin Piszcz @ 2011-10-18 4:09 ` Hugh Dickins 2011-10-18 13:42 ` Justin Piszcz 0 siblings, 1 reply; 3+ messages in thread From: Hugh Dickins @ 2011-10-18 4:09 UTC (permalink / raw) To: Justin Piszcz Cc: Pawel Sikora, arekm, Anders Ossowicki, linux-kernel, linux-mm On Sat, 15 Oct 2011, Justin Piszcz wrote: > > With 3.1-rc9 during a filesystem dump, this occurred, I thought a previous > patch fixed this but it did not, it occurs MUCH less (first time in a couple > of weeks) but the problem still occurs. Shaohua's nr_skip patch fixed, or at least worked around, the error I introduced there in 3.1-rc1. But now you're finding a similar problem still in 3.1-rc9: that confirms what you and others already reported, that something like it occurs even in 3.0 without my bug. > > Thoughts? No more than before: that it seems as if a page with refcount 0 has somehow got stuck in the radix_tree. We do know of a refcounting bug in THP, but I don't see how that one would manifest in this way. Or maybe the radix_tree is corrupt and it isn't even a struct page * there; but you're not the only one to see this, so random corruption is not at all likely. > > [675100.763357] BUG: soft lockup - CPU#0 stuck for 22s! [dump:11066] > [675100.763361] CPU 0 [675100.763364] Pid: 11066, comm: dump Not tainted > 3.1.0-rc9 #1 Supermicro X8DTH-i/6/iF/6F/X8DTH > [675100.763368] RIP: 0010:[<ffffffff81078eee>] [<ffffffff81078eee>] > find_get_pages+0x4e/0x140 > [675100.763375] RSP: 0018:ffff8806e6603d28 EFLAGS: 00000246 > [675100.763377] RAX: ffff880019a0a210 RBX: ffffea0028a65820 RCX: > 000000000000000e > [675100.763379] RDX: 0000000000000000 RSI: 0000000000000000 RDI: > ffffea0029e0faf0 > [675100.763381] RBP: 0000000001200ae9 R08: 0000000000000000 R09: > ffff8806e6603ce8 > [675100.763383] R10: 0000000001200b03 R11: 0000000000000002 R12: > ffffffff810805a4 > [675100.763386] R13: ffff880c3fffae00 R14: ffff880c3fffae00 R15: > ffff8806e6603db8 > [675100.763392] FS: 00007fe9b56cc760(0000) GS:ffff88063fc00000(0000) > knlGS:0000000000000000 > [675100.763395] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 > [675100.763397] CR2: 00007f2da3718fa8 CR3: 0000000c22da4000 CR4: > 00000000000006f0 > [675100.763400] DR0: 0000000000000000 DR1: 0000000000000000 DR2: > 0000000000000000 > [675100.763402] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: > 0000000000000400 > [675100.763405] Process dump (pid: 11066, threadinfo ffff8806e6602000, task > ffff880c21c931a0) > [675100.763407] Stack: > [675100.763408] ffff8800398aaa88 0000000000000000 ffff88063fc0d560 > 0000000000000005 > [675100.763415] ffff880c270652d8 ffff8806e6603da8 00000000000067b5 > ffffffffffffffff > [675100.763421] ffff880c270652d8 ffffea0028a65820 000000000000000d > ffffffff81083d15 > [675100.763427] Call Trace: > [675100.763433] [<ffffffff81083d15>] ? pagevec_lookup+0x15/0x20 > [675100.763437] [<ffffffff810843c6>] ? invalidate_mapping_pages+0x66/0x170 > [675100.763442] [<ffffffff812bc841>] ? blkdev_ioctl+0x6b1/0x700 > [675100.763451] [<ffffffff810e405b>] ? block_ioctl+0x3b/0x50 > [675100.763455] [<ffffffff810c692e>] ? do_vfs_ioctl+0x8e/0x4f0 > [675100.763459] [<ffffffff810c6dd9>] ? sys_ioctl+0x49/0x80 > [675100.763464] [<ffffffff8168b17b>] ? system_call_fastpath+0x16/0x1b > [675100.763466] Code: 48 89 de 4c 89 ef e8 72 37 25 00 85 c0 89 c1 0f 84 a8 > 00 00 00 49 89 df 31 d2 31 f6 45 31 f6 66 0f 1f 44 00 00 49 8b 07 48 8b 38 > [675100.763484] 85 ff 74 3e 40 f6 c7 03 75 5e 44 8b 47 1c 45 85 c0 74 ec 45 Since I've no idea what's causing this, all we can do is attempt to gather more info. The patch below, which applies to 3.0.N as well as 3.1-rc9, may help with that; but it makes no attempt to recover the situation, since I just don't know what this situation is. When you next hit the problem, please let us know the messages say, from the "find_get_pages(" line to the end of the trace, but the Page lines the most interesting - thanks, and good luck. The memcontrol.c part of it is to cut out the noise of an interfering bug and stacktrace, coming from an irrelevant error in some configs. Signed-off-for-debug-only-by: Hugh Dickins <hughd@google.com> --- mm/filemap.c | 38 ++++++++++++++++++++++++++++++++++++++ mm/memcontrol.c | 17 +---------------- 2 files changed, 39 insertions(+), 16 deletions(-) --- 3.1-rc9/mm/filemap.c 2011-09-21 17:44:52.246176260 -0700 +++ fgpdebug/mm/filemap.c 2011-10-17 20:47:20.777176328 -0700 @@ -806,6 +806,29 @@ repeat: } EXPORT_SYMBOL(find_or_create_page); +static void safe_dump_page(struct page *page, char *which) +{ + pg_data_t *pgdat; + bool good = false; + unsigned long pfn = 0; + + for_each_online_pgdat(pgdat) { + struct page *start_page; + + start_page = pfn_to_page(pgdat->node_start_pfn); + pfn = pgdat->node_start_pfn + (page - start_page); + if (page >= start_page && + page < start_page + pgdat->node_spanned_pages && + pfn_valid(pfn) && page == pfn_to_page(pfn)) { + good = true; + break; + } + } + printk(KERN_ALERT "Page %s is %p (pfn %lx)\n", which, page, pfn); + if (good) + dump_page(page); +} + /** * find_get_pages - gang pagecache lookup * @mapping: The address_space to search @@ -825,6 +848,7 @@ EXPORT_SYMBOL(find_or_create_page); unsigned find_get_pages(struct address_space *mapping, pgoff_t start, unsigned int nr_pages, struct page **pages) { + int spinning = 1000; unsigned int i; unsigned int ret; unsigned int nr_found, nr_skip; @@ -839,6 +863,20 @@ restart: struct page *page; repeat: page = radix_tree_deref_slot((void **)pages[i]); + if (spinning > 0 && unlikely(--spinning == 0)) { + printk(KERN_ALERT + "find_get_pages(%p, %lu, %u, %p)", + mapping, start, nr_pages, pages); + print_symbol(KERN_CONT " of %s:\n", + (unsigned long)mapping->a_ops); + if (ret) + safe_dump_page(pages[ret-1], "before"); + safe_dump_page(page, "stuck "); + if (i + 1 < nr_found) + safe_dump_page(radix_tree_deref_slot( + (void **)pages[i+1]), "after "); + dump_stack(); + } if (unlikely(!page)) continue; --- 3.1-rc9/mm/memcontrol.c 2011-09-21 17:44:52.250176292 -0700 +++ fgpdebug/mm/memcontrol.c 2011-10-17 19:28:47.427572665 -0700 @@ -3380,23 +3380,8 @@ void mem_cgroup_print_bad_page(struct pa pc = lookup_page_cgroup_used(page); if (pc) { - int ret = -1; - char *path; - - printk(KERN_ALERT "pc:%p pc->flags:%lx pc->mem_cgroup:%p", + printk(KERN_ALERT "pc:%p pc->flags:%lx pc->mem_cgroup:%p\n", pc, pc->flags, pc->mem_cgroup); - - path = kmalloc(PATH_MAX, GFP_KERNEL); - if (path) { - rcu_read_lock(); - ret = cgroup_path(pc->mem_cgroup->css.cgroup, - path, PATH_MAX); - rcu_read_unlock(); - } - - printk(KERN_CONT "(%s)\n", - (ret < 0) ? "cannot get the path" : path); - kfree(path); } } #endif ^ permalink raw reply [flat|nested] 3+ messages in thread
* Re: 3.1-rc9: BUG: soft lockup in find_get_pages+0x4e/0x140 2011-10-18 4:09 ` Hugh Dickins @ 2011-10-18 13:42 ` Justin Piszcz 0 siblings, 0 replies; 3+ messages in thread From: Justin Piszcz @ 2011-10-18 13:42 UTC (permalink / raw) To: Hugh Dickins Cc: Pawel Sikora, arekm, Anders Ossowicki, linux-kernel, linux-mm On Mon, 17 Oct 2011, Hugh Dickins wrote: > On Sat, 15 Oct 2011, Justin Piszcz wrote: >> >> With 3.1-rc9 during a filesystem dump, this occurred, I thought a previous >> patch fixed this but it did not, it occurs MUCH less (first time in a couple >> of weeks) but the problem still occurs. > > Shaohua's nr_skip patch fixed, or at least worked around, the error I > introduced there in 3.1-rc1. But now you're finding a similar problem > still in 3.1-rc9: that confirms what you and others already reported, > that something like it occurs even in 3.0 without my bug. Thanks, Patch applied: # patch -p1 < /tmp/memory_patch.patch patching file mm/filemap.c patching file mm/memcontrol.c Now running 3.1-rc9 + this patch + re-enabled frame pointers. Justin. ^ permalink raw reply [flat|nested] 3+ messages in thread
end of thread, other threads:[~2011-10-18 13:42 UTC | newest] Thread overview: 3+ messages (download: mbox.gz / follow: Atom feed) -- links below jump to the message on this page -- 2011-10-16 0:06 3.1-rc9: BUG: soft lockup in find_get_pages+0x4e/0x140 Justin Piszcz 2011-10-18 4:09 ` Hugh Dickins 2011-10-18 13:42 ` Justin Piszcz
This is a public inbox, see mirroring instructions for how to clone and mirror all data and code used for this inbox
all inboxes | Powered by JetHome®