From f1d3b8f91d965c4fd900ac5dd06240cc9df0c7a7 Mon Sep 17 00:00:00 2001 From: Alexander Aring Date: Tue, 2 Nov 2021 15:17:15 -0400 Subject: fs: dlm: initial support for tracepoints This patch adds initial support for dlm tracepoints. It will introduce tracepoints to dlm main functionality dlm_lock()/dlm_unlock() and their complete ast() callback or blocking bast() callback. The lock/unlock functionality has a start and end tracepoint, this is because there exists a race in case if would have a tracepoint at the end position only the complete/blocking callbacks could occur before. To work with eBPF tracing and using their lookup hash functionality there could be problems that an entry was not inserted yet. However use the start functionality for hash insert and check again in end functionality if there was an dlm internal error so there is no ast callback. In further it might also that locks with local masters will occur those callbacks immediately so we must have such functionality. I did not make everything accessible yet, although it seems eBPF can be used to access a lot of internal datastructures if it's aware of the struct definitions of the running kernel instance. We still can change it, if you do eBPF experiments e.g. time measurements between lock and callback functionality you can simple use the local lkb_id field as hash value in combination with the lockspace id if you have multiple lockspaces. Otherwise you can simple use trace-cmd for some functionality, e.g. `trace-cmd record -e dlm` and `trace-cmd report` afterwards. Signed-off-by: Alexander Aring Signed-off-by: David Teigland --- include/trace/events/dlm.h | 220 +++++++++++++++++++++++++++++++++++++++++++++ 1 file changed, 220 insertions(+) create mode 100644 include/trace/events/dlm.h (limited to 'include/trace') diff --git a/include/trace/events/dlm.h b/include/trace/events/dlm.h new file mode 100644 index 000000000000..c97b4c163c3e --- /dev/null +++ b/include/trace/events/dlm.h @@ -0,0 +1,220 @@ +/* SPDX-License-Identifier: GPL-2.0 */ +#undef TRACE_SYSTEM +#define TRACE_SYSTEM dlm + +#if !defined(_TRACE_DLM_H) || defined(TRACE_HEADER_MULTI_READ) +#define _TRACE_DLM_H + +#include +#include +#include + +#include "../../../fs/dlm/dlm_internal.h" + +#define show_lock_flags(flags) __print_flags(flags, "|", \ + { DLM_LKF_NOQUEUE, "NOQUEUE" }, \ + { DLM_LKF_CANCEL, "CANCEL" }, \ + { DLM_LKF_CONVERT, "CONVERT" }, \ + { DLM_LKF_VALBLK, "VALBLK" }, \ + { DLM_LKF_QUECVT, "QUECVT" }, \ + { DLM_LKF_IVVALBLK, "IVVALBLK" }, \ + { DLM_LKF_CONVDEADLK, "CONVDEADLK" }, \ + { DLM_LKF_PERSISTENT, "PERSISTENT" }, \ + { DLM_LKF_NODLCKWT, "NODLCKWT" }, \ + { DLM_LKF_NODLCKBLK, "NODLCKBLK" }, \ + { DLM_LKF_EXPEDITE, "EXPEDITE" }, \ + { DLM_LKF_NOQUEUEBAST, "NOQUEUEBAST" }, \ + { DLM_LKF_HEADQUE, "HEADQUE" }, \ + { DLM_LKF_NOORDER, "NOORDER" }, \ + { DLM_LKF_ORPHAN, "ORPHAN" }, \ + { DLM_LKF_ALTPR, "ALTPR" }, \ + { DLM_LKF_ALTCW, "ALTCW" }, \ + { DLM_LKF_FORCEUNLOCK, "FORCEUNLOCK" }, \ + { DLM_LKF_TIMEOUT, "TIMEOUT" }) + +#define show_lock_mode(mode) __print_symbolic(mode, \ + { DLM_LOCK_IV, "IV"}, \ + { DLM_LOCK_NL, "NL"}, \ + { DLM_LOCK_CR, "CR"}, \ + { DLM_LOCK_CW, "CW"}, \ + { DLM_LOCK_PR, "PR"}, \ + { DLM_LOCK_PW, "PW"}, \ + { DLM_LOCK_EX, "EX"}) + +#define show_dlm_sb_flags(flags) __print_flags(flags, "|", \ + { DLM_SBF_DEMOTED, "DEMOTED" }, \ + { DLM_SBF_VALNOTVALID, "VALNOTVALID" }, \ + { DLM_SBF_ALTMODE, "ALTMODE" }) + +/* note: we begin tracing dlm_lock_start() only if ls and lkb are found */ +TRACE_EVENT(dlm_lock_start, + + TP_PROTO(struct dlm_ls *ls, struct dlm_lkb *lkb, int mode, + __u32 flags), + + TP_ARGS(ls, lkb, mode, flags), + + TP_STRUCT__entry( + __field(__u32, ls_id) + __field(__u32, lkb_id) + __field(int, mode) + __field(__u32, flags) + ), + + TP_fast_assign( + __entry->ls_id = ls->ls_global_id; + __entry->lkb_id = lkb->lkb_id; + __entry->mode = mode; + __entry->flags = flags; + ), + + TP_printk("ls_id=%u lkb_id=%x mode=%s flags=%s", + __entry->ls_id, __entry->lkb_id, + show_lock_mode(__entry->mode), + show_lock_flags(__entry->flags)) + +); + +TRACE_EVENT(dlm_lock_end, + + TP_PROTO(struct dlm_ls *ls, struct dlm_lkb *lkb, int mode, __u32 flags, + int error), + + TP_ARGS(ls, lkb, mode, flags, error), + + TP_STRUCT__entry( + __field(__u32, ls_id) + __field(__u32, lkb_id) + __field(int, mode) + __field(__u32, flags) + __field(int, error) + ), + + TP_fast_assign( + __entry->ls_id = ls->ls_global_id; + __entry->lkb_id = lkb->lkb_id; + __entry->mode = mode; + __entry->flags = flags; + + /* return value will be zeroed in those cases by dlm_lock() + * we do it here again to not introduce more overhead if + * trace isn't running and error reflects the return value. + */ + if (error == -EAGAIN || error == -EDEADLK) + __entry->error = 0; + else + __entry->error = error; + ), + + TP_printk("ls_id=%u lkb_id=%x mode=%s flags=%s error=%d", + __entry->ls_id, __entry->lkb_id, + show_lock_mode(__entry->mode), + show_lock_flags(__entry->flags), __entry->error) + +); + +TRACE_EVENT(dlm_bast, + + TP_PROTO(struct dlm_ls *ls, struct dlm_lkb *lkb, int mode), + + TP_ARGS(ls, lkb, mode), + + TP_STRUCT__entry( + __field(__u32, ls_id) + __field(__u32, lkb_id) + __field(int, mode) + ), + + TP_fast_assign( + __entry->ls_id = ls->ls_global_id; + __entry->lkb_id = lkb->lkb_id; + __entry->mode = mode; + ), + + TP_printk("ls_id=%u lkb_id=%x mode=%s", __entry->ls_id, + __entry->lkb_id, show_lock_mode(__entry->mode)) + +); + +TRACE_EVENT(dlm_ast, + + TP_PROTO(struct dlm_ls *ls, struct dlm_lkb *lkb, struct dlm_lksb *lksb), + + TP_ARGS(ls, lkb, lksb), + + TP_STRUCT__entry( + __field(__u32, ls_id) + __field(__u32, lkb_id) + __field(u8, sb_flags) + __field(int, sb_status) + ), + + TP_fast_assign( + __entry->ls_id = ls->ls_global_id; + __entry->lkb_id = lkb->lkb_id; + __entry->sb_flags = lksb->sb_flags; + __entry->sb_status = lksb->sb_status; + ), + + TP_printk("ls_id=%u lkb_id=%x sb_flags=%s sb_status=%d", + __entry->ls_id, __entry->lkb_id, + show_dlm_sb_flags(__entry->sb_flags), __entry->sb_status) + +); + +/* note: we begin tracing dlm_unlock_start() only if ls and lkb are found */ +TRACE_EVENT(dlm_unlock_start, + + TP_PROTO(struct dlm_ls *ls, struct dlm_lkb *lkb, __u32 flags), + + TP_ARGS(ls, lkb, flags), + + TP_STRUCT__entry( + __field(__u32, ls_id) + __field(__u32, lkb_id) + __field(__u32, flags) + ), + + TP_fast_assign( + __entry->ls_id = ls->ls_global_id; + __entry->lkb_id = lkb->lkb_id; + __entry->flags = flags; + ), + + TP_printk("ls_id=%u lkb_id=%x flags=%s", + __entry->ls_id, __entry->lkb_id, + show_lock_flags(__entry->flags)) + +); + +TRACE_EVENT(dlm_unlock_end, + + TP_PROTO(struct dlm_ls *ls, struct dlm_lkb *lkb, __u32 flags, + int error), + + TP_ARGS(ls, lkb, flags, error), + + TP_STRUCT__entry( + __field(__u32, ls_id) + __field(__u32, lkb_id) + __field(__u32, flags) + __field(int, error) + ), + + TP_fast_assign( + __entry->ls_id = ls->ls_global_id; + __entry->lkb_id = lkb->lkb_id; + __entry->flags = flags; + __entry->error = error; + ), + + TP_printk("ls_id=%u lkb_id=%x flags=%s error=%d", + __entry->ls_id, __entry->lkb_id, + show_lock_flags(__entry->flags), __entry->error) + +); + +#endif /* if !defined(_TRACE_DLM_H) || defined(TRACE_HEADER_MULTI_READ) */ + +/* This part must be outside protection */ +#include -- cgit v1.2.3-59-g8ed1b From 92732376fd29462b502f41486bcef55f49c5713e Mon Sep 17 00:00:00 2001 From: Alexander Aring Date: Tue, 2 Nov 2021 15:17:16 -0400 Subject: fs: dlm: trace socket handling This patch adds tracepoints for dlm socket receive and send functionality. We can use it to track how much data was send or received to or from a specific nodeid. Signed-off-by: Alexander Aring Signed-off-by: David Teigland --- fs/dlm/lowcomms.c | 4 ++++ include/trace/events/dlm.h | 40 ++++++++++++++++++++++++++++++++++++++++ 2 files changed, 44 insertions(+) (limited to 'include/trace') diff --git a/fs/dlm/lowcomms.c b/fs/dlm/lowcomms.c index bee3757eb4c7..6d6dcf0d5ba9 100644 --- a/fs/dlm/lowcomms.c +++ b/fs/dlm/lowcomms.c @@ -53,6 +53,8 @@ #include #include +#include + #include "dlm_internal.h" #include "lowcomms.h" #include "midcomms.h" @@ -925,6 +927,7 @@ static int receive_from_sock(struct connection *con) msg.msg_flags = MSG_DONTWAIT | MSG_NOSIGNAL; ret = kernel_recvmsg(con->sock, &msg, &iov, 1, iov.iov_len, msg.msg_flags); + trace_dlm_recv(con->nodeid, ret); if (ret == -EAGAIN) break; else if (ret <= 0) @@ -1411,6 +1414,7 @@ static void send_to_sock(struct connection *con) ret = kernel_sendpage(con->sock, e->page, offset, len, msg_flags); + trace_dlm_send(con->nodeid, ret); if (ret == -EAGAIN || ret == 0) { if (ret == -EAGAIN && test_bit(SOCKWQ_ASYNC_NOSPACE, &con->sock->flags) && diff --git a/include/trace/events/dlm.h b/include/trace/events/dlm.h index c97b4c163c3e..32088c603244 100644 --- a/include/trace/events/dlm.h +++ b/include/trace/events/dlm.h @@ -214,6 +214,46 @@ TRACE_EVENT(dlm_unlock_end, ); +TRACE_EVENT(dlm_send, + + TP_PROTO(int nodeid, int ret), + + TP_ARGS(nodeid, ret), + + TP_STRUCT__entry( + __field(int, nodeid) + __field(int, ret) + ), + + TP_fast_assign( + __entry->nodeid = nodeid; + __entry->ret = ret; + ), + + TP_printk("nodeid=%d ret=%d", __entry->nodeid, __entry->ret) + +); + +TRACE_EVENT(dlm_recv, + + TP_PROTO(int nodeid, int ret), + + TP_ARGS(nodeid, ret), + + TP_STRUCT__entry( + __field(int, nodeid) + __field(int, ret) + ), + + TP_fast_assign( + __entry->nodeid = nodeid; + __entry->ret = ret; + ), + + TP_printk("nodeid=%d ret=%d", __entry->nodeid, __entry->ret) + +); + #endif /* if !defined(_TRACE_DLM_H) || defined(TRACE_HEADER_MULTI_READ) */ /* This part must be outside protection */ -- cgit v1.2.3-59-g8ed1b