Skip to contentSkip to conversation

btrfs/113: Assertion failure

DISCUSSION Chandan Rajendra 2 participants 3 messages Jul 1, 2016 – Jul 2, 2016 1 message not in the archive Btrfs file system

lore
Share & tools
lore

A message that is not in the archive (sent off-list or not yet received): [email protected]

Chandan Rajendra

author
#1 lore raw

Sorry, Forgot to add the mailing list to CC. Doing it now ...

Quoted 75 lines

While running btrfs/113, I see the following call trace,

[  182.272009] BTRFS: assertion failed: !current->journal_info || flush != BTRFS_RESERVE_FLUSH_ALL, file: /home/chandan/repos/linux/fs/btrfs/extent-tree.c, line: 5131
[  182.274010] ------------[ cut here ]------------
[  182.274685] kernel BUG at /home/chandan/repos/linux/fs/btrfs/ctree.h:3347!
[  182.274982] invalid opcode: 0000 [#1] SMP DEBUG_PAGEALLOC
[  182.274982] Modules linked in:
[  182.274982] CPU: 2 PID: 2911 Comm: xfs_io Not tainted 4.6.0-g5027553-dirty #29
[  182.274982] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Bochs 01/01/2011
[  182.274982] task: ffff8818a4c3a400 ti: ffff8818aec4c000 task.ti: ffff8818aec4c000
[  182.274982] RIP: 0010:[<ffffffff813e4bc5>]  [<ffffffff813e4bc5>] assfail+0x1a/0x1c
[  182.274982] RSP: 0018:ffff8818aec4f5d8  EFLAGS: 00010282
[  182.274982] RAX: 0000000000000097 RBX: 0000000000030000 RCX: ffffffff8203dc18
[  182.274982] RDX: 0000000000000001 RSI: 0000000000000286 RDI: ffffffff822c8ccc
[  182.274982] RBP: ffff8818aec4f5d8 R08: 00000000fffffffe R09: 0000000000000000
[  182.274982] R10: 0000000000000005 R11: 000000000000028d R12: ffff8818b44ff000
[  182.274982] R13: 0000000000030000 R14: ffff8818a54a01f0 R15: ffff8818a4f36150
[  182.274982] FS:  00007f54fbc6b700(0000) GS:ffff881933500000(0000) knlGS:0000000000000000
[  182.274982] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  182.274982] CR2: 000000000061eba0 CR3: 00000018aec54000 CR4: 00000000000006e0
[  182.274982] Stack:
[  182.274982]  ffff8818aec4fa70 ffffffff8134a891 0000000200000000 0000000000030000
[  182.274982]  ffff8818b2502600 ffff8818b44ff000 0000000000000000 0000000000000000
[  182.274982]  0000000000000000 0000000000000000 0000000000000000 0000000000000000
[  182.274982] Call Trace:
[  182.274982]  [<ffffffff8134a891>] __reserve_metadata_bytes+0xb1/0x1fe0
[  182.274982]  [<ffffffff8104ada3>] ? lookup_address+0x23/0x30
[  182.274982]  [<ffffffff8104ae8d>] ? _lookup_address_cpa.isra.9+0x2d/0x30
[  182.274982]  [<ffffffff8104af7b>] ? __change_page_attr_set_clr+0xeb/0xc80
[  182.274982]  [<ffffffff8104ada3>] ? lookup_address+0x23/0x30
[  182.274982]  [<ffffffff8133d46a>] ? get_alloc_profile+0x8a/0x1a0
[  182.274982]  [<ffffffff8134350b>] ? btrfs_get_alloc_profile+0x2b/0x30
[  182.274982]  [<ffffffff813435ae>] ? can_overcommit+0x9e/0x100
[  182.274982]  [<ffffffff8134b468>] ? __reserve_metadata_bytes+0xc88/0x1fe0
[  182.274982]  [<ffffffff81129b5d>] ? __alloc_pages_nodemask+0x10d/0xc80
[  182.274982]  [<ffffffff8104ae8d>] ? _lookup_address_cpa.isra.9+0x2d/0x30
[  182.274982]  [<ffffffff8104af7b>] ? __change_page_attr_set_clr+0xeb/0xc80
[  182.274982]  [<ffffffff8104ada3>] ? lookup_address+0x23/0x30
[  182.274982]  [<ffffffff811720f6>] ? __slab_free+0x96/0x2b0
[  182.274982]  [<ffffffff81125f09>] ? __probe_kernel_read+0x39/0x90
[  182.274982]  [<ffffffff8137e789>] ? insert_state+0xc9/0x150
[  182.274982]  [<ffffffff813af02e>] ? add_delayed_ref_tail_merge+0x2e/0x350
[  182.274982]  [<ffffffff8134c7df>] reserve_metadata_bytes+0x1f/0xe0
[  182.274982]  [<ffffffff8134c8c6>] btrfs_block_rsv_add+0x26/0x50
[  182.274982]  [<ffffffff8137e495>] ? free_extent_state+0x15/0x20
[  182.274982]  [<ffffffff8134ccee>] btrfs_delalloc_reserve_metadata+0x13e/0x490
[  182.274982]  [<ffffffff8134d06a>] btrfs_delalloc_reserve_space+0x2a/0x50
[  182.274982]  [<ffffffff8136acea>] btrfs_truncate_block+0x8a/0x430
[  182.274982]  [<ffffffff81335a46>] ? generic_bin_search.constprop.35+0x86/0x1e0
[  182.274982]  [<ffffffff8136b1e7>] truncate_inline_extent+0x157/0x260
[  182.274982]  [<ffffffff813387dc>] ? btrfs_search_slot+0x86c/0x990
[  182.274982]  [<ffffffff81378b6c>] ? free_extent_map+0x4c/0xa0
[  182.274982]  [<ffffffff8136be97>] btrfs_truncate_inode_items+0xba7/0xdc0
[  182.274982]  [<ffffffff8136c218>] btrfs_truncate+0x168/0x280
[  182.274982]  [<ffffffff8136ca44>] btrfs_setattr+0x214/0x320
[  182.274982]  [<ffffffff8119694c>] notify_change+0x1dc/0x380
[  182.274982]  [<ffffffff81178ae1>] do_truncate+0x61/0xa0
[  182.274982]  [<ffffffff81178e39>] do_sys_ftruncate.constprop.17+0xf9/0x160
[  182.274982]  [<ffffffff81178ec9>] SyS_ftruncate+0x9/0x10
[  182.274982]  [<ffffffff819fb3db>] entry_SYSCALL_64_fastpath+0x13/0x8f
[  182.274982] Code: 48 c7 c7 48 14 df 81 48 89 e5 e8 ac ac d3 ff 0f 0b 55 89 d1 31 c0 48 89 f2 48 89 fe 48 c7 c7 48 14 df 81 48 89 e5 e8 90 ac d3 ff <0f> 0b 55 b9 11 00 00 00 48 89 e5 41 55 49 89 f5 41 54 49 89 d4 
[  182.274982] RIP  [<ffffffff813e4bc5>] assfail+0x1a/0x1c
[  182.274982]  RSP <ffff8818aec4f5d8>
[  182.327207] ---[ end trace 44721e14eef0a6b2 ]---

Basically btrfs_truncate() starts a transaction, btrfs_truncate_inode_items() encounters an inline extent and invokes
btrfs_truncate_block(). btrfs_truncate_block() tries to reserve delalloc (both data & metadata) space. While doing so it passes BTRFS_RESERVE_FLUSH_ALL as an argument. Since we already have a transaction running, we fail the following ASSERT() statement in __reserve_metadata_bytes(),

   ASSERT(!current->journal_info || flush != BTRFS_RESERVE_FLUSH_ALL);
Signature · 1 line
chandan
#2 lore raw
Quoted 78 lines · Chandan Rajendra

Sorry, Forgot to add the mailing list to CC. Doing it now ...

Quoted 75 lines

While running btrfs/113, I see the following call trace,

[  182.272009] BTRFS: assertion failed: !current->journal_info || flush != BTRFS_RESERVE_FLUSH_ALL, file: /home/chandan/repos/linux/fs/btrfs/extent-tree.c, line: 5131
[  182.274010] ------------[ cut here ]------------
[  182.274685] kernel BUG at /home/chandan/repos/linux/fs/btrfs/ctree.h:3347!
[  182.274982] invalid opcode: 0000 [#1] SMP DEBUG_PAGEALLOC
[  182.274982] Modules linked in:
[  182.274982] CPU: 2 PID: 2911 Comm: xfs_io Not tainted 4.6.0-g5027553-dirty #29
[  182.274982] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Bochs 01/01/2011
[  182.274982] task: ffff8818a4c3a400 ti: ffff8818aec4c000 task.ti: ffff8818aec4c000
[  182.274982] RIP: 0010:[<ffffffff813e4bc5>]  [<ffffffff813e4bc5>] assfail+0x1a/0x1c
[  182.274982] RSP: 0018:ffff8818aec4f5d8  EFLAGS: 00010282
[  182.274982] RAX: 0000000000000097 RBX: 0000000000030000 RCX: ffffffff8203dc18
[  182.274982] RDX: 0000000000000001 RSI: 0000000000000286 RDI: ffffffff822c8ccc
[  182.274982] RBP: ffff8818aec4f5d8 R08: 00000000fffffffe R09: 0000000000000000
[  182.274982] R10: 0000000000000005 R11: 000000000000028d R12: ffff8818b44ff000
[  182.274982] R13: 0000000000030000 R14: ffff8818a54a01f0 R15: ffff8818a4f36150
[  182.274982] FS:  00007f54fbc6b700(0000) GS:ffff881933500000(0000) knlGS:0000000000000000
[  182.274982] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  182.274982] CR2: 000000000061eba0 CR3: 00000018aec54000 CR4: 00000000000006e0
[  182.274982] Stack:
[  182.274982]  ffff8818aec4fa70 ffffffff8134a891 0000000200000000 0000000000030000
[  182.274982]  ffff8818b2502600 ffff8818b44ff000 0000000000000000 0000000000000000
[  182.274982]  0000000000000000 0000000000000000 0000000000000000 0000000000000000
[  182.274982] Call Trace:
[  182.274982]  [<ffffffff8134a891>] __reserve_metadata_bytes+0xb1/0x1fe0
[  182.274982]  [<ffffffff8104ada3>] ? lookup_address+0x23/0x30
[  182.274982]  [<ffffffff8104ae8d>] ? _lookup_address_cpa.isra.9+0x2d/0x30
[  182.274982]  [<ffffffff8104af7b>] ? __change_page_attr_set_clr+0xeb/0xc80
[  182.274982]  [<ffffffff8104ada3>] ? lookup_address+0x23/0x30
[  182.274982]  [<ffffffff8133d46a>] ? get_alloc_profile+0x8a/0x1a0
[  182.274982]  [<ffffffff8134350b>] ? btrfs_get_alloc_profile+0x2b/0x30
[  182.274982]  [<ffffffff813435ae>] ? can_overcommit+0x9e/0x100
[  182.274982]  [<ffffffff8134b468>] ? __reserve_metadata_bytes+0xc88/0x1fe0
[  182.274982]  [<ffffffff81129b5d>] ? __alloc_pages_nodemask+0x10d/0xc80
[  182.274982]  [<ffffffff8104ae8d>] ? _lookup_address_cpa.isra.9+0x2d/0x30
[  182.274982]  [<ffffffff8104af7b>] ? __change_page_attr_set_clr+0xeb/0xc80
[  182.274982]  [<ffffffff8104ada3>] ? lookup_address+0x23/0x30
[  182.274982]  [<ffffffff811720f6>] ? __slab_free+0x96/0x2b0
[  182.274982]  [<ffffffff81125f09>] ? __probe_kernel_read+0x39/0x90
[  182.274982]  [<ffffffff8137e789>] ? insert_state+0xc9/0x150
[  182.274982]  [<ffffffff813af02e>] ? add_delayed_ref_tail_merge+0x2e/0x350
[  182.274982]  [<ffffffff8134c7df>] reserve_metadata_bytes+0x1f/0xe0
[  182.274982]  [<ffffffff8134c8c6>] btrfs_block_rsv_add+0x26/0x50
[  182.274982]  [<ffffffff8137e495>] ? free_extent_state+0x15/0x20
[  182.274982]  [<ffffffff8134ccee>] btrfs_delalloc_reserve_metadata+0x13e/0x490
[  182.274982]  [<ffffffff8134d06a>] btrfs_delalloc_reserve_space+0x2a/0x50
[  182.274982]  [<ffffffff8136acea>] btrfs_truncate_block+0x8a/0x430
[  182.274982]  [<ffffffff81335a46>] ? generic_bin_search.constprop.35+0x86/0x1e0
[  182.274982]  [<ffffffff8136b1e7>] truncate_inline_extent+0x157/0x260
[  182.274982]  [<ffffffff813387dc>] ? btrfs_search_slot+0x86c/0x990
[  182.274982]  [<ffffffff81378b6c>] ? free_extent_map+0x4c/0xa0
[  182.274982]  [<ffffffff8136be97>] btrfs_truncate_inode_items+0xba7/0xdc0
[  182.274982]  [<ffffffff8136c218>] btrfs_truncate+0x168/0x280
[  182.274982]  [<ffffffff8136ca44>] btrfs_setattr+0x214/0x320
[  182.274982]  [<ffffffff8119694c>] notify_change+0x1dc/0x380
[  182.274982]  [<ffffffff81178ae1>] do_truncate+0x61/0xa0
[  182.274982]  [<ffffffff81178e39>] do_sys_ftruncate.constprop.17+0xf9/0x160
[  182.274982]  [<ffffffff81178ec9>] SyS_ftruncate+0x9/0x10
[  182.274982]  [<ffffffff819fb3db>] entry_SYSCALL_64_fastpath+0x13/0x8f
[  182.274982] Code: 48 c7 c7 48 14 df 81 48 89 e5 e8 ac ac d3 ff 0f 0b 55 89 d1 31 c0 48 89 f2 48 89 fe 48 c7 c7 48 14 df 81 48 89 e5 e8 90 ac d3 ff <0f> 0b 55 b9 11 00 00 00 48 89 e5 41 55 49 89 f5 41 54 49 89 d4
[  182.274982] RIP  [<ffffffff813e4bc5>] assfail+0x1a/0x1c
[  182.274982]  RSP <ffff8818aec4f5d8>
[  182.327207] ---[ end trace 44721e14eef0a6b2 ]---

Basically btrfs_truncate() starts a transaction, btrfs_truncate_inode_items() encounters an inline extent and invokes
btrfs_truncate_block(). btrfs_truncate_block() tries to reserve delalloc (both data & metadata) space. While doing so it passes BTRFS_RESERVE_FLUSH_ALL as an argument. Since we already have a transaction running, we fail the following ASSERT() statement in __reserve_metadata_bytes(),

   ASSERT(!current->journal_info || flush != BTRFS_RESERVE_FLUSH_ALL);

Where is this code? I can't find it anywhere. Thanks,

Josef

author
#3 lore raw
Quoted 76 lines · Josef Bacik
Quoted 75 lines · Chandan Rajendra

Sorry, Forgot to add the mailing list to CC. Doing it now ...

Quoted 73 lines

While running btrfs/113, I see the following call trace,

[  182.272009] BTRFS: assertion failed: !current->journal_info || flush != BTRFS_RESERVE_FLUSH_ALL, file: /home/chandan/repos/linux/fs/btrfs/extent-tree.c, line: 5131
[  182.274010] ------------[ cut here ]------------
[  182.274685] kernel BUG at /home/chandan/repos/linux/fs/btrfs/ctree.h:3347!
[  182.274982] invalid opcode: 0000 [#1] SMP DEBUG_PAGEALLOC
[  182.274982] Modules linked in:
[  182.274982] CPU: 2 PID: 2911 Comm: xfs_io Not tainted 4.6.0-g5027553-dirty #29
[  182.274982] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Bochs 01/01/2011
[  182.274982] task: ffff8818a4c3a400 ti: ffff8818aec4c000 task.ti: ffff8818aec4c000
[  182.274982] RIP: 0010:[<ffffffff813e4bc5>]  [<ffffffff813e4bc5>] assfail+0x1a/0x1c
[  182.274982] RSP: 0018:ffff8818aec4f5d8  EFLAGS: 00010282
[  182.274982] RAX: 0000000000000097 RBX: 0000000000030000 RCX: ffffffff8203dc18
[  182.274982] RDX: 0000000000000001 RSI: 0000000000000286 RDI: ffffffff822c8ccc
[  182.274982] RBP: ffff8818aec4f5d8 R08: 00000000fffffffe R09: 0000000000000000
[  182.274982] R10: 0000000000000005 R11: 000000000000028d R12: ffff8818b44ff000
[  182.274982] R13: 0000000000030000 R14: ffff8818a54a01f0 R15: ffff8818a4f36150
[  182.274982] FS:  00007f54fbc6b700(0000) GS:ffff881933500000(0000) knlGS:0000000000000000
[  182.274982] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  182.274982] CR2: 000000000061eba0 CR3: 00000018aec54000 CR4: 00000000000006e0
[  182.274982] Stack:
[  182.274982]  ffff8818aec4fa70 ffffffff8134a891 0000000200000000 0000000000030000
[  182.274982]  ffff8818b2502600 ffff8818b44ff000 0000000000000000 0000000000000000
[  182.274982]  0000000000000000 0000000000000000 0000000000000000 0000000000000000
[  182.274982] Call Trace:
[  182.274982]  [<ffffffff8134a891>] __reserve_metadata_bytes+0xb1/0x1fe0
[  182.274982]  [<ffffffff8104ada3>] ? lookup_address+0x23/0x30
[  182.274982]  [<ffffffff8104ae8d>] ? _lookup_address_cpa.isra.9+0x2d/0x30
[  182.274982]  [<ffffffff8104af7b>] ? __change_page_attr_set_clr+0xeb/0xc80
[  182.274982]  [<ffffffff8104ada3>] ? lookup_address+0x23/0x30
[  182.274982]  [<ffffffff8133d46a>] ? get_alloc_profile+0x8a/0x1a0
[  182.274982]  [<ffffffff8134350b>] ? btrfs_get_alloc_profile+0x2b/0x30
[  182.274982]  [<ffffffff813435ae>] ? can_overcommit+0x9e/0x100
[  182.274982]  [<ffffffff8134b468>] ? __reserve_metadata_bytes+0xc88/0x1fe0
[  182.274982]  [<ffffffff81129b5d>] ? __alloc_pages_nodemask+0x10d/0xc80
[  182.274982]  [<ffffffff8104ae8d>] ? _lookup_address_cpa.isra.9+0x2d/0x30
[  182.274982]  [<ffffffff8104af7b>] ? __change_page_attr_set_clr+0xeb/0xc80
[  182.274982]  [<ffffffff8104ada3>] ? lookup_address+0x23/0x30
[  182.274982]  [<ffffffff811720f6>] ? __slab_free+0x96/0x2b0
[  182.274982]  [<ffffffff81125f09>] ? __probe_kernel_read+0x39/0x90
[  182.274982]  [<ffffffff8137e789>] ? insert_state+0xc9/0x150
[  182.274982]  [<ffffffff813af02e>] ? add_delayed_ref_tail_merge+0x2e/0x350
[  182.274982]  [<ffffffff8134c7df>] reserve_metadata_bytes+0x1f/0xe0
[  182.274982]  [<ffffffff8134c8c6>] btrfs_block_rsv_add+0x26/0x50
[  182.274982]  [<ffffffff8137e495>] ? free_extent_state+0x15/0x20
[  182.274982]  [<ffffffff8134ccee>] btrfs_delalloc_reserve_metadata+0x13e/0x490
[  182.274982]  [<ffffffff8134d06a>] btrfs_delalloc_reserve_space+0x2a/0x50
[  182.274982]  [<ffffffff8136acea>] btrfs_truncate_block+0x8a/0x430
[  182.274982]  [<ffffffff81335a46>] ? generic_bin_search.constprop.35+0x86/0x1e0
[  182.274982]  [<ffffffff8136b1e7>] truncate_inline_extent+0x157/0x260
[  182.274982]  [<ffffffff813387dc>] ? btrfs_search_slot+0x86c/0x990
[  182.274982]  [<ffffffff81378b6c>] ? free_extent_map+0x4c/0xa0
[  182.274982]  [<ffffffff8136be97>] btrfs_truncate_inode_items+0xba7/0xdc0
[  182.274982]  [<ffffffff8136c218>] btrfs_truncate+0x168/0x280
[  182.274982]  [<ffffffff8136ca44>] btrfs_setattr+0x214/0x320
[  182.274982]  [<ffffffff8119694c>] notify_change+0x1dc/0x380
[  182.274982]  [<ffffffff81178ae1>] do_truncate+0x61/0xa0
[  182.274982]  [<ffffffff81178e39>] do_sys_ftruncate.constprop.17+0xf9/0x160
[  182.274982]  [<ffffffff81178ec9>] SyS_ftruncate+0x9/0x10
[  182.274982]  [<ffffffff819fb3db>] entry_SYSCALL_64_fastpath+0x13/0x8f
[  182.274982] Code: 48 c7 c7 48 14 df 81 48 89 e5 e8 ac ac d3 ff 0f 0b 55 89 d1 31 c0 48 89 f2 48 89 fe 48 c7 c7 48 14 df 81 48 89 e5 e8 90 ac d3 ff <0f> 0b 55 b9 11 00 00 00 48 89 e5 41 55 49 89 f5 41 54 49 89 d4
[  182.274982] RIP  [<ffffffff813e4bc5>] assfail+0x1a/0x1c
[  182.274982]  RSP <ffff8818aec4f5d8>
[  182.327207] ---[ end trace 44721e14eef0a6b2 ]---

Basically btrfs_truncate() starts a transaction, btrfs_truncate_inode_items() encounters an inline extent and invokes
btrfs_truncate_block(). btrfs_truncate_block() tries to reserve delalloc (both data & metadata) space. While doing so it passes BTRFS_RESERVE_FLUSH_ALL as an argument. Since we already have a transaction running, we fail the following ASSERT() statement in __reserve_metadata_bytes(),

Quoted 6 lines
Quoted 3 lines
Quoted 2 lines
   ASSERT(!current->journal_info || flush != BTRFS_RESERVE_FLUSH_ALL);

Where is this code? I can't find it anywhere. Thanks,

Hi Josef, You can find the code in David's for-next branch at
git://git.kernel.org/pub/scm/linux/kernel/git/kdave/linux.git.

The relevant commit is ...

48f43b07fa3e2e7e86965c443979b578a9b1fe65

Author:     Josef Bacik <[email protected]>
AuthorDate: Fri May 27 13:24:13 2016 -0400
Commit:     David Sterba <[email protected]>
CommitDate: Tue May 31 22:57:37 2016 +0200

Btrfs: use FLUSH_LIMIT for relocation in reserve_metadata_bytes

We used to allow you to set FLUSH_ALL and then just wouldn't do things like commit transactions or wait on ordered extents if we noticed you were in a transaction. However now that all the flushing for FLUSH_ALL is asynchronous we've lost the ability to tell, and we could end up deadlocking. So instead use FLUSH_LIMIT in reserve_metadata_bytes in relocation and then return -EAGAIN if we error out to preserve the previous behavior. I've also added an ASSERT() to catch anybody else who tries to do this. Thanks,

Signature · 1 line
chandan