fd: dlm: trace send/recv of dlm message and rcom

[ Upstream commit 4e2c53902b680f20f248da51c78e4f82215ab81c ]

This patch adds tracepoints for send and recv cases of dlm messages and
dlm rcom messages. In case of send and dlm message we add the dlm rsb
resource name this dlm messages belongs to. This has the advantage to
follow dlm messages on a per lock basis. In case of recv message the
resource name can be extracted by follow the send message sequence
number.

The dlm message DLM_MSG_PURGE doesn't belong to a lock request and will
not set the resource name in a dlm_message trace. The same for all rcom
messages.

There is additional handling required for this debugging functionality
which is tried to be small as possible. Also the midcomms layer gets
aware of lock resource names, for now this is required to make a
connection between sequence number and lock resource names. It is for
debugging purpose only.

Signed-off-by: Alexander Aring <aahringo@redhat.com>
Signed-off-by: David Teigland <teigland@redhat.com>
Stable-dep-of: caf2799e0b84 ("fs: dlm: fix use after free in midcomms commit")
Signed-off-by: Sasha Levin <sashal@kernel.org>

diff --git a/fs/dlm/lock.c b/fs/dlm/lock.c
index b246d71b5e17a6864640652fef9e133b7caf1ee6..0b1bc24536cebe7026053f03ca27a5c34c77bbea 100644 (file)
--- a/fs/dlm/lock.c
+++ b/fs/dlm/lock.c
@@ -3611,9 +3611,10 @@ static int create_message(struct dlm_rsb *r, struct dlm_lkb *lkb,
 /* further lowcomms enhancements or alternate implementations may make
    the return value from this function useful at some point */
 
-static int send_message(struct dlm_mhandle *mh, struct dlm_message *ms)
+static int send_message(struct dlm_mhandle *mh, struct dlm_message *ms,
+                       const void *name, int namelen)
 {
-       dlm_midcomms_commit_mhandle(mh);
+       dlm_midcomms_commit_mhandle(mh, name, namelen);
        return 0;
 }
 
@@ -3679,7 +3680,7 @@ static int send_common(struct dlm_rsb *r, struct dlm_lkb *lkb, int mstype)
 
        send_args(r, lkb, ms);
 
-       error = send_message(mh, ms);
+       error = send_message(mh, ms, r->res_name, r->res_length);
        if (error)
                goto fail;
        return 0;
@@ -3742,7 +3743,7 @@ static int send_grant(struct dlm_rsb *r, struct dlm_lkb *lkb)
 
        ms->m_result = 0;
 
-       error = send_message(mh, ms);
+       error = send_message(mh, ms, r->res_name, r->res_length);
  out:
        return error;
 }
@@ -3763,7 +3764,7 @@ static int send_bast(struct dlm_rsb *r, struct dlm_lkb *lkb, int mode)
 
        ms->m_bastmode = cpu_to_le32(mode);
 
-       error = send_message(mh, ms);
+       error = send_message(mh, ms, r->res_name, r->res_length);
  out:
        return error;
 }
@@ -3786,7 +3787,7 @@ static int send_lookup(struct dlm_rsb *r, struct dlm_lkb *lkb)
 
        send_args(r, lkb, ms);
 
-       error = send_message(mh, ms);
+       error = send_message(mh, ms, r->res_name, r->res_length);
        if (error)
                goto fail;
        return 0;
@@ -3811,7 +3812,7 @@ static int send_remove(struct dlm_rsb *r)
        memcpy(ms->m_extra, r->res_name, r->res_length);
        ms->m_hash = cpu_to_le32(r->res_hash);
 
-       error = send_message(mh, ms);
+       error = send_message(mh, ms, r->res_name, r->res_length);
  out:
        return error;
 }
@@ -3833,7 +3834,7 @@ static int send_common_reply(struct dlm_rsb *r, struct dlm_lkb *lkb,
 
        ms->m_result = cpu_to_le32(to_dlm_errno(rv));
 
-       error = send_message(mh, ms);
+       error = send_message(mh, ms, r->res_name, r->res_length);
  out:
        return error;
 }
@@ -3874,7 +3875,7 @@ static int send_lookup_reply(struct dlm_ls *ls, struct dlm_message *ms_in,
        ms->m_result = cpu_to_le32(to_dlm_errno(rv));
        ms->m_nodeid = cpu_to_le32(ret_nodeid);
 
-       error = send_message(mh, ms);
+       error = send_message(mh, ms, ms_in->m_extra, receive_extralen(ms_in));
  out:
        return error;
 }
@@ -6300,7 +6301,7 @@ static int send_purge(struct dlm_ls *ls, int nodeid, int pid)
        ms->m_nodeid = cpu_to_le32(nodeid);
        ms->m_pid = cpu_to_le32(pid);
 
-       return send_message(mh, ms);
+       return send_message(mh, ms, NULL, 0);
 }
 
 int dlm_user_purge(struct dlm_ls *ls, struct dlm_user_proc *proc,

diff --git a/fs/dlm/midcomms.c b/fs/dlm/midcomms.c
index 4a8721ab9f149c0c2f43454487621d56ceeb8c64..8d11f104a97ebdbaff844b152803adf1e5b22f07 100644 (file)
--- a/fs/dlm/midcomms.c
+++ b/fs/dlm/midcomms.c
@@ -132,6 +132,7 @@
  */
 #define DLM_DEBUG_FENCE_TERMINATION    0
 
+#include <trace/events/dlm.h>
 #include <net/tcp.h>
 
 #include "dlm_internal.h"
@@ -415,7 +416,7 @@ static int dlm_send_fin(struct midcomms_node *node,
        m_header->h_cmd = DLM_FIN;
 
        pr_debug("sending fin msg to node %d\n", node->nodeid);
-       dlm_midcomms_commit_mhandle(mh);
+       dlm_midcomms_commit_mhandle(mh, NULL, 0);
        set_bit(DLM_NODE_FLAG_STOP_TX, &node->flags);
 
        return 0;
@@ -474,6 +475,20 @@ static void dlm_pas_fin_ack_rcv(struct midcomms_node *node)
        spin_unlock(&node->state_lock);
 }
 
+static void dlm_receive_buffer_3_2_trace(uint32_t seq, union dlm_packet *p)
+{
+       switch (p->header.h_cmd) {
+       case DLM_MSG:
+               trace_dlm_recv_message(seq, &p->message);
+               break;
+       case DLM_RCOM:
+               trace_dlm_recv_rcom(seq, &p->rcom);
+               break;
+       default:
+               break;
+       }
+}
+
 static void dlm_midcomms_receive_buffer(union dlm_packet *p,
                                        struct midcomms_node *node,
                                        uint32_t seq)
@@ -534,6 +549,7 @@ static void dlm_midcomms_receive_buffer(union dlm_packet *p,
                        break;
                default:
                        WARN_ON(test_bit(DLM_NODE_FLAG_STOP_RX, &node->flags));
+                       dlm_receive_buffer_3_2_trace(seq, p);
                        dlm_receive_buffer(p, node->nodeid);
                        set_bit(DLM_NODE_ULP_DELIVERED, &node->flags);
                        break;
@@ -1124,11 +1140,30 @@ err:
 }
 #endif
 
-static void dlm_midcomms_commit_msg_3_2(struct dlm_mhandle *mh)
+static void dlm_midcomms_commit_msg_3_2_trace(const struct dlm_mhandle *mh,
+                                             const void *name, int namelen)
+{
+       switch (mh->inner_p->header.h_cmd) {
+       case DLM_MSG:
+               trace_dlm_send_message(mh->seq, &mh->inner_p->message,
+                                      name, namelen);
+               break;
+       case DLM_RCOM:
+               trace_dlm_send_rcom(mh->seq, &mh->inner_p->rcom);
+               break;
+       default:
+               /* nothing to trace */
+               break;
+       }
+}
+
+static void dlm_midcomms_commit_msg_3_2(struct dlm_mhandle *mh,
+                                       const void *name, int namelen)
 {
        /* nexthdr chain for fast lookup */
        mh->opts->o_nextcmd = mh->inner_p->header.h_cmd;
        mh->committed = true;
+       dlm_midcomms_commit_msg_3_2_trace(mh, name, namelen);
        dlm_lowcomms_commit_msg(mh->msg);
 }
 
@@ -1136,8 +1171,10 @@ static void dlm_midcomms_commit_msg_3_2(struct dlm_mhandle *mh)
  * dlm_midcomms_get_mhandle
  */
 #ifndef __CHECKER__
-void dlm_midcomms_commit_mhandle(struct dlm_mhandle *mh)
+void dlm_midcomms_commit_mhandle(struct dlm_mhandle *mh,
+                                const void *name, int namelen)
 {
+
        switch (mh->node->version) {
        case DLM_VERSION_3_1:
                srcu_read_unlock(&nodes_srcu, mh->idx);
@@ -1148,7 +1185,7 @@ void dlm_midcomms_commit_mhandle(struct dlm_mhandle *mh)
                dlm_free_mhandle(mh);
                break;
        case DLM_VERSION_3_2:
-               dlm_midcomms_commit_msg_3_2(mh);
+               dlm_midcomms_commit_msg_3_2(mh, name, namelen);
                srcu_read_unlock(&nodes_srcu, mh->idx);
                break;
        default:

diff --git a/fs/dlm/midcomms.h b/fs/dlm/midcomms.h
index f61fce622e93d6c7cbf53f7d11be0b686262ab63..69296552d5add634a83ad8bfd596fa038e6b42d0 100644 (file)
--- a/fs/dlm/midcomms.h
+++ b/fs/dlm/midcomms.h
@@ -17,7 +17,8 @@ struct midcomms_node;
 int dlm_process_incoming_buffer(int nodeid, unsigned char *buf, int buflen);
 struct dlm_mhandle *dlm_midcomms_get_mhandle(int nodeid, int len,
                                             gfp_t allocation, char **ppc);
-void dlm_midcomms_commit_mhandle(struct dlm_mhandle *mh);
+void dlm_midcomms_commit_mhandle(struct dlm_mhandle *mh, const void *name,
+                                int namelen);
 int dlm_midcomms_close(int nodeid);
 int dlm_midcomms_start(void);
 void dlm_midcomms_stop(void);

diff --git a/fs/dlm/rcom.c b/fs/dlm/rcom.c
index f19860315043a4ffd99c5e19d28c8260950c09a5..b76d52e2f6bdde4c2ff89b7c4760ed9e98e4c52e 100644 (file)
--- a/fs/dlm/rcom.c
+++ b/fs/dlm/rcom.c
@@ -91,7 +91,7 @@ static int create_rcom_stateless(struct dlm_ls *ls, int to_nodeid, int type,
 
 static void send_rcom(struct dlm_mhandle *mh, struct dlm_rcom *rc)
 {
-       dlm_midcomms_commit_mhandle(mh);
+       dlm_midcomms_commit_mhandle(mh, NULL, 0);
 }
 
 static void send_rcom_stateless(struct dlm_msg *msg, struct dlm_rcom *rc)
@@ -516,7 +516,7 @@ int dlm_send_ls_not_ready(int nodeid, struct dlm_rcom *rc_in)
        rf = (struct rcom_config *) rc->rc_buf;
        rf->rf_lvblen = cpu_to_le32(~0U);
 
-       dlm_midcomms_commit_mhandle(mh);
+       dlm_midcomms_commit_mhandle(mh, NULL, 0);
 
        return 0;
 }

diff --git a/include/trace/events/dlm.h b/include/trace/events/dlm.h
index da0eaae98fa34641923fe7af8f0e3e686a092090..4ec47828d55eda8211fba9363fcb7ab00a4d1f8a 100644 (file)
--- a/include/trace/events/dlm.h
+++ b/include/trace/events/dlm.h
@@ -46,6 +46,56 @@
        { DLM_SBF_VALNOTVALID,  "VALNOTVALID" },                \
        { DLM_SBF_ALTMODE,      "ALTMODE" })
 
+#define show_lkb_flags(flags) __print_flags(flags, "|",                \
+       { DLM_IFL_MSTCPY,       "MSTCPY" },                     \
+       { DLM_IFL_RESEND,       "RESEND" },                     \
+       { DLM_IFL_DEAD,         "DEAD" },                       \
+       { DLM_IFL_OVERLAP_UNLOCK, "OVERLAP_UNLOCK" },           \
+       { DLM_IFL_OVERLAP_CANCEL, "OVERLAP_CANCEL" },           \
+       { DLM_IFL_ENDOFLIFE,    "ENDOFLIFE" },                  \
+       { DLM_IFL_DEADLOCK_CANCEL, "DEADLOCK_CANCEL" },         \
+       { DLM_IFL_STUB_MS,      "STUB_MS" },                    \
+       { DLM_IFL_USER,         "USER" },                       \
+       { DLM_IFL_ORPHAN,       "ORPHAN" })
+
+#define show_header_cmd(cmd) __print_symbolic(cmd,             \
+       { DLM_MSG,              "MSG"},                         \
+       { DLM_RCOM,             "RCOM"},                        \
+       { DLM_OPTS,             "OPTS"},                        \
+       { DLM_ACK,              "ACK"},                         \
+       { DLM_FIN,              "FIN"})
+
+#define show_message_version(version) __print_symbolic(version,        \
+       { DLM_VERSION_3_1,      "3.1"},                         \
+       { DLM_VERSION_3_2,      "3.2"})
+
+#define show_message_type(type) __print_symbolic(type,         \
+       { DLM_MSG_REQUEST,      "REQUEST"},                     \
+       { DLM_MSG_CONVERT,      "CONVERT"},                     \
+       { DLM_MSG_UNLOCK,       "UNLOCK"},                      \
+       { DLM_MSG_CANCEL,       "CANCEL"},                      \
+       { DLM_MSG_REQUEST_REPLY, "REQUEST_REPLY"},              \
+       { DLM_MSG_CONVERT_REPLY, "CONVERT_REPLY"},              \
+       { DLM_MSG_UNLOCK_REPLY, "UNLOCK_REPLY"},                \
+       { DLM_MSG_CANCEL_REPLY, "CANCEL_REPLY"},                \
+       { DLM_MSG_GRANT,        "GRANT"},                       \
+       { DLM_MSG_BAST,         "BAST"},                        \
+       { DLM_MSG_LOOKUP,       "LOOKUP"},                      \
+       { DLM_MSG_REMOVE,       "REMOVE"},                      \
+       { DLM_MSG_LOOKUP_REPLY, "LOOKUP_REPLY"},                \
+       { DLM_MSG_PURGE,        "PURGE"})
+
+#define show_rcom_type(type) __print_symbolic(type,            \
+       { DLM_RCOM_STATUS,              "STATUS"},              \
+       { DLM_RCOM_NAMES,               "NAMES"},               \
+       { DLM_RCOM_LOOKUP,              "LOOKUP"},              \
+       { DLM_RCOM_LOCK,                "LOCK"},                \
+       { DLM_RCOM_STATUS_REPLY,        "STATUS_REPLY"},        \
+       { DLM_RCOM_NAMES_REPLY,         "NAMES_REPLY"},         \
+       { DLM_RCOM_LOOKUP_REPLY,        "LOOKUP_REPLY"},        \
+       { DLM_RCOM_LOCK_REPLY,          "LOCK_REPLY"})
+
+
 /* note: we begin tracing dlm_lock_start() only if ls and lkb are found */
 TRACE_EVENT(dlm_lock_start,
 
@@ -290,6 +340,253 @@ TRACE_EVENT(dlm_unlock_end,
 
 );
 
+DECLARE_EVENT_CLASS(dlm_rcom_template,
+
+       TP_PROTO(uint32_t seq, const struct dlm_rcom *rc),
+
+       TP_ARGS(seq, rc),
+
+       TP_STRUCT__entry(
+               __field(uint32_t, seq)
+               __field(uint32_t, h_version)
+               __field(uint32_t, h_lockspace)
+               __field(uint32_t, h_nodeid)
+               __field(uint16_t, h_length)
+               __field(uint8_t, h_cmd)
+               __field(uint32_t, rc_type)
+               __field(int32_t, rc_result)
+               __field(uint64_t, rc_id)
+               __field(uint64_t, rc_seq)
+               __field(uint64_t, rc_seq_reply)
+               __dynamic_array(unsigned char, rc_buf,
+                               le16_to_cpu(rc->rc_header.h_length) - sizeof(*rc))
+       ),
+
+       TP_fast_assign(
+               __entry->seq = seq;
+               __entry->h_version = le32_to_cpu(rc->rc_header.h_version);
+               __entry->h_lockspace = le32_to_cpu(rc->rc_header.u.h_lockspace);
+               __entry->h_nodeid = le32_to_cpu(rc->rc_header.h_nodeid);
+               __entry->h_length = le16_to_cpu(rc->rc_header.h_length);
+               __entry->h_cmd = rc->rc_header.h_cmd;
+               __entry->rc_type = le32_to_cpu(rc->rc_type);
+               __entry->rc_result = le32_to_cpu(rc->rc_result);
+               __entry->rc_id = le64_to_cpu(rc->rc_id);
+               __entry->rc_seq = le64_to_cpu(rc->rc_seq);
+               __entry->rc_seq_reply = le64_to_cpu(rc->rc_seq_reply);
+               memcpy(__get_dynamic_array(rc_buf), rc->rc_buf,
+                      __get_dynamic_array_len(rc_buf));
+       ),
+
+       TP_printk("seq=%u, h_version=%s h_lockspace=%u h_nodeid=%u "
+                 "h_length=%u h_cmd=%s rc_type=%s rc_result=%d "
+                 "rc_id=%llu rc_seq=%llu rc_seq_reply=%llu "
+                 "rc_buf=0x%s", __entry->seq,
+                 show_message_version(__entry->h_version),
+                 __entry->h_lockspace, __entry->h_nodeid, __entry->h_length,
+                 show_header_cmd(__entry->h_cmd),
+                 show_rcom_type(__entry->rc_type),
+                 __entry->rc_result, __entry->rc_id, __entry->rc_seq,
+                 __entry->rc_seq_reply,
+                 __print_hex_str(__get_dynamic_array(rc_buf),
+                                 __get_dynamic_array_len(rc_buf)))
+
+);
+
+DEFINE_EVENT(dlm_rcom_template, dlm_send_rcom,
+            TP_PROTO(uint32_t seq, const struct dlm_rcom *rc),
+            TP_ARGS(seq, rc));
+
+DEFINE_EVENT(dlm_rcom_template, dlm_recv_rcom,
+            TP_PROTO(uint32_t seq, const struct dlm_rcom *rc),
+            TP_ARGS(seq, rc));
+
+TRACE_EVENT(dlm_send_message,
+
+       TP_PROTO(uint32_t seq, const struct dlm_message *ms,
+                const void *name, int namelen),
+
+       TP_ARGS(seq, ms, name, namelen),
+
+       TP_STRUCT__entry(
+               __field(uint32_t, seq)
+               __field(uint32_t, h_version)
+               __field(uint32_t, h_lockspace)
+               __field(uint32_t, h_nodeid)
+               __field(uint16_t, h_length)
+               __field(uint8_t, h_cmd)
+               __field(uint32_t, m_type)
+               __field(uint32_t, m_nodeid)
+               __field(uint32_t, m_pid)
+               __field(uint32_t, m_lkid)
+               __field(uint32_t, m_remid)
+               __field(uint32_t, m_parent_lkid)
+               __field(uint32_t, m_parent_remid)
+               __field(uint32_t, m_exflags)
+               __field(uint32_t, m_sbflags)
+               __field(uint32_t, m_flags)
+               __field(uint32_t, m_lvbseq)
+               __field(uint32_t, m_hash)
+               __field(int32_t, m_status)
+               __field(int32_t, m_grmode)
+               __field(int32_t, m_rqmode)
+               __field(int32_t, m_bastmode)
+               __field(int32_t, m_asts)
+               __field(int32_t, m_result)
+               __dynamic_array(unsigned char, m_extra,
+                               le16_to_cpu(ms->m_header.h_length) - sizeof(*ms))
+               __dynamic_array(unsigned char, res_name, namelen)
+       ),
+
+       TP_fast_assign(
+               __entry->seq = seq;
+               __entry->h_version = le32_to_cpu(ms->m_header.h_version);
+               __entry->h_lockspace = le32_to_cpu(ms->m_header.u.h_lockspace);
+               __entry->h_nodeid = le32_to_cpu(ms->m_header.h_nodeid);
+               __entry->h_length = le16_to_cpu(ms->m_header.h_length);
+               __entry->h_cmd = ms->m_header.h_cmd;
+               __entry->m_type = le32_to_cpu(ms->m_type);
+               __entry->m_nodeid = le32_to_cpu(ms->m_nodeid);
+               __entry->m_pid = le32_to_cpu(ms->m_pid);
+               __entry->m_lkid = le32_to_cpu(ms->m_lkid);
+               __entry->m_remid = le32_to_cpu(ms->m_remid);
+               __entry->m_parent_lkid = le32_to_cpu(ms->m_parent_lkid);
+               __entry->m_parent_remid = le32_to_cpu(ms->m_parent_remid);
+               __entry->m_exflags = le32_to_cpu(ms->m_exflags);
+               __entry->m_sbflags = le32_to_cpu(ms->m_sbflags);
+               __entry->m_flags = le32_to_cpu(ms->m_flags);
+               __entry->m_lvbseq = le32_to_cpu(ms->m_lvbseq);
+               __entry->m_hash = le32_to_cpu(ms->m_hash);
+               __entry->m_status = le32_to_cpu(ms->m_status);
+               __entry->m_grmode = le32_to_cpu(ms->m_grmode);
+               __entry->m_rqmode = le32_to_cpu(ms->m_rqmode);
+               __entry->m_bastmode = le32_to_cpu(ms->m_bastmode);
+               __entry->m_asts = le32_to_cpu(ms->m_asts);
+               __entry->m_result = le32_to_cpu(ms->m_result);
+               memcpy(__get_dynamic_array(m_extra), ms->m_extra,
+                      __get_dynamic_array_len(m_extra));
+               memcpy(__get_dynamic_array(res_name), name,
+                      __get_dynamic_array_len(res_name));
+       ),
+
+       TP_printk("seq=%u h_version=%s h_lockspace=%u h_nodeid=%u "
+                 "h_length=%u h_cmd=%s m_type=%s m_nodeid=%u "
+                 "m_pid=%u m_lkid=%u m_remid=%u m_parent_lkid=%u "
+                 "m_parent_remid=%u m_exflags=%s m_sbflags=%s m_flags=%s "
+                 "m_lvbseq=%u m_hash=%u m_status=%d m_grmode=%s "
+                 "m_rqmode=%s m_bastmode=%s m_asts=%d m_result=%d "
+                 "m_extra=0x%s res_name=0x%s",
+                 __entry->seq, show_message_version(__entry->h_version),
+                 __entry->h_lockspace, __entry->h_nodeid, __entry->h_length,
+                 show_header_cmd(__entry->h_cmd),
+                 show_message_type(__entry->m_type),
+                 __entry->m_nodeid, __entry->m_pid, __entry->m_lkid,
+                 __entry->m_remid, __entry->m_parent_lkid,
+                 __entry->m_parent_remid, show_lock_flags(__entry->m_exflags),
+                 show_dlm_sb_flags(__entry->m_sbflags),
+                 show_lkb_flags(__entry->m_flags), __entry->m_lvbseq,
+                 __entry->m_hash, __entry->m_status,
+                 show_lock_mode(__entry->m_grmode),
+                 show_lock_mode(__entry->m_rqmode),
+                 show_lock_mode(__entry->m_bastmode),
+                 __entry->m_asts, __entry->m_result,
+                 __print_hex_str(__get_dynamic_array(m_extra),
+                                 __get_dynamic_array_len(m_extra)),
+                 __print_hex_str(__get_dynamic_array(res_name),
+                                 __get_dynamic_array_len(res_name)))
+
+);
+
+TRACE_EVENT(dlm_recv_message,
+
+       TP_PROTO(uint32_t seq, const struct dlm_message *ms),
+
+       TP_ARGS(seq, ms),
+
+       TP_STRUCT__entry(
+               __field(uint32_t, seq)
+               __field(uint32_t, h_version)
+               __field(uint32_t, h_lockspace)
+               __field(uint32_t, h_nodeid)
+               __field(uint16_t, h_length)
+               __field(uint8_t, h_cmd)
+               __field(uint32_t, m_type)
+               __field(uint32_t, m_nodeid)
+               __field(uint32_t, m_pid)
+               __field(uint32_t, m_lkid)
+               __field(uint32_t, m_remid)
+               __field(uint32_t, m_parent_lkid)
+               __field(uint32_t, m_parent_remid)
+               __field(uint32_t, m_exflags)
+               __field(uint32_t, m_sbflags)
+               __field(uint32_t, m_flags)
+               __field(uint32_t, m_lvbseq)
+               __field(uint32_t, m_hash)
+               __field(int32_t, m_status)
+               __field(int32_t, m_grmode)
+               __field(int32_t, m_rqmode)
+               __field(int32_t, m_bastmode)
+               __field(int32_t, m_asts)
+               __field(int32_t, m_result)
+               __dynamic_array(unsigned char, m_extra,
+                               le16_to_cpu(ms->m_header.h_length) - sizeof(*ms))
+       ),
+
+       TP_fast_assign(
+               __entry->seq = seq;
+               __entry->h_version = le32_to_cpu(ms->m_header.h_version);
+               __entry->h_lockspace = le32_to_cpu(ms->m_header.u.h_lockspace);
+               __entry->h_nodeid = le32_to_cpu(ms->m_header.h_nodeid);
+               __entry->h_length = le16_to_cpu(ms->m_header.h_length);
+               __entry->h_cmd = ms->m_header.h_cmd;
+               __entry->m_type = le32_to_cpu(ms->m_type);
+               __entry->m_nodeid = le32_to_cpu(ms->m_nodeid);
+               __entry->m_pid = le32_to_cpu(ms->m_pid);
+               __entry->m_lkid = le32_to_cpu(ms->m_lkid);
+               __entry->m_remid = le32_to_cpu(ms->m_remid);
+               __entry->m_parent_lkid = le32_to_cpu(ms->m_parent_lkid);
+               __entry->m_parent_remid = le32_to_cpu(ms->m_parent_remid);
+               __entry->m_exflags = le32_to_cpu(ms->m_exflags);
+               __entry->m_sbflags = le32_to_cpu(ms->m_sbflags);
+               __entry->m_flags = le32_to_cpu(ms->m_flags);
+               __entry->m_lvbseq = le32_to_cpu(ms->m_lvbseq);
+               __entry->m_hash = le32_to_cpu(ms->m_hash);
+               __entry->m_status = le32_to_cpu(ms->m_status);
+               __entry->m_grmode = le32_to_cpu(ms->m_grmode);
+               __entry->m_rqmode = le32_to_cpu(ms->m_rqmode);
+               __entry->m_bastmode = le32_to_cpu(ms->m_bastmode);
+               __entry->m_asts = le32_to_cpu(ms->m_asts);
+               __entry->m_result = le32_to_cpu(ms->m_result);
+               memcpy(__get_dynamic_array(m_extra), ms->m_extra,
+                      __get_dynamic_array_len(m_extra));
+       ),
+
+       TP_printk("seq=%u h_version=%s h_lockspace=%u h_nodeid=%u "
+                 "h_length=%u h_cmd=%s m_type=%s m_nodeid=%u "
+                 "m_pid=%u m_lkid=%u m_remid=%u m_parent_lkid=%u "
+                 "m_parent_remid=%u m_exflags=%s m_sbflags=%s m_flags=%s "
+                 "m_lvbseq=%u m_hash=%u m_status=%d m_grmode=%s "
+                 "m_rqmode=%s m_bastmode=%s m_asts=%d m_result=%d "
+                 "m_extra=0x%s",
+                 __entry->seq, show_message_version(__entry->h_version),
+                 __entry->h_lockspace, __entry->h_nodeid, __entry->h_length,
+                 show_header_cmd(__entry->h_cmd),
+                 show_message_type(__entry->m_type),
+                 __entry->m_nodeid, __entry->m_pid, __entry->m_lkid,
+                 __entry->m_remid, __entry->m_parent_lkid,
+                 __entry->m_parent_remid, show_lock_flags(__entry->m_exflags),
+                 show_dlm_sb_flags(__entry->m_sbflags),
+                 show_lkb_flags(__entry->m_flags), __entry->m_lvbseq,
+                 __entry->m_hash, __entry->m_status,
+                 show_lock_mode(__entry->m_grmode),
+                 show_lock_mode(__entry->m_rqmode),
+                 show_lock_mode(__entry->m_bastmode),
+                 __entry->m_asts, __entry->m_result,
+                 __print_hex_str(__get_dynamic_array(m_extra),
+                                 __get_dynamic_array_len(m_extra)))
+
+);
+
 TRACE_EVENT(dlm_send,
 
        TP_PROTO(int nodeid, int ret),