From 80548b03991f58758a336424a90bf9f988e3b077 Mon Sep 17 00:00:00 2001 From: David Howells Date: Thu, 25 Apr 2019 14:26:51 +0100 Subject: [PATCH] afs: Add more tracepoints Add four more tracepoints: (1) afs_make_fs_call1 - Split from afs_make_fs_call but takes a filename to log also. (2) afs_make_fs_call2 - Like the above but takes two filenames to log. (3) afs_lookup - Log the result of doing a successful lookup, including a negative result (fid 0:0). (4) afs_get_tree - Log the set up of a volume for mounting. It also extends the name buffer on the afs_edit_dir tracepoint to 24 chars and puts quotes around the filename in the text representation. Signed-off-by: David Howells --- fs/afs/dir.c | 8 ++- fs/afs/fsclient.c | 10 ++-- fs/afs/super.c | 1 + fs/afs/yfsclient.c | 14 ++--- include/trace/events/afs.h | 146 ++++++++++++++++++++++++++++++++++++++++++++- 5 files changed, 163 insertions(+), 16 deletions(-) diff --git a/fs/afs/dir.c b/fs/afs/dir.c index 6c85235..48706ee 100644 --- a/fs/afs/dir.c +++ b/fs/afs/dir.c @@ -908,8 +908,14 @@ static struct dentry *afs_lookup(struct inode *dir, struct dentry *dentry, (void *)(unsigned long)dvnode->status.data_version; } d = d_splice_alias(inode, dentry); - if (!IS_ERR_OR_NULL(d)) + if (!IS_ERR_OR_NULL(d)) { d->d_fsdata = dentry->d_fsdata; + trace_afs_lookup(dvnode, &d->d_name, + inode ? AFS_FS_I(inode) : NULL); + } else { + trace_afs_lookup(dvnode, &dentry->d_name, + inode ? AFS_FS_I(inode) : NULL); + } return d; } diff --git a/fs/afs/fsclient.c b/fs/afs/fsclient.c index 9d405f9..be4520e 100644 --- a/fs/afs/fsclient.c +++ b/fs/afs/fsclient.c @@ -830,7 +830,7 @@ int afs_fs_create(struct afs_fs_cursor *fc, *bp++ = 0; /* segment size */ afs_use_fs_server(call, fc->cbi); - trace_afs_make_fs_call(call, &vnode->fid); + trace_afs_make_fs_call1(call, &vnode->fid, name); afs_make_call(&fc->ac, call, GFP_NOFS); return afs_wait_for_call_to_complete(call, &fc->ac); } @@ -926,7 +926,7 @@ int afs_fs_remove(struct afs_fs_cursor *fc, struct afs_vnode *vnode, } afs_use_fs_server(call, fc->cbi); - trace_afs_make_fs_call(call, &dvnode->fid); + trace_afs_make_fs_call1(call, &dvnode->fid, name); afs_make_call(&fc->ac, call, GFP_NOFS); return afs_wait_for_call_to_complete(call, &fc->ac); } @@ -1019,7 +1019,7 @@ int afs_fs_link(struct afs_fs_cursor *fc, struct afs_vnode *vnode, *bp++ = htonl(vnode->fid.unique); afs_use_fs_server(call, fc->cbi); - trace_afs_make_fs_call(call, &vnode->fid); + trace_afs_make_fs_call1(call, &vnode->fid, name); afs_make_call(&fc->ac, call, GFP_NOFS); return afs_wait_for_call_to_complete(call, &fc->ac); } @@ -1134,7 +1134,7 @@ int afs_fs_symlink(struct afs_fs_cursor *fc, *bp++ = 0; /* segment size */ afs_use_fs_server(call, fc->cbi); - trace_afs_make_fs_call(call, &vnode->fid); + trace_afs_make_fs_call1(call, &vnode->fid, name); afs_make_call(&fc->ac, call, GFP_NOFS); return afs_wait_for_call_to_complete(call, &fc->ac); } @@ -1253,7 +1253,7 @@ int afs_fs_rename(struct afs_fs_cursor *fc, } afs_use_fs_server(call, fc->cbi); - trace_afs_make_fs_call(call, &orig_dvnode->fid); + trace_afs_make_fs_call2(call, &orig_dvnode->fid, orig_name, new_name); afs_make_call(&fc->ac, call, GFP_NOFS); return afs_wait_for_call_to_complete(call, &fc->ac); } diff --git a/fs/afs/super.c b/fs/afs/super.c index 6438849..ce85ae6 100644 --- a/fs/afs/super.c +++ b/fs/afs/super.c @@ -550,6 +550,7 @@ static int afs_get_tree(struct fs_context *fc) } fc->root = dget(sb->s_root); + trace_afs_get_tree(as->cell, as->volume); _leave(" = 0 [%p]", sb); return 0; diff --git a/fs/afs/yfsclient.c b/fs/afs/yfsclient.c index 73546c2..5ea0350 100644 --- a/fs/afs/yfsclient.c +++ b/fs/afs/yfsclient.c @@ -809,7 +809,7 @@ int yfs_fs_create_file(struct afs_fs_cursor *fc, yfs_check_req(call, bp); afs_use_fs_server(call, fc->cbi); - trace_afs_make_fs_call(call, &vnode->fid); + trace_afs_make_fs_call1(call, &vnode->fid, name); afs_make_call(&fc->ac, call, GFP_NOFS); return afs_wait_for_call_to_complete(call, &fc->ac); } @@ -873,7 +873,7 @@ int yfs_fs_make_dir(struct afs_fs_cursor *fc, yfs_check_req(call, bp); afs_use_fs_server(call, fc->cbi); - trace_afs_make_fs_call(call, &vnode->fid); + trace_afs_make_fs_call1(call, &vnode->fid, name); afs_make_call(&fc->ac, call, GFP_NOFS); return afs_wait_for_call_to_complete(call, &fc->ac); } @@ -964,7 +964,7 @@ int yfs_fs_remove_file2(struct afs_fs_cursor *fc, struct afs_vnode *vnode, yfs_check_req(call, bp); afs_use_fs_server(call, fc->cbi); - trace_afs_make_fs_call(call, &dvnode->fid); + trace_afs_make_fs_call1(call, &dvnode->fid, name); afs_make_call(&fc->ac, call, GFP_NOFS); return afs_wait_for_call_to_complete(call, &fc->ac); } @@ -1052,7 +1052,7 @@ int yfs_fs_remove(struct afs_fs_cursor *fc, struct afs_vnode *vnode, yfs_check_req(call, bp); afs_use_fs_server(call, fc->cbi); - trace_afs_make_fs_call(call, &dvnode->fid); + trace_afs_make_fs_call1(call, &dvnode->fid, name); afs_make_call(&fc->ac, call, GFP_NOFS); return afs_wait_for_call_to_complete(call, &fc->ac); } @@ -1138,7 +1138,7 @@ int yfs_fs_link(struct afs_fs_cursor *fc, struct afs_vnode *vnode, yfs_check_req(call, bp); afs_use_fs_server(call, fc->cbi); - trace_afs_make_fs_call(call, &vnode->fid); + trace_afs_make_fs_call1(call, &vnode->fid, name); afs_make_call(&fc->ac, call, GFP_NOFS); return afs_wait_for_call_to_complete(call, &fc->ac); } @@ -1235,7 +1235,7 @@ int yfs_fs_symlink(struct afs_fs_cursor *fc, yfs_check_req(call, bp); afs_use_fs_server(call, fc->cbi); - trace_afs_make_fs_call(call, &dvnode->fid); + trace_afs_make_fs_call1(call, &dvnode->fid, name); afs_make_call(&fc->ac, call, GFP_NOFS); return afs_wait_for_call_to_complete(call, &fc->ac); } @@ -1334,7 +1334,7 @@ int yfs_fs_rename(struct afs_fs_cursor *fc, yfs_check_req(call, bp); afs_use_fs_server(call, fc->cbi); - trace_afs_make_fs_call(call, &orig_dvnode->fid); + trace_afs_make_fs_call2(call, &orig_dvnode->fid, orig_name, new_name); afs_make_call(&fc->ac, call, GFP_NOFS); return afs_wait_for_call_to_complete(call, &fc->ac); } diff --git a/include/trace/events/afs.h b/include/trace/events/afs.h index f67815e..e81d6a5 100644 --- a/include/trace/events/afs.h +++ b/include/trace/events/afs.h @@ -539,6 +539,88 @@ TRACE_EVENT(afs_make_fs_call, __print_symbolic(__entry->op, afs_fs_operations)) ); +TRACE_EVENT(afs_make_fs_call1, + TP_PROTO(struct afs_call *call, const struct afs_fid *fid, + const char *name), + + TP_ARGS(call, fid, name), + + TP_STRUCT__entry( + __field(unsigned int, call ) + __field(enum afs_fs_operation, op ) + __field_struct(struct afs_fid, fid ) + __array(char, name, 24 ) + ), + + TP_fast_assign( + int __len = strlen(name); + __len = min(__len, 23); + __entry->call = call->debug_id; + __entry->op = call->operation_ID; + if (fid) { + __entry->fid = *fid; + } else { + __entry->fid.vid = 0; + __entry->fid.vnode = 0; + __entry->fid.unique = 0; + } + memcpy(__entry->name, name, __len); + __entry->name[__len] = 0; + ), + + TP_printk("c=%08x %06llx:%06llx:%06x %s \"%s\"", + __entry->call, + __entry->fid.vid, + __entry->fid.vnode, + __entry->fid.unique, + __print_symbolic(__entry->op, afs_fs_operations), + __entry->name) + ); + +TRACE_EVENT(afs_make_fs_call2, + TP_PROTO(struct afs_call *call, const struct afs_fid *fid, + const char *name, const char *name2), + + TP_ARGS(call, fid, name, name2), + + TP_STRUCT__entry( + __field(unsigned int, call ) + __field(enum afs_fs_operation, op ) + __field_struct(struct afs_fid, fid ) + __array(char, name, 24 ) + __array(char, name2, 24 ) + ), + + TP_fast_assign( + int __len = strlen(name); + int __len2 = strlen(name2); + __len = min(__len, 23); + __len2 = min(__len2, 23); + __entry->call = call->debug_id; + __entry->op = call->operation_ID; + if (fid) { + __entry->fid = *fid; + } else { + __entry->fid.vid = 0; + __entry->fid.vnode = 0; + __entry->fid.unique = 0; + } + memcpy(__entry->name, name, __len); + __entry->name[__len] = 0; + memcpy(__entry->name2, name2, __len2); + __entry->name2[__len2] = 0; + ), + + TP_printk("c=%08x %06llx:%06llx:%06x %s \"%s\" \"%s\"", + __entry->call, + __entry->fid.vid, + __entry->fid.vnode, + __entry->fid.unique, + __print_symbolic(__entry->op, afs_fs_operations), + __entry->name, + __entry->name2) + ); + TRACE_EVENT(afs_make_vl_call, TP_PROTO(struct afs_call *call), @@ -736,6 +818,38 @@ TRACE_EVENT(afs_call_state, __entry->ret, __entry->abort) ); +TRACE_EVENT(afs_lookup, + TP_PROTO(struct afs_vnode *dvnode, const struct qstr *name, + struct afs_vnode *vnode), + + TP_ARGS(dvnode, name, vnode), + + TP_STRUCT__entry( + __field_struct(struct afs_fid, dfid ) + __field_struct(struct afs_fid, fid ) + __array(char, name, 24 ) + ), + + TP_fast_assign( + int __len = min_t(int, name->len, 23); + __entry->dfid = dvnode->fid; + if (vnode) { + __entry->fid = vnode->fid; + } else { + __entry->fid.vid = 0; + __entry->fid.vnode = 0; + __entry->fid.unique = 0; + } + memcpy(__entry->name, name->name, __len); + __entry->name[__len] = 0; + ), + + TP_printk("d=%llx:%llx:%x \"%s\" f=%llx:%x", + __entry->dfid.vid, __entry->dfid.vnode, __entry->dfid.unique, + __entry->name, + __entry->fid.vnode, __entry->fid.unique) + ); + TRACE_EVENT(afs_edit_dir, TP_PROTO(struct afs_vnode *dvnode, enum afs_edit_dir_reason why, @@ -757,12 +871,12 @@ TRACE_EVENT(afs_edit_dir, __field(unsigned short, slot ) __field(unsigned int, f_vnode ) __field(unsigned int, f_unique ) - __array(char, name, 18 ) + __array(char, name, 24 ) ), TP_fast_assign( int __len = strlen(name); - __len = min(__len, 17); + __len = min(__len, 23); __entry->vnode = dvnode->fid.vnode; __entry->unique = dvnode->fid.unique; __entry->why = why; @@ -775,7 +889,7 @@ TRACE_EVENT(afs_edit_dir, __entry->name[__len] = 0; ), - TP_printk("d=%x:%x %s %s %u[%u] f=%x:%x %s", + TP_printk("d=%x:%x %s %s %u[%u] f=%x:%x \"%s\"", __entry->vnode, __entry->unique, __print_symbolic(__entry->why, afs_edit_dir_reasons), __print_symbolic(__entry->op, afs_edit_dir_ops), @@ -994,6 +1108,32 @@ TRACE_EVENT(afs_silly_rename, __entry->done) ); +TRACE_EVENT(afs_get_tree, + TP_PROTO(struct afs_cell *cell, struct afs_volume *volume), + + TP_ARGS(cell, volume), + + TP_STRUCT__entry( + __field(u64, vid ) + __array(char, cell, 24 ) + __array(char, volume, 24 ) + ), + + TP_fast_assign( + int __len; + __entry->vid = volume->vid; + __len = min_t(int, cell->name_len, 23); + memcpy(__entry->cell, cell->name, __len); + __entry->cell[__len] = 0; + __len = min_t(int, volume->name_len, 23); + memcpy(__entry->volume, volume->name, __len); + __entry->volume[__len] = 0; + ), + + TP_printk("--- MOUNT %s:%s %llx", + __entry->cell, __entry->volume, __entry->vid) + ); + #endif /* _TRACE_AFS_H */ /* This part must be outside protection */ -- 2.7.4