Messages in this thread Patch in this message | | | From | Filipe Manana <> | Date | Mon, 13 Jun 2022 11:50:05 +0100 | Subject | Re: [btrfs] 62bd8124e2: WARNING:at_fs/btrfs/block-rsv.c:#btrfs_release_global_block_rsv[btrfs] |
| |
On Sun, Jun 12, 2022 at 3:37 PM Oliver Sang <oliver.sang@intel.com> wrote: > > hi, Filipe Manana, > > On Fri, Jun 10, 2022 at 09:26:59AM +0800, Oliver Sang wrote: > > hi, Filipe Manana, > > > > On Thu, Jun 09, 2022 at 10:46:52AM +0100, Filipe Manana wrote: > > > > > > I am unable to reproduce that on a 12 cores box. > > > I also don't see anything wrong that could lead to that by manual inspection. > > > > > > How easy is it for you to trigger it? > > > > we reproduced this upon 62bd8124e2 4 times out of 6 runs. > > but since the other 2 runs crash early due to other issues (below (1)), we > > cannot say they are clean. > > at the same time, the 6 runs for parent are clean. > > > > 7e2bb5b3f3bca223 62bd8124e2f17910fcd89568e50 > > ---------------- --------------------------- > > fail:runs %reproduction fail:runs > > | | | > > :6 67% 4:6 dmesg.RIP:btrfs_release_global_block_rsv[btrfs] > > :6 67% 4:6 dmesg.WARNING:at_fs/btrfs/block-rsv.c:#btrfs_release_global_block_rsv[btrfs] > > :6 33% 2:6 dmesg.kernel_BUG_at_fs/xfs/xfs_message.c <----- (1) > > > > > > > > > > Can you also run it with CONFIG_BTRFS_ASSERT=y set in the kernel config? > > > > got it, we will enable this config and rerun tests, for both this commit and > > parent. > > we enabled CONFIG_BTRFS_ASSERT=y as attached config and rerun tests, still can > reproduce the issue, like: > > > 7e2bb5b3f3bca223 62bd8124e2f17910fcd89568e50 > ---------------- --------------------------- > fail:runs %reproduction fail:runs > | | | > :16 94% 15:16 dmesg.RIP:btrfs_release_global_block_rsv[btrfs] > :16 94% 15:16 dmesg.WARNING:at_fs/btrfs/block-rsv.c:#btrfs_release_global_block_rsv[btrfs] > :16 6% 1:16 dmesg.kernel_BUG_at_fs/xfs/xfs_message.c > > > attached one dmesg FYI
Thanks for running the test again Oliver. Running the fxmark test on my machines, I can't trigger anything.
May I ask you to run again the test but with the attached debug patch on top of it?
Also, if possible, with ftrace enabled like this:
modprobe btrfs echo 0 > /sys/kernel/debug/tracing/tracing_on echo > /sys/kernel/debug/tracing/trace echo $((1 << 24)) > /sys/kernel/debug/tracing/buffer_size_kb echo nop > /sys/kernel/debug/tracing/current_tracer echo 1 > /sys/kernel/tracing/events/btrfs/btrfs_space_reservation/enable
echo 1 > /sys/kernel/debug/tracing/tracing_on
<run the test>
echo 0 > /sys/kernel/debug/tracing/tracing_on
Then collect the trace to a file and send it over to me:
cat /sys/kernel/debug/tracing/trace | xz -9 > trace.txt.xz
And of course, the dmesg result as well.
Thanks!
> > > diff --git a/fs/btrfs/block-rsv.c b/fs/btrfs/block-rsv.c index b3ee49b0b1e8..fab0638b1f1e 100644 --- a/fs/btrfs/block-rsv.c +++ b/fs/btrfs/block-rsv.c @@ -114,6 +114,9 @@ static u64 block_rsv_release_bytes(struct btrfs_fs_info *fs_info, num_bytes = block_rsv->size; qgroup_to_release = block_rsv->qgroup_rsv_size; } + if (WARN_ON(num_bytes > block_rsv->size)) + btrfs_err(fs_info, "block_rsv release size=%llu reserved=%llu type=%d num_bytes=%llu", + block_rsv->size, block_rsv->reserved, block_rsv->type, num_bytes); block_rsv->size -= num_bytes; if (block_rsv->reserved >= block_rsv->size) { num_bytes = block_rsv->reserved - block_rsv->size; @@ -316,9 +319,12 @@ void btrfs_block_rsv_add_bytes(struct btrfs_block_rsv *block_rsv, { spin_lock(&block_rsv->lock); block_rsv->reserved += num_bytes; - if (update_size) + if (update_size) { + if (block_rsv->size == 0) + trace_printk("block_rsv type=%d size became non-zero (%llu)\n", + block_rsv->type, num_bytes); block_rsv->size += num_bytes; - else if (block_rsv->reserved >= block_rsv->size) + } else if (block_rsv->reserved >= block_rsv->size) block_rsv->full = 1; spin_unlock(&block_rsv->lock); } @@ -460,18 +466,32 @@ void btrfs_init_global_block_rsv(struct btrfs_fs_info *fs_info) btrfs_update_global_block_rsv(fs_info); } +static void dump_block_rsv(struct btrfs_fs_info *fs_info, struct btrfs_block_rsv *rsv) +{ + btrfs_err(fs_info, "block_rsv type=%d size=%llu reserved=%llu", + rsv->type, rsv->size, rsv->reserved); +} + void btrfs_release_global_block_rsv(struct btrfs_fs_info *fs_info) { btrfs_block_rsv_release(fs_info, &fs_info->global_block_rsv, (u64)-1, NULL); - WARN_ON(fs_info->trans_block_rsv.size > 0); - WARN_ON(fs_info->trans_block_rsv.reserved > 0); - WARN_ON(fs_info->chunk_block_rsv.size > 0); - WARN_ON(fs_info->chunk_block_rsv.reserved > 0); - WARN_ON(fs_info->delayed_block_rsv.size > 0); - WARN_ON(fs_info->delayed_block_rsv.reserved > 0); - WARN_ON(fs_info->delayed_refs_rsv.reserved > 0); - WARN_ON(fs_info->delayed_refs_rsv.size > 0); + if (WARN_ON(fs_info->trans_block_rsv.size > 0)) + dump_block_rsv(fs_info, &fs_info->trans_block_rsv); + if (WARN_ON(fs_info->trans_block_rsv.reserved > 0)) + dump_block_rsv(fs_info, &fs_info->trans_block_rsv); + if (WARN_ON(fs_info->chunk_block_rsv.size > 0)) + dump_block_rsv(fs_info, &fs_info->chunk_block_rsv); + if (WARN_ON(fs_info->chunk_block_rsv.reserved > 0)) + dump_block_rsv(fs_info, &fs_info->chunk_block_rsv); + if (WARN_ON(fs_info->delayed_block_rsv.size > 0)) + dump_block_rsv(fs_info, &fs_info->delayed_block_rsv); + if (WARN_ON(fs_info->delayed_block_rsv.reserved > 0)) + dump_block_rsv(fs_info, &fs_info->delayed_block_rsv); + if (WARN_ON(fs_info->delayed_refs_rsv.reserved > 0)) + dump_block_rsv(fs_info, &fs_info->delayed_refs_rsv); + if (WARN_ON(fs_info->delayed_refs_rsv.size > 0)) + dump_block_rsv(fs_info, &fs_info->delayed_refs_rsv); } static struct btrfs_block_rsv *get_block_rsv( diff --git a/fs/btrfs/delayed-inode.c b/fs/btrfs/delayed-inode.c index e1e856436ad5..698ae8a91415 100644 --- a/fs/btrfs/delayed-inode.c +++ b/fs/btrfs/delayed-inode.c @@ -572,6 +572,17 @@ static void btrfs_delayed_item_release_metadata(struct btrfs_root *root, btrfs_block_rsv_release(fs_info, rsv, item->bytes_reserved, NULL); } +static void btrfs_delayed_item_release_leaves(struct btrfs_delayed_node *node, + unsigned int num_leaves) +{ + struct btrfs_fs_info *fs_info = node->root->fs_info; + const u64 bytes = btrfs_calc_insert_metadata_size(fs_info, num_leaves); + + trace_btrfs_space_reservation(fs_info, "delayed_item", node->inode_id, + bytes, 0); + btrfs_block_rsv_release(fs_info, &fs_info->delayed_block_rsv, bytes, NULL); +} + static int btrfs_delayed_inode_reserve_metadata( struct btrfs_trans_handle *trans, struct btrfs_root *root, @@ -761,9 +772,7 @@ static int btrfs_insert_delayed_item(struct btrfs_trans_handle *trans, * metadata space from the delayed block reserve. */ if (!test_bit(BTRFS_FS_LOG_RECOVERING, &fs_info->flags)) - btrfs_block_rsv_release(fs_info, &fs_info->delayed_block_rsv, - btrfs_calc_insert_metadata_size(fs_info, 1), - NULL); + btrfs_delayed_item_release_leaves(node, 1); ASSERT(node->index_items_size >= total_size); node->index_items_size -= total_size; @@ -785,6 +794,7 @@ static int btrfs_insert_delayed_items(struct btrfs_trans_handle *trans, mutex_lock(&node->mutex); curr = __btrfs_first_delayed_insertion_item(node); if (!curr) { + ASSERT(node->index_items_size == 0); mutex_unlock(&node->mutex); break; } @@ -1366,13 +1376,8 @@ static unsigned int num_dir_index_leaves(const struct btrfs_fs_info *fs_info, u32 index_items_size) { const unsigned int leaf_data_size = BTRFS_LEAF_DATA_SIZE(fs_info); - unsigned int result; - result = index_items_size / leaf_data_size; - if ((index_items_size % leaf_data_size) != 0) - result++; - - return result; + return DIV_ROUND_UP(index_items_size, leaf_data_size); } /* Will return 0 or -ENOMEM */ @@ -1449,6 +1454,8 @@ int btrfs_insert_delayed_dir_index(struct btrfs_trans_handle *trans, * the case where we had a transaction start and excludes the * transaction join case (when replaying log trees). */ + trace_btrfs_space_reservation(fs_info, "transaction", + trans->transid, bytes, 0); btrfs_block_rsv_release(fs_info, trans->block_rsv, bytes, NULL); ASSERT(trans->bytes_reserved >= bytes); trans->bytes_reserved -= bytes; @@ -1505,12 +1512,8 @@ static int btrfs_delete_delayed_insertion_item(struct btrfs_fs_info *fs_info, ASSERT((leaves_before - leaves_after) <= 1); if (leaves_after < leaves_before && - !test_bit(BTRFS_FS_LOG_RECOVERING, &fs_info->flags)) { - const u64 bytes = btrfs_calc_insert_metadata_size(fs_info, 1); - - btrfs_block_rsv_release(fs_info, &fs_info->delayed_block_rsv, - bytes, NULL); - } + !test_bit(BTRFS_FS_LOG_RECOVERING, &fs_info->flags)) + btrfs_delayed_item_release_leaves(node, 1); btrfs_release_delayed_item(item); mutex_unlock(&node->mutex); @@ -1936,14 +1939,10 @@ static void __btrfs_kill_delayed_node(struct btrfs_delayed_node *delayed_node) if (!test_bit(BTRFS_FS_LOG_RECOVERING, &fs_info->flags) && delayed_node->index_items_size > 0) { unsigned int num_leaves; - u64 bytes; num_leaves = num_dir_index_leaves(fs_info, delayed_node->index_items_size); - bytes = btrfs_calc_insert_metadata_size(fs_info, num_leaves); - - btrfs_block_rsv_release(fs_info, &fs_info->delayed_block_rsv, - bytes, NULL); + btrfs_delayed_item_release_leaves(delayed_node, num_leaves); } delayed_node->index_items_size = 0; | |