From 8e8d7f13b6d5a93b3d2cf9a4ceaaf923809fd5ac Mon Sep 17 00:00:00 2001 From: David Howells Date: Thu, 5 Jan 2017 10:38:34 +0000 Subject: [PATCH] afs: Add some tracepoints Add three tracepoints to the AFS filesystem: (1) The afs_recv_data tracepoint logs data segments that are extracted from the data received from the peer through afs_extract_data(). (2) The afs_notify_call tracepoint logs notification from AF_RXRPC of data coming in to an asynchronous call. (3) The afs_cb_call tracepoint logs incoming calls that have had their operation ID extracted and mapped into a supported cache manager service call. To make (3) work, the name strings in the afs_call_type struct objects have to be annotated with __tracepoint_string. This is done with the CM_NAME() macro. Further, the AFS call state enum needs a name so that it can be used to declare parameter types. Signed-off-by: David Howells --- fs/afs/cmservice.c | 22 ++++++-- fs/afs/internal.h | 21 ++++--- fs/afs/main.c | 1 + fs/afs/rxrpc.c | 6 ++ include/trace/events/afs.h | 109 +++++++++++++++++++++++++++++++++++++ 5 files changed, 144 insertions(+), 15 deletions(-) create mode 100644 include/trace/events/afs.h diff --git a/fs/afs/cmservice.c b/fs/afs/cmservice.c index d764236072b192..a2e1e02005f67f 100644 --- a/fs/afs/cmservice.c +++ b/fs/afs/cmservice.c @@ -25,11 +25,16 @@ static int afs_deliver_cb_probe_uuid(struct afs_call *); static int afs_deliver_cb_tell_me_about_yourself(struct afs_call *); static void afs_cm_destructor(struct afs_call *); +#define CM_NAME(name) \ + const char afs_SRXCB##name##_name[] __tracepoint_string = \ + "CB." #name + /* * CB.CallBack operation type */ +static CM_NAME(CallBack); static const struct afs_call_type afs_SRXCBCallBack = { - .name = "CB.CallBack", + .name = afs_SRXCBCallBack_name, .deliver = afs_deliver_cb_callback, .abort_to_error = afs_abort_to_error, .destructor = afs_cm_destructor, @@ -38,8 +43,9 @@ static const struct afs_call_type afs_SRXCBCallBack = { /* * CB.InitCallBackState operation type */ +static CM_NAME(InitCallBackState); static const struct afs_call_type afs_SRXCBInitCallBackState = { - .name = "CB.InitCallBackState", + .name = afs_SRXCBInitCallBackState_name, .deliver = afs_deliver_cb_init_call_back_state, .abort_to_error = afs_abort_to_error, .destructor = afs_cm_destructor, @@ -48,8 +54,9 @@ static const struct afs_call_type afs_SRXCBInitCallBackState = { /* * CB.InitCallBackState3 operation type */ +static CM_NAME(InitCallBackState3); static const struct afs_call_type afs_SRXCBInitCallBackState3 = { - .name = "CB.InitCallBackState3", + .name = afs_SRXCBInitCallBackState3_name, .deliver = afs_deliver_cb_init_call_back_state3, .abort_to_error = afs_abort_to_error, .destructor = afs_cm_destructor, @@ -58,8 +65,9 @@ static const struct afs_call_type afs_SRXCBInitCallBackState3 = { /* * CB.Probe operation type */ +static CM_NAME(Probe); static const struct afs_call_type afs_SRXCBProbe = { - .name = "CB.Probe", + .name = afs_SRXCBProbe_name, .deliver = afs_deliver_cb_probe, .abort_to_error = afs_abort_to_error, .destructor = afs_cm_destructor, @@ -68,8 +76,9 @@ static const struct afs_call_type afs_SRXCBProbe = { /* * CB.ProbeUuid operation type */ +static CM_NAME(ProbeUuid); static const struct afs_call_type afs_SRXCBProbeUuid = { - .name = "CB.ProbeUuid", + .name = afs_SRXCBProbeUuid_name, .deliver = afs_deliver_cb_probe_uuid, .abort_to_error = afs_abort_to_error, .destructor = afs_cm_destructor, @@ -78,8 +87,9 @@ static const struct afs_call_type afs_SRXCBProbeUuid = { /* * CB.TellMeAboutYourself operation type */ +static CM_NAME(TellMeAboutYourself); static const struct afs_call_type afs_SRXCBTellMeAboutYourself = { - .name = "CB.TellMeAboutYourself", + .name = afs_SRXCBTellMeAboutYourself_name, .deliver = afs_deliver_cb_tell_me_about_yourself, .abort_to_error = afs_abort_to_error, .destructor = afs_cm_destructor, diff --git a/fs/afs/internal.h b/fs/afs/internal.h index 6f7a9638ba1a40..f71e58fcc2f2d9 100644 --- a/fs/afs/internal.h +++ b/fs/afs/internal.h @@ -68,6 +68,15 @@ struct afs_wait_mode { extern const struct afs_wait_mode afs_sync_call; extern const struct afs_wait_mode afs_async_call; +enum afs_call_state { + AFS_CALL_REQUESTING, /* request is being sent for outgoing call */ + AFS_CALL_AWAIT_REPLY, /* awaiting reply to outgoing call */ + AFS_CALL_AWAIT_OP_ID, /* awaiting op ID on incoming call */ + AFS_CALL_AWAIT_REQUEST, /* awaiting request data on incoming call */ + AFS_CALL_REPLYING, /* replying to incoming call */ + AFS_CALL_AWAIT_ACK, /* awaiting final ACK of incoming call */ + AFS_CALL_COMPLETE, /* Completed or failed */ +}; /* * a record of an in-progress RxRPC call */ @@ -91,15 +100,7 @@ struct afs_call { pgoff_t first; /* first page in mapping to deal with */ pgoff_t last; /* last page in mapping to deal with */ size_t offset; /* offset into received data store */ - enum { /* call state */ - AFS_CALL_REQUESTING, /* request is being sent for outgoing call */ - AFS_CALL_AWAIT_REPLY, /* awaiting reply to outgoing call */ - AFS_CALL_AWAIT_OP_ID, /* awaiting op ID on incoming call */ - AFS_CALL_AWAIT_REQUEST, /* awaiting request data on incoming call */ - AFS_CALL_REPLYING, /* replying to incoming call */ - AFS_CALL_AWAIT_ACK, /* awaiting final ACK of incoming call */ - AFS_CALL_COMPLETE, /* Completed or failed */ - } state; + enum afs_call_state state; int error; /* error code */ u32 abort_code; /* Remote abort ID or 0 */ unsigned request_size; /* size of request data */ @@ -773,6 +774,8 @@ extern int afs_fsync(struct file *, loff_t, loff_t, int); /* * debug tracing */ +#include + extern unsigned afs_debug; #define dbgprintk(FMT,...) \ diff --git a/fs/afs/main.c b/fs/afs/main.c index 0b187ef3b5b7a2..f8188feb03adba 100644 --- a/fs/afs/main.c +++ b/fs/afs/main.c @@ -15,6 +15,7 @@ #include #include #include +#define CREATE_TRACE_POINTS #include "internal.h" MODULE_DESCRIPTION("AFS Client File System"); diff --git a/fs/afs/rxrpc.c b/fs/afs/rxrpc.c index 25f05a8d21b195..f26344a8c0291a 100644 --- a/fs/afs/rxrpc.c +++ b/fs/afs/rxrpc.c @@ -416,6 +416,8 @@ static void afs_deliver_to_call(struct afs_call *call) ret = rxrpc_kernel_recv_data(afs_socket, call->rxcall, NULL, 0, &offset, false, &call->abort_code); + trace_afs_recv_data(call, 0, offset, false, ret); + if (ret == -EINPROGRESS || ret == -EAGAIN) return; if (ret == 1 || ret < 0) { @@ -541,6 +543,7 @@ static void afs_wake_up_async_call(struct sock *sk, struct rxrpc_call *rxcall, { struct afs_call *call = (struct afs_call *)call_user_ID; + trace_afs_notify_call(rxcall, call); call->need_attention = true; queue_work(afs_async_calls, &call->async_work); } @@ -689,6 +692,8 @@ static int afs_deliver_cm_op_id(struct afs_call *call) if (!afs_cm_incoming_call(call)) return -ENOTSUPP; + trace_afs_cb_call(call); + /* pass responsibility for the remainer of this message off to the * cache manager op */ return call->type->deliver(call); @@ -780,6 +785,7 @@ int afs_extract_data(struct afs_call *call, void *buf, size_t count, ret = rxrpc_kernel_recv_data(afs_socket, call->rxcall, buf, count, &call->offset, want_more, &call->abort_code); + trace_afs_recv_data(call, count, call->offset, want_more, ret); if (ret == 0 || ret == -EAGAIN) return ret; diff --git a/include/trace/events/afs.h b/include/trace/events/afs.h new file mode 100644 index 00000000000000..845907b04ff442 --- /dev/null +++ b/include/trace/events/afs.h @@ -0,0 +1,109 @@ +/* AFS tracepoints + * + * Copyright (C) 2016 Red Hat, Inc. All Rights Reserved. + * Written by David Howells (dhowells@redhat.com) + * + * This program is free software; you can redistribute it and/or + * modify it under the terms of the GNU General Public Licence + * as published by the Free Software Foundation; either version + * 2 of the Licence, or (at your option) any later version. + */ +#undef TRACE_SYSTEM +#define TRACE_SYSTEM afs + +#if !defined(_TRACE_AFS_H) || defined(TRACE_HEADER_MULTI_READ) +#define _TRACE_AFS_H + +#include + +TRACE_EVENT(afs_recv_data, + TP_PROTO(struct afs_call *call, unsigned count, unsigned offset, + bool want_more, int ret), + + TP_ARGS(call, count, offset, want_more, ret), + + TP_STRUCT__entry( + __field(struct rxrpc_call *, rxcall ) + __field(struct afs_call *, call ) + __field(enum afs_call_state, state ) + __field(unsigned int, count ) + __field(unsigned int, offset ) + __field(unsigned short, unmarshall ) + __field(bool, want_more ) + __field(int, ret ) + ), + + TP_fast_assign( + __entry->rxcall = call->rxcall; + __entry->call = call; + __entry->state = call->state; + __entry->unmarshall = call->unmarshall; + __entry->count = count; + __entry->offset = offset; + __entry->want_more = want_more; + __entry->ret = ret; + ), + + TP_printk("c=%p ac=%p s=%u u=%u %u/%u wm=%u ret=%d", + __entry->rxcall, + __entry->call, + __entry->state, __entry->unmarshall, + __entry->offset, __entry->count, + __entry->want_more, __entry->ret) + ); + +TRACE_EVENT(afs_notify_call, + TP_PROTO(struct rxrpc_call *rxcall, struct afs_call *call), + + TP_ARGS(rxcall, call), + + TP_STRUCT__entry( + __field(struct rxrpc_call *, rxcall ) + __field(struct afs_call *, call ) + __field(enum afs_call_state, state ) + __field(unsigned short, unmarshall ) + ), + + TP_fast_assign( + __entry->rxcall = rxcall; + __entry->call = call; + __entry->state = call->state; + __entry->unmarshall = call->unmarshall; + ), + + TP_printk("c=%p ac=%p s=%u u=%u", + __entry->rxcall, + __entry->call, + __entry->state, __entry->unmarshall) + ); + +TRACE_EVENT(afs_cb_call, + TP_PROTO(struct afs_call *call), + + TP_ARGS(call), + + TP_STRUCT__entry( + __field(struct rxrpc_call *, rxcall ) + __field(struct afs_call *, call ) + __field(const char *, name ) + __field(u32, op ) + ), + + TP_fast_assign( + __entry->rxcall = call->rxcall; + __entry->call = call; + __entry->name = call->type->name; + __entry->op = call->operation_ID; + ), + + TP_printk("c=%p ac=%p %s o=%u", + __entry->rxcall, + __entry->call, + __entry->name, + __entry->op) + ); + +#endif /* _TRACE_AFS_H */ + +/* This part must be outside protection */ +#include