Groups | Search | Server Info | Keyboard shortcuts | Login | Register [http] [https] [nntp] [nntps]
Groups > linux.kernel > #1498974 > unrolled thread
| Started by | Dave Jones <davej@codemonkey.org.uk> |
|---|---|
| First post | 2016-10-11 17:30 +0200 |
| Last post | 2016-10-12 16:50 +0200 |
| Articles | 4 — 1 participant |
Back to article view | Back to linux.kernel
btrfs bio linked list corruption. Dave Jones <davej@codemonkey.org.uk> - 2016-10-11 17:30 +0200
Re: btrfs bio linked list corruption. Dave Jones <davej@codemonkey.org.uk> - 2016-10-11 18:30 +0200
Re: btrfs bio linked list corruption. Dave Jones <davej@codemonkey.org.uk> - 2016-10-12 15:50 +0200
Re: btrfs bio linked list corruption. Dave Jones <davej@codemonkey.org.uk> - 2016-10-12 16:50 +0200
| From | Dave Jones <davej@codemonkey.org.uk> |
|---|---|
| Date | 2016-10-11 17:30 +0200 |
| Subject | btrfs bio linked list corruption. |
| Message-ID | <sr70t-8n0-5@gated-at.bofh.it> |
This is from Linus' current tree, with Al's iovec fixups on top. ------------[ cut here ]------------ WARNING: CPU: 1 PID: 3673 at lib/list_debug.c:33 __list_add+0x89/0xb0 list_add corruption. prev->next should be next (ffffe8ffff806648), but was ffffc9000067fcd8. (prev=ffff880503878b80). CPU: 1 PID: 3673 Comm: trinity-c0 Not tainted 4.8.0-think+ #13 ffffc90000d87458 ffffffff8d32007c ffffc90000d874a8 0000000000000000 ffffc90000d87498 ffffffff8d07a6c1 0000002100000246 ffff88050388e880 ffff880503878b80 ffffe8ffff806648 ffffe8ffffc06600 ffff880502808008 Call Trace: [<ffffffff8d32007c>] dump_stack+0x4f/0x73 [<ffffffff8d07a6c1>] __warn+0xc1/0xe0 [<ffffffff8d07a73a>] warn_slowpath_fmt+0x5a/0x80 [<ffffffff8d33e689>] __list_add+0x89/0xb0 [<ffffffff8d30a1c8>] blk_sq_make_request+0x2f8/0x350 [<ffffffff8d2fd9cc>] ? generic_make_request+0xec/0x240 [<ffffffff8d2fd9d9>] generic_make_request+0xf9/0x240 [<ffffffff8d2fdb98>] submit_bio+0x78/0x150 [<ffffffff8d349c05>] ? __percpu_counter_add+0x85/0xb0 [<ffffffffc03627de>] btrfs_map_bio+0x19e/0x330 [btrfs] [<ffffffffc03289ca>] btree_submit_bio_hook+0xfa/0x110 [btrfs] [<ffffffffc034ff15>] submit_one_bio+0x65/0xa0 [btrfs] [<ffffffffc0358cb0>] read_extent_buffer_pages+0x2f0/0x3d0 [btrfs] [<ffffffffc0327020>] ? free_root_pointers+0x60/0x60 [btrfs] [<ffffffffc03283c8>] btree_read_extent_buffer_pages.constprop.55+0xa8/0x110 [btrfs] [<ffffffffc0328bcd>] read_tree_block+0x2d/0x50 [btrfs] [<ffffffffc03080a4>] read_block_for_search.isra.33+0x134/0x330 [btrfs] [<ffffffff8d7c2d6c>] ? _raw_write_unlock+0x2c/0x50 [<ffffffffc0302fec>] ? unlock_up+0x16c/0x1a0 [btrfs] [<ffffffffc030a3d0>] btrfs_search_slot+0x450/0xa40 [btrfs] [<ffffffffc0324983>] btrfs_del_csums+0xe3/0x2e0 [btrfs] [<ffffffffc03134fd>] __btrfs_free_extent.isra.82+0x32d/0xc90 [btrfs] [<ffffffffc03178b3>] __btrfs_run_delayed_refs+0x4d3/0x1010 [btrfs] [<ffffffff8d33e5d7>] ? debug_smp_processor_id+0x17/0x20 [<ffffffff8d0c6109>] ? get_lock_stats+0x19/0x50 [<ffffffffc031b32c>] btrfs_run_delayed_refs+0x9c/0x2d0 [btrfs] [<ffffffffc033d628>] btrfs_truncate_inode_items+0x888/0xda0 [btrfs] [<ffffffffc033dc25>] btrfs_truncate+0xe5/0x2b0 [btrfs] [<ffffffffc033e569>] btrfs_setattr+0x249/0x360 [btrfs] [<ffffffff8d1f4092>] notify_change+0x252/0x440 [<ffffffff8d1d164e>] do_truncate+0x6e/0xc0 [<ffffffff8d1d1a4c>] do_sys_ftruncate.constprop.19+0x10c/0x170 [<ffffffff8d33e5f3>] ? __this_cpu_preempt_check+0x13/0x20 [<ffffffff8d1d1ad9>] SyS_ftruncate+0x9/0x10 [<ffffffff8d00259c>] do_syscall_64+0x5c/0x170 [<ffffffff8d7c2f8b>] entry_SYSCALL64_slow_path+0x25/0x25 --[ end trace 906673a2f703b373 ]---
[toc] | [next] | [standalone]
| From | Dave Jones <davej@codemonkey.org.uk> |
|---|---|
| Date | 2016-10-11 18:30 +0200 |
| Message-ID | <sr86d-wM-11@gated-at.bofh.it> |
| In reply to | #1498974 |
On Tue, Oct 11, 2016 at 11:54:09AM -0400, Chris Mason wrote:
>
>
> On 10/11/2016 10:45 AM, Dave Jones wrote:
> > This is from Linus' current tree, with Al's iovec fixups on top.
> >
> > ------------[ cut here ]------------
> > WARNING: CPU: 1 PID: 3673 at lib/list_debug.c:33 __list_add+0x89/0xb0
> > list_add corruption. prev->next should be next (ffffe8ffff806648), but was ffffc9000067fcd8. (prev=ffff880503878b80).
> > CPU: 1 PID: 3673 Comm: trinity-c0 Not tainted 4.8.0-think+ #13
> > ffffc90000d87458 ffffffff8d32007c ffffc90000d874a8 0000000000000000
> > ffffc90000d87498 ffffffff8d07a6c1 0000002100000246 ffff88050388e880
> > ffff880503878b80 ffffe8ffff806648 ffffe8ffffc06600 ffff880502808008
> > Call Trace:
> > [<ffffffff8d32007c>] dump_stack+0x4f/0x73
> > [<ffffffff8d07a6c1>] __warn+0xc1/0xe0
> > [<ffffffff8d07a73a>] warn_slowpath_fmt+0x5a/0x80
> > [<ffffffff8d33e689>] __list_add+0x89/0xb0
> > [<ffffffff8d30a1c8>] blk_sq_make_request+0x2f8/0x350
>
> /*
> * A task plug currently exists. Since this is completely lockless,
> * utilize that to temporarily store requests until the task is
> * either done or scheduled away.
> */
> plug = current->plug;
> if (plug) {
> blk_mq_bio_to_request(rq, bio);
> if (!request_count)
> trace_block_plug(q);
>
> blk_mq_put_ctx(data.ctx);
>
> if (request_count >= BLK_MAX_REQUEST_COUNT) {
> blk_flush_plug_list(plug, false);
> trace_block_plug(q);
> }
>
> list_add_tail(&rq->queuelist, &plug->mq_list);
> ^^^^^^^^^^^^^^^^^^^^^^
>
> Dave, is this where we're crashing? This seems strange.
According to objdump -S ..
ffffffff8130a1b7: 48 8b 70 50 mov 0x50(%rax),%rsi
list_add_tail(&rq->queuelist, &ctx->rq_list);
ffffffff8130a1bb: 48 8d 50 48 lea 0x48(%rax),%rdx
ffffffff8130a1bf: 48 89 45 a8 mov %rax,-0x58(%rbp)
ffffffff8130a1c3: e8 38 44 03 00 callq ffffffff8133e600 <__list_add>
blk_mq_hctx_mark_pending(hctx, ctx);
ffffffff8130a1c8: 48 8b 45 a8 mov -0x58(%rbp),%rax
ffffffff8130a1cc: 4c 89 ff mov %r15,%rdi
That looks like the list_add_tail from __blk_mq_insert_req_list
Dave
[toc] | [prev] | [next] | [standalone]
| From | Dave Jones <davej@codemonkey.org.uk> |
|---|---|
| Date | 2016-10-12 15:50 +0200 |
| Message-ID | <srs4V-56s-3@gated-at.bofh.it> |
| In reply to | #1498974 |
On Tue, Oct 11, 2016 at 11:54:09AM -0400, Chris Mason wrote: > > > On 10/11/2016 10:45 AM, Dave Jones wrote: > > This is from Linus' current tree, with Al's iovec fixups on top. > > > > ------------[ cut here ]------------ > > WARNING: CPU: 1 PID: 3673 at lib/list_debug.c:33 __list_add+0x89/0xb0 > > list_add corruption. prev->next should be next (ffffe8ffff806648), but was ffffc9000067fcd8. (prev=ffff880503878b80). > > CPU: 1 PID: 3673 Comm: trinity-c0 Not tainted 4.8.0-think+ #13 > > ffffc90000d87458 ffffffff8d32007c ffffc90000d874a8 0000000000000000 > > ffffc90000d87498 ffffffff8d07a6c1 0000002100000246 ffff88050388e880 I hit this again overnight, it's the same trace, the only difference being slightly different addresses in the list pointers: [42572.777196] list_add corruption. prev->next should be next (ffffe8ffff806648), but was ffffc90000647cd8. (prev=ffff880503a0ba00). I'm actually a little surprised that ->next was the same across two reboots on two different kernel builds. That might be a sign this is more repeatable than I'd thought, even if it does take hours of runtime right now to trigger it. I'll try and narrow the scope of what trinity is doing to see if I can make it happen faster. Dave
[toc] | [prev] | [next] | [standalone]
| From | Dave Jones <davej@codemonkey.org.uk> |
|---|---|
| Date | 2016-10-12 16:50 +0200 |
| Message-ID | <srt10-5LT-21@gated-at.bofh.it> |
| In reply to | #1499705 |
On Wed, Oct 12, 2016 at 09:47:17AM -0400, Dave Jones wrote: > On Tue, Oct 11, 2016 at 11:54:09AM -0400, Chris Mason wrote: > > > > > > On 10/11/2016 10:45 AM, Dave Jones wrote: > > > This is from Linus' current tree, with Al's iovec fixups on top. > > > > > > ------------[ cut here ]------------ > > > WARNING: CPU: 1 PID: 3673 at lib/list_debug.c:33 __list_add+0x89/0xb0 > > > list_add corruption. prev->next should be next (ffffe8ffff806648), but was ffffc9000067fcd8. (prev=ffff880503878b80). > > > CPU: 1 PID: 3673 Comm: trinity-c0 Not tainted 4.8.0-think+ #13 > > > ffffc90000d87458 ffffffff8d32007c ffffc90000d874a8 0000000000000000 > > > ffffc90000d87498 ffffffff8d07a6c1 0000002100000246 ffff88050388e880 > > I hit this again overnight, it's the same trace, the only difference > being slightly different addresses in the list pointers: > > [42572.777196] list_add corruption. prev->next should be next (ffffe8ffff806648), but was ffffc90000647cd8. (prev=ffff880503a0ba00). > > I'm actually a little surprised that ->next was the same across two > reboots on two different kernel builds. That might be a sign this is > more repeatable than I'd thought, even if it does take hours of runtime > right now to trigger it. I'll try and narrow the scope of what trinity > is doing to see if I can make it happen faster. .. and of course the first thing that happens is a completely different btrfs trace.. WARNING: CPU: 1 PID: 21706 at fs/btrfs/transaction.c:489 start_transaction+0x40a/0x440 [btrfs] CPU: 1 PID: 21706 Comm: trinity-c16 Not tainted 4.8.0-think+ #14 ffffc900019076a8 ffffffffb731ff3c 0000000000000000 0000000000000000 ffffc900019076e8 ffffffffb707a6c1 000001e9f5806ce0 ffff8804f74c4d98 0000000000000801 ffff880501cfa2a8 000000000000008a 000000000000008a Call Trace: [<ffffffffb731ff3c>] dump_stack+0x4f/0x73 [<ffffffffb707a6c1>] __warn+0xc1/0xe0 [<ffffffffb707a7e8>] warn_slowpath_null+0x18/0x20 [<ffffffffc01d312a>] start_transaction+0x40a/0x440 [btrfs] [<ffffffffc01a6215>] ? btrfs_alloc_path+0x15/0x20 [btrfs] [<ffffffffc01d31b2>] btrfs_join_transaction+0x12/0x20 [btrfs] [<ffffffffc01d92cf>] cow_file_range_inline+0xef/0x830 [btrfs] [<ffffffffc01d9d75>] cow_file_range.isra.64+0x365/0x480 [btrfs] [<ffffffffb77c24cc>] ? _raw_spin_unlock+0x2c/0x50 [<ffffffffc01f229f>] ? release_extent_buffer+0x9f/0x110 [btrfs] [<ffffffffc01da299>] run_delalloc_nocow+0x409/0xbd0 [btrfs] [<ffffffffb70c6109>] ? get_lock_stats+0x19/0x50 [<ffffffffc01dadea>] run_delalloc_range+0x38a/0x3e0 [btrfs] [<ffffffffc01f4aba>] writepage_delalloc.isra.47+0x10a/0x190 [btrfs] [<ffffffffc01f7678>] __extent_writepage+0xd8/0x2c0 [btrfs] [<ffffffffc01f7b2e>] extent_write_cache_pages.isra.44.constprop.63+0x2ce/0x430 [btrfs] [<ffffffffb733e497>] ? debug_smp_processor_id+0x17/0x20 [<ffffffffb70c6109>] ? get_lock_stats+0x19/0x50 [<ffffffffc01f8278>] extent_writepages+0x58/0x80 [btrfs] [<ffffffffc01d7a80>] ? btrfs_releasepage+0x40/0x40 [btrfs] [<ffffffffc01d4a63>] btrfs_writepages+0x23/0x30 [btrfs] [<ffffffffb7162e9c>] do_writepages+0x1c/0x30 [<ffffffffb71550f1>] __filemap_fdatawrite_range+0xc1/0x100 [<ffffffffb71551ee>] filemap_fdatawrite_range+0xe/0x10 [<ffffffffc01eb2fb>] btrfs_fdatawrite_range+0x1b/0x50 [btrfs] [<ffffffffc01f0820>] btrfs_wait_ordered_range+0x40/0x100 [btrfs] [<ffffffffc01eb5d5>] btrfs_sync_file+0x285/0x390 [btrfs] [<ffffffffb7207626>] vfs_fsync_range+0x46/0xa0 [<ffffffffb72076d8>] do_fsync+0x38/0x60 [<ffffffffb720795b>] SyS_fsync+0xb/0x10 [<ffffffffb700259c>] do_syscall_64+0x5c/0x170 [<ffffffffb77c2e4b>] entry_SYSCALL64_slow_path+0x25/0x25
[toc] | [prev] | [standalone]
Back to top | Article view | linux.kernel
csiph-web