From ac0c7cf8be00f269f82964cf7b144ca3edc5dbc4 Mon Sep 17 00:00:00 2001 From: David Sterba Date: Fri, 6 Jan 2017 14:12:51 +0100 Subject: btrfs: fix crash when tracepoint arguments are freed by wq callbacks Enabling btrfs tracepoints leads to instant crash, as reported. The wq callbacks could free the memory and the tracepoints started to dereference the members to get to fs_info. The proposed fix https://marc.info/?l=linux-btrfs&m=148172436722606&w=2 removed the tracepoints but we could preserve them by passing only the required data in a safe way. Fixes: bc074524e123 ("btrfs: prefix fsid to all trace events") CC: stable@vger.kernel.org # 4.8+ Reported-by: Sebastian Andrzej Siewior Reviewed-by: Qu Wenruo Signed-off-by: David Sterba --- include/trace/events/btrfs.h | 22 +++++++++++++--------- 1 file changed, 13 insertions(+), 9 deletions(-) (limited to 'include/trace') diff --git a/include/trace/events/btrfs.h b/include/trace/events/btrfs.h index c14bed4ab097..b09225c77676 100644 --- a/include/trace/events/btrfs.h +++ b/include/trace/events/btrfs.h @@ -1157,22 +1157,26 @@ DECLARE_EVENT_CLASS(btrfs__work, __entry->func, __entry->ordered_func, __entry->ordered_free) ); -/* For situiations that the work is freed */ +/* + * For situiations when the work is freed, we pass fs_info and a tag that that + * matches address of the work structure so it can be paired with the + * scheduling event. + */ DECLARE_EVENT_CLASS(btrfs__work__done, - TP_PROTO(struct btrfs_work *work), + TP_PROTO(struct btrfs_fs_info *fs_info, void *wtag), - TP_ARGS(work), + TP_ARGS(fs_info, wtag), TP_STRUCT__entry_btrfs( - __field( void *, work ) + __field( void *, wtag ) ), - TP_fast_assign_btrfs(btrfs_work_owner(work), - __entry->work = work; + TP_fast_assign_btrfs(fs_info, + __entry->wtag = wtag; ), - TP_printk_btrfs("work->%p", __entry->work) + TP_printk_btrfs("work->%p", __entry->wtag) ); DEFINE_EVENT(btrfs__work, btrfs_work_queued, @@ -1191,9 +1195,9 @@ DEFINE_EVENT(btrfs__work, btrfs_work_sched, DEFINE_EVENT(btrfs__work__done, btrfs_all_work_done, - TP_PROTO(struct btrfs_work *work), + TP_PROTO(struct btrfs_fs_info *fs_info, void *wtag), - TP_ARGS(work) + TP_ARGS(fs_info, wtag) ); DEFINE_EVENT(btrfs__work, btrfs_ordered_sched, -- cgit v1.2.3 From 92a1bf76a89ad338f00eb9a2c7689a3907fbcaad Mon Sep 17 00:00:00 2001 From: Liu Bo Date: Thu, 17 Nov 2016 15:00:50 -0800 Subject: Btrfs: add 'inode' for extent map tracepoint 'inode' is an important field for btrfs_get_extent, lets trace it. Signed-off-by: Liu Bo Reviewed-by: David Sterba Signed-off-by: David Sterba --- fs/btrfs/inode.c | 2 +- include/trace/events/btrfs.h | 12 ++++++++---- 2 files changed, 9 insertions(+), 5 deletions(-) (limited to 'include/trace') diff --git a/fs/btrfs/inode.c b/fs/btrfs/inode.c index a713d9d324b0..fab189c67eff 100644 --- a/fs/btrfs/inode.c +++ b/fs/btrfs/inode.c @@ -7059,7 +7059,7 @@ insert: write_unlock(&em_tree->lock); out: - trace_btrfs_get_extent(root, em); + trace_btrfs_get_extent(root, inode, em); btrfs_free_path(path); if (trans) { diff --git a/include/trace/events/btrfs.h b/include/trace/events/btrfs.h index b09225c77676..3048f5205363 100644 --- a/include/trace/events/btrfs.h +++ b/include/trace/events/btrfs.h @@ -184,14 +184,16 @@ DEFINE_EVENT(btrfs__inode, btrfs_inode_evict, TRACE_EVENT_CONDITION(btrfs_get_extent, - TP_PROTO(struct btrfs_root *root, struct extent_map *map), + TP_PROTO(struct btrfs_root *root, struct inode *inode, + struct extent_map *map), - TP_ARGS(root, map), + TP_ARGS(root, inode, map), TP_CONDITION(map), TP_STRUCT__entry_btrfs( __field( u64, root_objectid ) + __field( u64, ino ) __field( u64, start ) __field( u64, len ) __field( u64, orig_start ) @@ -204,7 +206,8 @@ TRACE_EVENT_CONDITION(btrfs_get_extent, TP_fast_assign_btrfs(root->fs_info, __entry->root_objectid = root->root_key.objectid; - __entry->start = map->start; + __entry->ino = btrfs_ino(inode); + __entry->start = map->start; __entry->len = map->len; __entry->orig_start = map->orig_start; __entry->block_start = map->block_start; @@ -214,11 +217,12 @@ TRACE_EVENT_CONDITION(btrfs_get_extent, __entry->compress_type = map->compress_type; ), - TP_printk_btrfs("root = %llu(%s), start = %llu, len = %llu, " + TP_printk_btrfs("root = %llu(%s), ino = %llu start = %llu, len = %llu, " "orig_start = %llu, block_start = %llu(%s), " "block_len = %llu, flags = %s, refs = %u, " "compress_type = %u", show_root_type(__entry->root_objectid), + (unsigned long long)__entry->ino, (unsigned long long)__entry->start, (unsigned long long)__entry->len, (unsigned long long)__entry->orig_start, -- cgit v1.2.3 From 7856654842bdbebc0fbcbf51573da5d70a787aba Mon Sep 17 00:00:00 2001 From: Liu Bo Date: Wed, 30 Nov 2016 16:10:10 -0800 Subject: Btrfs: add truncated_len for ordered extent tracepoints This can help us monitor truncated ordered extents. Signed-off-by: Liu Bo Reviewed-by: David Sterba Signed-off-by: David Sterba --- include/trace/events/btrfs.h | 4 ++++ 1 file changed, 4 insertions(+) (limited to 'include/trace') diff --git a/include/trace/events/btrfs.h b/include/trace/events/btrfs.h index 3048f5205363..2026a89786b0 100644 --- a/include/trace/events/btrfs.h +++ b/include/trace/events/btrfs.h @@ -263,6 +263,7 @@ DECLARE_EVENT_CLASS(btrfs__ordered_extent, __field( int, compress_type ) __field( int, refs ) __field( u64, root_objectid ) + __field( u64, truncated_len ) ), TP_fast_assign_btrfs(btrfs_sb(inode->i_sb), @@ -277,10 +278,12 @@ DECLARE_EVENT_CLASS(btrfs__ordered_extent, __entry->refs = atomic_read(&ordered->refs); __entry->root_objectid = BTRFS_I(inode)->root->root_key.objectid; + __entry->truncated_len = ordered->truncated_len; ), TP_printk_btrfs("root = %llu(%s), ino = %llu, file_offset = %llu, " "start = %llu, len = %llu, disk_len = %llu, " + "truncated_len = %llu, " "bytes_left = %llu, flags = %s, compress_type = %d, " "refs = %d", show_root_type(__entry->root_objectid), @@ -289,6 +292,7 @@ DECLARE_EVENT_CLASS(btrfs__ordered_extent, (unsigned long long)__entry->start, (unsigned long long)__entry->len, (unsigned long long)__entry->disk_len, + (unsigned long long)__entry->truncated_len, (unsigned long long)__entry->bytes_left, show_ordered_flags(__entry->flags), __entry->compress_type, __entry->refs) -- cgit v1.2.3 From 562a7a07bf61e2949f7cbdb6ac7537ad9e2794d1 Mon Sep 17 00:00:00 2001 From: David Sterba Date: Fri, 6 Jan 2017 15:51:36 +0100 Subject: btrfs: make tracepoint format strings more compact We've recently added the fsid to trace events, this makes the line quite long. To reduce the it again, remove extra spaces around = and remove ",". Signed-off-by: David Sterba --- include/trace/events/btrfs.h | 112 +++++++++++++++++++++---------------------- 1 file changed, 56 insertions(+), 56 deletions(-) (limited to 'include/trace') diff --git a/include/trace/events/btrfs.h b/include/trace/events/btrfs.h index 2026a89786b0..88d18a8ceb59 100644 --- a/include/trace/events/btrfs.h +++ b/include/trace/events/btrfs.h @@ -130,8 +130,8 @@ DECLARE_EVENT_CLASS(btrfs__inode, BTRFS_I(inode)->root->root_key.objectid; ), - TP_printk_btrfs("root = %llu(%s), gen = %llu, ino = %lu, blocks = %llu, " - "disk_i_size = %llu, last_trans = %llu, logged_trans = %llu", + TP_printk_btrfs("root=%llu(%s) gen=%llu ino=%lu blocks=%llu " + "disk_i_size=%llu last_trans=%llu logged_trans=%llu", show_root_type(__entry->root_objectid), (unsigned long long)__entry->generation, (unsigned long)__entry->ino, @@ -217,10 +217,10 @@ TRACE_EVENT_CONDITION(btrfs_get_extent, __entry->compress_type = map->compress_type; ), - TP_printk_btrfs("root = %llu(%s), ino = %llu start = %llu, len = %llu, " - "orig_start = %llu, block_start = %llu(%s), " - "block_len = %llu, flags = %s, refs = %u, " - "compress_type = %u", + TP_printk_btrfs("root=%llu(%s) ino=%llu start=%llu len=%llu " + "orig_start=%llu block_start=%llu(%s) " + "block_len=%llu flags=%s refs=%u " + "compress_type=%u", show_root_type(__entry->root_objectid), (unsigned long long)__entry->ino, (unsigned long long)__entry->start, @@ -281,11 +281,11 @@ DECLARE_EVENT_CLASS(btrfs__ordered_extent, __entry->truncated_len = ordered->truncated_len; ), - TP_printk_btrfs("root = %llu(%s), ino = %llu, file_offset = %llu, " - "start = %llu, len = %llu, disk_len = %llu, " - "truncated_len = %llu, " - "bytes_left = %llu, flags = %s, compress_type = %d, " - "refs = %d", + TP_printk_btrfs("root=%llu(%s) ino=%llu file_offset=%llu " + "start=%llu len=%llu disk_len=%llu " + "truncated_len=%llu " + "bytes_left=%llu flags=%s compress_type=%d " + "refs=%d", show_root_type(__entry->root_objectid), (unsigned long long)__entry->ino, (unsigned long long)__entry->file_offset, @@ -362,10 +362,10 @@ DECLARE_EVENT_CLASS(btrfs__writepage, BTRFS_I(inode)->root->root_key.objectid; ), - TP_printk_btrfs("root = %llu(%s), ino = %lu, page_index = %lu, " - "nr_to_write = %ld, pages_skipped = %ld, range_start = %llu, " - "range_end = %llu, for_kupdate = %d, " - "for_reclaim = %d, range_cyclic = %d, writeback_index = %lu", + TP_printk_btrfs("root=%llu(%s) ino=%lu page_index=%lu " + "nr_to_write=%ld pages_skipped=%ld range_start=%llu " + "range_end=%llu for_kupdate=%d " + "for_reclaim=%d range_cyclic=%d writeback_index=%lu", show_root_type(__entry->root_objectid), (unsigned long)__entry->ino, __entry->index, __entry->nr_to_write, __entry->pages_skipped, @@ -408,8 +408,8 @@ TRACE_EVENT(btrfs_writepage_end_io_hook, BTRFS_I(page->mapping->host)->root->root_key.objectid; ), - TP_printk_btrfs("root = %llu(%s), ino = %lu, page_index = %lu, start = %llu, " - "end = %llu, uptodate = %d", + TP_printk_btrfs("root=%llu(%s) ino=%lu page_index=%lu start=%llu " + "end=%llu uptodate=%d", show_root_type(__entry->root_objectid), (unsigned long)__entry->ino, (unsigned long)__entry->index, (unsigned long long)__entry->start, @@ -441,7 +441,7 @@ TRACE_EVENT(btrfs_sync_file, BTRFS_I(inode)->root->root_key.objectid; ), - TP_printk_btrfs("root = %llu(%s), ino = %ld, parent = %ld, datasync = %d", + TP_printk_btrfs("root=%llu(%s) ino=%ld parent=%ld datasync=%d", show_root_type(__entry->root_objectid), (unsigned long)__entry->ino, (unsigned long)__entry->parent, __entry->datasync) @@ -492,9 +492,9 @@ TRACE_EVENT(btrfs_add_block_group, __entry->create = create; ), - TP_printk("%pU: block_group offset = %llu, size = %llu, " - "flags = %llu(%s), bytes_used = %llu, bytes_super = %llu, " - "create = %d", __entry->fsid, + TP_printk("%pU: block_group offset=%llu size=%llu " + "flags=%llu(%s) bytes_used=%llu bytes_super=%llu " + "create=%d", __entry->fsid, (unsigned long long)__entry->offset, (unsigned long long)__entry->size, (unsigned long long)__entry->flags, @@ -543,9 +543,9 @@ DECLARE_EVENT_CLASS(btrfs_delayed_tree_ref, __entry->seq = ref->seq; ), - TP_printk_btrfs("bytenr = %llu, num_bytes = %llu, action = %s, " - "parent = %llu(%s), ref_root = %llu(%s), level = %d, " - "type = %s, seq = %llu", + TP_printk_btrfs("bytenr=%llu num_bytes=%llu action=%s " + "parent=%llu(%s) ref_root=%llu(%s) level=%d " + "type=%s seq=%llu", (unsigned long long)__entry->bytenr, (unsigned long long)__entry->num_bytes, show_ref_action(__entry->action), @@ -608,9 +608,9 @@ DECLARE_EVENT_CLASS(btrfs_delayed_data_ref, __entry->seq = ref->seq; ), - TP_printk_btrfs("bytenr = %llu, num_bytes = %llu, action = %s, " - "parent = %llu(%s), ref_root = %llu(%s), owner = %llu, " - "offset = %llu, type = %s, seq = %llu", + TP_printk_btrfs("bytenr=%llu num_bytes=%llu action=%s " + "parent=%llu(%s) ref_root=%llu(%s) owner=%llu " + "offset=%llu type=%s seq=%llu", (unsigned long long)__entry->bytenr, (unsigned long long)__entry->num_bytes, show_ref_action(__entry->action), @@ -665,7 +665,7 @@ DECLARE_EVENT_CLASS(btrfs_delayed_ref_head, __entry->is_data = head_ref->is_data; ), - TP_printk_btrfs("bytenr = %llu, num_bytes = %llu, action = %s, is_data = %d", + TP_printk_btrfs("bytenr=%llu num_bytes=%llu action=%s is_data=%d", (unsigned long long)__entry->bytenr, (unsigned long long)__entry->num_bytes, show_ref_action(__entry->action), @@ -729,8 +729,8 @@ DECLARE_EVENT_CLASS(btrfs__chunk, __entry->root_objectid = fs_info->chunk_root->root_key.objectid; ), - TP_printk_btrfs("root = %llu(%s), offset = %llu, size = %llu, " - "num_stripes = %d, sub_stripes = %d, type = %s", + TP_printk_btrfs("root=%llu(%s) offset=%llu size=%llu " + "num_stripes=%d sub_stripes=%d type=%s", show_root_type(__entry->root_objectid), (unsigned long long)__entry->offset, (unsigned long long)__entry->size, @@ -779,8 +779,8 @@ TRACE_EVENT(btrfs_cow_block, __entry->cow_level = btrfs_header_level(cow); ), - TP_printk_btrfs("root = %llu(%s), refs = %d, orig_buf = %llu " - "(orig_level = %d), cow_buf = %llu (cow_level = %d)", + TP_printk_btrfs("root=%llu(%s) refs=%d orig_buf=%llu " + "(orig_level=%d) cow_buf=%llu (cow_level=%d)", show_root_type(__entry->root_objectid), __entry->refs, (unsigned long long)__entry->buf_start, @@ -844,7 +844,7 @@ TRACE_EVENT(btrfs_trigger_flush, __assign_str(reason, reason) ), - TP_printk("%pU: %s: flush = %d(%s), flags = %llu(%s), bytes = %llu", + TP_printk("%pU: %s: flush=%d(%s) flags=%llu(%s) bytes=%llu", __entry->fsid, __get_str(reason), __entry->flush, show_flush_action(__entry->flush), (unsigned long long)__entry->flags, @@ -887,8 +887,8 @@ TRACE_EVENT(btrfs_flush_space, __entry->ret = ret; ), - TP_printk("%pU: state = %d(%s), flags = %llu(%s), num_bytes = %llu, " - "orig_bytes = %llu, ret = %d", __entry->fsid, __entry->state, + TP_printk("%pU: state=%d(%s) flags=%llu(%s) num_bytes=%llu " + "orig_bytes=%llu ret=%d", __entry->fsid, __entry->state, show_flush_state(__entry->state), (unsigned long long)__entry->flags, __print_flags((unsigned long)__entry->flags, "|", @@ -913,7 +913,7 @@ DECLARE_EVENT_CLASS(btrfs__reserved_extent, __entry->len = len; ), - TP_printk_btrfs("root = %llu(%s), start = %llu, len = %llu", + TP_printk_btrfs("root=%llu(%s) start=%llu len=%llu", show_root_type(BTRFS_EXTENT_TREE_OBJECTID), (unsigned long long)__entry->start, (unsigned long long)__entry->len) @@ -952,7 +952,7 @@ TRACE_EVENT(find_free_extent, __entry->data = data; ), - TP_printk_btrfs("root = %Lu(%s), len = %Lu, empty_size = %Lu, flags = %Lu(%s)", + TP_printk_btrfs("root=%Lu(%s) len=%Lu empty_size=%Lu flags=%Lu(%s)", show_root_type(BTRFS_EXTENT_TREE_OBJECTID), __entry->num_bytes, __entry->empty_size, __entry->data, __print_flags((unsigned long)__entry->data, "|", @@ -981,8 +981,8 @@ DECLARE_EVENT_CLASS(btrfs__reserve_extent, __entry->len = len; ), - TP_printk_btrfs("root = %Lu(%s), block_group = %Lu, flags = %Lu(%s), " - "start = %Lu, len = %Lu", + TP_printk_btrfs("root=%Lu(%s) block_group=%Lu flags=%Lu(%s) " + "start=%Lu len=%Lu", show_root_type(BTRFS_EXTENT_TREE_OBJECTID), __entry->bg_objectid, __entry->flags, __print_flags((unsigned long)__entry->flags, @@ -1033,8 +1033,8 @@ TRACE_EVENT(btrfs_find_cluster, __entry->min_bytes = min_bytes; ), - TP_printk_btrfs("block_group = %Lu, flags = %Lu(%s), start = %Lu, len = %Lu," - " empty_size = %Lu, min_bytes = %Lu", __entry->bg_objectid, + TP_printk_btrfs("block_group=%Lu flags=%Lu(%s) start=%Lu len=%Lu " + "empty_size=%Lu min_bytes=%Lu", __entry->bg_objectid, __entry->flags, __print_flags((unsigned long)__entry->flags, "|", BTRFS_GROUP_FLAGS), __entry->start, @@ -1055,7 +1055,7 @@ TRACE_EVENT(btrfs_failed_cluster_setup, __entry->bg_objectid = block_group->key.objectid; ), - TP_printk_btrfs("block_group = %Lu", __entry->bg_objectid) + TP_printk_btrfs("block_group=%Lu", __entry->bg_objectid) ); TRACE_EVENT(btrfs_setup_cluster, @@ -1083,8 +1083,8 @@ TRACE_EVENT(btrfs_setup_cluster, __entry->bitmap = bitmap; ), - TP_printk_btrfs("block_group = %Lu, flags = %Lu(%s), window_start = %Lu, " - "size = %Lu, max_size = %Lu, bitmap = %d", + TP_printk_btrfs("block_group=%Lu flags=%Lu(%s) window_start=%Lu " + "size=%Lu max_size=%Lu bitmap=%d", __entry->bg_objectid, __entry->flags, __print_flags((unsigned long)__entry->flags, "|", @@ -1111,7 +1111,7 @@ TRACE_EVENT(alloc_extent_state, __entry->ip = IP ), - TP_printk("state=%p; mask = %s; caller = %pS", __entry->state, + TP_printk("state=%p mask=%s caller=%pS", __entry->state, show_gfp_flags(__entry->mask), (void *)__entry->ip) ); @@ -1131,7 +1131,7 @@ TRACE_EVENT(free_extent_state, __entry->ip = IP ), - TP_printk(" state=%p; caller = %pS", __entry->state, + TP_printk("state=%p caller=%pS", __entry->state, (void *)__entry->ip) ); @@ -1159,8 +1159,8 @@ DECLARE_EVENT_CLASS(btrfs__work, __entry->normal_work = &work->normal_work; ), - TP_printk_btrfs("work=%p (normal_work=%p), wq=%p, func=%pf, ordered_func=%p," - " ordered_free=%p", + TP_printk_btrfs("work=%p (normal_work=%p) wq=%p func=%pf ordered_func=%p " + "ordered_free=%p", __entry->work, __entry->normal_work, __entry->wq, __entry->func, __entry->ordered_func, __entry->ordered_free) ); @@ -1233,7 +1233,7 @@ DECLARE_EVENT_CLASS(btrfs__workqueue, __entry->high = high; ), - TP_printk_btrfs("name=%s%s, wq=%p", __get_str(name), + TP_printk_btrfs("name=%s%s wq=%p", __get_str(name), __print_flags(__entry->high, "", {(WQ_HIGHPRI), "-high"}), __entry->wq) @@ -1288,7 +1288,7 @@ DECLARE_EVENT_CLASS(btrfs__qgroup_data_map, __entry->free_reserved = free_reserved; ), - TP_printk_btrfs("rootid=%llu, ino=%lu, free_reserved=%llu", + TP_printk_btrfs("rootid=%llu ino=%lu free_reserved=%llu", __entry->rootid, __entry->ino, __entry->free_reserved) ); @@ -1335,7 +1335,7 @@ DECLARE_EVENT_CLASS(btrfs__qgroup_rsv_data, __entry->op = op; ), - TP_printk_btrfs("root=%llu, ino=%lu, start=%llu, len=%llu, reserved=%llu, op=%s", + TP_printk_btrfs("root=%llu ino=%lu start=%llu len=%llu reserved=%llu op=%s", __entry->rootid, __entry->ino, __entry->start, __entry->len, __entry->reserved, __print_flags((unsigned long)__entry->op, "", @@ -1373,7 +1373,7 @@ DECLARE_EVENT_CLASS(btrfs__qgroup_delayed_ref, __entry->reserved = reserved; ), - TP_printk_btrfs("root=%llu, reserved=%llu, op=free", + TP_printk_btrfs("root=%llu reserved=%llu op=free", __entry->ref_root, __entry->reserved) ); @@ -1400,7 +1400,7 @@ DECLARE_EVENT_CLASS(btrfs_qgroup_extent, __entry->num_bytes = rec->num_bytes; ), - TP_printk_btrfs("bytenr = %llu, num_bytes = %llu", + TP_printk_btrfs("bytenr=%llu num_bytes=%llu", (unsigned long long)__entry->bytenr, (unsigned long long)__entry->num_bytes) ); @@ -1442,8 +1442,8 @@ TRACE_EVENT(btrfs_qgroup_account_extent, __entry->nr_new_roots = nr_new_roots; ), - TP_printk_btrfs("bytenr = %llu, num_bytes = %llu, nr_old_roots = %llu, " - "nr_new_roots = %llu", + TP_printk_btrfs("bytenr=%llu num_bytes=%llu nr_old_roots=%llu " + "nr_new_roots=%llu", __entry->bytenr, __entry->num_bytes, __entry->nr_old_roots, @@ -1469,7 +1469,7 @@ TRACE_EVENT(qgroup_update_counters, __entry->cur_new_count = cur_new_count; ), - TP_printk_btrfs("qgid = %llu, cur_old_count = %llu, cur_new_count = %llu", + TP_printk_btrfs("qgid=%llu cur_old_count=%llu cur_new_count=%llu", __entry->qgid, __entry->cur_old_count, __entry->cur_new_count) -- cgit v1.2.3