From b82651b4a4dfe5659a2472e2f6b9646aa23cd8c2 Mon Sep 17 00:00:00 2001 From: Qu Wenruo Date: Mon, 15 Apr 2019 21:15:24 +0800 Subject: [PATCH] btrfs: trace: Introduce trace events for sleepable tree lock There are two tree lock events which can sleep: - btrfs_tree_read_lock() - btrfs_tree_lock() Sometimes we may need to look into the concurrency picture of the fs. For that case, we need the execution time of above two functions and the owner of @eb. Here we introduce a trace events for user space tools like bcc, to get the execution time of above two functions, and get detailed owner info where eBPF code can't. All the overhead is hidden behind the trace events, so if events are not enabled, there is no overhead. These trace events also output bytenr and generation, allow them to be pared with unlock events to pin down deadlock. Signed-off-by: Qu Wenruo Reviewed-by: David Sterba Signed-off-by: David Sterba --- fs/btrfs/locking.c | 12 ++++++++++ include/trace/events/btrfs.h | 44 ++++++++++++++++++++++++++++++++++++ 2 files changed, 56 insertions(+) diff --git a/fs/btrfs/locking.c b/fs/btrfs/locking.c index 6df03ba360266..67b77f1d113ed 100644 --- a/fs/btrfs/locking.c +++ b/fs/btrfs/locking.c @@ -158,6 +158,10 @@ void btrfs_clear_lock_blocking_write(struct extent_buffer *eb) */ void btrfs_tree_read_lock(struct extent_buffer *eb) { + u64 start_ns = 0; + + if (trace_btrfs_tree_read_lock_enabled()) + start_ns = ktime_get_ns(); again: BUG_ON(!atomic_read(&eb->blocking_writers) && current->pid == eb->lock_owner); @@ -174,6 +178,7 @@ again: BUG_ON(eb->lock_nested); eb->lock_nested = true; read_unlock(&eb->lock); + trace_btrfs_tree_read_lock(eb, start_ns); return; } if (atomic_read(&eb->blocking_writers)) { @@ -184,6 +189,7 @@ again: } btrfs_assert_tree_read_locks_get(eb); btrfs_assert_spinning_readers_get(eb); + trace_btrfs_tree_read_lock(eb, start_ns); } /* @@ -299,6 +305,11 @@ void btrfs_tree_read_unlock_blocking(struct extent_buffer *eb) */ void btrfs_tree_lock(struct extent_buffer *eb) { + u64 start_ns = 0; + + if (trace_btrfs_tree_lock_enabled()) + start_ns = ktime_get_ns(); + WARN_ON(eb->lock_owner == current->pid); again: wait_event(eb->read_lock_wq, atomic_read(&eb->blocking_readers) == 0); @@ -312,6 +323,7 @@ again: btrfs_assert_spinning_writers_get(eb); btrfs_assert_tree_write_locks_get(eb); eb->lock_owner = current->pid; + trace_btrfs_tree_lock(eb, start_ns); } /* diff --git a/include/trace/events/btrfs.h b/include/trace/events/btrfs.h index 8b12753fee788..e27ed5afb9586 100644 --- a/include/trace/events/btrfs.h +++ b/include/trace/events/btrfs.h @@ -2005,6 +2005,50 @@ TRACE_EVENT(btrfs_convert_extent_bit, __print_flags(__entry->clear_bits, "|", EXTENT_FLAGS)) ); +DECLARE_EVENT_CLASS(btrfs_sleep_tree_lock, + TP_PROTO(const struct extent_buffer *eb, u64 start_ns), + + TP_ARGS(eb, start_ns), + + TP_STRUCT__entry_btrfs( + __field( u64, block ) + __field( u64, generation ) + __field( u64, start_ns ) + __field( u64, end_ns ) + __field( u64, diff_ns ) + __field( u64, owner ) + __field( int, is_log_tree ) + ), + + TP_fast_assign_btrfs(eb->fs_info, + __entry->block = eb->start; + __entry->generation = btrfs_header_generation(eb); + __entry->start_ns = start_ns; + __entry->end_ns = ktime_get_ns(); + __entry->diff_ns = __entry->end_ns - start_ns; + __entry->owner = btrfs_header_owner(eb); + __entry->is_log_tree = (eb->log_index >= 0); + ), + + TP_printk_btrfs( +"block=%llu generation=%llu start_ns=%llu end_ns=%llu diff_ns=%llu owner=%llu is_log_tree=%d", + __entry->block, __entry->generation, + __entry->start_ns, __entry->end_ns, __entry->diff_ns, + __entry->owner, __entry->is_log_tree) +); + +DEFINE_EVENT(btrfs_sleep_tree_lock, btrfs_tree_read_lock, + TP_PROTO(const struct extent_buffer *eb, u64 start_ns), + + TP_ARGS(eb, start_ns) +); + +DEFINE_EVENT(btrfs_sleep_tree_lock, btrfs_tree_lock, + TP_PROTO(const struct extent_buffer *eb, u64 start_ns), + + TP_ARGS(eb, start_ns) +); + #endif /* _TRACE_BTRFS_H */ /* This part must be outside protection */ -- 2.39.5