| Message ID | 9841445a77c4721b7f5c92e642f7e1abf8689d8a.1715744555.git.wqu@suse.com (mailing list archive) |
|---|---|
| State | New |
| Headers | show |
| Series | [v2] btrfs: raid56: do extra dumping for CONFIG_BTRFS_ASSERT | expand |
On Wed, May 15, 2024 at 4:44 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: > > BTRFS critical (device dm-3): bioc logical=4598530048 full_stripe=4598530048 size=0 map_type=0x81 mirror=0 replace_nr_stripes=0 replace_stripe_src=-1 num_stripes=5 > BTRFS critical (device dm-3): nr=0 devid=1 physical=1166147584 > BTRFS critical (device dm-3): nr=1 devid=2 physical=1145176064 > BTRFS critical (device dm-3): nr=2 devid=4 physical=1145176064 > BTRFS critical (device dm-3): nr=3 devid=5 physical=1145176064 > BTRFS critical (device dm-3): nr=4 devid=3 physical=1145176064 > BTRFS critical (device dm-3): rbio flags=0x0 nr_sectors=80 nr_data=4 real_stripes=5 stripe_nsectors=16 scrubp=0 dbitmap=0x0 > BTRFS critical (device dm-3): logical=4598530048 > 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 | 113 ++++++++++++++++++++++++++++++++++++++++------ > 1 file changed, 100 insertions(+), 13 deletions(-) > --- > Changelog: > v2: > - Move btrfs_dump_bioc() to raid56.c and remove the "btrfs_" prefix. > - Use parentheses to protect macro parameters > - Add back the accidentally removed assert on @sector_nr inside > rbio_add_io_sector() > - Use btrfs_crit() to output the error messages > For the rare case where rbio->bioc is not yet set, use NULL for > fs_info which is supported for a long time. > > diff --git a/fs/btrfs/raid56.c b/fs/btrfs/raid56.c > index 6f4a9cfeea44..7444faa4b165 100644 > --- a/fs/btrfs/raid56.c > +++ b/fs/btrfs/raid56.c > @@ -40,6 +40,88 @@ > > #define BTRFS_STRIPE_HASH_TABLE_BITS 11 > > +static void dump_bioc(struct btrfs_fs_info *fs_info, fs_info can also be const. > + const struct btrfs_io_context *bioc) > +{ > + if (unlikely(!bioc)) { > + btrfs_crit(fs_info, "bioc=NULL"); > + return; > + } > + btrfs_crit(fs_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", > + 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++) { > + btrfs_crit(fs_info, > + " nr=%d devid=%llu physical=%llu", > + i, bioc->stripes[i].dev->devid, > + bioc->stripes[i].physical); > + } > +} > + > +static void btrfs_dump_rbio(struct btrfs_fs_info *fs_info, Same here. Anyway, these are minor things, you don't need to send another patch version, you can amend that (if you want to) when committing the patch to for-next. So: Reviewed-by: Filipe Manana <fdmanana@suse.com> Thanks. > + const struct btrfs_raid_bio *rbio) > +{ > + if (!IS_ENABLED(CONFIG_BTRFS_ASSERT)) > + return; > + > + dump_bioc(fs_info, rbio->bioc); > + btrfs_crit(fs_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))) { \ > + struct btrfs_fs_info *fs_info = (rbio)->bioc ? \ > + (rbio)->bioc->fs_info : NULL; \ > + \ > + btrfs_dump_rbio(fs_info, (rbio)); \ > + } \ > + ASSERT((expr)); \ > +}) > + > +#define ASSERT_RBIO_STRIPE(expr, rbio, stripe_nr) \ > +({ \ > + if (IS_ENABLED(CONFIG_BTRFS_ASSERT) && unlikely(!(expr))) { \ > + struct btrfs_fs_info *fs_info = (rbio)->bioc ? \ > + (rbio)->bioc->fs_info : NULL; \ > + \ > + btrfs_dump_rbio(fs_info, (rbio)); \ > + btrfs_crit(fs_info, "stripe_nr=%d", (stripe_nr)); \ > + } \ > + ASSERT((expr)); \ > +}) > + > +#define ASSERT_RBIO_SECTOR(expr, rbio, sector_nr) \ > +({ \ > + if (IS_ENABLED(CONFIG_BTRFS_ASSERT) && unlikely(!(expr))) { \ > + struct btrfs_fs_info *fs_info = (rbio)->bioc ? \ > + (rbio)->bioc->fs_info : NULL; \ > + \ > + btrfs_dump_rbio(fs_info, (rbio)); \ > + btrfs_crit(fs_info, "sector_nr=%d", (sector_nr)); \ > + } \ > + ASSERT((expr)); \ > +}) > + > +#define ASSERT_RBIO_LOGICAL(expr, rbio, logical) \ > +({ \ > + if (IS_ENABLED(CONFIG_BTRFS_ASSERT) && unlikely(!(expr))) { \ > + struct btrfs_fs_info *fs_info = (rbio)->bioc ? \ > + (rbio)->bioc->fs_info : NULL; \ > + \ > + btrfs_dump_rbio(fs_info, (rbio)); \ > + btrfs_crit(fs_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 +675,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 +956,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 +1142,10 @@ 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_RBIO_SECTOR(sector_nr >= 0 && sector_nr < rbio->stripe_nsectors, > + rbio, sector_nr); > ASSERT(sector->page); > > stripe = &rbio->bioc->stripes[stripe_nr]; > @@ -1198,14 +1284,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 +1728,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 +2477,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 +2643,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; > > -- > 2.45.0 > >
On Wed, May 15, 2024 at 01:14:01PM +0930, Qu Wenruo 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: > > BTRFS critical (device dm-3): bioc logical=4598530048 full_stripe=4598530048 size=0 map_type=0x81 mirror=0 replace_nr_stripes=0 replace_stripe_src=-1 num_stripes=5 > BTRFS critical (device dm-3): nr=0 devid=1 physical=1166147584 > BTRFS critical (device dm-3): nr=1 devid=2 physical=1145176064 > BTRFS critical (device dm-3): nr=2 devid=4 physical=1145176064 > BTRFS critical (device dm-3): nr=3 devid=5 physical=1145176064 > BTRFS critical (device dm-3): nr=4 devid=3 physical=1145176064 > BTRFS critical (device dm-3): rbio flags=0x0 nr_sectors=80 nr_data=4 real_stripes=5 stripe_nsectors=16 scrubp=0 dbitmap=0x0 > BTRFS critical (device dm-3): logical=4598530048 > 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> Please add the patch to for-next so we can start getting more info from the crashes, thanks.
On Wed, May 15, 2024 at 01:14:01PM +0930, Qu Wenruo 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: > > BTRFS critical (device dm-3): bioc logical=4598530048 full_stripe=4598530048 size=0 map_type=0x81 mirror=0 replace_nr_stripes=0 replace_stripe_src=-1 num_stripes=5 > BTRFS critical (device dm-3): nr=0 devid=1 physical=1166147584 > BTRFS critical (device dm-3): nr=1 devid=2 physical=1145176064 > BTRFS critical (device dm-3): nr=2 devid=4 physical=1145176064 > BTRFS critical (device dm-3): nr=3 devid=5 physical=1145176064 > BTRFS critical (device dm-3): nr=4 devid=3 physical=1145176064 > BTRFS critical (device dm-3): rbio flags=0x0 nr_sectors=80 nr_data=4 real_stripes=5 stripe_nsectors=16 scrubp=0 dbitmap=0x0 > BTRFS critical (device dm-3): logical=4598530048 > 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 For the record I'm posting the logs here too: [ 2612.426259] BTRFS info (device vdb): first mount of filesystem 5a06f8f6-d1c9-40d3-a2b6-edf82f13e058 [ 2612.428963] BTRFS info (device vdb): using crc32c (crc32c-generic) checksum algorithm [ 2612.431148] BTRFS info (device vdb): using free-space-tree [ 2612.447409] BTRFS info (device vdb): checking UUID tree [ 2612.481386] BTRFS info (device vdb): scrub: started on devid 1 [ 2612.490595] BTRFS info (device vdb): scrub: started on devid 5 [ 2612.491050] BTRFS info (device vdb): scrub: started on devid 6 [ 2612.497397] BTRFS info (device vdb): scrub: started on devid 2 [ 2612.505071] BTRFS info (device vdb): scrub: started on devid 3 [ 2612.517931] BTRFS info (device vdb): scrub: started on devid 7 [ 2612.525959] BTRFS info (device vdb): scrub: started on devid 4 [ 2613.261317] BTRFS info (device vdb): dev_replace from /dev/vdc (devid 2) to /dev/vdi started [ 2613.263922] BTRFS critical (device vdb): bioc logical=39780352 full_stripe=36569088 size=0 map_type=0x84 mirror=0 replace_nr_stripes=1 replace_stripe_src=0 num_stripes=8 [ 2613.269062] BTRFS critical (device vdb): nr=0 devid=2 physical=3473408 [ 2613.271803] BTRFS critical (device vdb): nr=1 devid=3 physical=3473408 [ 2613.273624] BTRFS critical (device vdb): nr=2 devid=4 physical=3473408 [ 2613.275409] BTRFS critical (device vdb): nr=3 devid=5 physical=3473408 [ 2613.277037] BTRFS critical (device vdb): nr=4 devid=6 physical=3473408 [ 2613.278717] BTRFS critical (device vdb): nr=5 devid=7 physical=3473408 [ 2613.280298] BTRFS critical (device vdb): nr=6 devid=1 physical=24444928 [ 2613.281886] BTRFS critical (device vdb): nr=7 devid=0 physical=3473408 [ 2613.283633] BTRFS critical (device vdb): rbio flags=0x0 nr_sectors=112 nr_data=6 real_stripes=7 stripe_nsectors=16 scrubp=0 dbitmap=0x0 [ 2613.286665] BTRFS critical (device vdb): logical=39780352 [ 2613.288042] assertion failed: (orig_logical >= full_stripe_start && orig_logical + orig_len <= full_stripe_start + rbio->nr_data * 0x00010000), in fs/btrfs/raid56.c:1731 [ 2613.291839] ------------[ cut here ]------------ [ 2613.293052] kernel BUG at fs/btrfs/raid56.c:1731! [ 2613.294208] invalid opcode: 0000 [#1] PREEMPT SMP KASAN [ 2613.294959] CPU: 0 PID: 17987 Comm: fsstress Not tainted 6.9.0-rc7-default+ #94 [ 2613.294959] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS rel-1.16.2-3-gd478f380-rebuilt.opensuse.org 04/01/2014 [ 2613.294959] RIP: 0010:rbio_add_bio.cold+0x8c/0x1a6 [btrfs] [ 2613.294959] RSP: 0018:ffff888009bb7240 EFLAGS: 00010286 [ 2613.294959] RAX: 000000000000009d RBX: 00000000022e0000 RCX: 0000000000000000 [ 2613.294959] RDX: 000000000000009d RSI: 0000000000000004 RDI: ffffed1001376e3b [ 2613.294959] RBP: ffff88804bf8c000 R08: 0000000000000000 R09: fffffbfff2ea4fcc [ 2613.294959] R10: 0000000000000003 R11: 0000000000000001 R12: 00000000025f0000 [ 2613.294959] R13: ffff888021d8be00 R14: ffff8880075dd2a0 R15: ffff888021d8f400 [ 2613.294959] FS: 00007f8b66d4bb80(0000) GS:ffff888066e00000(0000) knlGS:0000000000000000 [ 2613.294959] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 2613.294959] CR2: 00007f8b66f5c000 CR3: 00000000296a5000 CR4: 00000000000006b0 [ 2613.294959] Call Trace: [ 2613.294959] <TASK> [ 2613.294959] ? show_trace_log_lvl+0x1f3/0x330 [ 2613.294959] ? show_trace_log_lvl+0x1f3/0x330 [ 2613.294959] ? show_trace_log_lvl+0x1f3/0x330 [ 2613.294959] ? raid56_parity_write+0x8d/0x520 [btrfs] [ 2613.294959] ? __die+0x54/0x91 [ 2613.294959] ? die+0x2a/0x50 [ 2613.294959] ? do_trap+0x1b7/0x290 [ 2613.294959] ? rbio_add_bio.cold+0x8c/0x1a6 [btrfs] [ 2613.294959] ? rbio_add_bio.cold+0x8c/0x1a6 [btrfs] [ 2613.294959] ? do_error_trap+0xa3/0x170 [ 2613.294959] ? rbio_add_bio.cold+0x8c/0x1a6 [btrfs] [ 2613.294959] ? handle_invalid_op+0x2c/0x30 [ 2613.294959] ? rbio_add_bio.cold+0x8c/0x1a6 [btrfs] [ 2613.294959] ? exc_invalid_op+0x29/0x40 [ 2613.294959] ? asm_exc_invalid_op+0x16/0x20 [ 2613.294959] ? rbio_add_bio.cold+0x8c/0x1a6 [btrfs] [ 2613.294959] raid56_parity_write+0x8d/0x520 [btrfs] [ 2613.294959] btrfs_submit_chunk+0x444/0x1780 [btrfs] [ 2613.294959] ? btrfs_bio_init+0x100/0x100 [btrfs] [ 2613.294959] ? bio_set_pages_dirty+0x4a0/0x4a0 [ 2613.294959] ? mem_cgroup_css_from_folio+0x97/0x210 [ 2613.294959] ? write_one_eb+0xc34/0x1620 [btrfs] [ 2613.294959] btrfs_submit_bio+0x33/0x70 [btrfs] [ 2613.294959] submit_eb_page+0x3fa/0x520 [btrfs] [ 2613.294959] btree_write_cache_pages+0x337/0x6e0 [btrfs] [ 2613.294959] ? submit_eb_page+0x520/0x520 [btrfs] [ 2613.294959] ? ftrace_ops_trampoline+0x95/0x100 [ 2613.294959] do_writepages+0x163/0x750 [ 2613.294959] ? write_cache_pages+0x100/0x100 [ 2613.294959] ? __lock_acquired+0x200/0x830 [ 2613.294959] ? wbc_attach_and_unlock_inode.part.0+0x339/0x700 [ 2613.294959] ? do_raw_spin_unlock+0x54/0x220 [ 2613.294959] ? _raw_spin_unlock+0x29/0x40 [ 2613.294959] filemap_fdatawrite_wbc+0x10b/0x170 [ 2613.294959] __filemap_fdatawrite_range+0xab/0xf0 [ 2613.294959] ? delete_from_page_cache_batch+0x920/0x920 [ 2613.294959] ? free_extent_state+0x2f/0x3a0 [btrfs] [ 2613.294959] btrfs_write_marked_extents+0x15b/0x250 [btrfs] [ 2613.294959] ? btrfs_end_transaction_throttle+0x10/0x10 [btrfs] [ 2613.294959] ? reacquire_held_locks+0x213/0x4e0 [ 2613.294959] ? btrfs_commit_transaction+0x152c/0x2ee0 [btrfs] [ 2613.294959] btrfs_write_and_wait_transaction+0xfd/0x240 [btrfs] [ 2613.294959] ? btrfs_write_marked_extents+0x250/0x250 [btrfs] [ 2613.294959] ? _raw_spin_unlock_irqrestore+0x48/0x60 [ 2613.294959] ? lockdep_hardirqs_on+0x78/0x100 [ 2613.294959] ? btrfs_commit_transaction+0x15bc/0x2ee0 [btrfs] [ 2613.294959] btrfs_commit_transaction+0x1634/0x2ee0 [btrfs] [ 2613.294959] ? cleanup_transaction+0x170/0x170 [btrfs] [ 2613.294959] ? swake_up_locked+0x1b0/0x1b0 [ 2613.294959] ? preempt_count_add+0x79/0x150 [ 2613.294959] ? __up_write+0x1b3/0x520 [ 2613.294959] btrfs_sync_file+0x6ca/0xb20 [btrfs] [ 2613.294959] ? start_ordered_ops.constprop.0+0xf0/0xf0 [btrfs] [ 2613.294959] __x64_sys_fsync+0x55/0x80 [ 2613.294959] do_syscall_64+0x6e/0x140 [ 2613.294959] entry_SYSCALL_64_after_hwframe+0x4b/0x53 [ 2613.294959] RIP: 0033:0x7f8b66e56314 [ 2613.294959] RSP: 002b:00007ffdff102018 EFLAGS: 00000202 ORIG_RAX: 000000000000004a [ 2613.294959] RAX: ffffffffffffffda RBX: 0000000000000003 RCX: 00007f8b66e56314 [ 2613.294959] RDX: 0000000000000114 RSI: 000000000040f048 RDI: 0000000000000003 [ 2613.294959] RBP: 000000000000004c R08: fefefefefefefeff R09: 00007ffdff10202c [ 2613.294959] R10: 0000000000000000 R11: 0000000000000202 R12: 028f5c28f5c28f5c [ 2613.294959] R13: 8f5c28f5c28f5c29 R14: 000000000040bdc0 R15: 00007f8b66d4bb08 [ 2613.294959] </TASK> [ 2613.294959] Modules linked in: dm_flakey dm_mod btrfs blake2b_generic libcrc32c xor lzo_compress lzo_decompress raid6_pq zstd_decompress zstd_compress xxhash zstd_common loop [ 2613.414623] ---[ end trace 0000000000000000 ]--- [ 2613.415740] RIP: 0010:rbio_add_bio.cold+0x8c/0x1a6 [btrfs] [ 2613.421366] RSP: 0018:ffff888009bb7240 EFLAGS: 00010286 [ 2613.425639] RAX: 000000000000009d RBX: 00000000022e0000 RCX: 0000000000000000 [ 2613.427371] RDX: 000000000000009d RSI: 0000000000000004 RDI: ffffed1001376e3b [ 2613.428968] RBP: ffff88804bf8c000 R08: 0000000000000000 R09: fffffbfff2ea4fcc [ 2613.430627] R10: 0000000000000003 R11: 0000000000000001 R12: 00000000025f0000 [ 2613.432311] R13: ffff888021d8be00 R14: ffff8880075dd2a0 R15: ffff888021d8f400 [ 2613.434015] FS: 00007f8b66d4bb80(0000) GS:ffff888066e00000(0000) knlGS:0000000000000000 [ 2613.436141] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 2613.437544] CR2: 00007f8b66f5c000 CR3: 00000000296a5000 CR4: 00000000000006b0 [ 2613.439333] ------------[ cut here ]------------ [ 2613.440507] WARNING: CPU: 0 PID: 17987 at kernel/exit.c:827 do_exit+0xb5d/0xea0 [ 2613.442304] Modules linked in: dm_flakey dm_mod btrfs blake2b_generic libcrc32c xor lzo_compress lzo_decompress raid6_pq zstd_decompress zstd_compress xxhash zstd_common loop [ 2613.446163] CPU: 0 PID: 17987 Comm: fsstress Tainted: G D 6.9.0-rc7-default+ #94 [ 2613.448460] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS rel-1.16.2-3-gd478f380-rebuilt.opensuse.org 04/01/2014 [ 2613.451166] RIP: 0010:do_exit+0xb5d/0xea0 [ 2613.456647] RSP: 0018:ffff888009bb7e88 EFLAGS: 00010282 [ 2613.457944] RAX: dffffc0000000000 RBX: ffff8880084b9d80 RCX: 0000000000000000 [ 2613.459774] RDX: 1ffff11001097624 RSI: ffffffff96e0fe20 RDI: ffff8880084bb120 [ 2613.461455] RBP: ffff8880028ac640 R08: 0000000000000000 R09: 0000000000000000 [ 2613.463229] R10: ffffffff97d27187 R11: 0000000000000001 R12: ffff8880084ba4d0 [ 2613.464913] R13: ffff8880032ce8c0 R14: ffff8880084ba4c8 R15: 000000000000000b [ 2613.466638] FS: 00007f8b66d4bb80(0000) GS:ffff888066e00000(0000) knlGS:0000000000000000 [ 2613.468592] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 2613.470002] CR2: 00007f8b66f5c000 CR3: 00000000296a5000 CR4: 00000000000006b0 [ 2613.471852] Call Trace: [ 2613.472588] <TASK> [ 2613.473240] ? show_trace_log_lvl+0x1f3/0x330 [ 2613.474396] ? show_trace_log_lvl+0x1f3/0x330 [ 2613.475599] ? show_trace_log_lvl+0x1f3/0x330 [ 2613.476722] ? make_task_dead+0xf3/0x110 [ 2613.477756] ? do_exit+0xb5d/0xea0 [ 2613.478715] ? __warn+0xc8/0x170 [ 2613.479615] ? do_exit+0xb5d/0xea0 [ 2613.480538] ? report_bug+0x1f2/0x3c0 [ 2613.481515] ? handle_bug+0x65/0x90 [ 2613.482507] ? exc_invalid_op+0x13/0x40 [ 2613.483524] ? asm_exc_invalid_op+0x16/0x20 [ 2613.484608] ? do_exit+0xb5d/0xea0 [ 2613.485534] ? do_exit+0x14a/0xea0 [ 2613.486505] ? exit_mm+0x290/0x290 [ 2613.487437] make_task_dead+0xf3/0x110 [ 2613.488429] rewind_stack_and_make_dead+0x16/0x20 [ 2613.489627] RIP: 0033:0x7f8b66e56314 [ 2613.494909] RSP: 002b:00007ffdff102018 EFLAGS: 00000202 ORIG_RAX: 000000000000004a [ 2613.496789] RAX: ffffffffffffffda RBX: 0000000000000003 RCX: 00007f8b66e56314 [ 2613.498513] RDX: 0000000000000114 RSI: 000000000040f048 RDI: 0000000000000003 [ 2613.500221] RBP: 000000000000004c R08: fefefefefefefeff R09: 00007ffdff10202c [ 2613.501904] R10: 0000000000000000 R11: 0000000000000202 R12: 028f5c28f5c28f5c [ 2613.503732] R13: 8f5c28f5c28f5c29 R14: 000000000040bdc0 R15: 00007f8b66d4bb08 [ 2613.505415] </TASK> [ 2613.506097] irq event stamp: 22935 [ 2613.507088] hardirqs last enabled at (22935): [<ffffffff95081954>] do_error_trap+0xe4/0x170 [ 2613.509134] hardirqs last disabled at (22934): [<ffffffff9689b2df>] exc_invalid_op+0x1f/0x40 [ 2613.511236] softirqs last enabled at (22886): [<ffffffff9513d3e0>] handle_softirqs+0x4a0/0x8c0 [ 2613.513345] softirqs last disabled at (22859): [<ffffffff9513e13b>] irq_exit_rcu+0xdb/0x150 [ 2613.515460] ---[ end trace 0000000000000000 ]--- [ 2613.516672] BUG: unable to handle page fault for address: ffffffff968a92ea [ 2613.518298] #PF: supervisor write access in kernel mode [ 2613.518974] #PF: error_code(0x0003) - permissions violation [ 2613.518974] PGD 7c490067 P4D 7c490067 PUD 7c491063 PMD 7b8001a1 [ 2613.518974] Oops: 0003 [#2] PREEMPT SMP KASAN [ 2613.518974] CPU: 0 PID: 17987 Comm: fsstress Tainted: G D W 6.9.0-rc7-default+ #94 [ 2613.518974] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS rel-1.16.2-3-gd478f380-rebuilt.opensuse.org 04/01/2014 [ 2613.518974] RIP: 0010:__blk_flush_plug+0x138/0x4d0 [ 2613.518974] RSP: 0018:ffff888009bb7a08 EFLAGS: 00010246 [ 2613.518974] RAX: 1ffffffff2d1525d RBX: ffff888009bb7a68 RCX: 1ffff11001376f8d [ 2613.518974] RDX: ffff888009bb7bc8 RSI: ffff888009bb7be8 RDI: ffff888009bb7a70 [ 2613.518974] RBP: dffffc0000000000 R08: ffff888009bb7be8 R09: fffffbfff2fa4e30 [ 2613.518974] R10: ffffffff97d27187 R11: ffffffff95003236 R12: ffffffff968a92ea [ 2613.518974] R13: ffff888009bb7a68 R14: 0000000000000001 R15: ffff888009bb7bc8 [ 2613.518974] FS: 0000000000000000(0000) GS:ffff888066e00000(0000) knlGS:0000000000000000 [ 2613.518974] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 2613.518974] CR2: ffffffff968a92ea CR3: 00000000296a5000 CR4: 00000000000006b0 [ 2613.518974] Call Trace: [ 2613.518974] <TASK> [ 2613.518974] ? show_trace_log_lvl+0x1f3/0x330 [ 2613.518974] ? show_trace_log_lvl+0x1f3/0x330 [ 2613.518974] ? show_trace_log_lvl+0x1f3/0x330 [ 2613.518974] ? schedule+0x1a4/0x220 [ 2613.518974] ? __die+0x54/0x91 [ 2613.518974] ? __wait_for_common+0x3da/0x5f0 [ 2613.518974] ? page_fault_oops+0xe1/0x130 [ 2613.518974] ? __wait_for_common+0x3da/0x5f0 [ 2613.518974] ? exc_page_fault+0xa5/0xb0 [ 2613.518974] ? asm_exc_page_fault+0x22/0x30 [ 2613.518974] ? __wait_for_common+0x3da/0x5f0 [ 2613.518974] ? rewind_stack_and_make_dead+0x16/0x20 [ 2613.518974] ? __blk_flush_plug+0x138/0x4d0 [ 2613.518974] ? lock_sync+0x180/0x180 [ 2613.518974] ? blk_start_plug_nr_ios+0x270/0x270 [ 2613.518974] schedule+0x1a4/0x220 [ 2613.518974] schedule_timeout+0x25e/0x3d0 [ 2613.518974] ? usleep_range_state+0x170/0x170 [ 2613.518974] ? rcu_is_watching+0xe/0xb0 [ 2613.518974] __wait_for_common+0x3da/0x5f0 [ 2613.518974] ? usleep_range_state+0x170/0x170 [ 2613.518974] ? out_of_line_wait_on_bit_timeout+0x170/0x170 [ 2613.518974] ? trace_irq_enable.constprop.0+0x40/0x100 [ 2613.518974] ? _raw_spin_unlock_irqrestore+0x35/0x60 [ 2613.518974] ? kill_ioctx+0x1dd/0x2a0 [ 2613.518974] exit_aio+0x2e5/0x360 [ 2613.518974] ? __mutex_unlock_slowpath+0x16c/0x630 [ 2613.518974] ? aio_poll_complete_work+0xa80/0xa80 [ 2613.518974] mmput+0xa8/0x3b0 [ 2613.518974] exit_mm+0x1d3/0x290 [ 2613.518974] do_exit+0x6c9/0xea0 [ 2613.518974] ? exit_mm+0x290/0x290 [ 2613.518974] make_task_dead+0xf3/0x110 [ 2613.518974] rewind_stack_and_make_dead+0x16/0x20 [ 2613.518974] RIP: 0033:0x7f8b66e56314 [ 2613.518974] Code: Unable to access opcode bytes at 0x7f8b66e562ea. [ 2613.518974] RSP: 002b:00007ffdff102018 EFLAGS: 00000202 ORIG_RAX: 000000000000004a [ 2613.518974] RAX: ffffffffffffffda RBX: 0000000000000003 RCX: 00007f8b66e56314 [ 2613.518974] RDX: 0000000000000114 RSI: 000000000040f048 RDI: 0000000000000003 [ 2613.518974] RBP: 000000000000004c R08: fefefefefefefeff R09: 00007ffdff10202c [ 2613.518974] R10: 0000000000000000 R11: 0000000000000202 R12: 028f5c28f5c28f5c [ 2613.518974] R13: 8f5c28f5c28f5c29 R14: 000000000040bdc0 R15: 00007f8b66d4bb08 [ 2613.518974] </TASK> [ 2613.518974] Modules linked in: dm_flakey dm_mod btrfs blake2b_generic libcrc32c xor lzo_compress lzo_decompress raid6_pq zstd_decompress zstd_compress xxhash zstd_common loop [ 2613.518974] CR2: ffffffff968a92ea [ 2613.518974] ---[ end trace 0000000000000000 ]--- [ 2613.518974] RIP: 0010:rbio_add_bio.cold+0x8c/0x1a6 [btrfs] [ 2613.518974] RSP: 0018:ffff888009bb7240 EFLAGS: 00010286 [ 2613.518974] RAX: 000000000000009d RBX: 00000000022e0000 RCX: 0000000000000000 [ 2613.518974] RDX: 000000000000009d RSI: 0000000000000004 RDI: ffffed1001376e3b [ 2613.518974] RBP: ffff88804bf8c000 R08: 0000000000000000 R09: fffffbfff2ea4fcc [ 2613.518974] R10: 0000000000000003 R11: 0000000000000001 R12: 00000000025f0000 [ 2613.518974] R13: ffff888021d8be00 R14: ffff8880075dd2a0 R15: ffff888021d8f400 [ 2613.518974] FS: 0000000000000000(0000) GS:ffff888066e00000(0000) knlGS:0000000000000000 [ 2613.518974] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 2613.518974] CR2: ffffffff968a92ea CR3: 00000000296a5000 CR4: 00000000000006b0 [ 2613.518974] note: fsstress[17987] exited with irqs disabled [ 2613.629176] Fixing recursive fault but reboot is needed! [ 2613.630531] BUG: using smp_processor_id() in preemptible [00000000] code: fsstress/17987 [ 2613.632503] caller is __schedule+0xb3/0x1db0 [ 2613.633605] CPU: 0 PID: 17987 Comm: fsstress Tainted: G D W 6.9.0-rc7-default+ #94 [ 2613.634517] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS rel-1.16.2-3-gd478f380-rebuilt.opensuse.org 04/01/2014 [ 2613.634517] Call Trace: [ 2613.634517] <TASK> [ 2613.634517] dump_stack_lvl+0x61/0x80 [ 2613.634517] ? __wait_for_common+0x3da/0x5f0 [ 2613.634517] check_preemption_disabled+0xd7/0xe0 [ 2613.634517] ? do_task_dead+0x46/0x110 [ 2613.634517] __schedule+0xb3/0x1db0 [ 2613.634517] ? lock_acquire+0x392/0x520 [ 2613.634517] ? lock_sync+0x180/0x180 [ 2613.634517] ? vprintk_emit+0x14b/0x220 [ 2613.634517] ? io_schedule_timeout+0x160/0x160 [ 2613.634517] ? do_raw_spin_lock+0x270/0x270 [ 2613.634517] ? freeze_kernel_threads+0x70/0x70 [ 2613.634517] ? do_task_dead+0x46/0x110 [ 2613.634517] ? rcu_is_watching+0xe/0xb0 [ 2613.634517] ? do_task_dead+0x46/0x110 [ 2613.634517] ? __wait_for_common+0x3da/0x5f0 [ 2613.634517] do_task_dead+0xdc/0x110 [ 2613.634517] make_task_dead.cold+0x14e/0x178 [ 2613.634517] rewind_stack_and_make_dead+0x16/0x20 [ 2613.634517] RIP: 0033:0x7f8b66e56314 [ 2613.634517] Code: Unable to access opcode bytes at 0x7f8b66e562ea. [ 2613.634517] RSP: 002b:00007ffdff102018 EFLAGS: 00000202 ORIG_RAX: 000000000000004a [ 2613.634517] RAX: ffffffffffffffda RBX: 0000000000000003 RCX: 00007f8b66e56314 [ 2613.634517] RDX: 0000000000000114 RSI: 000000000040f048 RDI: 0000000000000003 [ 2613.634517] RBP: 000000000000004c R08: fefefefefefefeff R09: 00007ffdff10202c [ 2613.634517] R10: 0000000000000000 R11: 0000000000000202 R12: 028f5c28f5c28f5c [ 2613.634517] R13: 8f5c28f5c28f5c29 R14: 000000000040bdc0 R15: 00007f8b66d4bb08 [ 2613.634517] </TASK> [ 2613.675576] BUG: scheduling while atomic: fsstress/17987/0x00000000 [ 2613.677100] INFO: lockdep is turned off. [ 2613.678119] Modules linked in: dm_flakey dm_mod btrfs blake2b_generic libcrc32c xor lzo_compress lzo_decompress raid6_pq zstd_decompress zstd_compress xxhash zstd_common loop [ 2613.681958] Preemption disabled at: [ 2613.681960] [<0000000000000000>] 0x0 [ 2613.683934] CPU: 0 PID: 17987 Comm: fsstress Tainted: G D W 6.9.0-rc7-default+ #94 [ 2613.686052] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS rel-1.16.2-3-gd478f380-rebuilt.opensuse.org 04/01/2014 [ 2613.686681] Call Trace: [ 2613.686681] <TASK> [ 2613.686681] dump_stack_lvl+0x61/0x80 [ 2613.686681] __schedule_bug.cold+0xce/0xf4 [ 2613.686681] schedule_debug+0x1b7/0x210 [ 2613.686681] __schedule+0x129/0x1db0 [ 2613.686681] ? lock_acquire+0x392/0x520 [ 2613.686681] ? vprintk_emit+0x14b/0x220 [ 2613.686681] ? io_schedule_timeout+0x160/0x160 [ 2613.686681] ? do_raw_spin_lock+0x270/0x270 [ 2613.686681] ? freeze_kernel_threads+0x70/0x70 [ 2613.686681] ? do_task_dead+0x46/0x110 [ 2613.686681] ? rcu_is_watching+0xe/0xb0 [ 2613.686681] ? do_task_dead+0x46/0x110 [ 2613.686681] ? __wait_for_common+0x3da/0x5f0 [ 2613.686681] do_task_dead+0xdc/0x110 [ 2613.686681] make_task_dead.cold+0x14e/0x178 [ 2613.686681] rewind_stack_and_make_dead+0x16/0x20 [ 2613.686681] RIP: 0033:0x7f8b66e56314 [ 2613.686681] Code: Unable to access opcode bytes at 0x7f8b66e562ea. [ 2613.686681] RSP: 002b:00007ffdff102018 EFLAGS: 00000202 ORIG_RAX: 000000000000004a [ 2613.686681] RAX: ffffffffffffffda RBX: 0000000000000003 RCX: 00007f8b66e56314 [ 2613.686681] RDX: 0000000000000114 RSI: 000000000040f048 RDI: 0000000000000003 [ 2613.686681] RBP: 000000000000004c R08: fefefefefefefeff R09: 00007ffdff10202c [ 2613.686681] R10: 0000000000000000 R11: 0000000000000202 R12: 028f5c28f5c28f5c [ 2613.686681] R13: 8f5c28f5c28f5c29 R14: 000000000040bdc0 R15: 00007f8b66d4bb08 [ 2613.686681] </TASK> [ 2613.758407] ================================================================== [ 2613.760215] BUG: KASAN: use-after-free in free_ioctx_reqs+0x48/0x1c0 [ 2613.761736] Write of size 4 at addr ffff888009bb7db0 by task swapper/0/0 [ 2613.762383] [ 2613.762383] CPU: 0 PID: 0 Comm: swapper/0 Tainted: G D W 6.9.0-rc7-default+ #94 [ 2613.762383] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS rel-1.16.2-3-gd478f380-rebuilt.opensuse.org 04/01/2014 [ 2613.762383] Call Trace: [ 2613.762383] <IRQ> [ 2613.762383] dump_stack_lvl+0x61/0x80 [ 2613.762383] print_address_description.constprop.0+0x5e/0x2f0 [ 2613.762383] ? free_ioctx_reqs+0x48/0x1c0 [ 2613.762383] print_report+0x118/0x216 [ 2613.762383] ? __virt_addr_valid+0x19b/0x3a0 [ 2613.762383] ? free_ioctx_reqs+0x48/0x1c0 [ 2613.762383] kasan_report+0x11d/0x1f0 [ 2613.762383] ? free_ioctx_reqs+0x48/0x1c0 [ 2613.762383] kasan_check_range+0xec/0x190 [ 2613.762383] free_ioctx_reqs+0x48/0x1c0 [ 2613.762383] percpu_ref_put_many.constprop.0+0x197/0x1d0 [ 2613.762383] ? rcu_do_batch+0x35a/0xb80 [ 2613.762383] rcu_do_batch+0x35c/0xb80 [ 2613.762383] ? rcu_preempt_ctxt_queue+0x1450/0x1450 [ 2613.762383] ? trace_irq_enable.constprop.0+0x40/0x100 [ 2613.762383] ? _raw_spin_unlock_irqrestore+0x35/0x60 [ 2613.762383] rcu_core+0x29c/0x4d0 [ 2613.762383] handle_softirqs+0x20b/0x8c0 [ 2613.762383] ? _local_bh_enable+0xa0/0xa0 [ 2613.762383] ? sched_clock_tick+0x11c/0x270 [ 2613.762383] irq_exit_rcu+0xdb/0x150 [ 2613.762383] sysvec_apic_timer_interrupt+0x8a/0xb0 [ 2613.762383] </IRQ> [ 2613.762383] <TASK> [ 2613.762383] asm_sysvec_apic_timer_interrupt+0x16/0x20 [ 2613.762383] RIP: 0010:default_idle+0x13/0x20 [ 2613.762383] RSP: 0018:ffffffff97407e20 EFLAGS: 00000246 [ 2613.762383] RAX: 0000000000000000 RBX: 0000000000000000 RCX: ffffffff9689da47 [ 2613.762383] RDX: ffffed100cdff581 RSI: ffffffff96e0fe20 RDI: ffffffff9522cb8f [ 2613.762383] RBP: 0000000000000000 R08: 0000000000000000 R09: ffffed100cdff580 [ 2613.762383] R10: ffff888066ffac03 R11: 0000000000000000 R12: 1ffffffff2e80fc6 [ 2613.762383] R13: ffffffff9741bd80 R14: dffffc0000000000 R15: 0000000000013d10 [ 2613.762383] ? ct_kernel_exit.constprop.0+0xe7/0x130 [ 2613.762383] ? cpuidle_idle_call+0x1bf/0x1e0 [ 2613.762383] default_idle_call+0x67/0xa0 [ 2613.762383] cpuidle_idle_call+0x1bf/0x1e0 [ 2613.762383] ? arch_cpu_idle_exit+0x30/0x30 [ 2613.762383] ? mark_tsc_async_resets+0x30/0x30 [ 2613.762383] ? rcu_is_watching+0xe/0xb0 [ 2613.762383] do_idle+0xe2/0x140 [ 2613.762383] cpu_startup_entry+0x50/0x60 [ 2613.762383] rest_init+0x1f6/0x200 [ 2613.762383] start_kernel+0x2f8/0x300 [ 2613.762383] x86_64_start_reservations+0x20/0x20 [ 2613.762383] x86_64_start_kernel+0x76/0x80 [ 2613.762383] common_startup_64+0x129/0x138 [ 2613.762383] </TASK> [ 2613.762383] [ 2613.762383] The buggy address belongs to the physical page: [ 2613.762383] page: refcount:0 mapcount:0 mapping:0000000000000000 index:0x0 pfn:0x9bb7 [ 2613.762383] flags: 0x280000000000(section=1|zone=1) [ 2613.762383] page_type: 0xffffffff() [ 2613.762383] raw: 0000280000000000 0000000000000000 dead000000000122 0000000000000000 [ 2613.762383] raw: 0000000000000000 0000000000000000 00000000ffffffff 0000000000000000 [ 2613.762383] page dumped because: kasan: bad access detected [ 2613.762383] [ 2613.762383] Memory state around the buggy address: [ 2613.762383] ffff888009bb7c80: ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff [ 2613.762383] ffff888009bb7d00: ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff [ 2613.762383] >ffff888009bb7d80: ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff [ 2613.762383] ^ [ 2613.762383] ffff888009bb7e00: ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff [ 2613.762383] ffff888009bb7e80: ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff [ 2613.762383] ==================================================================
diff --git a/fs/btrfs/raid56.c b/fs/btrfs/raid56.c index 6f4a9cfeea44..7444faa4b165 100644 --- a/fs/btrfs/raid56.c +++ b/fs/btrfs/raid56.c @@ -40,6 +40,88 @@ #define BTRFS_STRIPE_HASH_TABLE_BITS 11 +static void dump_bioc(struct btrfs_fs_info *fs_info, + const struct btrfs_io_context *bioc) +{ + if (unlikely(!bioc)) { + btrfs_crit(fs_info, "bioc=NULL"); + return; + } + btrfs_crit(fs_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", + 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++) { + btrfs_crit(fs_info, + " nr=%d devid=%llu physical=%llu", + i, bioc->stripes[i].dev->devid, + bioc->stripes[i].physical); + } +} + +static void btrfs_dump_rbio(struct btrfs_fs_info *fs_info, + const struct btrfs_raid_bio *rbio) +{ + if (!IS_ENABLED(CONFIG_BTRFS_ASSERT)) + return; + + dump_bioc(fs_info, rbio->bioc); + btrfs_crit(fs_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))) { \ + struct btrfs_fs_info *fs_info = (rbio)->bioc ? \ + (rbio)->bioc->fs_info : NULL; \ + \ + btrfs_dump_rbio(fs_info, (rbio)); \ + } \ + ASSERT((expr)); \ +}) + +#define ASSERT_RBIO_STRIPE(expr, rbio, stripe_nr) \ +({ \ + if (IS_ENABLED(CONFIG_BTRFS_ASSERT) && unlikely(!(expr))) { \ + struct btrfs_fs_info *fs_info = (rbio)->bioc ? \ + (rbio)->bioc->fs_info : NULL; \ + \ + btrfs_dump_rbio(fs_info, (rbio)); \ + btrfs_crit(fs_info, "stripe_nr=%d", (stripe_nr)); \ + } \ + ASSERT((expr)); \ +}) + +#define ASSERT_RBIO_SECTOR(expr, rbio, sector_nr) \ +({ \ + if (IS_ENABLED(CONFIG_BTRFS_ASSERT) && unlikely(!(expr))) { \ + struct btrfs_fs_info *fs_info = (rbio)->bioc ? \ + (rbio)->bioc->fs_info : NULL; \ + \ + btrfs_dump_rbio(fs_info, (rbio)); \ + btrfs_crit(fs_info, "sector_nr=%d", (sector_nr)); \ + } \ + ASSERT((expr)); \ +}) + +#define ASSERT_RBIO_LOGICAL(expr, rbio, logical) \ +({ \ + if (IS_ENABLED(CONFIG_BTRFS_ASSERT) && unlikely(!(expr))) { \ + struct btrfs_fs_info *fs_info = (rbio)->bioc ? \ + (rbio)->bioc->fs_info : NULL; \ + \ + btrfs_dump_rbio(fs_info, (rbio)); \ + btrfs_crit(fs_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 +675,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 +956,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 +1142,10 @@ 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_RBIO_SECTOR(sector_nr >= 0 && sector_nr < rbio->stripe_nsectors, + rbio, sector_nr); ASSERT(sector->page); stripe = &rbio->bioc->stripes[stripe_nr]; @@ -1198,14 +1284,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 +1728,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 +2477,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 +2643,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;
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: BTRFS critical (device dm-3): bioc logical=4598530048 full_stripe=4598530048 size=0 map_type=0x81 mirror=0 replace_nr_stripes=0 replace_stripe_src=-1 num_stripes=5 BTRFS critical (device dm-3): nr=0 devid=1 physical=1166147584 BTRFS critical (device dm-3): nr=1 devid=2 physical=1145176064 BTRFS critical (device dm-3): nr=2 devid=4 physical=1145176064 BTRFS critical (device dm-3): nr=3 devid=5 physical=1145176064 BTRFS critical (device dm-3): nr=4 devid=3 physical=1145176064 BTRFS critical (device dm-3): rbio flags=0x0 nr_sectors=80 nr_data=4 real_stripes=5 stripe_nsectors=16 scrubp=0 dbitmap=0x0 BTRFS critical (device dm-3): logical=4598530048 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 | 113 ++++++++++++++++++++++++++++++++++++++++------ 1 file changed, 100 insertions(+), 13 deletions(-) --- Changelog: v2: - Move btrfs_dump_bioc() to raid56.c and remove the "btrfs_" prefix. - Use parentheses to protect macro parameters - Add back the accidentally removed assert on @sector_nr inside rbio_add_io_sector() - Use btrfs_crit() to output the error messages For the rare case where rbio->bioc is not yet set, use NULL for fs_info which is supported for a long time.