From 2a07e6f642105570b442949aeffd5fa50959cd2d Mon Sep 17 00:00:00 2001 From: Mark Fasheh Date: Fri, 22 Sep 2017 17:34:07 -0500 Subject: [PATCH] scoutfs: replace trace_printk in data.c Signed-off-by: Mark Fasheh --- kmod/src/data.c | 32 +++--- kmod/src/scoutfs_trace.h | 212 +++++++++++++++++++++++++++++++++++++-- 2 files changed, 217 insertions(+), 27 deletions(-) diff --git a/kmod/src/data.c b/kmod/src/data.c index 082fc13d..9b72d18b 100644 --- a/kmod/src/data.c +++ b/kmod/src/data.c @@ -383,8 +383,8 @@ static int set_segno_free(struct super_block *sb, u64 segno) ret = scoutfs_item_update(sb, &key, val, NULL); out: - trace_printk("segno %llu base %llu bit %u ret %d\n", - segno, be64_to_cpu(fbk.base), bit, ret); + trace_scoutfs_data_set_segno_free(sb, segno, be64_to_cpu(fbk.base), + bit, ret); return ret; } @@ -616,8 +616,7 @@ int scoutfs_data_truncate_items(struct super_block *sb, u64 ino, u64 iblock, int ret = 0; int i; - trace_printk("iblock %llu len %llu offline %u\n", - iblock, len, offline); + trace_scoutfs_data_truncate_items(sb, iblock, len, offline); if (WARN_ON_ONCE(iblock + len < iblock)) return -EINVAL; @@ -774,8 +773,7 @@ static struct task_cursor *get_cursor(struct data_info *datinf) if (!curs) { curs = list_last_entry(&datinf->cursor_lru, struct task_cursor, list_head); - trace_printk("resetting curs %p was task %p pid %u\n", - curs, task, pid); + trace_scoutfs_data_get_cursor(curs, task, pid); hlist_del_init(&curs->hnode); curs->task = task; curs->pid = pid; @@ -916,7 +914,7 @@ static int find_alloc_block(struct super_block *sb, struct block_mapping *map, curs = get_cursor(datinf); - trace_printk("got curs %p blkno %llu\n", curs, curs->blkno); + trace_scoutfs_data_find_alloc_block_curs(sb, curs, curs->blkno); /* try to find the next blkno in our cursor if we have one */ if (curs->blkno) { @@ -947,7 +945,7 @@ static int find_alloc_block(struct super_block *sb, struct block_mapping *map, goto out; } - trace_printk("found free segno %llu blkno %llu\n", segno, blkno); + trace_scoutfs_data_find_alloc_block_found_seg(sb, segno, blkno); /* ensure that we can copy in encoded without failing */ scoutfs_kvec_init(val, map->encoded, sizeof(map->encoded)); @@ -983,7 +981,7 @@ static int find_alloc_block(struct super_block *sb, struct block_mapping *map, out: up_write(&datinf->alloc_rwsem); - trace_printk("ret %d\n", ret); + trace_scoutfs_data_find_alloc_block_ret(sb, ret); return ret; } @@ -1057,9 +1055,8 @@ static int scoutfs_get_block(struct inode *inode, sector_t iblock, ret = 0; out: - trace_printk("ino %llu iblock %llu create %d ret %d bnr %llu size %zu\n", - scoutfs_ino(inode), (u64)iblock, create, ret, - (u64)bh->b_blocknr, bh->b_size); + trace_scoutfs_get_block(sb, scoutfs_ino(inode), iblock, create, + ret, bh->b_blocknr, bh->b_size); kfree(map); @@ -1131,8 +1128,7 @@ static int scoutfs_write_begin(struct file *file, struct super_block *sb = inode->i_sb; int ret; - trace_printk("ino %llu pos %llu len %u\n", - scoutfs_ino(inode), (u64)pos, len); + trace_scoutfs_write_begin(sb, scoutfs_ino(inode), (__u64)pos, len); ret = scoutfs_hold_trans(sb, SIC_WRITE_BEGIN()); if (ret) @@ -1161,8 +1157,8 @@ static int scoutfs_write_end(struct file *file, struct address_space *mapping, struct super_block *sb = inode->i_sb; int ret; - trace_printk("ino %llu pgind %lu pos %llu len %u copied %d\n", - scoutfs_ino(inode), page->index, (u64)pos, len, copied); + trace_scoutfs_write_end(sb, scoutfs_ino(inode), page->index, (u64)pos, + len, copied); ret = generic_write_end(file, mapping, pos, len, copied, page, fsdata); if (ret > 0) { @@ -1315,8 +1311,8 @@ int scoutfs_data_fiemap(struct inode *inode, struct fiemap_extent_info *fieinfo, if (map->blknos[i] == 0 && !offline) continue; - trace_printk("blk_off %llu i %u blkno %llu\n", - blk_off, i, map->blknos[i]); + trace_scoutfs_data_fiemap(sb, blk_off, i, + map->blknos[i]); logical = blk_off << SCOUTFS_BLOCK_SHIFT; phys = map->blknos[i] << SCOUTFS_BLOCK_SHIFT; diff --git a/kmod/src/scoutfs_trace.h b/kmod/src/scoutfs_trace.h index 029ee4c8..2f31db6d 100644 --- a/kmod/src/scoutfs_trace.h +++ b/kmod/src/scoutfs_trace.h @@ -40,6 +40,192 @@ struct lock_info; #define FSID_ARG(sb) le64_to_cpu(SCOUTFS_SB(sb)->super.hdr.fsid) #define FSID_FMT "%llx" +TRACE_EVENT(scoutfs_data_fiemap, + TP_PROTO(struct super_block *sb, __u64 off, int i, __u64 blkno), + + + TP_ARGS(sb, off, i, blkno), + + TP_STRUCT__entry( + __field(__u64, fsid) + __field(__u64, off) + __field(int, i) + __field(__u64, blkno) + ), + + TP_fast_assign( + __entry->fsid = FSID_ARG(sb); + __entry->off = off; + __entry->i = i; + __entry->blkno = blkno; + ), + + TP_printk(FSID_FMT" blk_off %llu i %u blkno %llu", __entry->fsid, + __entry->off, __entry->i, __entry->blkno) +); + +TRACE_EVENT(scoutfs_get_block, + TP_PROTO(struct super_block *sb, __u64 ino, __u64 iblock, + int create, int ret, __u64 blkno, size_t size), + + TP_ARGS(sb, ino, iblock, create, ret, blkno, size), + + TP_STRUCT__entry( + __field(__u64, fsid) + __field(__u64, ino) + __field(__u64, iblock) + __field(int, create) + __field(int, ret) + __field(__u64, blkno) + __field(size_t, size) + ), + + TP_fast_assign( + __entry->fsid = FSID_ARG(sb); + __entry->ino = ino; + __entry->iblock = iblock; + __entry->create = create; + __entry->ret = ret; + __entry->blkno = blkno; + __entry->size = size; + ), + + TP_printk(FSID_FMT" ino %llu iblock %llu create %d ret %d bnr %llu " + "size %zu", __entry->fsid, __entry->ino, __entry->iblock, + __entry->create, __entry->ret, __entry->blkno, __entry->size) +); + +TRACE_EVENT(scoutfs_data_find_alloc_block_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_data_find_alloc_block_found_seg, + TP_PROTO(struct super_block *sb, __u64 segno, __u64 blkno), + + TP_ARGS(sb, segno, blkno), + + TP_STRUCT__entry( + __field(__u64, fsid) + __field(__u64, segno) + __field(__u64, blkno) + ), + + TP_fast_assign( + __entry->fsid = FSID_ARG(sb); + __entry->segno = segno; + __entry->blkno = blkno; + ), + + TP_printk(FSID_FMT" found free segno %llu blkno %llu", __entry->fsid, + __entry->segno, __entry->blkno) +); + +TRACE_EVENT(scoutfs_data_find_alloc_block_curs, + TP_PROTO(struct super_block *sb, void *curs, __u64 blkno), + + TP_ARGS(sb, curs, blkno), + + TP_STRUCT__entry( + __field(__u64, fsid) + __field(void *, curs) + __field(__u64, blkno) + ), + + TP_fast_assign( + __entry->fsid = FSID_ARG(sb); + __entry->curs = curs; + __entry->blkno = blkno; + ), + + TP_printk(FSID_FMT" got curs %p blkno %llu", __entry->fsid, + __entry->curs, __entry->blkno) +); + +TRACE_EVENT(scoutfs_data_get_cursor, + TP_PROTO(void *curs, void *task, unsigned int pid), + + TP_ARGS(curs, task, pid), + + TP_STRUCT__entry( + __field(__u64, fsid) + __field(void *, curs) + __field(void *, task) + __field(unsigned int, pid) + ), + + TP_fast_assign( + __entry->curs = curs; + __entry->task = task; + __entry->pid = pid; + ), + + TP_printk("resetting curs %p was task %p pid %u", __entry->curs, + __entry->task, __entry->pid) +); + +TRACE_EVENT(scoutfs_data_truncate_items, + TP_PROTO(struct super_block *sb, __u64 iblock, __u64 len, int offline), + + TP_ARGS(sb, iblock, len, offline), + + TP_STRUCT__entry( + __field(__u64, fsid) + __field(__u64, iblock) + __field(__u64, len) + __field(int, offline) + ), + + TP_fast_assign( + __entry->fsid = FSID_ARG(sb); + __entry->iblock = iblock; + __entry->len = len; + __entry->offline = offline; + ), + + TP_printk(FSID_FMT" iblock %llu len %llu offline %u", __entry->fsid, + __entry->iblock, __entry->len, __entry->offline) +); + +TRACE_EVENT(scoutfs_data_set_segno_free, + TP_PROTO(struct super_block *sb, __u64 segno, __u64 base, + unsigned int bit, int ret), + + TP_ARGS(sb, segno, base, bit, ret), + + TP_STRUCT__entry( + __field(__u64, fsid) + __field(__u64, segno) + __field(__u64, base) + __field(unsigned int, bit) + __field(int, ret) + ), + + TP_fast_assign( + __entry->fsid = FSID_ARG(sb); + __entry->segno = segno; + __entry->base = base; + __entry->bit = bit; + __entry->ret = ret; + ), + + TP_printk(FSID_FMT" segno %llu base %llu bit %u ret %d", __entry->fsid, + __entry->segno, __entry->base, __entry->bit, __entry->ret) +); + TRACE_EVENT(scoutfs_sync_fs, TP_PROTO(struct super_block *sb, int wait), @@ -649,47 +835,55 @@ TRACE_EVENT(scoutfs_alloc_segno, ); TRACE_EVENT(scoutfs_write_begin, - TP_PROTO(u64 ino, loff_t pos, unsigned len), + TP_PROTO(struct super_block *sb, u64 ino, loff_t pos, unsigned len), - TP_ARGS(ino, pos, len), + TP_ARGS(sb, ino, pos, len), TP_STRUCT__entry( + __field(__u64, fsid) __field(__u64, inode) __field(__u64, pos) __field(__u32, len) ), TP_fast_assign( + __entry->fsid = FSID_ARG(sb); __entry->inode = ino; __entry->pos = pos; __entry->len = len; ), - TP_printk("ino %llu pos %llu len %u", + TP_printk(FSID_FMT" ino %llu pos %llu len %u", __entry->fsid, __entry->inode, __entry->pos, __entry->len) ); TRACE_EVENT(scoutfs_write_end, - TP_PROTO(u64 ino, loff_t pos, unsigned len, unsigned copied), + TP_PROTO(struct super_block *sb, u64 ino, unsigned long idx, u64 pos, + unsigned len, unsigned copied), - TP_ARGS(ino, pos, len, copied), + TP_ARGS(sb, ino, idx, pos, len, copied), TP_STRUCT__entry( - __field(__u64, inode) + __field(__u64, fsid) + __field(__u64, ino) + __field(unsigned long, idx) __field(__u64, pos) __field(__u32, len) __field(__u32, copied) ), TP_fast_assign( - __entry->inode = ino; + __entry->fsid = FSID_ARG(sb); + __entry->ino = ino; + __entry->idx = idx; __entry->pos = pos; __entry->len = len; __entry->copied = copied; ), - TP_printk("ino %llu pos %llu len %u", - __entry->inode, __entry->pos, __entry->len) + TP_printk(FSID_FMT" ino %llu pgind %lu pos %llu len %u copied %d", + __entry->fsid, __entry->ino, __entry->idx, __entry->pos, + __entry->len, __entry->copied) ); TRACE_EVENT(scoutfs_dirty_inode,