From b8bea09a456fc31af8f10029e69d105cac7e530e Mon Sep 17 00:00:00 2001 From: Qu Wenruo Date: Wed, 1 Jun 2022 17:46:59 +0800 Subject: btrfs: add trace event for submitted RAID56 bio Add tracepoint for better insight to how the RAID56 data are submitted. The output looks like this: (trace event header and UUID skipped) raid56_read_partial: full_stripe=389152768 devid=3 type=DATA1 offset=32768 opf=0x0 physical=323059712 len=32768 raid56_read_partial: full_stripe=389152768 devid=1 type=DATA2 offset=0 opf=0x0 physical=67174400 len=65536 raid56_write_stripe: full_stripe=389152768 devid=3 type=DATA1 offset=0 opf=0x1 physical=323026944 len=32768 raid56_write_stripe: full_stripe=389152768 devid=2 type=PQ1 offset=0 opf=0x1 physical=323026944 len=32768 The above debug output is from a 32K data write into an empty RAID56 data chunk. Some explanation on the event output: full_stripe: the logical bytenr of the full stripe devid: btrfs devid type: raid stripe type. DATA1: the first data stripe DATA2: the second data stripe PQ1: the P stripe PQ2: the Q stripe offset: the offset inside the stripe. opf: the bio op type physical: the physical offset the bio is for len: the length of the bio The first two lines are from partial RMW read, which is reading the remaining data stripes from disks. The last two lines are for full stripe RMW write, which is writing the involved two 16K stripes (one for DATA1 stripe, one for P stripe). The stripe for DATA2 doesn't need to be written. There are 5 types of trace events: - raid56_read_partial Read remaining data for regular read/write path. - raid56_write_stripe Write the modified stripes for regular read/write path. - raid56_scrub_read_recover Read remaining data for scrub recovery path. - raid56_scrub_write_stripe Write the modified stripes for scrub path. - raid56_scrub_read Read remaining data for scrub path. Also, since the trace events are included at super.c, we have to export needed structure definitions to 'raid56.h' and include the header in super.c, or we're unable to access those members. Signed-off-by: Qu Wenruo Reviewed-by: David Sterba [ reformat comments ] Signed-off-by: David Sterba --- include/trace/events/btrfs.h | 94 ++++++++++++++++++++++++++++++++++++++++++++ 1 file changed, 94 insertions(+) (limited to 'include/trace') diff --git a/include/trace/events/btrfs.h b/include/trace/events/btrfs.h index 9ae94ef3e270..29fa8ea2cc0f 100644 --- a/include/trace/events/btrfs.h +++ b/include/trace/events/btrfs.h @@ -30,6 +30,8 @@ struct btrfs_qgroup; struct extent_io_tree; struct prelim_ref; struct btrfs_space_info; +struct btrfs_raid_bio; +struct raid56_bio_trace_info; #define show_ref_type(type) \ __print_symbolic(type, \ @@ -2258,6 +2260,98 @@ DEFINE_EVENT(btrfs__space_info_update, update_bytes_pinned, TP_ARGS(fs_info, sinfo, old, diff) ); +DECLARE_EVENT_CLASS(btrfs_raid56_bio, + + TP_PROTO(const struct btrfs_raid_bio *rbio, + const struct bio *bio, + const struct raid56_bio_trace_info *trace_info), + + TP_ARGS(rbio, bio, trace_info), + + TP_STRUCT__entry_btrfs( + __field( u64, full_stripe ) + __field( u64, physical ) + __field( u64, devid ) + __field( u32, offset ) + __field( u32, len ) + __field( u8, opf ) + __field( u8, total_stripes ) + __field( u8, real_stripes ) + __field( u8, nr_data ) + __field( u8, stripe_nr ) + ), + + TP_fast_assign_btrfs(rbio->bioc->fs_info, + __entry->full_stripe = rbio->bioc->raid_map[0]; + __entry->physical = bio->bi_iter.bi_sector << SECTOR_SHIFT; + __entry->len = bio->bi_iter.bi_size; + __entry->opf = bio_op(bio); + __entry->devid = trace_info->devid; + __entry->offset = trace_info->offset; + __entry->stripe_nr = trace_info->stripe_nr; + __entry->total_stripes = rbio->bioc->num_stripes; + __entry->real_stripes = rbio->real_stripes; + __entry->nr_data = rbio->nr_data; + ), + /* + * For type output, we need to output things like "DATA1" + * (the first data stripe), "DATA2" (the second data stripe), + * "PQ1" (P stripe),"PQ2" (Q stripe), "REPLACE0" (replace target device). + */ + TP_printk_btrfs( +"full_stripe=%llu devid=%lld type=%s%d offset=%d opf=0x%x physical=%llu len=%u", + __entry->full_stripe, __entry->devid, + (__entry->stripe_nr < __entry->nr_data) ? "DATA" : + ((__entry->stripe_nr < __entry->real_stripes) ? "PQ" : + "REPLACE"), + (__entry->stripe_nr < __entry->nr_data) ? + (__entry->stripe_nr + 1) : + ((__entry->stripe_nr < __entry->real_stripes) ? + (__entry->stripe_nr - __entry->nr_data + 1) : 0), + __entry->offset, __entry->opf, __entry->physical, __entry->len) +); + +DEFINE_EVENT(btrfs_raid56_bio, raid56_read_partial, + TP_PROTO(const struct btrfs_raid_bio *rbio, + const struct bio *bio, + const struct raid56_bio_trace_info *trace_info), + + TP_ARGS(rbio, bio, trace_info) +); + +DEFINE_EVENT(btrfs_raid56_bio, raid56_write_stripe, + TP_PROTO(const struct btrfs_raid_bio *rbio, + const struct bio *bio, + const struct raid56_bio_trace_info *trace_info), + + TP_ARGS(rbio, bio, trace_info) +); + + +DEFINE_EVENT(btrfs_raid56_bio, raid56_scrub_write_stripe, + TP_PROTO(const struct btrfs_raid_bio *rbio, + const struct bio *bio, + const struct raid56_bio_trace_info *trace_info), + + TP_ARGS(rbio, bio, trace_info) +); + +DEFINE_EVENT(btrfs_raid56_bio, raid56_scrub_read, + TP_PROTO(const struct btrfs_raid_bio *rbio, + const struct bio *bio, + const struct raid56_bio_trace_info *trace_info), + + TP_ARGS(rbio, bio, trace_info) +); + +DEFINE_EVENT(btrfs_raid56_bio, raid56_scrub_read_recover, + TP_PROTO(const struct btrfs_raid_bio *rbio, + const struct bio *bio, + const struct raid56_bio_trace_info *trace_info), + + TP_ARGS(rbio, bio, trace_info) +); + #endif /* _TRACE_BTRFS_H */ /* This part must be outside protection */ -- cgit v1.2.3 From 5bea2508811ec76105b01c90c1f1661024c257a9 Mon Sep 17 00:00:00 2001 From: Johannes Thumshirn Date: Thu, 9 Jun 2022 09:28:04 -0700 Subject: btrfs: add tracepoints for ordered extents When debugging a reference counting issue with ordered extents, I've found we're lacking a lot of tracepoint coverage in the ordered extent code. Close these gaps by adding tracepoints after every refcount_inc() in the ordered extent code. Reviewed-by: Boris Burkov Reviewed-by: Qu Wenruo Reviewed-by: Anand Jain Signed-off-by: Johannes Thumshirn Reviewed-by: David Sterba Signed-off-by: David Sterba --- fs/btrfs/ordered-data.c | 19 ++++++++++--- include/trace/events/btrfs.h | 64 ++++++++++++++++++++++++++++++++++++++++++++ 2 files changed, 80 insertions(+), 3 deletions(-) (limited to 'include/trace') diff --git a/fs/btrfs/ordered-data.c b/fs/btrfs/ordered-data.c index dc88d2b3721f..41b3bc44c92b 100644 --- a/fs/btrfs/ordered-data.c +++ b/fs/btrfs/ordered-data.c @@ -401,6 +401,7 @@ void btrfs_mark_ordered_io_finished(struct btrfs_inode *inode, set_bit(BTRFS_ORDERED_IO_DONE, &entry->flags); cond_wake_up(&entry->wait); refcount_inc(&entry->refs); + trace_btrfs_ordered_extent_mark_finished(inode, entry); spin_unlock_irqrestore(&tree->lock, flags); btrfs_init_work(&entry->work, finish_func, NULL, NULL); btrfs_queue_work(wq, &entry->work); @@ -473,6 +474,7 @@ out: if (finished && cached && entry) { *cached = entry; refcount_inc(&entry->refs); + trace_btrfs_ordered_extent_dec_test_pending(inode, entry); } spin_unlock_irqrestore(&tree->lock, flags); return finished; @@ -807,8 +809,10 @@ struct btrfs_ordered_extent *btrfs_lookup_ordered_extent(struct btrfs_inode *ino entry = rb_entry(node, struct btrfs_ordered_extent, rb_node); if (!in_range(file_offset, entry->file_offset, entry->num_bytes)) entry = NULL; - if (entry) + if (entry) { refcount_inc(&entry->refs); + trace_btrfs_ordered_extent_lookup(inode, entry); + } out: spin_unlock_irqrestore(&tree->lock, flags); return entry; @@ -848,8 +852,10 @@ struct btrfs_ordered_extent *btrfs_lookup_ordered_range( break; } out: - if (entry) + if (entry) { refcount_inc(&entry->refs); + trace_btrfs_ordered_extent_lookup_range(inode, entry); + } spin_unlock_irq(&tree->lock); return entry; } @@ -878,6 +884,7 @@ void btrfs_get_ordered_extents_for_logging(struct btrfs_inode *inode, ASSERT(list_empty(&ordered->log_list)); list_add_tail(&ordered->log_list, list); refcount_inc(&ordered->refs); + trace_btrfs_ordered_extent_lookup_for_logging(inode, ordered); } spin_unlock_irq(&tree->lock); } @@ -901,6 +908,7 @@ btrfs_lookup_first_ordered_extent(struct btrfs_inode *inode, u64 file_offset) entry = rb_entry(node, struct btrfs_ordered_extent, rb_node); refcount_inc(&entry->refs); + trace_btrfs_ordered_extent_lookup_first(inode, entry); out: spin_unlock_irq(&tree->lock); return entry; @@ -975,8 +983,11 @@ struct btrfs_ordered_extent *btrfs_lookup_first_ordered_range( /* No ordered extent in the range */ entry = NULL; out: - if (entry) + if (entry) { refcount_inc(&entry->refs); + trace_btrfs_ordered_extent_lookup_first_range(inode, entry); + } + spin_unlock_irq(&tree->lock); return entry; } @@ -1055,6 +1066,8 @@ int btrfs_split_ordered_extent(struct btrfs_ordered_extent *ordered, u64 pre, struct btrfs_fs_info *fs_info = btrfs_sb(inode->i_sb); int ret = 0; + trace_btrfs_ordered_extent_split(BTRFS_I(inode), ordered); + spin_lock_irq(&tree->lock); /* Remove from tree once */ node = &ordered->rb_node; diff --git a/include/trace/events/btrfs.h b/include/trace/events/btrfs.h index 29fa8ea2cc0f..73df80d462dc 100644 --- a/include/trace/events/btrfs.h +++ b/include/trace/events/btrfs.h @@ -598,6 +598,70 @@ DEFINE_EVENT(btrfs__ordered_extent, btrfs_ordered_extent_put, TP_ARGS(inode, ordered) ); +DEFINE_EVENT(btrfs__ordered_extent, btrfs_ordered_extent_lookup, + + TP_PROTO(const struct btrfs_inode *inode, + const struct btrfs_ordered_extent *ordered), + + TP_ARGS(inode, ordered) +); + +DEFINE_EVENT(btrfs__ordered_extent, btrfs_ordered_extent_lookup_range, + + TP_PROTO(const struct btrfs_inode *inode, + const struct btrfs_ordered_extent *ordered), + + TP_ARGS(inode, ordered) +); + +DEFINE_EVENT(btrfs__ordered_extent, btrfs_ordered_extent_lookup_first_range, + + TP_PROTO(const struct btrfs_inode *inode, + const struct btrfs_ordered_extent *ordered), + + TP_ARGS(inode, ordered) +); + +DEFINE_EVENT(btrfs__ordered_extent, btrfs_ordered_extent_lookup_for_logging, + + TP_PROTO(const struct btrfs_inode *inode, + const struct btrfs_ordered_extent *ordered), + + TP_ARGS(inode, ordered) +); + +DEFINE_EVENT(btrfs__ordered_extent, btrfs_ordered_extent_lookup_first, + + TP_PROTO(const struct btrfs_inode *inode, + const struct btrfs_ordered_extent *ordered), + + TP_ARGS(inode, ordered) +); + +DEFINE_EVENT(btrfs__ordered_extent, btrfs_ordered_extent_split, + + TP_PROTO(const struct btrfs_inode *inode, + const struct btrfs_ordered_extent *ordered), + + TP_ARGS(inode, ordered) +); + +DEFINE_EVENT(btrfs__ordered_extent, btrfs_ordered_extent_dec_test_pending, + + TP_PROTO(const struct btrfs_inode *inode, + const struct btrfs_ordered_extent *ordered), + + TP_ARGS(inode, ordered) +); + +DEFINE_EVENT(btrfs__ordered_extent, btrfs_ordered_extent_mark_finished, + + TP_PROTO(const struct btrfs_inode *inode, + const struct btrfs_ordered_extent *ordered), + + TP_ARGS(inode, ordered) +); + DECLARE_EVENT_CLASS(btrfs__writepage, TP_PROTO(const struct page *page, const struct inode *inode, -- cgit v1.2.3