diff mbox series

btrfs: raid56: do extra dumping for CONFIG_BTRFS_ASSERT

Message ID 096e0e552749093231fae4f2f6eb450eb9e0d465.1715678510.git.wqu@suse.com (mailing list archive)
State New
Headers show
Series btrfs: raid56: do extra dumping for CONFIG_BTRFS_ASSERT | expand

Commit Message

Qu Wenruo May 14, 2024, 9:22 a.m. UTC
There are several hard-to-hit ASSERT()s hit inside raid56.
Unfortunately the ASSERT() expression is a little complex, and except
the ASSERT(), there is nothing to provide any clue.

Considering if race is involved, it's pretty hard to reproduce.
Meanwhile sometimes the dump of the rbio structure can provide some
pretty good clues, it's worthy to do the extra multi-line dump for
btrfs raid56 related code.

The dump looks like this:

 bioc logical=298917888 full_stripe=298844160 size=0 map_type=0x101 mirror=4 replace_nr_stripes=0 replace_stripe_src=-1 num_stripes=4
     nr=0 devid=1 physical=22020096
     nr=1 devid=2 physical=1048576
     nr=2 devid=3 physical=277872640
     nr=3 devid=4 physical=277872640
 rbio flags=0x0 nr_sectors=64 nr_data=2 real_stripes=4 stripe_nsectors=16 scrubp=0 dbitmap=0x0
 logical=298917888
 assertion failed: orig_logical >= full_stripe_start && orig_logical + orig_len <= full_stripe_start + rbio->nr_data * BTRFS_STRIPE_LEN, in fs/btrfs/raid56.c:1702
 ------------[ cut here ]------------

Signed-off-by: Qu Wenruo <wqu@suse.com>
---
 fs/btrfs/raid56.c  | 77 ++++++++++++++++++++++++++++++++++++++--------
 fs/btrfs/volumes.h | 20 ++++++++++++
 2 files changed, 84 insertions(+), 13 deletions(-)

Comments

Filipe Manana May 14, 2024, 11:44 a.m. UTC | #1
On Tue, May 14, 2024 at 10:35 AM Qu Wenruo <wqu@suse.com> wrote:
>
> There are several hard-to-hit ASSERT()s hit inside raid56.
> Unfortunately the ASSERT() expression is a little complex, and except
> the ASSERT(), there is nothing to provide any clue.
>
> Considering if race is involved, it's pretty hard to reproduce.
> Meanwhile sometimes the dump of the rbio structure can provide some
> pretty good clues, it's worthy to do the extra multi-line dump for
> btrfs raid56 related code.
>
> The dump looks like this:
>
>  bioc logical=298917888 full_stripe=298844160 size=0 map_type=0x101 mirror=4 replace_nr_stripes=0 replace_stripe_src=-1 num_stripes=4
>      nr=0 devid=1 physical=22020096
>      nr=1 devid=2 physical=1048576
>      nr=2 devid=3 physical=277872640
>      nr=3 devid=4 physical=277872640
>  rbio flags=0x0 nr_sectors=64 nr_data=2 real_stripes=4 stripe_nsectors=16 scrubp=0 dbitmap=0x0
>  logical=298917888
>  assertion failed: orig_logical >= full_stripe_start && orig_logical + orig_len <= full_stripe_start + rbio->nr_data * BTRFS_STRIPE_LEN, in fs/btrfs/raid56.c:1702
>  ------------[ cut here ]------------
>
> Signed-off-by: Qu Wenruo <wqu@suse.com>
> ---
>  fs/btrfs/raid56.c  | 77 ++++++++++++++++++++++++++++++++++++++--------
>  fs/btrfs/volumes.h | 20 ++++++++++++
>  2 files changed, 84 insertions(+), 13 deletions(-)
>
> diff --git a/fs/btrfs/raid56.c b/fs/btrfs/raid56.c
> index 6f4a9cfeea44..b8fffac7cd24 100644
> --- a/fs/btrfs/raid56.c
> +++ b/fs/btrfs/raid56.c
> @@ -40,6 +40,54 @@
>
>  #define BTRFS_STRIPE_HASH_TABLE_BITS                           11
>
> +static void btrfs_dump_rbio(const struct btrfs_raid_bio *rbio)
> +{
> +       if (!IS_ENABLED(CONFIG_BTRFS_ASSERT))
> +               return;
> +
> +       btrfs_dump_bioc(rbio->bioc);
> +       pr_info(

You can use btrfs_err() or btrfs_crit() here for a more standardized message.
Also I don't think info level is appropriate, either error or critical
seem the right choice to me.

Remember that CONFIG_BTRFS_ASSERT is also set for some non-debug
kernel configs like SUSE kernels, and it may be useful to know from
which fs the problem came for example.

The fs_info is accessible through rbio->bioc->fs_info.
And even if rbio->bioc is NULL (and btrfs_dump_bioc() checks for
that), you can still pass a NULL fs_info to those helpers.

> +"rbio flags=0x%lx nr_sectors=%u nr_data=%u real_stripes=%u stripe_nsectors=%u scrubp=%u dbitmap=0x%lx",
> +               rbio->flags, rbio->nr_sectors, rbio->nr_data,
> +               rbio->real_stripes, rbio->stripe_nsectors,
> +               rbio->scrubp, rbio->dbitmap);
> +}
> +
> +#define ASSERT_RBIO(expr, rbio)                                                \
> +({                                                                     \
> +       if (IS_ENABLED(CONFIG_BTRFS_ASSERT) && unlikely(!(expr)))       \
> +               btrfs_dump_rbio(rbio);                                  \

As a good practice, there should be parenthesis around rbio too
because we're inside a macro, that is:

btrfs_dump_rbio((rbio));

> +       ASSERT(expr);                                                   \

Same here.

> +})
> +
> +#define ASSERT_RBIO_STRIPE(expr, rbio, stripe_nr)                      \
> +({                                                                     \
> +       if (IS_ENABLED(CONFIG_BTRFS_ASSERT) && unlikely(!(expr))) {     \
> +               btrfs_dump_rbio(rbio);                                  \

Same here.

> +               pr_info("stripe_nr=%d", stripe_nr);                     \

Same here for stripe_nr.

> +       }                                                               \
> +       ASSERT(expr);                                                   \

Same here.

> +})
> +
> +#define ASSERT_RBIO_SECTOR(expr, rbio, sector_nr)                      \
> +({                                                                     \
> +       if (IS_ENABLED(CONFIG_BTRFS_ASSERT) && unlikely(!(expr))) {     \
> +               btrfs_dump_rbio(rbio);                                  \
> +               pr_info("sector_nr=%d", sector_nr);                     \

Same here.

> +       }                                                               \
> +       ASSERT(expr);                                                   \

Same here.

> +})
> +
> +#define ASSERT_RBIO_LOGICAL(expr, rbio, logical)                       \
> +({                                                                     \
> +       if (IS_ENABLED(CONFIG_BTRFS_ASSERT) && unlikely(!(expr))) {     \
> +               btrfs_dump_rbio(rbio);                                  \
> +               pr_info("logical=%llu", logical);                       \

Same here (rbio and logical).

> +       }                                                               \
> +       ASSERT(expr);                                                   \

Same here.

> +})
> +
> +
>  /* Used by the raid56 code to lock stripes for read/modify/write */
>  struct btrfs_stripe_hash {
>         struct list_head hash_list;
> @@ -593,8 +641,8 @@ static unsigned int rbio_stripe_sector_index(const struct btrfs_raid_bio *rbio,
>                                              unsigned int stripe_nr,
>                                              unsigned int sector_nr)
>  {
> -       ASSERT(stripe_nr < rbio->real_stripes);
> -       ASSERT(sector_nr < rbio->stripe_nsectors);
> +       ASSERT_RBIO_STRIPE(stripe_nr < rbio->real_stripes, rbio, stripe_nr);
> +       ASSERT_RBIO_SECTOR(sector_nr < rbio->stripe_nsectors, rbio, sector_nr);
>
>         return stripe_nr * rbio->stripe_nsectors + sector_nr;
>  }
> @@ -874,8 +922,10 @@ static struct sector_ptr *sector_in_rbio(struct btrfs_raid_bio *rbio,
>         struct sector_ptr *sector;
>         int index;
>
> -       ASSERT(stripe_nr >= 0 && stripe_nr < rbio->real_stripes);
> -       ASSERT(sector_nr >= 0 && sector_nr < rbio->stripe_nsectors);
> +       ASSERT_RBIO_STRIPE(stripe_nr >= 0 && stripe_nr < rbio->real_stripes,
> +                          rbio, stripe_nr);
> +       ASSERT_RBIO_SECTOR(sector_nr >= 0 && sector_nr < rbio->stripe_nsectors,
> +                          rbio, sector_nr);
>
>         index = stripe_nr * rbio->stripe_nsectors + sector_nr;
>         ASSERT(index >= 0 && index < rbio->nr_sectors);
> @@ -1058,8 +1108,8 @@ static int rbio_add_io_sector(struct btrfs_raid_bio *rbio,
>          * thus it can be larger than rbio->real_stripe.
>          * So here we check against bioc->num_stripes, not rbio->real_stripes.
>          */
> -       ASSERT(stripe_nr >= 0 && stripe_nr < rbio->bioc->num_stripes);
> -       ASSERT(sector_nr >= 0 && sector_nr < rbio->stripe_nsectors);
> +       ASSERT_RBIO_STRIPE(stripe_nr >= 0 && stripe_nr < rbio->bioc->num_stripes,
> +                          rbio, stripe_nr);

Why was the second assertion removed?
There's no replacement for the one checking sector_nr.

>         ASSERT(sector->page);
>
>         stripe = &rbio->bioc->stripes[stripe_nr];
> @@ -1198,14 +1248,14 @@ static void assert_rbio(struct btrfs_raid_bio *rbio)
>          * At least two stripes (2 disks RAID5), and since real_stripes is U8,
>          * we won't go beyond 256 disks anyway.
>          */
> -       ASSERT(rbio->real_stripes >= 2);
> -       ASSERT(rbio->nr_data > 0);
> +       ASSERT_RBIO(rbio->real_stripes >= 2, rbio);
> +       ASSERT_RBIO(rbio->nr_data > 0, rbio);
>
>         /*
>          * This is another check to make sure nr data stripes is smaller
>          * than total stripes.
>          */
> -       ASSERT(rbio->nr_data < rbio->real_stripes);
> +       ASSERT_RBIO(rbio->nr_data < rbio->real_stripes, rbio);
>  }
>
>  /* Generate PQ for one vertical stripe. */
> @@ -1642,9 +1692,10 @@ static void rbio_add_bio(struct btrfs_raid_bio *rbio, struct bio *orig_bio)
>         const u32 sectorsize = fs_info->sectorsize;
>         u64 cur_logical;
>
> -       ASSERT(orig_logical >= full_stripe_start &&
> +       ASSERT_RBIO_LOGICAL(orig_logical >= full_stripe_start &&
>                orig_logical + orig_len <= full_stripe_start +
> -              rbio->nr_data * BTRFS_STRIPE_LEN);
> +              rbio->nr_data * BTRFS_STRIPE_LEN,
> +              rbio, orig_logical);
>
>         bio_list_add(&rbio->bio_list, orig_bio);
>         rbio->bio_list_bytes += orig_bio->bi_iter.bi_size;
> @@ -2390,7 +2441,7 @@ struct btrfs_raid_bio *raid56_parity_alloc_scrub_rbio(struct bio *bio,
>                         break;
>                 }
>         }
> -       ASSERT(i < rbio->real_stripes);
> +       ASSERT_RBIO_STRIPE(i < rbio->real_stripes, rbio, i);
>
>         bitmap_copy(&rbio->dbitmap, dbitmap, stripe_nsectors);
>         return rbio;
> @@ -2556,7 +2607,7 @@ static int finish_parity_scrub(struct btrfs_raid_bio *rbio)
>          * Replace is running and our parity stripe needs to be duplicated to
>          * the target device.  Check we have a valid source stripe number.
>          */
> -       ASSERT(rbio->bioc->replace_stripe_src >= 0);
> +       ASSERT_RBIO(rbio->bioc->replace_stripe_src >= 0, rbio);
>         for_each_set_bit(sectornr, pbitmap, rbio->stripe_nsectors) {
>                 struct sector_ptr *sector;
>
> diff --git a/fs/btrfs/volumes.h b/fs/btrfs/volumes.h
> index 66e6fc481ecd..1373721f8e53 100644
> --- a/fs/btrfs/volumes.h
> +++ b/fs/btrfs/volumes.h
> @@ -554,6 +554,26 @@ struct btrfs_io_context {
>         struct btrfs_io_stripe stripes[];
>  };
>
> +static inline void btrfs_dump_bioc(const struct btrfs_io_context *bioc)
> +{
> +       if (!IS_ENABLED(CONFIG_BTRFS_ASSERT))
> +               return;

The caller already checked this.

> +
> +       if (unlikely(!bioc)) {
> +               pr_err("bioc=NULL\n");
> +               return;
> +       }
> +       pr_info("bioc logical=%llu full_stripe=%llu size=%llu map_type=0x%llx mirror=%u replace_nr_stripes=%u replace_stripe_src=%d num_stripes=%u\n",

Same here as pointed out before, could use btrfs_err() or btrfs_crit().

Also since this is only used inside raid56.c, it could be placed there.

Thanks.

> +               bioc->logical, bioc->full_stripe_logical, bioc->size,
> +               bioc->map_type, bioc->mirror_num, bioc->replace_nr_stripes,
> +               bioc->replace_stripe_src, bioc->num_stripes);
> +       for (int i = 0; i < bioc->num_stripes; i++) {
> +               pr_info("    nr=%d devid=%llu physical=%llu\n",
> +                       i, bioc->stripes[i].dev->devid,
> +                       bioc->stripes[i].physical);
> +       }
> +}
> +
>  struct btrfs_device_info {
>         struct btrfs_device *dev;
>         u64 dev_offset;
> --
> 2.45.0
>
>
diff mbox series

Patch

diff --git a/fs/btrfs/raid56.c b/fs/btrfs/raid56.c
index 6f4a9cfeea44..b8fffac7cd24 100644
--- a/fs/btrfs/raid56.c
+++ b/fs/btrfs/raid56.c
@@ -40,6 +40,54 @@ 
 
 #define BTRFS_STRIPE_HASH_TABLE_BITS				11
 
+static void btrfs_dump_rbio(const struct btrfs_raid_bio *rbio)
+{
+	if (!IS_ENABLED(CONFIG_BTRFS_ASSERT))
+		return;
+
+	btrfs_dump_bioc(rbio->bioc);
+	pr_info(
+"rbio flags=0x%lx nr_sectors=%u nr_data=%u real_stripes=%u stripe_nsectors=%u scrubp=%u dbitmap=0x%lx",
+		rbio->flags, rbio->nr_sectors, rbio->nr_data,
+		rbio->real_stripes, rbio->stripe_nsectors,
+		rbio->scrubp, rbio->dbitmap);
+}
+
+#define ASSERT_RBIO(expr, rbio)						\
+({									\
+	if (IS_ENABLED(CONFIG_BTRFS_ASSERT) && unlikely(!(expr)))	\
+		btrfs_dump_rbio(rbio);					\
+	ASSERT(expr);							\
+})
+
+#define ASSERT_RBIO_STRIPE(expr, rbio, stripe_nr)			\
+({									\
+	if (IS_ENABLED(CONFIG_BTRFS_ASSERT) && unlikely(!(expr))) {	\
+		btrfs_dump_rbio(rbio);					\
+		pr_info("stripe_nr=%d", stripe_nr);			\
+	}								\
+	ASSERT(expr);							\
+})
+
+#define ASSERT_RBIO_SECTOR(expr, rbio, sector_nr)			\
+({									\
+	if (IS_ENABLED(CONFIG_BTRFS_ASSERT) && unlikely(!(expr))) {	\
+		btrfs_dump_rbio(rbio);					\
+		pr_info("sector_nr=%d", sector_nr);			\
+	}								\
+	ASSERT(expr);							\
+})
+
+#define ASSERT_RBIO_LOGICAL(expr, rbio, logical)			\
+({									\
+	if (IS_ENABLED(CONFIG_BTRFS_ASSERT) && unlikely(!(expr))) {	\
+		btrfs_dump_rbio(rbio);					\
+		pr_info("logical=%llu", logical);			\
+	}								\
+	ASSERT(expr);							\
+})
+
+
 /* Used by the raid56 code to lock stripes for read/modify/write */
 struct btrfs_stripe_hash {
 	struct list_head hash_list;
@@ -593,8 +641,8 @@  static unsigned int rbio_stripe_sector_index(const struct btrfs_raid_bio *rbio,
 					     unsigned int stripe_nr,
 					     unsigned int sector_nr)
 {
-	ASSERT(stripe_nr < rbio->real_stripes);
-	ASSERT(sector_nr < rbio->stripe_nsectors);
+	ASSERT_RBIO_STRIPE(stripe_nr < rbio->real_stripes, rbio, stripe_nr);
+	ASSERT_RBIO_SECTOR(sector_nr < rbio->stripe_nsectors, rbio, sector_nr);
 
 	return stripe_nr * rbio->stripe_nsectors + sector_nr;
 }
@@ -874,8 +922,10 @@  static struct sector_ptr *sector_in_rbio(struct btrfs_raid_bio *rbio,
 	struct sector_ptr *sector;
 	int index;
 
-	ASSERT(stripe_nr >= 0 && stripe_nr < rbio->real_stripes);
-	ASSERT(sector_nr >= 0 && sector_nr < rbio->stripe_nsectors);
+	ASSERT_RBIO_STRIPE(stripe_nr >= 0 && stripe_nr < rbio->real_stripes,
+			   rbio, stripe_nr);
+	ASSERT_RBIO_SECTOR(sector_nr >= 0 && sector_nr < rbio->stripe_nsectors,
+			   rbio, sector_nr);
 
 	index = stripe_nr * rbio->stripe_nsectors + sector_nr;
 	ASSERT(index >= 0 && index < rbio->nr_sectors);
@@ -1058,8 +1108,8 @@  static int rbio_add_io_sector(struct btrfs_raid_bio *rbio,
 	 * thus it can be larger than rbio->real_stripe.
 	 * So here we check against bioc->num_stripes, not rbio->real_stripes.
 	 */
-	ASSERT(stripe_nr >= 0 && stripe_nr < rbio->bioc->num_stripes);
-	ASSERT(sector_nr >= 0 && sector_nr < rbio->stripe_nsectors);
+	ASSERT_RBIO_STRIPE(stripe_nr >= 0 && stripe_nr < rbio->bioc->num_stripes,
+			   rbio, stripe_nr);
 	ASSERT(sector->page);
 
 	stripe = &rbio->bioc->stripes[stripe_nr];
@@ -1198,14 +1248,14 @@  static void assert_rbio(struct btrfs_raid_bio *rbio)
 	 * At least two stripes (2 disks RAID5), and since real_stripes is U8,
 	 * we won't go beyond 256 disks anyway.
 	 */
-	ASSERT(rbio->real_stripes >= 2);
-	ASSERT(rbio->nr_data > 0);
+	ASSERT_RBIO(rbio->real_stripes >= 2, rbio);
+	ASSERT_RBIO(rbio->nr_data > 0, rbio);
 
 	/*
 	 * This is another check to make sure nr data stripes is smaller
 	 * than total stripes.
 	 */
-	ASSERT(rbio->nr_data < rbio->real_stripes);
+	ASSERT_RBIO(rbio->nr_data < rbio->real_stripes, rbio);
 }
 
 /* Generate PQ for one vertical stripe. */
@@ -1642,9 +1692,10 @@  static void rbio_add_bio(struct btrfs_raid_bio *rbio, struct bio *orig_bio)
 	const u32 sectorsize = fs_info->sectorsize;
 	u64 cur_logical;
 
-	ASSERT(orig_logical >= full_stripe_start &&
+	ASSERT_RBIO_LOGICAL(orig_logical >= full_stripe_start &&
 	       orig_logical + orig_len <= full_stripe_start +
-	       rbio->nr_data * BTRFS_STRIPE_LEN);
+	       rbio->nr_data * BTRFS_STRIPE_LEN,
+	       rbio, orig_logical);
 
 	bio_list_add(&rbio->bio_list, orig_bio);
 	rbio->bio_list_bytes += orig_bio->bi_iter.bi_size;
@@ -2390,7 +2441,7 @@  struct btrfs_raid_bio *raid56_parity_alloc_scrub_rbio(struct bio *bio,
 			break;
 		}
 	}
-	ASSERT(i < rbio->real_stripes);
+	ASSERT_RBIO_STRIPE(i < rbio->real_stripes, rbio, i);
 
 	bitmap_copy(&rbio->dbitmap, dbitmap, stripe_nsectors);
 	return rbio;
@@ -2556,7 +2607,7 @@  static int finish_parity_scrub(struct btrfs_raid_bio *rbio)
 	 * Replace is running and our parity stripe needs to be duplicated to
 	 * the target device.  Check we have a valid source stripe number.
 	 */
-	ASSERT(rbio->bioc->replace_stripe_src >= 0);
+	ASSERT_RBIO(rbio->bioc->replace_stripe_src >= 0, rbio);
 	for_each_set_bit(sectornr, pbitmap, rbio->stripe_nsectors) {
 		struct sector_ptr *sector;
 
diff --git a/fs/btrfs/volumes.h b/fs/btrfs/volumes.h
index 66e6fc481ecd..1373721f8e53 100644
--- a/fs/btrfs/volumes.h
+++ b/fs/btrfs/volumes.h
@@ -554,6 +554,26 @@  struct btrfs_io_context {
 	struct btrfs_io_stripe stripes[];
 };
 
+static inline void btrfs_dump_bioc(const struct btrfs_io_context *bioc)
+{
+	if (!IS_ENABLED(CONFIG_BTRFS_ASSERT))
+		return;
+
+	if (unlikely(!bioc)) {
+		pr_err("bioc=NULL\n");
+		return;
+	}
+	pr_info("bioc logical=%llu full_stripe=%llu size=%llu map_type=0x%llx mirror=%u replace_nr_stripes=%u replace_stripe_src=%d num_stripes=%u\n",
+		bioc->logical, bioc->full_stripe_logical, bioc->size,
+		bioc->map_type, bioc->mirror_num, bioc->replace_nr_stripes,
+		bioc->replace_stripe_src, bioc->num_stripes);
+	for (int i = 0; i < bioc->num_stripes; i++) {
+		pr_info("    nr=%d devid=%llu physical=%llu\n",
+			i, bioc->stripes[i].dev->devid,
+			bioc->stripes[i].physical);
+	}
+}
+
 struct btrfs_device_info {
 	struct btrfs_device *dev;
 	u64 dev_offset;