Groups | Search | Server Info | Keyboard shortcuts | Login | Register [http] [https] [nntp] [nntps]

Groups > linux.kernel > #1503409 > unrolled thread

Re: bio linked list corruption.

Started byDave Jones <davej@codemonkey.org.uk>
First post2016-10-19 00:50 +0200
Last post2016-10-20 09:30 +0200
Articles 20 on this page of 52 — 9 participants

Back to article view | Back to linux.kernel

This discussion starts older than the indexed window; earlier articles aren't shown. The article labeled Started by below is the oldest one visible, not the original post.

Contents

  Re: bio linked list corruption. Dave Jones <davej@codemonkey.org.uk> - 2016-10-19 00:50 +0200
    Re: bio linked list corruption. Linus Torvalds <torvalds@linux-foundation.org> - 2016-10-19 01:40 +0200
      Re: bio linked list corruption. Linus Torvalds <torvalds@linux-foundation.org> - 2016-10-19 02:20 +0200
        Re: bio linked list corruption. Linus Torvalds <torvalds@linux-foundation.org> - 2016-10-19 02:30 +0200
          Re: bio linked list corruption. Dave Jones <davej@codemonkey.org.uk> - 2016-10-21 00:50 +0200
        Re: bio linked list corruption. Andy Lutomirski <luto@kernel.org> - 2016-10-19 03:10 +0200
          Re: bio linked list corruption. Dave Jones <davej@codemonkey.org.uk> - 2016-10-21 01:00 +0200
            Re: bio linked list corruption. Dave Jones <davej@codemonkey.org.uk> - 2016-10-21 01:10 +0200
              Re: bio linked list corruption. Andy Lutomirski <luto@amacapital.net> - 2016-10-21 01:30 +0200
                Re: bio linked list corruption. Dave Jones <davej@codemonkey.org.uk> - 2016-10-21 22:10 +0200
                  Re: bio linked list corruption. Dave Jones <davej@codemonkey.org.uk> - 2016-10-21 22:30 +0200
                    Re: bio linked list corruption. Dave Jones <davej@codemonkey.org.uk> - 2016-10-21 23:20 +0200
                  Re: bio linked list corruption. Dave Jones <davej@codemonkey.org.uk> - 2016-10-22 17:30 +0200
                    Re: bio linked list corruption. Dave Jones <davej@codemonkey.org.uk> - 2016-10-24 06:50 +0200
                      Re: bio linked list corruption. Andy Lutomirski <luto@amacapital.net> - 2016-10-24 22:10 +0200
                        Re: bio linked list corruption. Linus Torvalds <torvalds@linux-foundation.org> - 2016-10-24 22:50 +0200
                          Re: bio linked list corruption. Linus Torvalds <torvalds@linux-foundation.org> - 2016-10-24 23:20 +0200
                            Re: bio linked list corruption. Linus Torvalds <torvalds@linux-foundation.org> - 2016-10-25 00:00 +0200
                          Re: bio linked list corruption. Andy Lutomirski <luto@amacapital.net> - 2016-10-25 00:50 +0200
                            Re: bio linked list corruption. Linus Torvalds <torvalds@linux-foundation.org> - 2016-10-25 02:10 +0200
                              Re: bio linked list corruption. Andy Lutomirski <luto@amacapital.net> - 2016-10-25 03:20 +0200
                      Re: bio linked list corruption. Dave Jones <davej@codemonkey.org.uk> - 2016-10-26 02:30 +0200
                        Re: bio linked list corruption. Linus Torvalds <torvalds@linux-foundation.org> - 2016-10-26 03:40 +0200
                          Re: bio linked list corruption. Linus Torvalds <torvalds@linux-foundation.org> - 2016-10-26 03:40 +0200
                            Re: bio linked list corruption. Dave Jones <davej@codemonkey.org.uk> - 2016-10-26 18:40 +0200
                              Re: bio linked list corruption. Linus Torvalds <torvalds@linux-foundation.org> - 2016-10-26 18:50 +0200
                                Re: bio linked list corruption. Dave Jones <davej@codemonkey.org.uk> - 2016-10-26 20:20 +0200
                                Re: bio linked list corruption. Dave Jones <davej@codemonkey.org.uk> - 2016-10-26 20:50 +0200
                                  Re: bio linked list corruption. Linus Torvalds <torvalds@linux-foundation.org> - 2016-10-26 21:10 +0200
                                    Re: bio linked list corruption. Linus Torvalds <torvalds@linux-foundation.org> - 2016-10-27 00:10 +0200
                                    Re: bio linked list corruption. Linus Torvalds <torvalds@linux-foundation.org> - 2016-10-27 00:30 +0200
                                      Re: bio linked list corruption. Dave Jones <davej@codemonkey.org.uk> - 2016-10-27 00:50 +0200
                                        Re: bio linked list corruption. Linus Torvalds <torvalds@linux-foundation.org> - 2016-10-27 01:00 +0200
                                          Re: bio linked list corruption. Linus Torvalds <torvalds@linux-foundation.org> - 2016-10-27 01:00 +0200
                                            Re: bio linked list corruption. Linus Torvalds <torvalds@linux-foundation.org> - 2016-10-27 01:10 +0200
                                              Re: bio linked list corruption. Dave Jones <davej@codemonkey.org.uk> - 2016-10-27 01:50 +0200
                                                Re: bio linked list corruption. Dave Jones <davej@codemonkey.org.uk> - 2016-10-31 20:00 +0100
                                                  Re: bio linked list corruption. Linus Torvalds <torvalds@linux-foundation.org> - 2016-10-31 20:40 +0100
                                                    Re: btrfs btree_ctree_super fault Dave Jones <davej@codemonkey.org.uk> - 2016-11-06 18:00 +0100
                                                      Re: btrfs btree_ctree_super fault Dave Jones <davej@codemonkey.org.uk> - 2016-11-08 16:00 +0100
                                                        Re: btrfs btree_ctree_super fault Dave Jones <davej@codemonkey.org.uk> - 2016-11-10 15:40 +0100
                                            Re: bio linked list corruption. Dave Jones <davej@codemonkey.org.uk> - 2016-10-27 01:10 +0200
                                            Re: bio linked list corruption. Christoph Hellwig <hch@infradead.org> - 2016-10-27 08:40 +0200
                                              Re: bio linked list corruption. Linus Torvalds <torvalds@linux-foundation.org> - 2016-10-27 18:40 +0200
                                          Re: bio linked list corruption. Dave Jones <davej@codemonkey.org.uk> - 2016-10-27 01:10 +0200
                        Re: bio linked list corruption. Dave Chinner <david@fromorbit.com> - 2016-10-27 07:50 +0200
                          Re: bio linked list corruption. Dave Jones <davej@codemonkey.org.uk> - 2016-10-27 19:30 +0200
            Re: bio linked list corruption. Andy Lutomirski <luto@amacapital.net> - 2016-10-21 01:10 +0200
      Re: bio linked list corruption. Philipp Hahn <pmhahn@pmhahn.de> - 2016-10-19 19:10 +0200
        Re: bio linked list corruption. Linus Torvalds <torvalds@linux-foundation.org> - 2016-10-19 19:50 +0200
          Re: bio linked list corruption. Ingo Molnar <mingo@kernel.org> - 2016-10-20 09:00 +0200
            Re: bio linked list corruption. Thomas Gleixner <tglx@linutronix.de> - 2016-10-20 09:30 +0200

Page 2 of 3 — ← Prev page 1 [2] 3  Next page →

#1507901

FromAndy Lutomirski <luto@amacapital.net>
Date2016-10-25 03:20 +0200
Message-ID<svYzf-72Z-1@gated-at.bofh.it>
In reply to#1507839
On Oct 24, 2016 5:00 PM, "Linus Torvalds" <torvalds@linux-foundation.org> wrote:
>
> On Mon, Oct 24, 2016 at 3:42 PM, Andy Lutomirski <luto@amacapital.net> wrote:
>
> > Now the fallocate thread catches up and *exits*.  Dave's test makes a
> > new thread that reuses the stack (the vmap area or the backing store).
> >
> > Now the shmem_fault thread continues on its merry way and takes
> > q->lock.  But oh crap, q->lock is pointing at some random spot on some
> > other thread's stack.  Kaboom!
>
> Note that q->lock should be entirely immaterial, since inode->i_lock
> nests outside of it in all uses.
>
> Now, if there is some code that runs *without* the inode->i_lock, then
> that would be a big bug.
>
> But I'm not seeing it.
>
> I do agree that some race on some stack data structure could easily be
> the cause of these issues. And yes, the vmap code obviously starts
> reusing the stack much earlier, and would trigger problems that would
> essentially be hidden by the fact that the kernel stack used to stay
> around not just until exit(), but until the process was reaped.
>
> I just think that in this case i_lock really looks like it should
> serialize things correctly.
>
> Or are you seeing something I'm not?

No, I missed that.

--Andy

[toc] | [prev] | [next] | [standalone]

#1508725

FromDave Jones <davej@codemonkey.org.uk>
Date2016-10-26 02:30 +0200
Message-ID<swkgp-4s8-3@gated-at.bofh.it>
In reply to#1506894
On Mon, Oct 24, 2016 at 09:42:39AM -0400, Chris Mason wrote:

 > >  > Well crud, we're back to wondering if this is Btrfs or the stack
 > >  > corruption.  Since the pagevecs are on the stack and this is a new
 > >  > crash, my guess is you'll be able to trigger it on xfs/ext4 too.  But we
 > >  > should make sure.
 > >
 > > Here's an interesting one from today, pointing the finger at xattrs again.
 > >
 > >
 > > [69943.450108] Oops: 0003 [#1] PREEMPT SMP DEBUG_PAGEALLOC
 > > [69943.454452] CPU: 1 PID: 21558 Comm: trinity-c60 Not tainted 4.9.0-rc1-think+ #11
 > > [69943.463510] task: ffff8804f8dd3740 task.stack: ffffc9000b108000
 > > [69943.468077] RIP: 0010:[<ffffffff810c3f6b>]
 > 
 > Was this btrfs?

I already told you elsewhere, but for benefit of everyone else, yes, it was.

At Chris' behest, I gave ext4 some more air-time with this workload.
It ran for 1 day 6 hrs without incident before I got bored and tried
something else.  I threw XFS on the test partition, restarted the test,
and got the warnings below across two reboots.

DaveC: Do these look like real problems, or is this more "looks like
random memory corruption" ?  It's been a while since I did some stress
testing on XFS, so these might not be new..



XFS: Assertion failed: oldlen > newlen, file: fs/xfs/libxfs/xfs_bmap.c, line: 2938
------------[ cut here ]------------
kernel BUG at fs/xfs/xfs_message.c:113!
invalid opcode: 0000 [#1] PREEMPT SMP
CPU: 1 PID: 6227 Comm: trinity-c9 Not tainted 4.9.0-rc1-think+ #6 
task: ffff8804f4658040 task.stack: ffff88050568c000
RIP: 0010:[<ffffffffa02d3e2b>] 
  [<ffffffffa02d3e2b>] assfail+0x1b/0x20 [xfs]
RSP: 0000:ffff88050568f9e8  EFLAGS: 00010282
RAX: 00000000ffffffea RBX: 0000000000000046 RCX: 0000000000000001
RDX: 00000000ffffffc0 RSI: 000000000000000a RDI: ffffffffa02fe34d
RBP: ffff88050568f9e8 R08: 0000000000000000 R09: 0000000000000000
R10: 000000000000000a R11: f000000000000000 R12: ffff88050568fb44
R13: 00000000000000f3 R14: ffff8804f292bf88 R15: 000ffffffffe0046
FS:  00007fe2ddfdfb40(0000) GS:ffff88050a000000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007fe2dbabd000 CR3: 00000004f461f000 CR4: 00000000001406e0
Stack:
 ffff88050568fa88  ffffffffa027ccee  fffffffffffffff9  ffff8804f16fd8b0
 0000000000003ffa  0000000000000032  ffff8804f292bf40  0000000000004976
 000ffffffffe0008  00000000000004fd  ffff880400000000  0000000000005107
Call Trace:
 [<ffffffffa027ccee>] xfs_bmap_add_extent_hole_delay+0x54e/0x620 [xfs]
 [<ffffffffa027f2d4>] xfs_bmapi_reserve_delalloc+0x2b4/0x400 [xfs]
 [<ffffffffa02cadd7>] xfs_file_iomap_begin_delay.isra.12+0x247/0x3c0 [xfs]
 [<ffffffffa02cb0d1>] xfs_file_iomap_begin+0x181/0x270 [xfs]
 [<ffffffffa02ca13e>] ? xfs_file_iomap_end+0x9e/0xe0 [xfs]
 [<ffffffff8122e573>] iomap_apply+0x53/0x100
 [<ffffffff8122df10>] ? iomap_write_end+0x70/0x70
 [<ffffffff8122e68b>] iomap_file_buffered_write+0x6b/0x90
 [<ffffffff8122df10>] ? iomap_write_end+0x70/0x70
 [<ffffffffa02c1dd8>] xfs_file_buffered_aio_write+0xe8/0x1d0 [xfs]
 [<ffffffff810c3b7f>] ? __lock_acquire.isra.32+0x1cf/0x8c0
 [<ffffffffa02c1f45>] xfs_file_write_iter+0x85/0x120 [xfs]
 [<ffffffff811c8c98>] do_iter_readv_writev+0xa8/0x100
 [<ffffffff811c9622>] do_readv_writev+0x172/0x210
 [<ffffffffa02c1ec0>] ? xfs_file_buffered_aio_write+0x1d0/0x1d0 [xfs]
 [<ffffffff811e9794>] ? __fdget_pos+0x44/0x50
 [<ffffffff8178b2f2>] ? mutex_lock_nested+0x272/0x3f0
 [<ffffffff811e9794>] ? __fdget_pos+0x44/0x50
 [<ffffffff811e9794>] ? __fdget_pos+0x44/0x50
 [<ffffffff811c98ea>] vfs_writev+0x3a/0x50
 [<ffffffff811c9950>] do_writev+0x50/0xd0
 [<ffffffff811ca9fb>] SyS_writev+0xb/0x10
 [<ffffffff8100255c>] do_syscall_64+0x5c/0x170
 [<ffffffff8178ff4b>] entry_SYSCALL64_slow_path+0x25/0x25
Code: 48 c7 c7 65 e3 2f a0 e8 74 37 da e0 5d c3 66 90 55 48 89 f1 41 89 d0 48 c7 c6 18 93 30 a0 48 89 fa 48 89 e5 31 ff e8 65 fa ff ff <0f> 0b 0f 1f 00 55 48 63 f6 49 89 f9 41 b8 01 00 00 00 48 89 e5 
RIP 
  [<ffffffffa02d3e2b>] assfail+0x1b/0x20 [xfs]
 RSP <ffff88050568f9e8>



XFS: Assertion failed: tp->t_blk_res_used <= tp->t_blk_res, file: fs/xfs/xfs_trans.c, line: 309
kernel BUG at fs/xfs/xfs_message.c:113!
invalid opcode: 0000 [#1] PREEMPT SMP DEBUG_PAGEALLOC
CPU: 0 PID: 7309 Comm: kworker/u8:1 Not tainted 4.9.0-rc1-think+ #11 
Workqueue: writeback wb_workfn
  (flush-8:0)
task: ffff88025eb98040 task.stack: ffffc9000a914000
RIP: 0010:[<ffffffffa0571e2b>] 
  [<ffffffffa0571e2b>] assfail+0x1b/0x20 [xfs]
RSP: 0018:ffffc9000a917410  EFLAGS: 00010282
RAX: 00000000ffffffea RBX: ffff8804538d22b8 RCX: 0000000000000001
RDX: 00000000ffffffc0 RSI: 000000000000000a RDI: ffffffffa059c34d
RBP: ffffc9000a917410 R08: 0000000000000000 R09: 0000000000000000
R10: 000000000000000a R11: f000000000000000 R12: ffffffffffffffff
R13: ffff88047c765698 R14: 0000000000000001 R15: 0000000000000000
FS:  0000000000000000(0000) GS:ffff880507800000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 0000000000000008 CR3: 00000004c56e7000 CR4: 00000000001406f0
DR0: 00007fec5e3c9000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000600
Stack:
 ffffc9000a917438  ffffffffa057abe1  ffffc9000a917510  ffffc9000a917510
 ffffc9000a917510  ffffc9000a917460  ffffffffa0548eff  ffffc9000a917510
 0000000000000001  ffffc9000a917510  ffffc9000a917480  ffffffffa050aa3d
Call Trace:
 [<ffffffffa057abe1>] xfs_trans_mod_sb+0x241/0x280 [xfs]
 [<ffffffffa0548eff>] xfs_ag_resv_alloc_extent+0x4f/0xc0 [xfs]
 [<ffffffffa050aa3d>] xfs_alloc_ag_vextent+0x23d/0x300 [xfs]
 [<ffffffffa050bb1b>] xfs_alloc_vextent+0x5fb/0x6d0 [xfs]
 [<ffffffffa051c1b4>] xfs_bmap_btalloc+0x304/0x8e0 [xfs]
 [<ffffffffa054648e>] ? xfs_iext_bno_to_ext+0xee/0x170 [xfs]
 [<ffffffffa051c8db>] xfs_bmap_alloc+0x2b/0x40 [xfs]
 [<ffffffffa051dc30>] xfs_bmapi_write+0x640/0x1210 [xfs]
 [<ffffffffa0569326>] xfs_iomap_write_allocate+0x166/0x350 [xfs]
 [<ffffffffa05540b0>] xfs_map_blocks+0x1b0/0x260 [xfs]
 [<ffffffffa0554beb>] xfs_do_writepage+0x23b/0x730 [xfs]
 [<ffffffff81159ef8>] ? clear_page_dirty_for_io+0x128/0x210
 [<ffffffff81159e71>] ? clear_page_dirty_for_io+0xa1/0x210
 [<ffffffff8115a1b6>] write_cache_pages+0x1d6/0x4a0
 [<ffffffffa05549b0>] ? xfs_aops_discard_page+0x140/0x140 [xfs]
 [<ffffffffa0554419>] xfs_vm_writepages+0x59/0x80 [xfs]
 [<ffffffff8115af6c>] do_writepages+0x1c/0x30
 [<ffffffff811f6d33>] __writeback_single_inode+0x33/0x180
 [<ffffffff811f7528>] writeback_sb_inodes+0x2a8/0x5b0
 [<ffffffff811f78bd>] __writeback_inodes_wb+0x8d/0xc0
 [<ffffffff811f7b73>] wb_writeback+0x1e3/0x1f0
 [<ffffffff811f80b2>] wb_workfn+0xd2/0x280
 [<ffffffff81090875>] process_one_work+0x1d5/0x490
 [<ffffffff81090815>] ? process_one_work+0x175/0x490
 [<ffffffff81090b79>] worker_thread+0x49/0x490
 [<ffffffff81090b30>] ? process_one_work+0x490/0x490
 [<ffffffff81090b30>] ? process_one_work+0x490/0x490
 [<ffffffff81095cee>] kthread+0xee/0x110
 [<ffffffff81095c00>] ? kthread_park+0x60/0x60
 [<ffffffff81790bd2>] ret_from_fork+0x22/0x30
Code: 48 c7 c7 65 c3 59 a0 e8 c4 5c b0 e0 5d c3 66 90 55 48 89 f1 41 89 d0 48 c7 c6 18 73 5a a0 48 89 fa 48 89 e5 31 ff e8 65 fa ff ff <0f> 0b 0f 1f 00 55 48 63 f6 49 89 f9 41 b8 01 00 00 00 48 89 e5 
RIP 
  [<ffffffffa0571e2b>] assfail+0x1b/0x20 [xfs]
 RSP <ffffc9000a917410>

[toc] | [prev] | [next] | [standalone]

#1508744

FromLinus Torvalds <torvalds@linux-foundation.org>
Date2016-10-26 03:40 +0200
Message-ID<swlm9-58c-1@gated-at.bofh.it>
In reply to#1508725
On Tue, Oct 25, 2016 at 5:27 PM, Dave Jones <davej@codemonkey.org.uk> wrote:
>
> DaveC: Do these look like real problems, or is this more "looks like
> random memory corruption" ?  It's been a while since I did some stress
> testing on XFS, so these might not be new..

Andy, do you think we could just do some poisoning of the stack as we
free it, to see if that catches anything?

Something truly stupid like just

    --- a/kernel/fork.c
    +++ b/kernel/fork.c
    @@ -218,6 +218,7 @@ static inline void free_thread_stack(struct
task_struct *tsk)
                    unsigned long flags;
                    int i;

    +               memset(tsk->stack_vm_area->addr, 0xd0, THREAD_SIZE);
                    local_irq_save(flags);
                    for (i = 0; i < NR_CACHED_STACKS; i++) {
                            if (this_cpu_read(cached_stacks[i]))

or similar?

It seems like DaveJ had an easier time triggering these problems with
the stack cache, but they clearly didn't go away when the stack cache
was disabled. So maybe the stack cache just made the reuse more likely
and faster, making the problem show up faster too. But if we actively
poison things, we'll corrupt the free'd stack *immediately* if there
is some stale use..

Completely untested. Maybe there's some reason we can't write to the
whole thing like that?

                 Linus

              Linus

[toc] | [prev] | [next] | [standalone]

#1508749

FromLinus Torvalds <torvalds@linux-foundation.org>
Date2016-10-26 03:40 +0200
Message-ID<swlm9-58c-11@gated-at.bofh.it>
In reply to#1508744
On Tue, Oct 25, 2016 at 6:33 PM, Linus Torvalds
<torvalds@linux-foundation.org> wrote:
>
> Completely untested. Maybe there's some reason we can't write to the
> whole thing like that?

That hack boots and seems to work for me, but doesn't show anything.

Dave, mind just trying that oneliner?

               Linus

[toc] | [prev] | [next] | [standalone]

#1509588

FromDave Jones <davej@codemonkey.org.uk>
Date2016-10-26 18:40 +0200
Message-ID<swzp8-6mF-27@gated-at.bofh.it>
In reply to#1508749
On Tue, Oct 25, 2016 at 06:39:03PM -0700, Linus Torvalds wrote:
 > On Tue, Oct 25, 2016 at 6:33 PM, Linus Torvalds
 > <torvalds@linux-foundation.org> wrote:
 > >
 > > Completely untested. Maybe there's some reason we can't write to the
 > > whole thing like that?
 > 
 > That hack boots and seems to work for me, but doesn't show anything.
 > 
 > Dave, mind just trying that oneliner?

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.  I rebooted, and tried again and
went to bed.

12 hours later, it's still doing it's thing.

Heisenbugs man, literally the worst.

	Dave

[toc] | [prev] | [next] | [standalone]

#1509592

FromLinus Torvalds <torvalds@linux-foundation.org>
Date2016-10-26 18:50 +0200
Message-ID<swzyO-6qe-3@gated-at.bofh.it>
In reply to#1509588
On Wed, Oct 26, 2016 at 9:30 AM, Dave Jones <davej@codemonkey.org.uk> 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.

> 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?

              Linus

[toc] | [prev] | [next] | [standalone]

#1509687

FromDave Jones <davej@codemonkey.org.uk>
Date2016-10-26 20:20 +0200
Message-ID<swAXU-7td-29@gated-at.bofh.it>
In reply to#1509592
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@codemonkey.org.uk> 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

[toc] | [prev] | [next] | [standalone]

#1509701

FromDave Jones <davej@codemonkey.org.uk>
Date2016-10-26 20:50 +0200
Message-ID<swBqV-7E5-29@gated-at.bofh.it>
In reply to#1509592
On Wed, Oct 26, 2016 at 09:48:39AM -0700, Linus Torvalds wrote:

 > 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?

So I was about to give that a shot again. That this has been running
doing for 24hrs was bugging me.  I ctrl-c'd the current run, and trinity
just sat there, because all of its child processes are stuck in D state.

The stacks show nearly all of them are stuck in sync_inodes_sb

iotop & vmstat shows there is _zero_ io actually happening.
So it's spent most the night doing next to nothing useful afaict.

Chris ?

Here's the /proc/pid/stack's of those children..


[<ffffffff811f5806>] sync_inodes_sb+0xc6/0x300
[<ffffffff811fbd37>] sync_filesystem+0x57/0xa0
[<ffffffff811fbebc>] SyS_syncfs+0x3c/0x70
[<ffffffff8100255c>] do_syscall_64+0x5c/0x170
[<ffffffff817908cb>] entry_SYSCALL64_slow_path+0x25/0x25
[<ffffffffffffffff>] 0xffffffffffffffff

[<ffffffff811f5806>] sync_inodes_sb+0xc6/0x300
[<ffffffff811fbac0>] sync_inodes_one_sb+0x10/0x20
[<ffffffff811cdd3f>] iterate_supers+0xaf/0x100
[<ffffffff811fbdb0>] sys_sync+0x30/0x90
[<ffffffff8100255c>] do_syscall_64+0x5c/0x170
[<ffffffff817908cb>] entry_SYSCALL64_slow_path+0x25/0x25
[<ffffffffffffffff>] 0xffffffffffffffff

[<ffffffff811f5806>] sync_inodes_sb+0xc6/0x300
[<ffffffff811fbac0>] sync_inodes_one_sb+0x10/0x20
[<ffffffff811cdd3f>] iterate_supers+0xaf/0x100
[<ffffffff811fbdb0>] sys_sync+0x30/0x90
[<ffffffff8100255c>] do_syscall_64+0x5c/0x170
[<ffffffff817908cb>] entry_SYSCALL64_slow_path+0x25/0x25
[<ffffffffffffffff>] 0xffffffffffffffff

[<ffffffff811f5806>] sync_inodes_sb+0xc6/0x300
[<ffffffff811fbac0>] sync_inodes_one_sb+0x10/0x20
[<ffffffff811cdd3f>] iterate_supers+0xaf/0x100
[<ffffffff811fbdb0>] sys_sync+0x30/0x90
[<ffffffff8100255c>] do_syscall_64+0x5c/0x170
[<ffffffff817908cb>] entry_SYSCALL64_slow_path+0x25/0x25
[<ffffffffffffffff>] 0xffffffffffffffff

[<ffffffffa009554f>] btrfs_wait_ordered_roots+0x3f/0x200 [btrfs]
[<ffffffffa00470d1>] btrfs_sync_fs+0x31/0xc0 [btrfs]
[<ffffffff811fbd4e>] sync_filesystem+0x6e/0xa0
[<ffffffff811fbebc>] SyS_syncfs+0x3c/0x70
[<ffffffff8100255c>] do_syscall_64+0x5c/0x170
[<ffffffff817908cb>] entry_SYSCALL64_slow_path+0x25/0x25
[<ffffffffffffffff>] 0xffffffffffffffff

[<ffffffff8131ae87>] call_rwsem_down_write_failed+0x17/0x30
[<ffffffff811fc294>] utimes_common+0xd4/0x190
[<ffffffff811fc457>] do_utimes+0x107/0x120
[<ffffffff811fc641>] SyS_futimesat+0xa1/0xd0
[<ffffffff8100255c>] do_syscall_64+0x5c/0x170
[<ffffffff817908cb>] entry_SYSCALL64_slow_path+0x25/0x25
[<ffffffffffffffff>] 0xffffffffffffffff

[<ffffffff811f5806>] sync_inodes_sb+0xc6/0x300
[<ffffffff811fbac0>] sync_inodes_one_sb+0x10/0x20
[<ffffffff811cdd3f>] iterate_supers+0xaf/0x100
[<ffffffff811fbdb0>] sys_sync+0x30/0x90
[<ffffffff8100255c>] do_syscall_64+0x5c/0x170
[<ffffffff817908cb>] entry_SYSCALL64_slow_path+0x25/0x25
[<ffffffffffffffff>] 0xffffffffffffffff

[<ffffffff811f5806>] sync_inodes_sb+0xc6/0x300
[<ffffffff811fbd37>] sync_filesystem+0x57/0xa0
[<ffffffff811fbebc>] SyS_syncfs+0x3c/0x70
[<ffffffff8100255c>] do_syscall_64+0x5c/0x170
[<ffffffff817908cb>] entry_SYSCALL64_slow_path+0x25/0x25
[<ffffffffffffffff>] 0xffffffffffffffff

[<ffffffff811f5806>] sync_inodes_sb+0xc6/0x300
[<ffffffff811fbd37>] sync_filesystem+0x57/0xa0
[<ffffffff811fbebc>] SyS_syncfs+0x3c/0x70
[<ffffffff8100255c>] do_syscall_64+0x5c/0x170
[<ffffffff817908cb>] entry_SYSCALL64_slow_path+0x25/0x25
[<ffffffffffffffff>] 0xffffffffffffffff

[<ffffffff811f5806>] sync_inodes_sb+0xc6/0x300
[<ffffffff811fbd37>] sync_filesystem+0x57/0xa0
[<ffffffff811fbebc>] SyS_syncfs+0x3c/0x70
[<ffffffff8100255c>] do_syscall_64+0x5c/0x170
[<ffffffff817908cb>] entry_SYSCALL64_slow_path+0x25/0x25
[<ffffffffffffffff>] 0xffffffffffffffff

[<ffffffff811f5806>] sync_inodes_sb+0xc6/0x300
[<ffffffff811fbac0>] sync_inodes_one_sb+0x10/0x20
[<ffffffff811cdd3f>] iterate_supers+0xaf/0x100
[<ffffffff811fbdb0>] sys_sync+0x30/0x90
[<ffffffff8100255c>] do_syscall_64+0x5c/0x170
[<ffffffff817908cb>] entry_SYSCALL64_slow_path+0x25/0x25
[<ffffffffffffffff>] 0xffffffffffffffff

[<ffffffff811f5806>] sync_inodes_sb+0xc6/0x300
[<ffffffff811fbd37>] sync_filesystem+0x57/0xa0
[<ffffffff811fbebc>] SyS_syncfs+0x3c/0x70
[<ffffffff8100255c>] do_syscall_64+0x5c/0x170
[<ffffffff817908cb>] entry_SYSCALL64_slow_path+0x25/0x25
[<ffffffffffffffff>] 0xffffffffffffffff

[<ffffffff811f5806>] sync_inodes_sb+0xc6/0x300
[<ffffffff811fbd37>] sync_filesystem+0x57/0xa0
[<ffffffff811fbebc>] SyS_syncfs+0x3c/0x70
[<ffffffff8100255c>] do_syscall_64+0x5c/0x170
[<ffffffff817908cb>] entry_SYSCALL64_slow_path+0x25/0x25
[<ffffffffffffffff>] 0xffffffffffffffff

[<ffffffff811f5806>] sync_inodes_sb+0xc6/0x300
[<ffffffff811fbac0>] sync_inodes_one_sb+0x10/0x20
[<ffffffff811cdd3f>] iterate_supers+0xaf/0x100
[<ffffffff811fbdb0>] sys_sync+0x30/0x90
[<ffffffff8100255c>] do_syscall_64+0x5c/0x170
[<ffffffff817908cb>] entry_SYSCALL64_slow_path+0x25/0x25
[<ffffffffffffffff>] 0xffffffffffffffff

[<ffffffff811f5806>] sync_inodes_sb+0xc6/0x300
[<ffffffff811fbd37>] sync_filesystem+0x57/0xa0
[<ffffffff811fbebc>] SyS_syncfs+0x3c/0x70
[<ffffffff8100255c>] do_syscall_64+0x5c/0x170
[<ffffffff817908cb>] entry_SYSCALL64_slow_path+0x25/0x25
[<ffffffffffffffff>] 0xffffffffffffffff

[<ffffffff811f5806>] sync_inodes_sb+0xc6/0x300
[<ffffffff811fbac0>] sync_inodes_one_sb+0x10/0x20
[<ffffffff811cdd3f>] iterate_supers+0xaf/0x100
[<ffffffff811fbdb0>] sys_sync+0x30/0x90
[<ffffffff8100255c>] do_syscall_64+0x5c/0x170
[<ffffffff817908cb>] entry_SYSCALL64_slow_path+0x25/0x25
[<ffffffffffffffff>] 0xffffffffffffffff

[<ffffffff811f5806>] sync_inodes_sb+0xc6/0x300
[<ffffffff811fbd37>] sync_filesystem+0x57/0xa0
[<ffffffff811fbebc>] SyS_syncfs+0x3c/0x70
[<ffffffff8100255c>] do_syscall_64+0x5c/0x170
[<ffffffff817908cb>] entry_SYSCALL64_slow_path+0x25/0x25
[<ffffffffffffffff>] 0xffffffffffffffff

[<ffffffff811f5806>] sync_inodes_sb+0xc6/0x300
[<ffffffff811fbd37>] sync_filesystem+0x57/0xa0
[<ffffffff811fbebc>] SyS_syncfs+0x3c/0x70
[<ffffffff8100255c>] do_syscall_64+0x5c/0x170
[<ffffffff817908cb>] entry_SYSCALL64_slow_path+0x25/0x25
[<ffffffffffffffff>] 0xffffffffffffffff

[<ffffffff811f5806>] sync_inodes_sb+0xc6/0x300
[<ffffffff811fbd37>] sync_filesystem+0x57/0xa0
[<ffffffff811fbebc>] SyS_syncfs+0x3c/0x70
[<ffffffff8100255c>] do_syscall_64+0x5c/0x170
[<ffffffff817908cb>] entry_SYSCALL64_slow_path+0x25/0x25
[<ffffffffffffffff>] 0xffffffffffffffff

[<ffffffff811f5806>] sync_inodes_sb+0xc6/0x300
[<ffffffff811fbd37>] sync_filesystem+0x57/0xa0
[<ffffffff811fbebc>] SyS_syncfs+0x3c/0x70
[<ffffffff8100255c>] do_syscall_64+0x5c/0x170
[<ffffffff817908cb>] entry_SYSCALL64_slow_path+0x25/0x25
[<ffffffffffffffff>] 0xffffffffffffffff

[<ffffffff811f5806>] sync_inodes_sb+0xc6/0x300
[<ffffffff811fbac0>] sync_inodes_one_sb+0x10/0x20
[<ffffffff811cdd3f>] iterate_supers+0xaf/0x100
[<ffffffff811fbdb0>] sys_sync+0x30/0x90
[<ffffffff8100255c>] do_syscall_64+0x5c/0x170
[<ffffffff817908cb>] entry_SYSCALL64_slow_path+0x25/0x25
[<ffffffffffffffff>] 0xffffffffffffffff

[<ffffffff8131ae87>] call_rwsem_down_write_failed+0x17/0x30
[<ffffffffa008ed32>] btrfs_fallocate+0xb2/0xfd0 [btrfs]
[<ffffffff811c6c3e>] vfs_fallocate+0x13e/0x220
[<ffffffff811c79f3>] SyS_fallocate+0x43/0x80
[<ffffffff8100255c>] do_syscall_64+0x5c/0x170
[<ffffffff817908cb>] entry_SYSCALL64_slow_path+0x25/0x25
[<ffffffffffffffff>] 0xffffffffffffffff

[<ffffffff811f5806>] sync_inodes_sb+0xc6/0x300
[<ffffffff811fbac0>] sync_inodes_one_sb+0x10/0x20
[<ffffffff811cdd3f>] iterate_supers+0xaf/0x100
[<ffffffff811fbdb0>] sys_sync+0x30/0x90
[<ffffffff8100255c>] do_syscall_64+0x5c/0x170
[<ffffffff817908cb>] entry_SYSCALL64_slow_path+0x25/0x25
[<ffffffffffffffff>] 0xffffffffffffffff

[<ffffffffa009554f>] btrfs_wait_ordered_roots+0x3f/0x200 [btrfs]
[<ffffffffa00470d1>] btrfs_sync_fs+0x31/0xc0 [btrfs]
[<ffffffff811fbcdb>] sync_fs_one_sb+0x1b/0x20
[<ffffffff811cdd3f>] iterate_supers+0xaf/0x100
[<ffffffff811fbdd0>] sys_sync+0x50/0x90
[<ffffffff8100255c>] do_syscall_64+0x5c/0x170
[<ffffffff817908cb>] entry_SYSCALL64_slow_path+0x25/0x25
[<ffffffffffffffff>] 0xffffffffffffffff

[<ffffffff811f5806>] sync_inodes_sb+0xc6/0x300
[<ffffffff811fbac0>] sync_inodes_one_sb+0x10/0x20
[<ffffffff811cdd3f>] iterate_supers+0xaf/0x100
[<ffffffff811fbdb0>] sys_sync+0x30/0x90
[<ffffffff8100255c>] do_syscall_64+0x5c/0x170
[<ffffffff817908cb>] entry_SYSCALL64_slow_path+0x25/0x25
[<ffffffffffffffff>] 0xffffffffffffffff

[<ffffffff811f5806>] sync_inodes_sb+0xc6/0x300
[<ffffffff811fbac0>] sync_inodes_one_sb+0x10/0x20
[<ffffffff811cdd3f>] iterate_supers+0xaf/0x100
[<ffffffff811fbdb0>] sys_sync+0x30/0x90
[<ffffffff8100255c>] do_syscall_64+0x5c/0x170
[<ffffffff817908cb>] entry_SYSCALL64_slow_path+0x25/0x25
[<ffffffffffffffff>] 0xffffffffffffffff

[<ffffffff811f5806>] sync_inodes_sb+0xc6/0x300
[<ffffffff811fbd37>] sync_filesystem+0x57/0xa0
[<ffffffff811fbebc>] SyS_syncfs+0x3c/0x70
[<ffffffff8100255c>] do_syscall_64+0x5c/0x170
[<ffffffff817908cb>] entry_SYSCALL64_slow_path+0x25/0x25
[<ffffffffffffffff>] 0xffffffffffffffff

[<ffffffff811f5806>] sync_inodes_sb+0xc6/0x300
[<ffffffff811fbac0>] sync_inodes_one_sb+0x10/0x20
[<ffffffff811cdd3f>] iterate_supers+0xaf/0x100
[<ffffffff811fbdb0>] sys_sync+0x30/0x90
[<ffffffff8100255c>] do_syscall_64+0x5c/0x170
[<ffffffff817908cb>] entry_SYSCALL64_slow_path+0x25/0x25
[<ffffffffffffffff>] 0xffffffffffffffff

[<ffffffff8131ae87>] call_rwsem_down_write_failed+0x17/0x30
[<ffffffffa008c0f4>] btrfs_file_llseek+0x34/0x290 [btrfs]
[<ffffffff811c9ab5>] SyS_lseek+0x85/0xa0
[<ffffffff8100255c>] do_syscall_64+0x5c/0x170
[<ffffffff817908cb>] entry_SYSCALL64_slow_path+0x25/0x25
[<ffffffffffffffff>] 0xffffffffffffffff

[<ffffffff811f5806>] sync_inodes_sb+0xc6/0x300
[<ffffffff811fbac0>] sync_inodes_one_sb+0x10/0x20
[<ffffffff811cdd3f>] iterate_supers+0xaf/0x100
[<ffffffff811fbdb0>] sys_sync+0x30/0x90
[<ffffffff8100255c>] do_syscall_64+0x5c/0x170
[<ffffffff817908cb>] entry_SYSCALL64_slow_path+0x25/0x25
[<ffffffffffffffff>] 0xffffffffffffffff

[<ffffffff811f5806>] sync_inodes_sb+0xc6/0x300
[<ffffffff811fbd37>] sync_filesystem+0x57/0xa0
[<ffffffff811fbebc>] SyS_syncfs+0x3c/0x70
[<ffffffff8100255c>] do_syscall_64+0x5c/0x170
[<ffffffff817908cb>] entry_SYSCALL64_slow_path+0x25/0x25
[<ffffffffffffffff>] 0xffffffffffffffff

[<ffffffff8131ae87>] call_rwsem_down_write_failed+0x17/0x30
[<ffffffffa0090a0e>] btrfs_sync_file+0x7e/0x360 [btrfs]
[<ffffffff811fbbe6>] vfs_fsync_range+0x46/0xa0
[<ffffffffa00910e0>] btrfs_file_write_iter+0x3f0/0x550 [btrfs]
[<ffffffff811c97d8>] do_iter_readv_writev+0xa8/0x100
[<ffffffff811ca162>] do_readv_writev+0x172/0x210
[<ffffffff811ca42a>] vfs_writev+0x3a/0x50
[<ffffffff811ca5c0>] do_pwritev+0xb0/0xd0
[<ffffffff811cb592>] SyS_pwritev2+0x12/0x20
[<ffffffff8100255c>] do_syscall_64+0x5c/0x170
[<ffffffff817908cb>] entry_SYSCALL64_slow_path+0x25/0x25
[<ffffffffffffffff>] 0xffffffffffffffff

[<ffffffff811ea2d4>] __fdget_pos+0x44/0x50
[<ffffffff811de8ec>] SyS_getdents+0x6c/0x110
[<ffffffff8100255c>] do_syscall_64+0x5c/0x170
[<ffffffff817908cb>] entry_SYSCALL64_slow_path+0x25/0x25
[<ffffffffffffffff>] 0xffffffffffffffff

[<ffffffff8131ae87>] call_rwsem_down_write_failed+0x17/0x30
[<ffffffff811c752a>] do_truncate+0x4a/0x90
[<ffffffff811c790c>] do_sys_ftruncate.constprop.19+0x10c/0x170
[<ffffffff811c7999>] SyS_ftruncate+0x9/0x10
[<ffffffff8100255c>] do_syscall_64+0x5c/0x170
[<ffffffff817908cb>] entry_SYSCALL64_slow_path+0x25/0x25
[<ffffffffffffffff>] 0xffffffffffffffff

[<ffffffff811f5806>] sync_inodes_sb+0xc6/0x300
[<ffffffff811fbac0>] sync_inodes_one_sb+0x10/0x20
[<ffffffff811cdd3f>] iterate_supers+0xaf/0x100
[<ffffffff811fbdb0>] sys_sync+0x30/0x90
[<ffffffff8100255c>] do_syscall_64+0x5c/0x170
[<ffffffff817908cb>] entry_SYSCALL64_slow_path+0x25/0x25
[<ffffffffffffffff>] 0xffffffffffffffff

[<ffffffff811f5806>] sync_inodes_sb+0xc6/0x300
[<ffffffff811fbac0>] sync_inodes_one_sb+0x10/0x20
[<ffffffff811cdd3f>] iterate_supers+0xaf/0x100
[<ffffffff811fbdb0>] sys_sync+0x30/0x90
[<ffffffff8100255c>] do_syscall_64+0x5c/0x170
[<ffffffff817908cb>] entry_SYSCALL64_slow_path+0x25/0x25
[<ffffffffffffffff>] 0xffffffffffffffff

[<ffffffffa0095413>] btrfs_wait_ordered_extents+0x1e3/0x2e0 [btrfs]
[<ffffffffa0095647>] btrfs_wait_ordered_roots+0x137/0x200 [btrfs]
[<ffffffffa00470d1>] btrfs_sync_fs+0x31/0xc0 [btrfs]
[<ffffffff811fbcdb>] sync_fs_one_sb+0x1b/0x20
[<ffffffff811cdd3f>] iterate_supers+0xaf/0x100
[<ffffffff811fbdd0>] sys_sync+0x50/0x90
[<ffffffff8100255c>] do_syscall_64+0x5c/0x170
[<ffffffff817908cb>] entry_SYSCALL64_slow_path+0x25/0x25
[<ffffffffffffffff>] 0xffffffffffffffff

[<ffffffff811f5806>] sync_inodes_sb+0xc6/0x300
[<ffffffff811fbd37>] sync_filesystem+0x57/0xa0
[<ffffffff811fbebc>] SyS_syncfs+0x3c/0x70
[<ffffffff8100255c>] do_syscall_64+0x5c/0x170
[<ffffffff817908cb>] entry_SYSCALL64_slow_path+0x25/0x25
[<ffffffffffffffff>] 0xffffffffffffffff

[<ffffffff81149fbf>] wait_on_page_bit+0xaf/0xc0
[<ffffffff8114a121>] __filemap_fdatawait_range+0x151/0x170
[<ffffffff8114d79c>] filemap_fdatawait_keep_errors+0x1c/0x20
[<ffffffff811f59b3>] sync_inodes_sb+0x273/0x300
[<ffffffff811fbd37>] sync_filesystem+0x57/0xa0
[<ffffffff811fbebc>] SyS_syncfs+0x3c/0x70
[<ffffffff8100255c>] do_syscall_64+0x5c/0x170
[<ffffffff817908cb>] entry_SYSCALL64_slow_path+0x25/0x25
[<ffffffffffffffff>] 0xffffffffffffffff

[<ffffffff811f5806>] sync_inodes_sb+0xc6/0x300
[<ffffffff811fbd37>] sync_filesystem+0x57/0xa0
[<ffffffff811fbebc>] SyS_syncfs+0x3c/0x70
[<ffffffff8100255c>] do_syscall_64+0x5c/0x170
[<ffffffff817908cb>] entry_SYSCALL64_slow_path+0x25/0x25
[<ffffffffffffffff>] 0xffffffffffffffff

[<ffffffff8131ae87>] call_rwsem_down_write_failed+0x17/0x30
[<ffffffffa0090d50>] btrfs_file_write_iter+0x60/0x550 [btrfs]
[<ffffffff811c97d8>] do_iter_readv_writev+0xa8/0x100
[<ffffffff811ca162>] do_readv_writev+0x172/0x210
[<ffffffff811ca42a>] vfs_writev+0x3a/0x50
[<ffffffff811ca5c0>] do_pwritev+0xb0/0xd0
[<ffffffff811cb57c>] SyS_pwritev+0xc/0x10
[<ffffffff8100255c>] do_syscall_64+0x5c/0x170
[<ffffffff817908cb>] entry_SYSCALL64_slow_path+0x25/0x25
[<ffffffffffffffff>] 0xffffffffffffffff

[<ffffffff811ea2d4>] __fdget_pos+0x44/0x50
[<ffffffff811c9a48>] SyS_lseek+0x18/0xa0
[<ffffffff8100255c>] do_syscall_64+0x5c/0x170
[<ffffffff817908cb>] entry_SYSCALL64_slow_path+0x25/0x25
[<ffffffffffffffff>] 0xffffffffffffffff

[<ffffffff811f5806>] sync_inodes_sb+0xc6/0x300
[<ffffffff811fbd37>] sync_filesystem+0x57/0xa0
[<ffffffff811fbebc>] SyS_syncfs+0x3c/0x70
[<ffffffff8100255c>] do_syscall_64+0x5c/0x170
[<ffffffff817908cb>] entry_SYSCALL64_slow_path+0x25/0x25
[<ffffffffffffffff>] 0xffffffffffffffff

[<ffffffff811f5806>] sync_inodes_sb+0xc6/0x300
[<ffffffff811fbd37>] sync_filesystem+0x57/0xa0
[<ffffffff811fbebc>] SyS_syncfs+0x3c/0x70
[<ffffffff8100255c>] do_syscall_64+0x5c/0x170
[<ffffffff817908cb>] entry_SYSCALL64_slow_path+0x25/0x25
[<ffffffffffffffff>] 0xffffffffffffffff

[<ffffffff811f5806>] sync_inodes_sb+0xc6/0x300
[<ffffffff811fbd37>] sync_filesystem+0x57/0xa0
[<ffffffff811fbebc>] SyS_syncfs+0x3c/0x70
[<ffffffff8100255c>] do_syscall_64+0x5c/0x170
[<ffffffff817908cb>] entry_SYSCALL64_slow_path+0x25/0x25
[<ffffffffffffffff>] 0xffffffffffffffff

[<ffffffff811f5806>] sync_inodes_sb+0xc6/0x300
[<ffffffff811fbd37>] sync_filesystem+0x57/0xa0
[<ffffffff811fbebc>] SyS_syncfs+0x3c/0x70
[<ffffffff8100255c>] do_syscall_64+0x5c/0x170
[<ffffffff817908cb>] entry_SYSCALL64_slow_path+0x25/0x25
[<ffffffffffffffff>] 0xffffffffffffffff

[<ffffffff811f5806>] sync_inodes_sb+0xc6/0x300
[<ffffffff811fbd37>] sync_filesystem+0x57/0xa0
[<ffffffff811fbebc>] SyS_syncfs+0x3c/0x70
[<ffffffff8100255c>] do_syscall_64+0x5c/0x170
[<ffffffff817908cb>] entry_SYSCALL64_slow_path+0x25/0x25
[<ffffffffffffffff>] 0xffffffffffffffff

[<ffffffff811f5806>] sync_inodes_sb+0xc6/0x300
[<ffffffff811fbd37>] sync_filesystem+0x57/0xa0
[<ffffffff811fbebc>] SyS_syncfs+0x3c/0x70
[<ffffffff8100255c>] do_syscall_64+0x5c/0x170
[<ffffffff817908cb>] entry_SYSCALL64_slow_path+0x25/0x25
[<ffffffffffffffff>] 0xffffffffffffffff

[<ffffffff811f5806>] sync_inodes_sb+0xc6/0x300
[<ffffffff811fbac0>] sync_inodes_one_sb+0x10/0x20
[<ffffffff811cdd3f>] iterate_supers+0xaf/0x100
[<ffffffff811fbdb0>] sys_sync+0x30/0x90
[<ffffffff8100255c>] do_syscall_64+0x5c/0x170
[<ffffffff817908cb>] entry_SYSCALL64_slow_path+0x25/0x25
[<ffffffffffffffff>] 0xffffffffffffffff

[<ffffffff811f5806>] sync_inodes_sb+0xc6/0x300
[<ffffffff811fbac0>] sync_inodes_one_sb+0x10/0x20
[<ffffffff811cdd3f>] iterate_supers+0xaf/0x100
[<ffffffff811fbdb0>] sys_sync+0x30/0x90
[<ffffffff8100255c>] do_syscall_64+0x5c/0x170
[<ffffffff817908cb>] entry_SYSCALL64_slow_path+0x25/0x25
[<ffffffffffffffff>] 0xffffffffffffffff

[<ffffffff811f5806>] sync_inodes_sb+0xc6/0x300
[<ffffffff811fbd37>] sync_filesystem+0x57/0xa0
[<ffffffff811fbebc>] SyS_syncfs+0x3c/0x70
[<ffffffff8100255c>] do_syscall_64+0x5c/0x170
[<ffffffff817908cb>] entry_SYSCALL64_slow_path+0x25/0x25
[<ffffffffffffffff>] 0xffffffffffffffff

[<ffffffff8131ae87>] call_rwsem_down_write_failed+0x17/0x30
[<ffffffffa0090d50>] btrfs_file_write_iter+0x60/0x550 [btrfs]
[<ffffffff811c8e64>] __vfs_write+0xc4/0x120
[<ffffffff811c9f03>] vfs_write+0xb3/0x1a0
[<ffffffff811cb3d4>] SyS_pwrite64+0x74/0x90
[<ffffffff8100255c>] do_syscall_64+0x5c/0x170
[<ffffffff817908cb>] entry_SYSCALL64_slow_path+0x25/0x25
[<ffffffffffffffff>] 0xffffffffffffffff

[<ffffffff811f5806>] sync_inodes_sb+0xc6/0x300
[<ffffffff811fbd37>] sync_filesystem+0x57/0xa0
[<ffffffff811fbebc>] SyS_syncfs+0x3c/0x70
[<ffffffff8100255c>] do_syscall_64+0x5c/0x170
[<ffffffff817908cb>] entry_SYSCALL64_slow_path+0x25/0x25
[<ffffffffffffffff>] 0xffffffffffffffff

[<ffffffff811f5806>] sync_inodes_sb+0xc6/0x300
[<ffffffff811fbd37>] sync_filesystem+0x57/0xa0
[<ffffffff811fbebc>] SyS_syncfs+0x3c/0x70
[<ffffffff8100255c>] do_syscall_64+0x5c/0x170
[<ffffffff817908cb>] entry_SYSCALL64_slow_path+0x25/0x25
[<ffffffffffffffff>] 0xffffffffffffffff

[<ffffffff811f5806>] sync_inodes_sb+0xc6/0x300
[<ffffffff811fbac0>] sync_inodes_one_sb+0x10/0x20
[<ffffffff811cdd3f>] iterate_supers+0xaf/0x100
[<ffffffff811fbdb0>] sys_sync+0x30/0x90
[<ffffffff8100255c>] do_syscall_64+0x5c/0x170
[<ffffffff817908cb>] entry_SYSCALL64_slow_path+0x25/0x25
[<ffffffffffffffff>] 0xffffffffffffffff

[<ffffffff811f5806>] sync_inodes_sb+0xc6/0x300
[<ffffffff811fbd37>] sync_filesystem+0x57/0xa0
[<ffffffff811fbebc>] SyS_syncfs+0x3c/0x70
[<ffffffff8100255c>] do_syscall_64+0x5c/0x170
[<ffffffff817908cb>] entry_SYSCALL64_slow_path+0x25/0x25
[<ffffffffffffffff>] 0xffffffffffffffff

[<ffffffff811f5806>] sync_inodes_sb+0xc6/0x300
[<ffffffff811fbac0>] sync_inodes_one_sb+0x10/0x20
[<ffffffff811cdd3f>] iterate_supers+0xaf/0x100
[<ffffffff811fbdb0>] sys_sync+0x30/0x90
[<ffffffff8100255c>] do_syscall_64+0x5c/0x170
[<ffffffff817908cb>] entry_SYSCALL64_slow_path+0x25/0x25
[<ffffffffffffffff>] 0xffffffffffffffff

[<ffffffff811f5806>] sync_inodes_sb+0xc6/0x300
[<ffffffff811fbac0>] sync_inodes_one_sb+0x10/0x20
[<ffffffff811cdd3f>] iterate_supers+0xaf/0x100
[<ffffffff811fbdb0>] sys_sync+0x30/0x90
[<ffffffff8100255c>] do_syscall_64+0x5c/0x170
[<ffffffff817908cb>] entry_SYSCALL64_slow_path+0x25/0x25
[<ffffffffffffffff>] 0xffffffffffffffff

[<ffffffff811f5806>] sync_inodes_sb+0xc6/0x300
[<ffffffff811fbac0>] sync_inodes_one_sb+0x10/0x20
[<ffffffff811cdd3f>] iterate_supers+0xaf/0x100
[<ffffffff811fbdb0>] sys_sync+0x30/0x90
[<ffffffff8100255c>] do_syscall_64+0x5c/0x170
[<ffffffff817908cb>] entry_SYSCALL64_slow_path+0x25/0x25
[<ffffffffffffffff>] 0xffffffffffffffff

[<ffffffff811f5806>] sync_inodes_sb+0xc6/0x300
[<ffffffff811fbd37>] sync_filesystem+0x57/0xa0
[<ffffffff811fbebc>] SyS_syncfs+0x3c/0x70
[<ffffffff8100255c>] do_syscall_64+0x5c/0x170
[<ffffffff817908cb>] entry_SYSCALL64_slow_path+0x25/0x25
[<ffffffffffffffff>] 0xffffffffffffffff

[<ffffffff811f5806>] sync_inodes_sb+0xc6/0x300
[<ffffffff811fbac0>] sync_inodes_one_sb+0x10/0x20
[<ffffffff811cdd3f>] iterate_supers+0xaf/0x100
[<ffffffff811fbdb0>] sys_sync+0x30/0x90
[<ffffffff8100255c>] do_syscall_64+0x5c/0x170
[<ffffffff817908cb>] entry_SYSCALL64_slow_path+0x25/0x25
[<ffffffffffffffff>] 0xffffffffffffffff

[<ffffffffa009576b>] btrfs_start_ordered_extent+0x5b/0xb0 [btrfs]
[<ffffffffa008bf5d>] lock_and_cleanup_extent_if_need+0x22d/0x290 [btrfs]
[<ffffffffa008d1e8>] __btrfs_buffered_write+0x1b8/0x6e0 [btrfs]
[<ffffffffa0090e60>] btrfs_file_write_iter+0x170/0x550 [btrfs]
[<ffffffff811c97d8>] do_iter_readv_writev+0xa8/0x100
[<ffffffff811ca162>] do_readv_writev+0x172/0x210
[<ffffffff811ca42a>] vfs_writev+0x3a/0x50
[<ffffffff811ca5c0>] do_pwritev+0xb0/0xd0
[<ffffffff811cb57c>] SyS_pwritev+0xc/0x10
[<ffffffff8100255c>] do_syscall_64+0x5c/0x170
[<ffffffff817908cb>] entry_SYSCALL64_slow_path+0x25/0x25
[<ffffffffffffffff>] 0xffffffffffffffff

[<ffffffff8131ae87>] call_rwsem_down_write_failed+0x17/0x30
[<ffffffffa0090d50>] btrfs_file_write_iter+0x60/0x550 [btrfs]
[<ffffffff811c8e64>] __vfs_write+0xc4/0x120
[<ffffffff811c998d>] __kernel_write+0x4d/0xf0
[<ffffffff811f995d>] write_pipe_buf+0x6d/0x80
[<ffffffff811f9cdf>] __splice_from_pipe+0x12f/0x1b0
[<ffffffff811fabdc>] splice_from_pipe+0x4c/0x70
[<ffffffff811fac34>] default_file_splice_write+0x14/0x20
[<ffffffff811f9081>] direct_splice_actor+0x31/0x40
[<ffffffff811f972c>] splice_direct_to_actor+0xcc/0x1e0
[<ffffffff811f98d0>] do_splice_direct+0x90/0xb0
[<ffffffff811cad30>] do_sendfile+0x1b0/0x390
[<ffffffff811cb7cf>] SyS_sendfile64+0x5f/0xd0
[<ffffffff8100255c>] do_syscall_64+0x5c/0x170
[<ffffffff817908cb>] entry_SYSCALL64_slow_path+0x25/0x25
[<ffffffffffffffff>] 0xffffffffffffffff

[<ffffffff811f5806>] sync_inodes_sb+0xc6/0x300
[<ffffffff811fbac0>] sync_inodes_one_sb+0x10/0x20
[<ffffffff811cdd3f>] iterate_supers+0xaf/0x100
[<ffffffff811fbdb0>] sys_sync+0x30/0x90
[<ffffffff8100255c>] do_syscall_64+0x5c/0x170
[<ffffffff817908cb>] entry_SYSCALL64_slow_path+0x25/0x25
[<ffffffffffffffff>] 0xffffffffffffffff

[<ffffffff81086eee>] do_sigtimedwait+0x16e/0x260
[<ffffffff81087084>] SYSC_rt_sigtimedwait+0xa4/0x100
[<ffffffff810870e9>] SyS_rt_sigtimedwait+0x9/0x10
[<ffffffff8100255c>] do_syscall_64+0x5c/0x170
[<ffffffff817908cb>] entry_SYSCALL64_slow_path+0x25/0x25
[<ffffffffffffffff>] 0xffffffffffffffff

[toc] | [prev] | [next] | [standalone]

#1509710

FromLinus Torvalds <torvalds@linux-foundation.org>
Date2016-10-26 21:10 +0200
Message-ID<swBKh-809-17@gated-at.bofh.it>
In reply to#1509701
On Wed, Oct 26, 2016 at 11:42 AM, Dave Jones <davej@codemonkey.org.uk> wrote:
>
> The stacks show nearly all of them are stuck in sync_inodes_sb

That's just wb_wait_for_completion(), and it means that some IO isn't
completing.

There's also a lot of processes waiting for inode_lock(), and a few
waiting for mnt_want_write()

Ignoring those, we have

> [<ffffffffa009554f>] btrfs_wait_ordered_roots+0x3f/0x200 [btrfs]
> [<ffffffffa00470d1>] btrfs_sync_fs+0x31/0xc0 [btrfs]
> [<ffffffff811fbd4e>] sync_filesystem+0x6e/0xa0
> [<ffffffff811fbebc>] SyS_syncfs+0x3c/0x70
> [<ffffffff8100255c>] do_syscall_64+0x5c/0x170
> [<ffffffff817908cb>] entry_SYSCALL64_slow_path+0x25/0x25
> [<ffffffffffffffff>] 0xffffffffffffffff

Don't know this one. There's a couple of them. Could there be some
ABBA deadlock on the ordered roots waiting?

> [<ffffffff8131ae87>] call_rwsem_down_write_failed+0x17/0x30
> [<ffffffffa008ed32>] btrfs_fallocate+0xb2/0xfd0 [btrfs]
> [<ffffffff811c6c3e>] vfs_fallocate+0x13e/0x220
> [<ffffffff811c79f3>] SyS_fallocate+0x43/0x80
> [<ffffffff8100255c>] do_syscall_64+0x5c/0x170
> [<ffffffff817908cb>] entry_SYSCALL64_slow_path+0x25/0x25
> [<ffffffffffffffff>] 0xffffffffffffffff

This one is also inode_lock(), and is interesting only because it's
fallocate(), which has shown up so many times before..

But there are other threads blocked on do_truncate, or
btrfs_file_write_iter instead, or on lseek, so this is not different
for any other reason.

> [<ffffffff81149fbf>] wait_on_page_bit+0xaf/0xc0
> [<ffffffff8114a121>] __filemap_fdatawait_range+0x151/0x170
> [<ffffffff8114d79c>] filemap_fdatawait_keep_errors+0x1c/0x20
> [<ffffffff811f59b3>] sync_inodes_sb+0x273/0x300
> [<ffffffff811fbd37>] sync_filesystem+0x57/0xa0
> [<ffffffff811fbebc>] SyS_syncfs+0x3c/0x70
> [<ffffffff8100255c>] do_syscall_64+0x5c/0x170
> [<ffffffff817908cb>] entry_SYSCALL64_slow_path+0x25/0x25
> [<ffffffffffffffff>] 0xffffffffffffffff

This is actually waiting on the page. Possibly this is the IO that is
never completing, and keeps the inode lock.

> [<ffffffffa009576b>] btrfs_start_ordered_extent+0x5b/0xb0 [btrfs]
> [<ffffffffa008bf5d>] lock_and_cleanup_extent_if_need+0x22d/0x290 [btrfs]
> [<ffffffffa008d1e8>] __btrfs_buffered_write+0x1b8/0x6e0 [btrfs]
> [<ffffffffa0090e60>] btrfs_file_write_iter+0x170/0x550 [btrfs]
> [<ffffffff811c97d8>] do_iter_readv_writev+0xa8/0x100
> [<ffffffff811ca162>] do_readv_writev+0x172/0x210
> [<ffffffff811ca42a>] vfs_writev+0x3a/0x50
> [<ffffffff811ca5c0>] do_pwritev+0xb0/0xd0
> [<ffffffff811cb57c>] SyS_pwritev+0xc/0x10
> [<ffffffff8100255c>] do_syscall_64+0x5c/0x170
> [<ffffffff817908cb>] entry_SYSCALL64_slow_path+0x25/0x25

Hmm. This is the one that *started* the ordered extents (as opposed to
the ones waiting for it)

I dunno. There might be a lost IO. More likely it's the same
corruption that causes it, it just didn't result in an oops this time.

             Linus

[toc] | [prev] | [next] | [standalone]

#1509892

FromLinus Torvalds <torvalds@linux-foundation.org>
Date2016-10-27 00:10 +0200
Message-ID<swEyu-1qp-25@gated-at.bofh.it>
In reply to#1509710
On Wed, Oct 26, 2016 at 1:00 PM, Chris Mason <clm@fb.com> wrote:
>
> Today I turned off every CONFIG_DEBUG_* except for list debugging, and
> ran dbench 2048:
>
> [ 2759.118711] WARNING: CPU: 2 PID: 31039 at lib/list_debug.c:33 __list_add+0xbe/0xd0
> [ 2759.119652] list_add corruption. prev->next should be next (ffffe8ffffc80308), but was ffffc90000ccfb88. (prev=ffff880128522380).
> [ 2759.121039] Modules linked in: crc32c_intel i2c_piix4 aesni_intel aes_x86_64 virtio_net glue_helper i2c_core lrw floppy gf128mul serio_raw pcspkr button ablk_helper cryptd sch_fq_codel autofs4 virtio_blk
> [ 2759.124369] CPU: 2 PID: 31039 Comm: dbench Not tainted 4.9.0-rc1-15246-g4ce9206-dirty #317
> [ 2759.125077] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.9.0-1.fc24 04/01/2014
> [ 2759.125077]  ffffc9000f6fb868 ffffffff814fe4ff ffffffff8151cb5e ffffc9000f6fb8c8
> [ 2759.125077]  ffffc9000f6fb8c8 0000000000000000 ffffc9000f6fb8b8 ffffffff81064bbf
> [ 2759.127444]  ffff880128523680 0000002139968000 ffff880138b7a4a0 ffff880128523540
> [ 2759.127444] Call Trace:
> [ 2759.127444]  [<ffffffff814fe4ff>] dump_stack+0x53/0x74
> [ 2759.127444]  [<ffffffff8151cb5e>] ? __list_add+0xbe/0xd0
> [ 2759.127444]  [<ffffffff81064bbf>] __warn+0xff/0x120
> [ 2759.127444]  [<ffffffff81064c99>] warn_slowpath_fmt+0x49/0x50
> [ 2759.127444]  [<ffffffff8151cb5e>] __list_add+0xbe/0xd0
> [ 2759.127444]  [<ffffffff814df338>] blk_sq_make_request+0x388/0x580

Ok, that's definitely the same one that Dave started out seeing.

The fact that it is that reliable - two different machines, two very
different loads (dbench looks nothing like trinity) really makes me
think that maybe the problem really is in the block plugging after
all.

It very much does not smell like random stack corruption. It's simply
not random enough.

And I just noticed something: I originally thought that this is the
"list_add_tail()" to the plug - which is the only "list_add()" variant
in that function.

But that never made sense, because the whole "but was" isn't a stack
address, and "next" in "list_add_tail()" is basically fixed, and would
have to be the stack.

But I now notice that there's actually another "list_add()" variant
there, and it's the one from __blk_mq_insert_request() that gets
inlined into blk_mq_insert_request(), which then gets inlined into
blk_mq_make_request().

And that actually makes some sense just looking at the offsets too:

     blk_sq_make_request+0x388/0x580

so it's somewhat at the end of blk_sq_make_request(). So it's not unlikely.

And there it makes perfect sense that the "next should be" value is
*not* on the stack.

Chris, if you built with debug info, you can try

    ./scripts/faddr2line /boot/vmlinux blk_sq_make_request+0x388

to get what line that blk_sq_make_request+0x388 address actually is. I
think it's the

                list_add_tail(&rq->queuelist, &ctx->rq_list);

in __blk_mq_insert_req_list() (when it's inlined from
blk_sq_make_request(), "at_head" will be false.

So it smells like "&ctx->rq_list" might be corrupt.

And that actually seems much more likely than the "plug" list, because
while the plug is entirely thread-local (and thus shouldn't have any
races), the ctx->rq_list very much is not.

Jens?

For example, should we have a

    BUG_ON(ctx != rq->mq_ctx);

in blk_mq_merge_queue_io()? Because it locks ctx->lock, but then
__blk_mq_insert_request() will insert things onto the queues of
rq->mq_ctx.

blk_mq_insert_requests() has similar issues, but there has that BUG_ON().

The locking there really is *very* messy. All the lockers do

        spin_lock(&ctx->lock);
        ...
        spin_unlock(&ctx->lock);

but then __blk_mq_insert_request() and __blk_mq_insert_req_list don't
act on "ctx", but on "ctx = rq->mq_ctx", so if you ever get those
wrong, you're completely dead.

Now, I'm not seeing why they'd be wrong, and why they'd be associated
with the VMAP_STACK thing, but it could just be an unlucky timing
thing.

           Linus

[toc] | [prev] | [next] | [standalone]

#1509904

FromLinus Torvalds <torvalds@linux-foundation.org>
Date2016-10-27 00:30 +0200
Message-ID<swERP-1zh-3@gated-at.bofh.it>
In reply to#1509710

[Multipart message — attachments visible in raw view] — view raw

On Wed, Oct 26, 2016 at 2:52 PM, Chris Mason <clm@fb.com> wrote:
>
> This one is special because CONFIG_VMAP_STACK is not set.  Btrfs triggers in < 10 minutes.
> I've done 30 minutes each with XFS and Ext4 without luck.

Ok, see the email I wrote that crossed yours - if it's really some
list corruption on ctx->rq_list due to some locking problem, I really
would expect CONFIG_VMAP_STACK to be entirely irrelevant, except
perhaps from a timing standpoint.

> WARNING: CPU: 6 PID: 4481 at lib/list_debug.c:33 __list_add+0xbe/0xd0
> list_add corruption. prev->next should be next (ffffe8ffffd80b08), but was ffff88012b65fb88. (prev=ffff880128c8d500).
> Modules linked in: crc32c_intel aesni_intel aes_x86_64 glue_helper lrw gf128mul ablk_helper i2c_piix4 cryptd i2c_core virtio_net serio_raw floppy button pcspkr sch_fq_codel autofs4 virtio_blk
> CPU: 6 PID: 4481 Comm: dbench Not tainted 4.9.0-rc2-15419-g811d54d #319
> Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.9.0-1.fc24 04/01/2014
>  ffff880104eff868 ffffffff814fde0f ffffffff8151c46e ffff880104eff8c8
>  ffff880104eff8c8 0000000000000000 ffff880104eff8b8 ffffffff810648cf
>  ffff880128cab2c0 000000213fc57c68 ffff8801384e8928 ffff880128cab180
> Call Trace:
>  [<ffffffff814fde0f>] dump_stack+0x53/0x74
>  [<ffffffff8151c46e>] ? __list_add+0xbe/0xd0
>  [<ffffffff810648cf>] __warn+0xff/0x120
>  [<ffffffff810649a9>] warn_slowpath_fmt+0x49/0x50
>  [<ffffffff8151c46e>] __list_add+0xbe/0xd0
>  [<ffffffff814dec38>] blk_sq_make_request+0x388/0x580
>  [<ffffffff814d5444>] generic_make_request+0x104/0x200

Well, it's very consistent, I have to say. So I really don't think
this is random corruption.

Could you try the attached patch? It adds a couple of sanity tests:

 - a number of tests to verify that 'rq->queuelist' isn't already on
some queue when it is added to a queue

 - one test to verify that rq->mq_ctx is the same ctx that we have locked.

I may be completely full of shit, and this patch may be pure garbage
or "obviously will never trigger", but humor me.

          Linus

[toc] | [prev] | [next] | [standalone]

#1509911

FromDave Jones <davej@codemonkey.org.uk>
Date2016-10-27 00:50 +0200
Message-ID<swFbb-1Gb-9@gated-at.bofh.it>
In reply to#1509904
On Wed, Oct 26, 2016 at 03:21:53PM -0700, Linus Torvalds wrote:

 > Could you try the attached patch? It adds a couple of sanity tests:
 > 
 >  - a number of tests to verify that 'rq->queuelist' isn't already on
 > some queue when it is added to a queue
 > 
 >  - one test to verify that rq->mq_ctx is the same ctx that we have locked.
 > 
 > I may be completely full of shit, and this patch may be pure garbage
 > or "obviously will never trigger", but humor me.
 
I gave it a shot too for shits & giggles.
This falls out during boot.

[    9.244030] EXT4-fs (sda4): mounted filesystem with ordered data mode. Opts: (null)
[    9.271391] ------------[ cut here ]------------
[    9.278420] WARNING: CPU: 0 PID: 1 at block/blk-mq.c:1181 blk_sq_make_request+0x465/0x4a0
[    9.285613] CPU: 0 PID: 1 Comm: init Not tainted 4.9.0-rc2-think+ #4
[    9.300106]  ffffc90000013848
[    9.307353]  ffffffff8130d27c
[    9.307420]  0000000000000000
[    9.307456]  0000000000000000
[    9.307494]  ffffc90000013888
[    9.314780]  ffffffff81077a41
[    9.314847]  0000049d00013898
[    9.314884]  0000000000000001
[    9.314922]  0000000000000002
[    9.322213]  ffffe8ffffc06600
[    9.322280]  ffffe8ffff606600
[    9.322317]  ffff8805015c2e80
[    9.322355] Call Trace:
[    9.329689]  [<ffffffff8130d27c>] dump_stack+0x4f/0x73
[    9.337208]  [<ffffffff81077a41>] __warn+0xc1/0xe0
[    9.344730]  [<ffffffff81077b18>] warn_slowpath_null+0x18/0x20
[    9.352282]  [<ffffffff812f7975>] blk_sq_make_request+0x465/0x4a0
[    9.359816]  [<ffffffff812eb44a>] ? generic_make_request+0xca/0x210
[    9.367367]  [<ffffffff812eb457>] generic_make_request+0xd7/0x210
[    9.374931]  [<ffffffff812eb5f9>] submit_bio+0x69/0x120
[    9.382488]  [<ffffffff812004ef>] ? submit_bh_wbc+0x16f/0x1e0
[    9.390083]  [<ffffffff812004ef>] submit_bh_wbc+0x16f/0x1e0
[    9.397673]  [<ffffffff81200bfe>] submit_bh+0xe/0x10
[    9.405205]  [<ffffffff81255eac>] __ext4_get_inode_loc+0x1ac/0x3d0
[    9.412795]  [<ffffffff81258f4b>] ext4_iget+0x6b/0xb70
[    9.420366]  [<ffffffff811d6018>] ? lookup_slow+0xf8/0x1f0
[    9.427947]  [<ffffffff81259a7a>] ext4_iget_normal+0x2a/0x30
[    9.435541]  [<ffffffff81264734>] ext4_lookup+0x114/0x230

[toc] | [prev] | [next] | [standalone]

#1509914

FromLinus Torvalds <torvalds@linux-foundation.org>
Date2016-10-27 01:00 +0200
Message-ID<swFkR-1JB-5@gated-at.bofh.it>
In reply to#1509911
On Wed, Oct 26, 2016 at 3:40 PM, Dave Jones <davej@codemonkey.org.uk> wrote:
>
> I gave it a shot too for shits & giggles.
> This falls out during boot.
>
> [    9.278420] WARNING: CPU: 0 PID: 1 at block/blk-mq.c:1181 blk_sq_make_request+0x465/0x4a0

Hmm. That's the

    WARN_ON_ONCE(rq->mq_ctx != ctx);

that I added to blk_mq_merge_queue_io(), and I really think that
warning is valid, and the fact that it triggers shows that something
is wrong with locking.

We just did a

                spin_lock(&ctx->lock);

and that lock is *supposed* to protect the __blk_mq_insert_request(),
but that uses rq->mq_ctx.

So if rq->mq_ctx != ctx, then we're locking the wrong context.

Jens - please explain to me why I'm wrong.

Or maybe I actually might have found the problem? In which case please
send me a patch that fixes it ;)

Dave: it might be a good idea to split that "WARN_ON_ONCE()" in
blk_mq_merge_queue_io() into two, since right now it can trigger both
for the

                blk_mq_bio_to_request(rq, bio);

path _and_ for the

                if (!blk_mq_attempt_merge(q, ctx, bio)) {
                        blk_mq_bio_to_request(rq, bio);
                        goto insert_rq;

path. If you split it into two: one before that "insert_rq:" label,
and one before the "goto insert_rq" thing, then we could see if it is
just one of the blk_mq_merge_queue_io() cases (or both) that is
broken..

                  Linus

[toc] | [prev] | [next] | [standalone]

#1509917

FromLinus Torvalds <torvalds@linux-foundation.org>
Date2016-10-27 01:00 +0200
Message-ID<swFkR-1JB-15@gated-at.bofh.it>
In reply to#1509914
On Wed, Oct 26, 2016 at 3:51 PM, Linus Torvalds
<torvalds@linux-foundation.org> wrote:
>
> Dave: it might be a good idea to split that "WARN_ON_ONCE()" in
> blk_mq_merge_queue_io() into two

I did that myself too, since Dave sees this during boot.

But I'm not getting the warning ;(

Dave gets it with ext4, and thats' what I have too, so I'm not sure
what the required trigger would be.

              Linus

[toc] | [prev] | [next] | [standalone]

#1509922

FromLinus Torvalds <torvalds@linux-foundation.org>
Date2016-10-27 01:10 +0200
Message-ID<swFuy-226-9@gated-at.bofh.it>
In reply to#1509917
On Wed, Oct 26, 2016 at 4:03 PM, Jens Axboe <axboe@fb.com> wrote:
>
> Actually, I think I see what might trigger it. You are on nvme, iirc,
> and that has a deep queue.

Yes. I have long since moved on from slow disks, so all my systems are
not just flash, but m.2 nvme ssd's.

So at least that could explain why Dave sees it at bootup but I don't.

            Linus

[toc] | [prev] | [next] | [standalone]

#1509958

FromDave Jones <davej@codemonkey.org.uk>
Date2016-10-27 01:50 +0200
Message-ID<swG7g-2fy-19@gated-at.bofh.it>
In reply to#1509922
On Wed, Oct 26, 2016 at 07:38:08PM -0400, Chris Mason wrote:
 
 > >-	hctx->queued++;
 > >-	data->hctx = hctx;
 > >-	data->ctx = ctx;
 > >+	data->hctx = alloc_data.hctx;
 > >+	data->ctx = alloc_data.ctx;
 > >+	data->hctx->queued++;
 > > 	return rq;
 > > }
 > 
 > This made it through an entire dbench 2048 run on btrfs.  My script has 
 > it running in a loop, but this is farther than I've gotten before.  
 > Looking great so far.

Fixed the splat during boot for me too.
Now the fun part, let's see if it fixed the 'weird shit' that Trinity
was stumbling on.

	Dave

[toc] | [prev] | [next] | [standalone]

#1512796

FromDave Jones <davej@codemonkey.org.uk>
Date2016-10-31 20:00 +0100
Message-ID<sypYl-6cx-15@gated-at.bofh.it>
In reply to#1509958
On Wed, Oct 26, 2016 at 07:47:51PM -0400, Dave Jones wrote:
 > On Wed, Oct 26, 2016 at 07:38:08PM -0400, Chris Mason wrote:
 >  
 >  > >-	hctx->queued++;
 >  > >-	data->hctx = hctx;
 >  > >-	data->ctx = ctx;
 >  > >+	data->hctx = alloc_data.hctx;
 >  > >+	data->ctx = alloc_data.ctx;
 >  > >+	data->hctx->queued++;
 >  > > 	return rq;
 >  > > }
 >  > 
 >  > This made it through an entire dbench 2048 run on btrfs.  My script has 
 >  > it running in a loop, but this is farther than I've gotten before.  
 >  > Looking great so far.
 > 
 > Fixed the splat during boot for me too.
 > Now the fun part, let's see if it fixed the 'weird shit' that Trinity
 > was stumbling on.

It took a while, but.. bad news.


BUG: Bad page state in process kworker/u8:12  pfn:4e0e39
page:ffffea0013838e40 count:0 mapcount:0 mapping:ffff8804a20310e0 index:0x100c
flags: 0x400000000000000c(referenced|uptodate)
page dumped because: non-NULL mapping
CPU: 3 PID: 1586 Comm: kworker/u8:12 Not tainted 4.9.0-rc3-think+ #1 
Workqueue: writeback wb_workfn
  (flush-btrfs-2)
 ffffc90000777828
 ffffffff8130d04c
 ffffea0013838e40
 ffffffff819ff654
 ffffc90000777850
 ffffffff81150e5f
 0000000000000000
 ffffea0013838e40
 400000000000000c
 ffffc90000777860
 ffffffff81150f1a
 ffffc900007778a8
Call Trace:
 [<ffffffff8130d04c>] dump_stack+0x4f/0x73
 [<ffffffff81150e5f>] bad_page+0xbf/0x120
 [<ffffffff81150f1a>] free_pages_check_bad+0x5a/0x70
 [<ffffffff81153818>] free_hot_cold_page+0x248/0x290
 [<ffffffff81153b1b>] free_hot_cold_page_list+0x2b/0x50
 [<ffffffff8115c52d>] release_pages+0x2bd/0x350
 [<ffffffff8115da62>] __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]
 [<ffffffff8115ac4c>] do_writepages+0x1c/0x30
 [<ffffffff811f69f3>] __writeback_single_inode+0x33/0x180
 [<ffffffff811f71e8>] writeback_sb_inodes+0x2a8/0x5b0
 [<ffffffff811f757d>] __writeback_inodes_wb+0x8d/0xc0
 [<ffffffff811f7833>] wb_writeback+0x1e3/0x1f0
 [<ffffffff811f7d72>] wb_workfn+0xd2/0x280
 [<ffffffff810908d5>] process_one_work+0x1d5/0x490
 [<ffffffff81090875>] ? process_one_work+0x175/0x490
 [<ffffffff81090bd9>] worker_thread+0x49/0x490
 [<ffffffff81090b90>] ? process_one_work+0x490/0x490
 [<ffffffff81095d4e>] kthread+0xee/0x110
 [<ffffffff81095c60>] ? kthread_park+0x60/0x60
 [<ffffffff81790b12>] ret_from_fork+0x22/0x30

[toc] | [prev] | [next] | [standalone]

#1512815

FromLinus Torvalds <torvalds@linux-foundation.org>
Date2016-10-31 20:40 +0100
Message-ID<syqB3-6Fs-1@gated-at.bofh.it>
In reply to#1512796
On Mon, Oct 31, 2016 at 11:55 AM, Dave Jones <davej@codemonkey.org.uk> wrote:
>
> BUG: Bad page state in process kworker/u8:12  pfn:4e0e39
> page:ffffea0013838e40 count:0 mapcount:0 mapping:ffff8804a20310e0 index:0x100c
> flags: 0x400000000000000c(referenced|uptodate)
> page dumped because: non-NULL mapping

Hmm. So this seems to be btrfs-specific, right?

I searched for all your "non-NULL mapping" cases, and they all seem to
have basically the same call trace, with some work thread doing
writeback and going through btrfs_writepages().

Sounds like it's a race with either fallocate hole-punching or
truncate. I'm not seeing it, but I suspect it's btrfs, since DaveJ
clearly ran other filesystems too but I am not seeing this backtrace
for anything else.

 Linus

[toc] | [prev] | [next] | [standalone]

#1515717 — Re: btrfs btree_ctree_super fault

FromDave Jones <davej@codemonkey.org.uk>
Date2016-11-06 18:00 +0100
SubjectRe: btrfs btree_ctree_super fault
Message-ID<sAyXv-7VA-1@gated-at.bofh.it>
In reply to#1512815
<subject changed, hopefully we're done with bio corruption for now>

On Mon, Oct 31, 2016 at 01:44:55PM -0600, Chris Mason wrote:
 > On Mon, Oct 31, 2016 at 12:35:16PM -0700, Linus Torvalds wrote:
 > >On Mon, Oct 31, 2016 at 11:55 AM, Dave Jones <davej@codemonkey.org.uk> wrote:
 > >>
 > >> BUG: Bad page state in process kworker/u8:12  pfn:4e0e39
 > >> page:ffffea0013838e40 count:0 mapcount:0 mapping:ffff8804a20310e0 index:0x100c
 > >> flags: 0x400000000000000c(referenced|uptodate)
 > >> page dumped because: non-NULL mapping
 > >
 > >Hmm. So this seems to be btrfs-specific, right?
 > >
 > >I searched for all your "non-NULL mapping" cases, and they all seem to
 > >have basically the same call trace, with some work thread doing
 > >writeback and going through btrfs_writepages().
 > >
 > >Sounds like it's a race with either fallocate hole-punching or
 > >truncate. I'm not seeing it, but I suspect it's btrfs, since DaveJ
 > >clearly ran other filesystems too but I am not seeing this backtrace
 > >for anything else.
 > 
 > Agreed, I think this is a separate bug, almost certainly btrfs specific.  
 > I'll work with Dave on a better reproducer.

Still refining my 'capture ftrace when trinity detects taint' feature,
but in the meantime, here's a variant I don't think we've seen before:

general protection fault: 0000 [#1] PREEMPT SMP DEBUG_PAGEALLOC
CPU: 3 PID: 1913 Comm: trinity-c51 Not tainted 4.9.0-rc3-think+ #3 
task: ffff880503350040 task.stack: ffffc90000240000
RIP: 0010:[<ffffffffa007c2f6>] 
  [<ffffffffa007c2f6>] write_ctree_super+0x96/0xb30 [btrfs]
RSP: 0018:ffffc90000243c90  EFLAGS: 00010286
RAX: dae05adadadad000 RBX: 0000000000000000 RCX: 0000000000000002
RDX: ffff8804fdfcc000 RSI: ffff8804edcee313 RDI: ffff8804edcee1c3
RBP: ffffc90000243d00 R08: 0000000000000003 R09: ffff880000000000
R10: 0000000000000001 R11: 0000000000000100 R12: ffff88045151c548
R13: 0000000000000000 R14: ffff8804ee5122a8 R15: ffff8804572267e8
FS:  00007f25c3e0eb40(0000) GS:ffff880507e00000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007f25c1560d44 CR3: 0000000454e20000 CR4: 00000000001406e0
DR0: 00007fee93506000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000600
Stack:
 0000000000000001
 ffff88050227b3f8
 ffff8804fff01b28
 00000001810b7f35
 ffffffffa007c265
 0000000000000001
 ffffc90000243cb8
 000000002c9a8645
 ffff8804fff01b28
 ffff8804fff01b28
 ffff88045151c548
 0000000000000000
Call Trace:
 [<ffffffffa007c265>] ? write_ctree_super+0x5/0xb30 [btrfs]
 [<ffffffffa00d2956>] btrfs_sync_log+0x886/0xa60 [btrfs]
 [<ffffffffa009f4f9>] btrfs_sync_file+0x479/0x4d0 [btrfs]
 [<ffffffff812789ab>] vfs_fsync_range+0x4b/0xb0
 [<ffffffff81260755>] ? __fget_light+0x5/0x60
 [<ffffffff81278a6d>] do_fsync+0x3d/0x70
 [<ffffffff81278a35>] ? do_fsync+0x5/0x70
 [<ffffffff81278d20>] SyS_fsync+0x10/0x20
 [<ffffffff81002d81>] do_syscall_64+0x61/0x170
 [<ffffffff81894a8b>] entry_SYSCALL64_slow_path+0x25/0x25
Code: c7 48 8b 42 30 4c 8b 08 48 b8 00 00 00 00 00 16 00 00 49 03 81 a0 01 00 00 49 b9 00 00 00 00 00 88 ff ff 48 c1 f8 06 48 c1 e0 0c <4a> 8b 44 08 50 48 39 46 08 0f 84 8d 08 00 00 49 63 c0 48 8d 0c 
RIP 
  [<ffffffffa007c2f6>] write_ctree_super+0x96/0xb30 [btrfs]
 RSP <ffffc90000243c90>

All code
========
   0:	c7                   	(bad)  
   1:	48 8b 42 30          	mov    0x30(%rdx),%rax
   5:	4c 8b 08             	mov    (%rax),%r9
   8:	48 b8 00 00 00 00 00 	movabs $0x160000000000,%rax
   f:	16 00 00 
  12:	49 03 81 a0 01 00 00 	add    0x1a0(%r9),%rax
  19:	49 b9 00 00 00 00 00 	movabs $0xffff880000000000,%r9
  20:	88 ff ff 
  23:	48 c1 f8 06          	sar    $0x6,%rax
  27:	48 c1 e0 0c          	shl    $0xc,%rax
  2b:*	4a 8b 44 08 50       	mov    0x50(%rax,%r9,1),%rax		<-- trapping instruction
  30:	48 39 46 08          	cmp    %rax,0x8(%rsi)
  34:	0f 84 8d 08 00 00    	je     0x8c7
  3a:	49 63 c0             	movslq %r8d,%rax
  3d:	48                   	rex.W
  3e:	8d                   	.byte 0x8d
  3f:	0c                   	.byte 0xc

Code starting with the faulting instruction
===========================================
   0:	4a 8b 44 08 50       	mov    0x50(%rax,%r9,1),%rax
   5:	48 39 46 08          	cmp    %rax,0x8(%rsi)
   9:	0f 84 8d 08 00 00    	je     0x89c
   f:	49 63 c0             	movslq %r8d,%rax
  12:	48                   	rex.W
  13:	8d                   	.byte 0x8d
  14:	0c                   	.byte 0xc


According to objdump -S, it looks like this is an inlined copy of backup_super_roots

        root_backup = info->super_for_commit->super_roots + last_backup;
    2706:       48 8d b8 2b 0b 00 00    lea    0xb2b(%rax),%rdi
    270d:       48 63 c1                movslq %ecx,%rax
    2710:       48 8d 34 80             lea    (%rax,%rax,4),%rsi
    2714:       48 8d 04 b0             lea    (%rax,%rsi,4),%rax
    2718:       48 8d 34 c7             lea    (%rdi,%rax,8),%rsi
            btrfs_header_generation(info->tree_root->node))
    271c:       48 8b 42 30             mov    0x30(%rdx),%rax
    2720:       4c 8b 08                mov    (%rax),%r9
    2723:       48 b8 00 00 00 00 00    movabs $0x160000000000,%rax
    272a:       16 00 00 
    272d:       49 03 81 a0 01 00 00    add    0x1a0(%r9),%rax
        if (btrfs_backup_tree_root_gen(root_backup) ==
    2734:       49 b9 00 00 00 00 00    movabs $0xffff880000000000,%r9
    273b:       88 ff ff 
    273e:       48 c1 f8 06             sar    $0x6,%rax
    2742:       48 c1 e0 0c             shl    $0xc,%rax
    2746:       4a 8b 44 08 50          mov    0x50(%rax,%r9,1),%rax      <-- trapping instruction
    274b:       48 39 46 08             cmp    %rax,0x8(%rsi)
    274f:       0f 84 8d 08 00 00       je     2fe2 <write_ctree_super+0x932>

[toc] | [prev] | [next] | [standalone]

#1517264 — Re: btrfs btree_ctree_super fault

FromDave Jones <davej@codemonkey.org.uk>
Date2016-11-08 16:00 +0100
SubjectRe: btrfs btree_ctree_super fault
Message-ID<sBg2v-2e5-45@gated-at.bofh.it>
In reply to#1515717
On Sun, Nov 06, 2016 at 11:55:39AM -0500, Dave Jones wrote:
 > <subject changed, hopefully we're done with bio corruption for now>
 > 
 > On Mon, Oct 31, 2016 at 01:44:55PM -0600, Chris Mason wrote:
 >  > On Mon, Oct 31, 2016 at 12:35:16PM -0700, Linus Torvalds wrote:
 >  > >On Mon, Oct 31, 2016 at 11:55 AM, Dave Jones <davej@codemonkey.org.uk> wrote:
 >  > >>
 >  > >> BUG: Bad page state in process kworker/u8:12  pfn:4e0e39
 >  > >> page:ffffea0013838e40 count:0 mapcount:0 mapping:ffff8804a20310e0 index:0x100c
 >  > >> flags: 0x400000000000000c(referenced|uptodate)
 >  > >> page dumped because: non-NULL mapping
 >  > >
 >  > >Hmm. So this seems to be btrfs-specific, right?
 >  > >
 >  > >I searched for all your "non-NULL mapping" cases, and they all seem to
 >  > >have basically the same call trace, with some work thread doing
 >  > >writeback and going through btrfs_writepages().
 >  > >
 >  > >Sounds like it's a race with either fallocate hole-punching or
 >  > >truncate. I'm not seeing it, but I suspect it's btrfs, since DaveJ
 >  > >clearly ran other filesystems too but I am not seeing this backtrace
 >  > >for anything else.
 >  > 
 >  > Agreed, I think this is a separate bug, almost certainly btrfs specific.  
 >  > I'll work with Dave on a better reproducer.
 > 
 > Still refining my 'capture ftrace when trinity detects taint' feature,
 > but in the meantime, here's a variant I don't think we've seen before:

And another new one:

kernel BUG at fs/btrfs/ctree.c:3172!
invalid opcode: 0000 [#1] PREEMPT SMP DEBUG_PAGEALLOC
CPU: 0 PID: 22702 Comm: trinity-c40 Not tainted 4.9.0-rc4-think+ #1 
task: ffff8804ffde37c0 task.stack: ffffc90002188000
RIP: 0010:[<ffffffffa00576b9>] 
  [<ffffffffa00576b9>] btrfs_set_item_key_safe+0x179/0x190 [btrfs]
RSP: 0000:ffffc9000218b8a8  EFLAGS: 00010246
RAX: 0000000000000000 RBX: ffff8804fddcf348 RCX: 0000000000001000
RDX: 0000000000000000 RSI: ffffc9000218b9ce RDI: ffffc9000218b8c7
RBP: ffffc9000218b908 R08: 0000000000004000 R09: ffffc9000218b8c8
R10: 0000000000000000 R11: 0000000000000001 R12: ffffc9000218b8b6
R13: ffffc9000218b9ce R14: 0000000000000001 R15: ffff880480684a88
FS:  00007f7c7f998b40(0000) GS:ffff880507800000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 0000000000000000 CR3: 000000044f15f000 CR4: 00000000001406f0
DR0: 00007f4ce439d000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000600
Stack:
 ffff880501430000 d305ffffa00a2245 006c000000000002 0500000000000010
 6c000000000002d3 0000000000001000 000000006427eebb ffff880480684a88
 0000000000000000 ffff8804fddcf348 0000000000002000 0000000000000000
Call Trace:
 [<ffffffffa009cff0>] __btrfs_drop_extents+0xb00/0xe30 [btrfs]
 [<ffffffff8116c80c>] ? function_trace_call+0x13c/0x190
 [<ffffffffa009c4f5>] ? __btrfs_drop_extents+0x5/0xe30 [btrfs]
 [<ffffffff810e2b00>] ? do_raw_write_lock+0xb0/0xc0
 [<ffffffffa00cd43d>] btrfs_log_changed_extents+0x35d/0x630 [btrfs]
 [<ffffffffa00a6a74>] ? release_extent_buffer+0xa4/0x110 [btrfs]
 [<ffffffffa00cd0e5>] ? btrfs_log_changed_extents+0x5/0x630 [btrfs]
 [<ffffffffa00d1085>] btrfs_log_inode+0xb05/0x11d0 [btrfs]
 [<ffffffff8116536c>] ? trace_function+0x6c/0x80
 [<ffffffffa00d0580>] ? log_directory_changes+0xc0/0xc0 [btrfs]
 [<ffffffffa00d1a20>] ? btrfs_log_inode_parent+0x240/0x940 [btrfs]
 [<ffffffff8116c80c>] ? function_trace_call+0x13c/0x190
 [<ffffffffa00d1a20>] btrfs_log_inode_parent+0x240/0x940 [btrfs]
 [<ffffffffa00d17e5>] ? btrfs_log_inode_parent+0x5/0x940 [btrfs]
 [<ffffffff81259131>] ? dget_parent+0x71/0x150
 [<ffffffffa00d3102>] btrfs_log_dentry_safe+0x62/0x80 [btrfs]
 [<ffffffffa009f404>] btrfs_sync_file+0x344/0x4d0 [btrfs]
 [<ffffffff81278a1b>] vfs_fsync_range+0x4b/0xb0
 [<ffffffff812607c5>] ? __fget_light+0x5/0x60
 [<ffffffff81278add>] do_fsync+0x3d/0x70
 [<ffffffff81278aa5>] ? do_fsync+0x5/0x70
 [<ffffffff81278db3>] SyS_fdatasync+0x13/0x20
 [<ffffffff81002d81>] do_syscall_64+0x61/0x170
 [<ffffffff81894ccb>] entry_SYSCALL64_slow_path+0x25/0x25
Code: 48 8b 45 b7 48 8d 7d bf 4c 89 ee 48 89 45 c8 0f b6 45 b6 88 45 c7 48 8b 45 ae 48 89 45 bf e8 af f2 ff ff 85 c0 0f 8f 43 ff ff ff <0f> 0b 0f 0b e8 ee f3 02 e1 0f 1f 40 00 66 2e 0f 1f 84 00 00 00 



Unfortunatly, because this was a BUG_ON, it locked up the box so it
didn't save any additional debug info. Tempted to see if making BUG_ON
a no-op will at least let it live long enough to save the ftrace buffer.

Given this seems to be mutating every time I see something go wrong,
I'm wondering if this is fallout from memory corruption again.

	Dave

[toc] | [prev] | [next] | [standalone]

Page 2 of 3 — ← Prev page 1 [2] 3  Next page →

Back to top | Article view | linux.kernel

csiph-web