diff --git a/kmod/src/item.c b/kmod/src/item.c index f996bd1e..b0920e2f 100644 --- a/kmod/src/item.c +++ b/kmod/src/item.c @@ -374,7 +374,7 @@ static void item_referenced(struct item_cache *cac, struct cached_item *item) static void erase_item(struct super_block *sb, struct item_cache *cac, struct cached_item *item) { - trace_printk("erasing item %p\n", item); + trace_scoutfs_erase_item(sb, item); clear_item_dirty(sb, cac, item); rb_erase_augmented(&item->node, &cac->items, &scoutfs_item_rb_cb); @@ -755,7 +755,7 @@ int scoutfs_item_lookup(struct super_block *sb, struct scoutfs_key_buf *key, } while (ret == -ENODATA && (ret = scoutfs_manifest_read_items(sb, key, end)) == 0); - trace_printk("ret %d\n", ret); + trace_scoutfs_item_lookup_ret(sb, ret); return ret; } @@ -950,7 +950,7 @@ out: scoutfs_key_free(sb, pos); scoutfs_key_free(sb, range_end); - trace_printk("ret %d\n", ret); + trace_scoutfs_item_next_ret(sb, ret); return ret; } @@ -969,7 +969,7 @@ int scoutfs_item_next_same_min(struct super_block *sb, int key_len = key->key_len; int ret; - trace_printk("key len %u min val len %d\n", key_len, len); + trace_scoutfs_item_next_same_min(sb, key_len, len); if (WARN_ON_ONCE(!val || scoutfs_kvec_length(val) < len)) return -EINVAL; @@ -978,7 +978,7 @@ int scoutfs_item_next_same_min(struct super_block *sb, if (ret >= 0 && (key->key_len != key_len || ret < len)) ret = -EIO; - trace_printk("ret %d\n", ret); + trace_scoutfs_item_next_same_min_ret(sb, ret); return ret; } @@ -994,13 +994,13 @@ int scoutfs_item_next_same(struct super_block *sb, struct scoutfs_key_buf *key, int key_len = key->key_len; int ret; - trace_printk("key len %u\n", key_len); + trace_scoutfs_item_next_same(sb, key_len); ret = scoutfs_item_next(sb, key, last, val, end); if (ret >= 0 && (key->key_len != key_len)) ret = -EIO; - trace_printk("ret %d\n", ret); + trace_scoutfs_item_next_same_ret(sb, ret); return ret; } @@ -1304,7 +1304,7 @@ int scoutfs_item_dirty(struct super_block *sb, struct scoutfs_key_buf *key, } while (ret == -ENODATA && (ret = scoutfs_manifest_read_items(sb, key, end)) == 0); - trace_printk("ret %d\n", ret); + trace_scoutfs_item_dirty_ret(sb, ret); return ret; } @@ -1357,7 +1357,7 @@ int scoutfs_item_update(struct super_block *sb, struct scoutfs_key_buf *key, out: scoutfs_kvec_kfree(up_val); - trace_printk("ret %d\n", ret); + trace_scoutfs_item_update_ret(sb, ret); return ret; } @@ -1405,7 +1405,7 @@ int scoutfs_item_delete(struct super_block *sb, struct scoutfs_key_buf *key, scoutfs_kvec_kfree(del_val); - trace_printk("ret %d\n", ret); + trace_scoutfs_item_delete_ret(sb, ret); return ret; } diff --git a/kmod/src/scoutfs_trace.h b/kmod/src/scoutfs_trace.h index 2f31db6d..85deb845 100644 --- a/kmod/src/scoutfs_trace.h +++ b/kmod/src/scoutfs_trace.h @@ -40,6 +40,171 @@ struct lock_info; #define FSID_ARG(sb) le64_to_cpu(SCOUTFS_SB(sb)->super.hdr.fsid) #define FSID_FMT "%llx" +TRACE_EVENT(scoutfs_item_delete_ret, + TP_PROTO(struct super_block *sb, int ret), + + TP_ARGS(sb, ret), + + TP_STRUCT__entry( + __field(__u64, fsid) + __field(int, ret) + ), + + TP_fast_assign( + __entry->fsid = FSID_ARG(sb); + __entry->ret = ret; + ), + + TP_printk(FSID_FMT" ret %d", __entry->fsid, __entry->ret) +); + +TRACE_EVENT(scoutfs_item_dirty_ret, + TP_PROTO(struct super_block *sb, int ret), + + TP_ARGS(sb, ret), + + TP_STRUCT__entry( + __field(__u64, fsid) + __field(int, ret) + ), + + TP_fast_assign( + __entry->fsid = FSID_ARG(sb); + __entry->ret = ret; + ), + + TP_printk(FSID_FMT" ret %d", __entry->fsid, __entry->ret) +); + +TRACE_EVENT(scoutfs_item_update_ret, + TP_PROTO(struct super_block *sb, int ret), + + TP_ARGS(sb, ret), + + TP_STRUCT__entry( + __field(__u64, fsid) + __field(int, ret) + ), + + TP_fast_assign( + __entry->fsid = FSID_ARG(sb); + __entry->ret = ret; + ), + + TP_printk(FSID_FMT" ret %d", __entry->fsid, __entry->ret) +); + +TRACE_EVENT(scoutfs_item_next_same, + TP_PROTO(struct super_block *sb, unsigned int key_len), + + TP_ARGS(sb, key_len), + + TP_STRUCT__entry( + __field(__u64, fsid) + __field(unsigned int, key_len) + ), + + TP_fast_assign( + __entry->fsid = FSID_ARG(sb); + __entry->key_len = key_len; + ), + + TP_printk(FSID_FMT" key len %u", __entry->fsid, __entry->key_len) +); + +TRACE_EVENT(scoutfs_item_next_same_ret, + TP_PROTO(struct super_block *sb, int ret), + + TP_ARGS(sb, ret), + + TP_STRUCT__entry( + __field(__u64, fsid) + __field(int, ret) + ), + + TP_fast_assign( + __entry->fsid = FSID_ARG(sb); + __entry->ret = ret; + ), + + TP_printk(FSID_FMT" ret %d", __entry->fsid, __entry->ret) +); + +TRACE_EVENT(scoutfs_item_next_same_min, + TP_PROTO(struct super_block *sb, int key_len, int len), + + TP_ARGS(sb, key_len, len), + + TP_STRUCT__entry( + __field(__u64, fsid) + __field(int, key_len) + __field(int, len) + ), + + TP_fast_assign( + __entry->fsid = FSID_ARG(sb); + __entry->key_len = key_len; + __entry->len = len; + ), + + TP_printk(FSID_FMT" key len %u min val len %d", __entry->fsid, + __entry->key_len, __entry->len) +); + +TRACE_EVENT(scoutfs_item_next_same_min_ret, + TP_PROTO(struct super_block *sb, int ret), + + TP_ARGS(sb, ret), + + TP_STRUCT__entry( + __field(__u64, fsid) + __field(int, ret) + ), + + TP_fast_assign( + __entry->fsid = FSID_ARG(sb); + __entry->ret = ret; + ), + + TP_printk(FSID_FMT" ret %d", __entry->fsid, __entry->ret) +); + +TRACE_EVENT(scoutfs_item_next_ret, + TP_PROTO(struct super_block *sb, int ret), + + TP_ARGS(sb, ret), + + TP_STRUCT__entry( + __field(__u64, fsid) + __field(int, ret) + ), + + TP_fast_assign( + __entry->fsid = FSID_ARG(sb); + __entry->ret = ret; + ), + + TP_printk(FSID_FMT" ret %d", __entry->fsid, __entry->ret) +); + +TRACE_EVENT(scoutfs_erase_item, + TP_PROTO(struct super_block *sb, void *item), + + TP_ARGS(sb, item), + + TP_STRUCT__entry( + __field(__u64, fsid) + __field(void *, item) + ), + + TP_fast_assign( + __entry->fsid = FSID_ARG(sb); + __entry->item = item; + ), + + TP_printk(FSID_FMT" erasing item %p", __entry->fsid, __entry->item) +); + TRACE_EVENT(scoutfs_data_fiemap, TP_PROTO(struct super_block *sb, __u64 off, int i, __u64 blkno), @@ -1031,12 +1196,14 @@ DECLARE_EVENT_CLASS(scoutfs_key_class, TP_PROTO(struct super_block *sb, struct scoutfs_key_buf *key), TP_ARGS(sb, key), TP_STRUCT__entry( - __dynamic_array(char, key, scoutfs_key_str(NULL, key)) + __field(__u64, fsid) + __dynamic_array(char, key, scoutfs_key_str(NULL, key)) ), TP_fast_assign( + __entry->fsid = FSID_ARG(sb); scoutfs_key_str(__get_dynamic_array(key), key); ), - TP_printk("key %s", __get_str(key)) + TP_printk(FSID_FMT" key %s", __entry->fsid, __get_str(key)) ); DEFINE_EVENT(scoutfs_key_class, scoutfs_item_lookup, @@ -1044,6 +1211,24 @@ DEFINE_EVENT(scoutfs_key_class, scoutfs_item_lookup, TP_ARGS(sb, key) ); +TRACE_EVENT(scoutfs_item_lookup_ret, + TP_PROTO(struct super_block *sb, int ret), + + TP_ARGS(sb, ret), + + TP_STRUCT__entry( + __field(__u64, fsid) + __field(int, ret) + ), + + TP_fast_assign( + __entry->fsid = FSID_ARG(sb); + __entry->ret = ret; + ), + + TP_printk(FSID_FMT" ret %d", __entry->fsid, __entry->ret) +); + DEFINE_EVENT(scoutfs_key_class, scoutfs_item_insertion, TP_PROTO(struct super_block *sb, struct scoutfs_key_buf *key), TP_ARGS(sb, key)