Gather lpfc debug logs in kernel tracefs ringbuffer

Gather lpfc debug logs in kernel tracefs ringbuffer

[Rajan Shanmugavelu]

    Having the lpfc debug logs inside a ring buffer enhances the driver to debug better/faster for hard to reproduce problem saving cyles.  Please review.

Thanks,
Rajan
Oracle Linux Engineering.

[PATCH] lpfc: Gather lpfc debug logs using tracefs ringbuffer

[Rajan Shanmugavelu]

Having this log in a ringbuffer helps to diagnose lpfc driver and
firmware issues instead of having it run again with lpfc_verbose_log
enabled saving cycles and hard to reproduce problem.

Signed-off-by: Rajan Shanmugavelu <rajan.shanmugavelu@oracle.com>
Signed-off-by: Joe Jin <joe.jin@oracle.com>
---
 drivers/scsi/lpfc/lpfc_logmsg.h | 44 ++++++++++++++++++++++++++++-------------
 drivers/scsi/lpfc/lpfc_scsi.c   | 20 +++++++++++++++++++
 include/trace/events/lpfc.h     | 41 ++++++++++++++++++++++++++++++++++++++
 3 files changed, 91 insertions(+), 14 deletions(-)
 create mode 100644 include/trace/events/lpfc.h

diff --git a/drivers/scsi/lpfc/lpfc_logmsg.h b/drivers/scsi/lpfc/lpfc_logmsg.h
index ea10f03..676ebe4 100644
--- a/drivers/scsi/lpfc/lpfc_logmsg.h
+++ b/drivers/scsi/lpfc/lpfc_logmsg.h
@@ -46,20 +46,36 @@
 #define LOG_NVME_IOERR  0x00800000      /* NVME IO Error events. */
 #define LOG_ALL_MSG	0xffffffff	/* LOG all messages */
 
-#define lpfc_printf_vlog(vport, level, mask, fmt, arg...) \
-do { \
-	{ if (((mask) & (vport)->cfg_log_verbose) || (level[1] <= '3')) \
-		dev_printk(level, &((vport)->phba->pcidev)->dev, "%d:(%d):" \
-			   fmt, (vport)->phba->brd_no, vport->vpi, ##arg); } \
+void lpfc_log_ringbuf(struct device *dev, const char *fmt, ...);
+
+#define lpfc_printf_vlog(vport, level, mask, fmt, arg...)		\
+do {									\
+	{								\
+	if (((mask) & (vport)->cfg_log_verbose) || (level[1] <= '3')) { \
+		dev_printk(level, &((vport)->phba->pcidev)->dev,	\
+			"%d:(%d):" fmt, (vport)->phba->brd_no,		\
+			vport->vpi, ##arg);				\
+	} else {							\
+		lpfc_log_ringbuf(&((vport)->phba->pcidev)->dev,		\
+			"%d:(%d):" fmt, (vport)->phba->brd_no,		\
+			vport->vpi, ##arg);				\
+	}								\
+	}								\
 } while (0)
 
-#define lpfc_printf_log(phba, level, mask, fmt, arg...) \
-do { \
-	{ uint32_t log_verbose = (phba)->pport ? \
-				 (phba)->pport->cfg_log_verbose : \
-				 (phba)->cfg_log_verbose; \
-	  if (((mask) & log_verbose) || (level[1] <= '3')) \
-		dev_printk(level, &((phba)->pcidev)->dev, "%d:" \
-			   fmt, phba->brd_no, ##arg); \
-	} \
+#define lpfc_printf_log(phba, level, mask, fmt, arg...)			\
+do {									\
+	{								\
+	uint32_t log_verbose = (phba)->pport ?				\
+		(phba)->pport->cfg_log_verbose :			\
+		(phba)->cfg_log_verbose;				\
+	if (((mask) & log_verbose) || (level[1] <= '3')) {		\
+		dev_printk(level, &((phba)->pcidev)->dev, "%d:"		\
+			fmt, phba->brd_no, ##arg);			\
+	} else {							\
+		lpfc_log_ringbuf(&((phba)->pcidev)->dev, "%d:"		\
+			fmt, phba->brd_no, ##arg);			\
+	}								\
+	}								\
 } while (0)
+
diff --git a/drivers/scsi/lpfc/lpfc_scsi.c b/drivers/scsi/lpfc/lpfc_scsi.c
index 6ba4a74..d8256e6 100644
--- a/drivers/scsi/lpfc/lpfc_scsi.c
+++ b/drivers/scsi/lpfc/lpfc_scsi.c
@@ -37,6 +37,7 @@
 #include <scsi/scsi_tcq.h>
 #include <scsi/scsi_transport_fc.h>
 
+
 #include "lpfc_version.h"
 #include "lpfc_hw4.h"
 #include "lpfc_hw.h"
@@ -52,6 +53,8 @@
 
 #define LPFC_RESET_WAIT  2
 #define LPFC_ABORT_WAIT  2
+#define CREATE_TRACE_POINTS
+#include <trace/events/lpfc.h>
 
 int _dump_buf_done = 1;
 
@@ -5927,3 +5930,20 @@ struct scsi_host_template lpfc_vport_template = {
 	.change_queue_depth	= scsi_change_queue_depth,
 	.track_queue_depth	= 1,
 };
+
+
+/*
+ * Helper function declaration.
+ */
+void lpfc_log_ringbuf(struct device *dev, const char *fmt, ...)
+{
+	struct va_format vaf;
+	va_list args;
+
+	va_start(args, fmt);
+	vaf.fmt = fmt;
+	vaf.va = &args;
+
+	trace_lpfc_dbg_log(dev, &vaf);
+	va_end(args);
+}
diff --git a/include/trace/events/lpfc.h b/include/trace/events/lpfc.h
new file mode 100644
index 00000000..4cba505
--- /dev/null
+++ b/include/trace/events/lpfc.h
@@ -0,0 +1,41 @@
+/* SPDX-License-Identifier: GPL-2.0 */
+#undef TRACE_SYSTEM
+#define TRACE_SYSTEM lpfc
+
+#if !defined(_TRACE_LPFC_H_) || defined(TRACE_HEADER_MULTI_READ)
+#define _TRACE_LPFC_H_
+
+#include <linux/tracepoint.h>
+
+/* Max debug message length */
+#define LPFC_MSG_MAX 256
+
+DECLARE_EVENT_CLASS(lpfc_log_event,
+	TP_PROTO(struct device *dev, struct va_format *vaf),
+
+	TP_ARGS(dev, vaf),
+
+	TP_STRUCT__entry(
+		__string(dname, dev_name(dev))
+		__dynamic_array(char, msg, LPFC_MSG_MAX)
+	),
+
+	TP_fast_assign(
+		__assign_str(dname, dev_name(dev));
+		vsnprintf(__get_str(msg), LPFC_MSG_MAX,
+			vaf->fmt, *vaf->va);
+	),
+
+	TP_printk("%s: %s", __get_str(dname), __get_str(msg))
+);
+
+DEFINE_EVENT(lpfc_log_event, lpfc_dbg_log,
+	TP_PROTO(struct device *dev, struct va_format *vaf),
+	TP_ARGS(dev, vaf)
+);
+
+#endif /* _TRACE_LPFC_H */
+
+#define TRACE_INCLUDE_FILE lpfc
+
+#include <trace/define_trace.h>
-- 
1.8.3.1