scoutfs: replace trace_printk in data.c

Signed-off-by: Mark Fasheh <mfasheh@versity.com>

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",
+	trace_scoutfs_data_set_segno_free(sb, segno, be64_to_cpu(fbk.base),
-		     segno, be64_to_cpu(fbk.base), bit, ret);
+					  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",
+	trace_scoutfs_data_truncate_items(sb, iblock, len, offline);
-		     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",
+		trace_scoutfs_data_get_cursor(curs, task, pid);
-				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",
+	trace_scoutfs_get_block(sb, scoutfs_ino(inode), iblock, create,
-		     scoutfs_ino(inode), (u64)iblock, create, ret,
+				ret, bh->b_blocknr, bh->b_size);
-		     (u64)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",
+	trace_scoutfs_write_begin(sb, scoutfs_ino(inode), (__u64)pos, len);
-		     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",
+	trace_scoutfs_write_end(sb, scoutfs_ino(inode), page->index, (u64)pos,
-		     scoutfs_ino(inode), page->index, (u64)pos, len, copied);
+				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",
+			trace_scoutfs_data_fiemap(sb, blk_off, i,
-					blk_off, i, map->blknos[i]);
+						  map->blknos[i]);
 
 			logical = blk_off << SCOUTFS_BLOCK_SHIFT;
 			phys = map->blknos[i] << SCOUTFS_BLOCK_SHIFT;

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",
+	TP_printk(FSID_FMT" ino %llu pgind %lu pos %llu len %u copied %d",
-		  __entry->inode, __entry->pos, __entry->len)
+		  __entry->fsid, __entry->ino, __entry->idx, __entry->pos,
+		  __entry->len, __entry->copied)
 );
 
 TRACE_EVENT(scoutfs_dirty_inode,