lkml.org 
[lkml]   [2022]   [Jun]   [13]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
Patch in this message
/
From
Date
SubjectRe: [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;
\
 
 \ /
  Last update: 2022-06-13 13:48    [W:0.061 / U:0.160 seconds]
©2003-2020 Jasper Spaans|hosted at Digital Ocean and TransIP|Read the blog|Advertise on this site