afs: Trace the initiation and completion of client calls

Add tracepoints to trace the initiation and completion of client calls
within the kafs filesystem.

The afs_make_vl_call tracepoint watches calls to the volume location
database server.

The afs_make_fs_call tracepoint watches calls to the file server.

The afs_call_done tracepoint watches for call completion.

Signed-off-by: David Howells <dhowells@redhat.com>

5 files changed, 233 insertions, 20 deletions

diff --git a/fs/afs/fsclient.c b/fs/afs/fsclient.c
index 72ff3679fa2a..10e5ead629c2 100644
--- a/fs/afs/fsclient.c
+++ b/fs/afs/fsclient.c
@@ -16,6 +16,8 @@
 #include "internal.h"
 #include "afs_fs.h"
 
+static const struct afs_fid afs_zero_fid;
+
 /*
  * We need somewhere to discard into in case the server helpfully returns more
  * than we asked for in FS.FetchData{,64}.
@@ -299,6 +301,7 @@ static int afs_deliver_fs_fetch_status(struct afs_call *call)
  */
 static const struct afs_call_type afs_RXFSFetchStatus = {
         .name           = "FS.FetchStatus",
+        .op             = afs_FS_FetchStatus,
         .deliver        = afs_deliver_fs_fetch_status,
         .destructor     = afs_flat_call_destructor,
 };
@@ -335,6 +338,7 @@ int afs_fs_fetch_file_status(struct afs_fs_cursor *fc, struct afs_volsync *volsy
 
         call->cb_break = fc->cb_break;
         afs_use_fs_server(call, fc->cbi);
+        trace_afs_make_fs_call(call, &vnode->fid);
         return afs_make_call(&fc->ac, call, GFP_NOFS, false);
 }
 
@@ -497,12 +501,14 @@ static void afs_fetch_data_destructor(struct afs_call *call)
  */
 static const struct afs_call_type afs_RXFSFetchData = {
         .name           = "FS.FetchData",
+        .op             = afs_FS_FetchData,
         .deliver        = afs_deliver_fs_fetch_data,
         .destructor     = afs_fetch_data_destructor,
 };
 
 static const struct afs_call_type afs_RXFSFetchData64 = {
         .name           = "FS.FetchData64",
+        .op             = afs_FS_FetchData64,
         .deliver        = afs_deliver_fs_fetch_data,
         .destructor     = afs_fetch_data_destructor,
 };
@@ -527,7 +533,6 @@ static int afs_fs_fetch_data64(struct afs_fs_cursor *fc, struct afs_read *req)
         call->reply[0] = vnode;
         call->reply[1] = NULL; /* volsync */
         call->reply[2] = req;
-        call->operation_ID = FSFETCHDATA64;
 
         /* marshall the parameters */
         bp = call->request;
@@ -543,6 +548,7 @@ static int afs_fs_fetch_data64(struct afs_fs_cursor *fc, struct afs_read *req)
         atomic_inc(&req->usage);
         call->cb_break = fc->cb_break;
         afs_use_fs_server(call, fc->cbi);
+        trace_afs_make_fs_call(call, &vnode->fid);
         return afs_make_call(&fc->ac, call, GFP_NOFS, false);
 }
 
@@ -571,7 +577,6 @@ int afs_fs_fetch_data(struct afs_fs_cursor *fc, struct afs_read *req)
         call->reply[0] = vnode;
         call->reply[1] = NULL; /* volsync */
         call->reply[2] = req;
-        call->operation_ID = FSFETCHDATA;
 
         /* marshall the parameters */
         bp = call->request;
@@ -585,6 +590,7 @@ int afs_fs_fetch_data(struct afs_fs_cursor *fc, struct afs_read *req)
         atomic_inc(&req->usage);
         call->cb_break = fc->cb_break;
         afs_use_fs_server(call, fc->cbi);
+        trace_afs_make_fs_call(call, &vnode->fid);
         return afs_make_call(&fc->ac, call, GFP_NOFS, false);
 }
 
@@ -618,8 +624,16 @@ static int afs_deliver_fs_create_vnode(struct afs_call *call)
 /*
  * FS.CreateFile and FS.MakeDir operation type
  */
-static const struct afs_call_type afs_RXFSCreateXXXX = {
-        .name           = "FS.CreateXXXX",
+static const struct afs_call_type afs_RXFSCreateFile = {
+        .name           = "FS.CreateFile",
+        .op             = afs_FS_CreateFile,
+        .deliver        = afs_deliver_fs_create_vnode,
+        .destructor     = afs_flat_call_destructor,
+};
+
+static const struct afs_call_type afs_RXFSMakeDir = {
+        .name           = "FS.MakeDir",
+        .op             = afs_FS_MakeDir,
         .deliver        = afs_deliver_fs_create_vnode,
         .destructor     = afs_flat_call_destructor,
 };
@@ -646,8 +660,9 @@ int afs_fs_create(struct afs_fs_cursor *fc,
         padsz = (4 - (namesz & 3)) & 3;
         reqsz = (5 * 4) + namesz + padsz + (6 * 4);
 
-        call = afs_alloc_flat_call(net, &afs_RXFSCreateXXXX, reqsz,
-                                   (3 + 21 + 21 + 3 + 6) * 4);
+        call = afs_alloc_flat_call(
+                net, S_ISDIR(mode) ? &afs_RXFSMakeDir : &afs_RXFSCreateFile,
+                reqsz, (3 + 21 + 21 + 3 + 6) * 4);
         if (!call)
                 return -ENOMEM;
 
@@ -678,6 +693,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);
         return afs_make_call(&fc->ac, call, GFP_NOFS, false);
 }
 
@@ -708,8 +724,16 @@ static int afs_deliver_fs_remove(struct afs_call *call)
 /*
  * FS.RemoveDir/FS.RemoveFile operation type
  */
-static const struct afs_call_type afs_RXFSRemoveXXXX = {
-        .name           = "FS.RemoveXXXX",
+static const struct afs_call_type afs_RXFSRemoveFile = {
+        .name           = "FS.RemoveFile",
+        .op             = afs_FS_RemoveFile,
+        .deliver        = afs_deliver_fs_remove,
+        .destructor     = afs_flat_call_destructor,
+};
+
+static const struct afs_call_type afs_RXFSRemoveDir = {
+        .name           = "FS.RemoveDir",
+        .op             = afs_FS_RemoveDir,
         .deliver        = afs_deliver_fs_remove,
         .destructor     = afs_flat_call_destructor,
 };
@@ -731,7 +755,9 @@ int afs_fs_remove(struct afs_fs_cursor *fc, const char *name, bool isdir)
         padsz = (4 - (namesz & 3)) & 3;
         reqsz = (5 * 4) + namesz + padsz;
 
-        call = afs_alloc_flat_call(net, &afs_RXFSRemoveXXXX, reqsz, (21 + 6) * 4);
+        call = afs_alloc_flat_call(
+                net, isdir ? &afs_RXFSRemoveDir : &afs_RXFSRemoveFile,
+                reqsz, (21 + 6) * 4);
         if (!call)
                 return -ENOMEM;
 
@@ -753,6 +779,7 @@ int afs_fs_remove(struct afs_fs_cursor *fc, const char *name, bool isdir)
         }
 
         afs_use_fs_server(call, fc->cbi);
+        trace_afs_make_fs_call(call, &vnode->fid);
         return afs_make_call(&fc->ac, call, GFP_NOFS, false);
 }
 
@@ -786,6 +813,7 @@ static int afs_deliver_fs_link(struct afs_call *call)
  */
 static const struct afs_call_type afs_RXFSLink = {
         .name           = "FS.Link",
+        .op             = afs_FS_Link,
         .deliver        = afs_deliver_fs_link,
         .destructor     = afs_flat_call_destructor,
 };
@@ -834,6 +862,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);
         return afs_make_call(&fc->ac, call, GFP_NOFS, false);
 }
 
@@ -868,6 +897,7 @@ static int afs_deliver_fs_symlink(struct afs_call *call)
  */
 static const struct afs_call_type afs_RXFSSymlink = {
         .name           = "FS.Symlink",
+        .op             = afs_FS_Symlink,
         .deliver        = afs_deliver_fs_symlink,
         .destructor     = afs_flat_call_destructor,
 };
@@ -935,6 +965,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);
         return afs_make_call(&fc->ac, call, GFP_NOFS, false);
 }
 
@@ -970,6 +1001,7 @@ static int afs_deliver_fs_rename(struct afs_call *call)
  */
 static const struct afs_call_type afs_RXFSRename = {
         .name           = "FS.Rename",
+        .op             = afs_FS_Rename,
         .deliver        = afs_deliver_fs_rename,
         .destructor     = afs_flat_call_destructor,
 };
@@ -1035,6 +1067,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);
         return afs_make_call(&fc->ac, call, GFP_NOFS, false);
 }
 
@@ -1070,12 +1103,14 @@ static int afs_deliver_fs_store_data(struct afs_call *call)
  */
 static const struct afs_call_type afs_RXFSStoreData = {
         .name           = "FS.StoreData",
+        .op             = afs_FS_StoreData,
         .deliver        = afs_deliver_fs_store_data,
         .destructor     = afs_flat_call_destructor,
 };
 
 static const struct afs_call_type afs_RXFSStoreData64 = {
         .name           = "FS.StoreData64",
+        .op             = afs_FS_StoreData64,
         .deliver        = afs_deliver_fs_store_data,
         .destructor     = afs_flat_call_destructor,
 };
@@ -1135,6 +1170,7 @@ static int afs_fs_store_data64(struct afs_fs_cursor *fc,
         *bp++ = htonl(i_size >> 32);
         *bp++ = htonl((u32) i_size);
 
+        trace_afs_make_fs_call(call, &vnode->fid);
         return afs_make_call(&fc->ac, call, GFP_NOFS, false);
 }
 
@@ -1208,6 +1244,7 @@ int afs_fs_store_data(struct afs_fs_cursor *fc, struct afs_writeback *wb,
         *bp++ = htonl(i_size);
 
         afs_use_fs_server(call, fc->cbi);
+        trace_afs_make_fs_call(call, &vnode->fid);
         return afs_make_call(&fc->ac, call, GFP_NOFS, false);
 }
 
@@ -1245,18 +1282,21 @@ static int afs_deliver_fs_store_status(struct afs_call *call)
  */
 static const struct afs_call_type afs_RXFSStoreStatus = {
         .name           = "FS.StoreStatus",
+        .op             = afs_FS_StoreStatus,
         .deliver        = afs_deliver_fs_store_status,
         .destructor     = afs_flat_call_destructor,
 };
 
 static const struct afs_call_type afs_RXFSStoreData_as_Status = {
         .name           = "FS.StoreData",
+        .op             = afs_FS_StoreData,
         .deliver        = afs_deliver_fs_store_status,
         .destructor     = afs_flat_call_destructor,
 };
 
 static const struct afs_call_type afs_RXFSStoreData64_as_Status = {
         .name           = "FS.StoreData64",
+        .op             = afs_FS_StoreData64,
         .deliver        = afs_deliver_fs_store_status,
         .destructor     = afs_flat_call_destructor,
 };
@@ -1286,7 +1326,6 @@ static int afs_fs_setattr_size64(struct afs_fs_cursor *fc, struct iattr *attr)
         call->key = fc->key;
         call->reply[0] = vnode;
         call->store_version = vnode->status.data_version + 1;
-        call->operation_ID = FSSTOREDATA;
 
         /* marshall the parameters */
         bp = call->request;
@@ -1305,6 +1344,7 @@ static int afs_fs_setattr_size64(struct afs_fs_cursor *fc, struct iattr *attr)
         *bp++ = htonl((u32) attr->ia_size);
 
         afs_use_fs_server(call, fc->cbi);
+        trace_afs_make_fs_call(call, &vnode->fid);
         return afs_make_call(&fc->ac, call, GFP_NOFS, false);
 }
 
@@ -1335,7 +1375,6 @@ static int afs_fs_setattr_size(struct afs_fs_cursor *fc, struct iattr *attr)
         call->key = fc->key;
         call->reply[0] = vnode;
         call->store_version = vnode->status.data_version + 1;
-        call->operation_ID = FSSTOREDATA;
 
         /* marshall the parameters */
         bp = call->request;
@@ -1351,6 +1390,7 @@ static int afs_fs_setattr_size(struct afs_fs_cursor *fc, struct iattr *attr)
         *bp++ = htonl(attr->ia_size);           /* new file length */
 
         afs_use_fs_server(call, fc->cbi);
+        trace_afs_make_fs_call(call, &vnode->fid);
         return afs_make_call(&fc->ac, call, GFP_NOFS, false);
 }
 
@@ -1379,7 +1419,6 @@ int afs_fs_setattr(struct afs_fs_cursor *fc, struct iattr *attr)
 
         call->key = fc->key;
         call->reply[0] = vnode;
-        call->operation_ID = FSSTORESTATUS;
 
         /* marshall the parameters */
         bp = call->request;
@@ -1391,6 +1430,7 @@ int afs_fs_setattr(struct afs_fs_cursor *fc, struct iattr *attr)
         xdr_encode_AFS_StoreStatus(&bp, attr);
 
         afs_use_fs_server(call, fc->cbi);
+        trace_afs_make_fs_call(call, &vnode->fid);
         return afs_make_call(&fc->ac, call, GFP_NOFS, false);
 }
 
@@ -1581,6 +1621,7 @@ static void afs_get_volume_status_call_destructor(struct afs_call *call)
  */
 static const struct afs_call_type afs_RXFSGetVolumeStatus = {
         .name           = "FS.GetVolumeStatus",
+        .op             = afs_FS_GetVolumeStatus,
         .deliver        = afs_deliver_fs_get_volume_status,
         .destructor     = afs_get_volume_status_call_destructor,
 };
@@ -1620,6 +1661,7 @@ int afs_fs_get_volume_status(struct afs_fs_cursor *fc,
         bp[1] = htonl(vnode->fid.vid);
 
         afs_use_fs_server(call, fc->cbi);
+        trace_afs_make_fs_call(call, &vnode->fid);
         return afs_make_call(&fc->ac, call, GFP_NOFS, false);
 }
 
@@ -1650,6 +1692,7 @@ static int afs_deliver_fs_xxxx_lock(struct afs_call *call)
  */
 static const struct afs_call_type afs_RXFSSetLock = {
         .name           = "FS.SetLock",
+        .op             = afs_FS_SetLock,
         .deliver        = afs_deliver_fs_xxxx_lock,
         .destructor     = afs_flat_call_destructor,
 };
@@ -1659,6 +1702,7 @@ static const struct afs_call_type afs_RXFSSetLock = {
  */
 static const struct afs_call_type afs_RXFSExtendLock = {
         .name           = "FS.ExtendLock",
+        .op             = afs_FS_ExtendLock,
         .deliver        = afs_deliver_fs_xxxx_lock,
         .destructor     = afs_flat_call_destructor,
 };
@@ -1668,6 +1712,7 @@ static const struct afs_call_type afs_RXFSExtendLock = {
  */
 static const struct afs_call_type afs_RXFSReleaseLock = {
         .name           = "FS.ReleaseLock",
+        .op             = afs_FS_ReleaseLock,
         .deliver        = afs_deliver_fs_xxxx_lock,
         .destructor     = afs_flat_call_destructor,
 };
@@ -1700,6 +1745,7 @@ int afs_fs_set_lock(struct afs_fs_cursor *fc, afs_lock_type_t type)
         *bp++ = htonl(type);
 
         afs_use_fs_server(call, fc->cbi);
+        trace_afs_make_fs_call(call, &vnode->fid);
         return afs_make_call(&fc->ac, call, GFP_NOFS, false);
 }
 
@@ -1730,6 +1776,7 @@ int afs_fs_extend_lock(struct afs_fs_cursor *fc)
         *bp++ = htonl(vnode->fid.unique);
 
         afs_use_fs_server(call, fc->cbi);
+        trace_afs_make_fs_call(call, &vnode->fid);
         return afs_make_call(&fc->ac, call, GFP_NOFS, false);
 }
 
@@ -1760,6 +1807,7 @@ int afs_fs_release_lock(struct afs_fs_cursor *fc)
         *bp++ = htonl(vnode->fid.unique);
 
         afs_use_fs_server(call, fc->cbi);
+        trace_afs_make_fs_call(call, &vnode->fid);
         return afs_make_call(&fc->ac, call, GFP_NOFS, false);
 }
 
@@ -1776,6 +1824,7 @@ static int afs_deliver_fs_give_up_all_callbacks(struct afs_call *call)
  */
 static const struct afs_call_type afs_RXFSGiveUpAllCallBacks = {
         .name           = "FS.GiveUpAllCallBacks",
+        .op             = afs_FS_GiveUpAllCallBacks,
         .deliver        = afs_deliver_fs_give_up_all_callbacks,
         .destructor     = afs_flat_call_destructor,
 };
@@ -1866,6 +1915,7 @@ again:
  */
 static const struct afs_call_type afs_RXFSGetCapabilities = {
         .name           = "FS.GetCapabilities",
+        .op             = afs_FS_GetCapabilities,
         .deliver        = afs_deliver_fs_get_capabilities,
         .destructor     = afs_flat_call_destructor,
 };
@@ -1895,5 +1945,6 @@ int afs_fs_get_capabilities(struct afs_net *net,
         *bp++ = htonl(FSGETCAPABILITIES);
 
         /* Can't take a ref on server */
+        trace_afs_make_fs_call(call, NULL);
         return afs_make_call(ac, call, GFP_NOFS, false);
 }
diff --git a/fs/afs/internal.h b/fs/afs/internal.h
index 767317bf33db..aad12546e0ea 100644
--- a/fs/afs/internal.h
+++ b/fs/afs/internal.h
@@ -124,6 +124,7 @@ struct afs_call {
 
 struct afs_call_type {
         const char *name;
+        unsigned int op; /* Really enum afs_fs_operation */
 
         /* deliver request or reply data to an call
          * - returning an error will cause the call to be aborted
diff --git a/fs/afs/rxrpc.c b/fs/afs/rxrpc.c
index 1d075696bf55..59cc58022c4d 100644
--- a/fs/afs/rxrpc.c
+++ b/fs/afs/rxrpc.c
@@ -219,6 +219,7 @@ struct afs_call *afs_alloc_flat_call(struct afs_net *net,
                         goto nomem_free;
         }
 
+        call->operation_ID = type->op;
         init_waitqueue_head(&call->waitq);
         return call;
 
@@ -422,6 +423,8 @@ error_do_abort:
                 ac->abort_code = call->abort_code;
                 ac->responded = true;
         }
+        call->error = ret;
+        trace_afs_call_done(call);
 error_kill_call:
         afs_put_call(call);
         ac->error = ret;
@@ -455,10 +458,10 @@ static void afs_deliver_to_call(struct afs_call *call)
 
                         if (ret == -EINPROGRESS || ret == -EAGAIN)
                                 return;
-                        if (ret == 1 || ret < 0) {
-                                call->state = AFS_CALL_COMPLETE;
-                                goto done;
-                        }
+                        if (ret < 0)
+                                call->error = ret;
+                        if (ret < 0 || ret == 1)
+                                goto call_complete;
                         return;
                 }
 
@@ -466,7 +469,7 @@ static void afs_deliver_to_call(struct afs_call *call)
                 switch (ret) {
                 case 0:
                         if (call->state == AFS_CALL_AWAIT_REPLY)
-                                call->state = AFS_CALL_COMPLETE;
+                                goto call_complete;
                         goto done;
                 case -EINPROGRESS:
                 case -EAGAIN:
@@ -505,7 +508,11 @@ out:
 
 save_error:
         call->error = ret;
-        call->state = AFS_CALL_COMPLETE;
+call_complete:
+        if (call->state != AFS_CALL_COMPLETE) {
+                call->state = AFS_CALL_COMPLETE;
+                trace_afs_call_done(call);
+        }
         goto done;
 }
 
@@ -567,8 +574,10 @@ static long afs_wait_for_call_to_complete(struct afs_call *call,
         if (call->state < AFS_CALL_COMPLETE) {
                 _debug("call interrupted");
                 if (rxrpc_kernel_abort_call(call->net->socket, call->rxcall,
-                                            RX_USER_ABORT, -EINTR, "KWI"))
+                                            RX_USER_ABORT, -EINTR, "KWI")) {
                         call->error = -ERESTARTSYS;
+                        trace_afs_call_done(call);
+                }
         }
 
         ac->abort_code = call->abort_code;
@@ -882,6 +891,7 @@ int afs_extract_data(struct afs_call *call, void *buf, size_t count,
                 switch (call->state) {
                 case AFS_CALL_AWAIT_REPLY:
                         call->state = AFS_CALL_COMPLETE;
+                        trace_afs_call_done(call);
                         break;
                 case AFS_CALL_AWAIT_REQUEST:
                         call->state = AFS_CALL_REPLYING;
@@ -894,5 +904,6 @@ int afs_extract_data(struct afs_call *call, void *buf, size_t count,
 
         call->error = ret;
         call->state = AFS_CALL_COMPLETE;
+        trace_afs_call_done(call);
         return ret;
 }
diff --git a/fs/afs/vlclient.c b/fs/afs/vlclient.c
index 1d38cbdf6cad..e372f89fd36a 100644
--- a/fs/afs/vlclient.c
+++ b/fs/afs/vlclient.c
@@ -114,6 +114,7 @@ static void afs_destroy_vl_get_entry_by_name_u(struct afs_call *call)
  */
 static const struct afs_call_type afs_RXVLGetEntryByNameU = {
         .name           = "VL.GetEntryByNameU",
+        .op             = afs_VL_GetEntryByNameU,
         .deliver        = afs_deliver_vl_get_entry_by_name_u,
         .destructor     = afs_destroy_vl_get_entry_by_name_u,
 };
@@ -161,6 +162,7 @@ struct afs_vldb_entry *afs_vl_get_entry_by_name_u(struct afs_net *net,
         if (padsz > 0)
                 memset((void *)bp + volnamesz, 0, padsz);
 
+        trace_afs_make_vl_call(call);
         return (struct afs_vldb_entry *)afs_make_call(ac, call, GFP_KERNEL, false);
 }
 
@@ -251,6 +253,7 @@ static void afs_vl_get_addrs_u_destructor(struct afs_call *call)
  */
 static const struct afs_call_type afs_RXVLGetAddrsU = {
         .name           = "VL.GetAddrsU",
+        .op             = afs_VL_GetAddrsU,
         .deliver        = afs_deliver_vl_get_addrs_u,
         .destructor     = afs_vl_get_addrs_u_destructor,
 };
@@ -298,6 +301,7 @@ struct afs_addr_list *afs_vl_get_addrs_u(struct afs_net *net,
         for (i = 0; i < 6; i++)
                 r->uuid.node[i] = ntohl(u->node[i]);
 
+        trace_afs_make_vl_call(call);
         return (struct afs_addr_list *)afs_make_call(ac, call, GFP_KERNEL, false);
 }
 
@@ -362,6 +366,7 @@ again:
  */
 static const struct afs_call_type afs_RXVLGetCapabilities = {
         .name           = "VL.GetCapabilities",
+        .op             = afs_VL_GetCapabilities,
         .deliver        = afs_deliver_vl_get_capabilities,
         .destructor     = afs_flat_call_destructor,
 };
@@ -396,6 +401,7 @@ int afs_vl_get_capabilities(struct afs_net *net,
         *bp++ = htonl(VLGETCAPABILITIES);
 
         /* Can't take a ref on server */
+        trace_afs_make_vl_call(call);
         return afs_make_call(ac, call, GFP_KERNEL, false);
 }
 
@@ -598,7 +604,8 @@ again:
  * YFSVL.GetEndpoints operation type.
  */
 static const struct afs_call_type afs_YFSVLGetEndpoints = {
-        .name           = "VL.GetEndpoints",
+        .name           = "YFSVL.GetEndpoints",
+        .op             = afs_YFSVL_GetEndpoints,
         .deliver        = afs_deliver_yfsvl_get_endpoints,
         .destructor     = afs_vl_get_addrs_u_destructor,
 };
@@ -633,5 +640,6 @@ struct afs_addr_list *afs_yfsvl_get_endpoints(struct afs_net *net,
         *bp++ = htonl(YFS_SERVER_UUID);
         memcpy(bp, uuid, sizeof(*uuid)); /* Type opr_uuid */
 
+        trace_afs_make_vl_call(call);
         return (struct afs_addr_list *)afs_make_call(ac, call, GFP_KERNEL, false);
 }
diff --git a/include/trace/events/afs.h b/include/trace/events/afs.h
index 8b95c16b7045..dd9d2600ee98 100644
--- a/include/trace/events/afs.h
+++ b/include/trace/events/afs.h
@@ -30,6 +30,38 @@ enum afs_call_trace {
         afs_call_trace_work,
 };
 
+enum afs_fs_operation {
+        afs_FS_FetchData                = 130,  /* AFS Fetch file data */
+        afs_FS_FetchStatus              = 132,  /* AFS Fetch file status */
+        afs_FS_StoreData                = 133,  /* AFS Store file data */
+        afs_FS_StoreStatus              = 135,  /* AFS Store file status */
+        afs_FS_RemoveFile               = 136,  /* AFS Remove a file */
+        afs_FS_CreateFile               = 137,  /* AFS Create a file */
+        afs_FS_Rename                   = 138,  /* AFS Rename or move a file or directory */
+        afs_FS_Symlink                  = 139,  /* AFS Create a symbolic link */
+        afs_FS_Link                     = 140,  /* AFS Create a hard link */
+        afs_FS_MakeDir                  = 141,  /* AFS Create a directory */
+        afs_FS_RemoveDir                = 142,  /* AFS Remove a directory */
+        afs_FS_GetVolumeInfo            = 148,  /* AFS Get information about a volume */
+        afs_FS_GetVolumeStatus          = 149,  /* AFS Get volume status information */
+        afs_FS_GetRootVolume            = 151,  /* AFS Get root volume name */
+        afs_FS_SetLock                  = 156,  /* AFS Request a file lock */
+        afs_FS_ExtendLock               = 157,  /* AFS Extend a file lock */
+        afs_FS_ReleaseLock              = 158,  /* AFS Release a file lock */
+        afs_FS_Lookup                   = 161,  /* AFS lookup file in directory */
+        afs_FS_FetchData64              = 65537, /* AFS Fetch file data */
+        afs_FS_StoreData64              = 65538, /* AFS Store file data */
+        afs_FS_GiveUpAllCallBacks       = 65539, /* AFS Give up all our callbacks on a server */
+        afs_FS_GetCapabilities          = 65540, /* AFS Get FS server capabilities */
+};
+
+enum afs_vl_operation {
+        afs_VL_GetEntryByNameU  = 527,          /* AFS Get Vol Entry By Name operation ID */
+        afs_VL_GetAddrsU        = 533,          /* AFS Get FS server addresses */
+        afs_YFSVL_GetEndpoints  = 64002,        /* YFS Get FS & Vol server addresses */
+        afs_VL_GetCapabilities  = 65537,        /* AFS Get VL server capabilities */
+};
+
 #endif /* end __AFS_DECLARE_TRACE_ENUMS_ONCE_ONLY */
 
 /*
@@ -42,6 +74,37 @@ enum afs_call_trace {
         EM(afs_call_trace_wake,                 "WAKE ") \
         E_(afs_call_trace_work,                 "WORK ")
 
+#define afs_fs_operations \
+        EM(afs_FS_FetchData,                    "FS.FetchData") \
+        EM(afs_FS_FetchStatus,                  "FS.FetchStatus") \
+        EM(afs_FS_StoreData,                    "FS.StoreData") \
+        EM(afs_FS_StoreStatus,                  "FS.StoreStatus") \
+        EM(afs_FS_RemoveFile,                   "FS.RemoveFile") \
+        EM(afs_FS_CreateFile,                   "FS.CreateFile") \
+        EM(afs_FS_Rename,                       "FS.Rename") \
+        EM(afs_FS_Symlink,                      "FS.Symlink") \
+        EM(afs_FS_Link,                         "FS.Link") \
+        EM(afs_FS_MakeDir,                      "FS.MakeDir") \
+        EM(afs_FS_RemoveDir,                    "FS.RemoveDir") \
+        EM(afs_FS_GetVolumeInfo,                "FS.GetVolumeInfo") \
+        EM(afs_FS_GetVolumeStatus,              "FS.GetVolumeStatus") \
+        EM(afs_FS_GetRootVolume,                "FS.GetRootVolume") \
+        EM(afs_FS_SetLock,                      "FS.SetLock") \
+        EM(afs_FS_ExtendLock,                   "FS.ExtendLock") \
+        EM(afs_FS_ReleaseLock,                  "FS.ReleaseLock") \
+        EM(afs_FS_Lookup,                       "FS.Lookup") \
+        EM(afs_FS_FetchData64,                  "FS.FetchData64") \
+        EM(afs_FS_StoreData64,                  "FS.StoreData64") \
+        EM(afs_FS_GiveUpAllCallBacks,           "FS.GiveUpAllCallBacks") \
+        E_(afs_FS_GetCapabilities,              "FS.GetCapabilities")
+
+#define afs_vl_operations \
+        EM(afs_VL_GetEntryByNameU,              "VL.GetEntryByNameU") \
+        EM(afs_VL_GetAddrsU,                    "VL.GetAddrsU") \
+        EM(afs_YFSVL_GetEndpoints,              "YFSVL.GetEndpoints") \
+        E_(afs_VL_GetCapabilities,              "VL.GetCapabilities")
+
+
 /*
  * Export enum symbols via userspace.
  */
@@ -51,6 +114,8 @@ enum afs_call_trace {
 #define E_(a, b) TRACE_DEFINE_ENUM(a);
 
 afs_call_traces;
+afs_fs_operations;
+afs_vl_operations;
 
 /*
  * Now redefine the EM() and E_() macros to map the enums to the strings that
@@ -178,6 +243,83 @@ TRACE_EVENT(afs_call,
                       __entry->where)
             );
 
+TRACE_EVENT(afs_make_fs_call,
+            TP_PROTO(struct afs_call *call, const struct afs_fid *fid),
+
+            TP_ARGS(call, fid),
+
+            TP_STRUCT__entry(
+                    __field(struct afs_call *,          call            )
+                    __field(enum afs_fs_operation,      op              )
+                    __field_struct(struct afs_fid,      fid             )
+                             ),
+
+            TP_fast_assign(
+                    __entry->call = call;
+                    __entry->op = call->operation_ID;
+                    if (fid) {
+                            __entry->fid = *fid;
+                    } else {
+                            __entry->fid.vid = 0;
+                            __entry->fid.vnode = 0;
+                            __entry->fid.unique = 0;
+                    }
+                           ),
+
+            TP_printk("c=%p %06x:%06x:%06x %s",
+                      __entry->call,
+                      __entry->fid.vid,
+                      __entry->fid.vnode,
+                      __entry->fid.unique,
+                      __print_symbolic(__entry->op, afs_fs_operations))
+            );
+
+TRACE_EVENT(afs_make_vl_call,
+            TP_PROTO(struct afs_call *call),
+
+            TP_ARGS(call),
+
+            TP_STRUCT__entry(
+                    __field(struct afs_call *,          call            )
+                    __field(enum afs_vl_operation,      op              )
+                             ),
+
+            TP_fast_assign(
+                    __entry->call = call;
+                    __entry->op = call->operation_ID;
+                           ),
+
+            TP_printk("c=%p %s",
+                      __entry->call,
+                      __print_symbolic(__entry->op, afs_vl_operations))
+            );
+
+TRACE_EVENT(afs_call_done,
+            TP_PROTO(struct afs_call *call),
+
+            TP_ARGS(call),
+
+            TP_STRUCT__entry(
+                    __field(struct afs_call *,          call            )
+                    __field(struct rxrpc_call *,        rx_call         )
+                    __field(int,                        ret             )
+                    __field(u32,                        abort_code      )
+                             ),
+
+            TP_fast_assign(
+                    __entry->call = call;
+                    __entry->rx_call = call->rxcall;
+                    __entry->ret = call->error;
+                    __entry->abort_code = call->abort_code;
+                           ),
+
+            TP_printk("   c=%p ret=%d ab=%d [%p]",
+                      __entry->call,
+                      __entry->ret,
+                      __entry->abort_code,
+                      __entry->rx_call)
+            );
+
 #endif /* _TRACE_AFS_H */
 
 /* This part must be outside protection */