Re: [PATCH] iscsi: Capture iscsi debug messages using tracepoints

[Fred Herard <fred.herard-QHcLZuEGTsvQT0dZR+AlfA@public.gmane.org>]

Doug,

Response is inline below.

On 11/26/2018 08:41 PM, Douglas Gilbert wrote:
> Lee,
> See about 3/4 of the way down your patch.
>
> Summary: how about generalizing the message logging to tracefs so the
> whole SCSI subsystem can use it?
>
> Doug Gilbert
>
>
> On 2018-11-26 8:01 p.m., Lee Duncan wrote:
>> On 11/21/18 9:04 AM, fred.herard@oracle.com wrote:
>>> From: Fred Herard <fred.herard@oracle.com>
>>>
>>> This commit enhances iscsi initiator modules to capture iscsi debug 
>>> messages
>>> using linux kernel tracepoint facility:
>>>
>>> https://www.kernel.org/doc/Documentation/trace/tracepoints.txt
>>>
>>> The following tracepoint events have been created under the iscsi 
>>> tracepoint
>>> event group:
>>>
>>> iscsi_dbg_conn - to capture connection debug messages (libiscsi module)
>>> iscsi_dbg_session - to capture session debug messages (libiscsi module)
>>> iscsi_dbg_eh - to capture error handling debug messages (libiscsi 
>>> module)
>>> iscsi_dbg_tcp - to capture iscsi tcp debug messages (libiscsi_tcp 
>>> module)
>>> iscsi_dbg_sw_tcp - to capture iscsi sw tcp debug messages (iscsi_tcp 
>>> module)
>>> iscsi_dbg_trans_session - to cpature iscsi trasnsport sess debug 
>>> messages
>>>     (scsi_transport_iscsi module)
>>> iscsi_dbg_trans_conn - to capture iscsi tansport conn debug messages
>>>     (scsi_transport_iscsi module)
>>>
>>> Signed-off-by: Fred Herard <fred.herard@oracle.com>
>>> Reviewed-by: Rajan Shanmugavelu <rajan.shanmugavelu@oracle.com>
>>> ---
>>>   drivers/scsi/iscsi_tcp.c            |   4 ++
>>>   drivers/scsi/libiscsi.c             |  10 +++
>>>   drivers/scsi/libiscsi_tcp.c         |   4 ++
>>>   drivers/scsi/scsi_transport_iscsi.c |  34 ++++++++-
>>>   include/trace/events/iscsi.h        | 107 
>>> ++++++++++++++++++++++++++++
>>>   5 files changed, 158 insertions(+), 1 deletion(-)
>>>   create mode 100644 include/trace/events/iscsi.h
>>>
>>> diff --git a/drivers/scsi/iscsi_tcp.c b/drivers/scsi/iscsi_tcp.c
>>> index e11eff6b0e97..cf6475af72b1 100644
>>> --- a/drivers/scsi/iscsi_tcp.c
>>> +++ b/drivers/scsi/iscsi_tcp.c
>>> @@ -44,6 +44,7 @@
>>>   #include <scsi/scsi_host.h>
>>>   #include <scsi/scsi.h>
>>>   #include <scsi/scsi_transport_iscsi.h>
>>> +#include <trace/events/iscsi.h>
>>>     #include "iscsi_tcp.h"
>>>   @@ -72,6 +73,9 @@ MODULE_PARM_DESC(debug_iscsi_tcp, "Turn on 
>>> debugging for iscsi_tcp module "
>>>               iscsi_conn_printk(KERN_INFO, _conn,    \
>>>                            "%s " dbg_fmt,    \
>>>                            __func__, ##arg);    \
>>> +        iscsi_dbg_trace(trace_iscsi_dbg_sw_tcp,        \
>>> +                &(_conn)->cls_conn->dev,    \
>>> +                "%s " dbg_fmt, __func__, ##arg);\
>>>       } while (0);
>>>     diff --git a/drivers/scsi/libiscsi.c b/drivers/scsi/libiscsi.c
>>> index cf8a15e54d83..088e90308c1f 100644
>>> --- a/drivers/scsi/libiscsi.c
>>> +++ b/drivers/scsi/libiscsi.c
>>> @@ -40,6 +40,7 @@
>>>   #include <scsi/scsi_transport.h>
>>>   #include <scsi/scsi_transport_iscsi.h>
>>>   #include <scsi/libiscsi.h>
>>> +#include <trace/events/iscsi.h>
>>>     static int iscsi_dbg_lib_conn;
>>>   module_param_named(debug_libiscsi_conn, iscsi_dbg_lib_conn, int,
>>> @@ -68,6 +69,9 @@ MODULE_PARM_DESC(debug_libiscsi_eh,
>>>               iscsi_conn_printk(KERN_INFO, _conn,    \
>>>                            "%s " dbg_fmt,    \
>>>                            __func__, ##arg);    \
>>> +        iscsi_dbg_trace(trace_iscsi_dbg_conn,        \
>>> +                &(_conn)->cls_conn->dev,    \
>>> +                "%s " dbg_fmt, __func__, ##arg);\
>>>       } while (0);
>>>     #define ISCSI_DBG_SESSION(_session, dbg_fmt, arg...)            \
>>> @@ -76,6 +80,9 @@ MODULE_PARM_DESC(debug_libiscsi_eh,
>>>               iscsi_session_printk(KERN_INFO, _session,    \
>>>                            "%s " dbg_fmt,        \
>>>                            __func__, ##arg);        \
>>> +        iscsi_dbg_trace(trace_iscsi_dbg_session,         \
>>> + &(_session)->cls_session->dev,        \
>>> +                "%s " dbg_fmt, __func__, ##arg);    \
>>>       } while (0);
>>>     #define ISCSI_DBG_EH(_session, dbg_fmt, arg...)                \
>>> @@ -84,6 +91,9 @@ MODULE_PARM_DESC(debug_libiscsi_eh,
>>>               iscsi_session_printk(KERN_INFO, _session,    \
>>>                            "%s " dbg_fmt,        \
>>>                            __func__, ##arg);        \
>>> +        iscsi_dbg_trace(trace_iscsi_dbg_eh,            \
>>> + &(_session)->cls_session->dev,        \
>>> +                "%s " dbg_fmt, __func__, ##arg);    \
>>>       } while (0);
>>>     inline void iscsi_conn_queue_work(struct iscsi_conn *conn)
>>> diff --git a/drivers/scsi/libiscsi_tcp.c b/drivers/scsi/libiscsi_tcp.c
>>> index 63a1d69ff515..d641a72ae033 100644
>>> --- a/drivers/scsi/libiscsi_tcp.c
>>> +++ b/drivers/scsi/libiscsi_tcp.c
>>> @@ -43,6 +43,7 @@
>>>   #include <scsi/scsi_host.h>
>>>   #include <scsi/scsi.h>
>>>   #include <scsi/scsi_transport_iscsi.h>
>>> +#include <trace/events/iscsi.h>
>>>     #include "iscsi_tcp.h"
>>>   @@ -65,6 +66,9 @@ MODULE_PARM_DESC(debug_libiscsi_tcp, "Turn on 
>>> debugging for libiscsi_tcp "
>>>               iscsi_conn_printk(KERN_INFO, _conn,    \
>>>                            "%s " dbg_fmt,    \
>>>                            __func__, ##arg);    \
>>> +        iscsi_dbg_trace(trace_iscsi_dbg_tcp,        \
>>> +                &(_conn)->cls_conn->dev,    \
>>> +                "%s " dbg_fmt, __func__, ##arg);\
>>>       } while (0);
>>>     static int iscsi_tcp_hdr_recv_done(struct iscsi_tcp_conn *tcp_conn,
>>> diff --git a/drivers/scsi/scsi_transport_iscsi.c 
>>> b/drivers/scsi/scsi_transport_iscsi.c
>>> index f6542c159ed6..58e0310ce258 100644
>>> --- a/drivers/scsi/scsi_transport_iscsi.c
>>> +++ b/drivers/scsi/scsi_transport_iscsi.c
>>> @@ -37,6 +37,18 @@
>>>     #define ISCSI_TRANSPORT_VERSION "2.0-870"
>>>   +#define CREATE_TRACE_POINTS
>>> +#include <trace/events/iscsi.h>
>>> +
>>> +/*
>>> + * Export tracepoint symbols to be used by other modules.
>>> + */
>>> +EXPORT_TRACEPOINT_SYMBOL_GPL(iscsi_dbg_conn);
>>> +EXPORT_TRACEPOINT_SYMBOL_GPL(iscsi_dbg_eh);
>>> +EXPORT_TRACEPOINT_SYMBOL_GPL(iscsi_dbg_session);
>>> +EXPORT_TRACEPOINT_SYMBOL_GPL(iscsi_dbg_tcp);
>>> +EXPORT_TRACEPOINT_SYMBOL_GPL(iscsi_dbg_sw_tcp);
>>> +
>>>   static int dbg_session;
>>>   module_param_named(debug_session, dbg_session, int,
>>>              S_IRUGO | S_IWUSR);
>>> @@ -59,6 +71,9 @@ MODULE_PARM_DESC(debug_conn,
>>>               iscsi_cls_session_printk(KERN_INFO, _session, \
>>>                            "%s: " dbg_fmt,    \
>>>                            __func__, ##arg);    \
>>> +        iscsi_dbg_trace(trace_iscsi_dbg_trans_session, \
>>> +                &(_session)->dev,            \
>>> +                "%s " dbg_fmt, __func__, ##arg);    \
>>>       } while (0);
>>>     #define ISCSI_DBG_TRANS_CONN(_conn, dbg_fmt, arg...)            \
>>> @@ -66,7 +81,10 @@ MODULE_PARM_DESC(debug_conn,
>>>           if (dbg_conn)                        \
>>>               iscsi_cls_conn_printk(KERN_INFO, _conn,        \
>>>                             "%s: " dbg_fmt,        \
>>> -                          __func__, ##arg);    \
>>> +                          __func__, ##arg);        \
>>> +        iscsi_dbg_trace(trace_iscsi_dbg_trans_conn,        \
>>> +                &(_conn)->dev,                \
>>> +                "%s " dbg_fmt, __func__, ##arg);    \
>>>       } while (0);
>>>     struct iscsi_internal {
>>> @@ -4497,6 +4515,20 @@ int iscsi_unregister_transport(struct 
>>> iscsi_transport *tt)
>>>   }
>>>   EXPORT_SYMBOL_GPL(iscsi_unregister_transport);
>>>   +void iscsi_dbg_trace(void (*trace)(struct device *dev, struct 
>>> va_format *),
>>> +             struct device *dev, const char *fmt, ...)
>>> +{
>>> +    struct va_format vaf;
>>> +    va_list args;
>>> +
>>> +    va_start(args, fmt);
>>> +    vaf.fmt = fmt;
>>> +    vaf.va = &args;
>>> +    trace(dev, &vaf);
>>> +    va_end(args);
>>> +}
>>> +EXPORT_SYMBOL_GPL(iscsi_dbg_trace);
>>> +
>>>   static __init int iscsi_transport_init(void)
>>>   {
>>>       int err;
>>> diff --git a/include/trace/events/iscsi.h 
>>> b/include/trace/events/iscsi.h
>>> new file mode 100644
>>> index 000000000000..87408faf6e4e
>>> --- /dev/null
>>> +++ b/include/trace/events/iscsi.h
>>> @@ -0,0 +1,107 @@
>>> +#undef TRACE_SYSTEM
>>> +#define TRACE_SYSTEM iscsi
>>> +
>>> +#if !defined(_TRACE_ISCSI_H) || defined(TRACE_HEADER_MULTI_READ)
>>> +#define _TRACE_ISCSI_H
>>> +
>>> +#include <linux/tracepoint.h>
>>> +
>>> +/* max debug message length */
>>> +#define ISCSI_MSG_MAX    256
>>> +
>>> +/*
>>> + * Declare tracepoint helper function.
>>> + */
>>> +void iscsi_dbg_trace(void (*trace)(struct device *dev, struct 
>>> va_format *),
>>> +             struct device *dev, const char *fmt, ...);
>>> +
>>> +/*
>>> + * Declare event class for iscsi debug messages.
>>> + */
>>> +DECLARE_EVENT_CLASS(iscsi_log_msg,
>
> Could the "i" be dropped from the start of that name, that is:
>     DECLARE_EVENT_CLASS(scsi_log_msg,
>
> and that and the definition that follows be moved into
>     include/trace/events/scsi.h ??
>
> That would make it available to all the current SCSI upper level
> drivers (e.g. the sg driver) and lower level drivers (e.g.
> scsi_debug).
Tracepoint does not facilitate the exporting of event class (e.g. 
EXPORT_TRACEPOINT_SYMBOL macro exports tracepoint events but not event 
class).  Also, this approach enables iscsi events to be grouped.

-Fred Herard
>
> Doug Gilbert
>

-- 
You received this message because you are subscribed to the Google Groups "open-iscsi" group.
To unsubscribe from this group and stop receiving emails from it, send an email to open-iscsi+unsubscribe@googlegroups.com.
To post to this group, send email to open-iscsi@googlegroups.com.
Visit this group at https://groups.google.com/group/open-iscsi.
For more options, visit https://groups.google.com/d/optout.