Re: bio linked list corruption.

From: Dave Jones
Date: Wed Oct 26 2016 - 14:18:49 EST


On Wed, Oct 26, 2016 at 09:48:39AM -0700, Linus Torvalds wrote:
> On Wed, Oct 26, 2016 at 9:30 AM, Dave Jones <davej@xxxxxxxxxxxxxxxxx> wrote:
> >
> > I gave this a go last thing last night. It crashed within 5 minutes,
> > but it was one we've already seen (the bad page map trace) with nothing
> > additional that looked interesting.
>
> Did the bad page map trace have any registers that looked like they
> had 0xd0d0d0d0d0d0 in them?
>
> I assume not, but worth checking.

sadly not. In case I did overlook something, here's last nights..

BUG: Bad page state in process kworker/u8:13 pfn:4dae31
page:ffffea00136b8c40 count:0 mapcount:0 mapping:ffff8804f011d6e0 index:0xd1530
flags: 0x400000000000000c(referenced|uptodate)
page dumped because: non-NULL mapping
CPU: 3 PID: 1207 Comm: kworker/u8:13 Not tainted 4.9.0-rc2-think+ #3
Workqueue: writeback wb_workfn
(flush-btrfs-1)
ffffc900006fb870
ffffffff8130cf3c
ffffea00136b8c40
ffffffff819ff54c
ffffc900006fb898
ffffffff811511af
0000000000000000
ffffea00136b8c40
400000000000000c
ffffc900006fb8a8
ffffffff8115126a
ffffc900006fb8f0
Call Trace:
[<ffffffff8130cf3c>] dump_stack+0x4f/0x73
[<ffffffff811511af>] bad_page+0xbf/0x120
[<ffffffff8115126a>] free_pages_check_bad+0x5a/0x70
[<ffffffff81153b68>] free_hot_cold_page+0x248/0x290
[<ffffffff81153e6b>] free_hot_cold_page_list+0x2b/0x50
[<ffffffff8115c87d>] release_pages+0x2bd/0x350
[<ffffffff8115ddb2>] __pagevec_release+0x22/0x30
[<ffffffffa00a0d4e>] extent_write_cache_pages.isra.48.constprop.63+0x32e/0x400 [btrfs]
[<ffffffffa00a1199>] extent_writepages+0x49/0x60 [btrfs]
[<ffffffffa0081840>] ? btrfs_releasepage+0x40/0x40 [btrfs]
[<ffffffffa007e993>] btrfs_writepages+0x23/0x30 [btrfs]
[<ffffffff8115af9c>] do_writepages+0x1c/0x30
[<ffffffff811f6d73>] __writeback_single_inode+0x33/0x180
[<ffffffff811f7568>] writeback_sb_inodes+0x2a8/0x5b0
[<ffffffff811f7abb>] wb_writeback+0xeb/0x1f0
[<ffffffff811f80f2>] wb_workfn+0xd2/0x280
[<ffffffff810908a5>] process_one_work+0x1d5/0x490
[<ffffffff81090845>] ? process_one_work+0x175/0x490
[<ffffffff81090ba9>] worker_thread+0x49/0x490
[<ffffffff81090b60>] ? process_one_work+0x490/0x490
[<ffffffff81095d1e>] kthread+0xee/0x110
[<ffffffff81095c30>] ? kthread_park+0x60/0x60
[<ffffffff81790a52>] ret_from_fork+0x22/0x30


> > Heisenbugs man, literally the worst.
>
> I know you already had this in some email, but I lost it. I think you
> narrowed it down to a specific set of system calls that seems to
> trigger this best. fallocate and xattrs or something?

I did. Or so I thought. Then iirc, it ran for a really long time
with those. I'll revisit that just to be sure.

Something else I tried: Trinity is very heavily stressing
the fork path, with new children forking off and doing crazy shit
all the time, segfaulting, repeat. I wrote a small test app that
models all of that sans the "do crazy shit with syscalls", and that
didn't do anything useful in terms of reproducing this.
I hoped that had panned out, because I could totally see the relationship
between reusing vmap'ing stacks and heavy fork() use.
Perhaps I'm still missing something non-obvious.

Dave