diff mbox series

[v2,5/7] qla2xxx: Enhance driver tracing with separate tunable and more

Message ID 20220826102559.17474-6-njavali@marvell.com
State New
Headers show
Series qla2xxx driver features | expand

Commit Message

Nilesh Javali Aug. 26, 2022, 10:25 a.m. UTC 
From: Arun Easi <aeasi@marvell.com>

Older tracing of driver messages was to:
    - log only debug messages to kernel main trace buffer AND
    - log only if extended logging bits corresponding to this
      message is off

This has been modified and extended as follows:
    - Tracing is now controlled via ql2xextended_error_logging_ktrace
      module parameter. Bit usages same as ql2xextended_error_logging.
    - Tracing uses "qla2xxx" trace instance, unless instance creation
      have issues.
    - Tracing is enabled (compile time tunable).
    - All driver messages, include debug and log messages are now traced
      in kernel trace buffer.

Trace messages can be viewed by looking at the qla2xxx instance at:
    /sys/kernel/tracing/instances/qla2xxx/trace

Trace tunable that takes the same bit mask as ql2xextended_error_logging
is:
    ql2xextended_error_logging_ktrace (default=1)

Suggested-by: Daniel Wagner <dwagner@suse.de>
Suggested-by: Steven Rostedt <rostedt@goodmis.org>
Signed-off-by: Arun Easi <aeasi@marvell.com>
Signed-off-by: Nilesh Javali <njavali@marvell.com>
---
 drivers/scsi/qla2xxx/qla_dbg.c | 50 ++++++++++++++++++++++++----------
 drivers/scsi/qla2xxx/qla_dbg.h | 43 +++++++++++++++++++++++++++++
 drivers/scsi/qla2xxx/qla_gbl.h |  1 +
 drivers/scsi/qla2xxx/qla_os.c  | 35 ++++++++++++++++++++++++
 4 files changed, 115 insertions(+), 14 deletions(-)

Comments

Himanshu Madhani Aug. 29, 2022, 4:24 p.m. UTC | #1 
Small nits

> On Aug 26, 2022, at 3:25 AM, Nilesh Javali <njavali@marvell.com> wrote:
> 
> From: Arun Easi <aeasi@marvell.com>
> 
> Older tracing of driver messages was to:
>    - log only debug messages to kernel main trace buffer AND
>    - log only if extended logging bits corresponding to this
>      message is off
> 
> This has been modified and extended as follows:
>    - Tracing is now controlled via ql2xextended_error_logging_ktrace
>      module parameter. Bit usages same as ql2xextended_error_logging.
>    - Tracing uses "qla2xxx" trace instance, unless instance creation
>      have issues.
>    - Tracing is enabled (compile time tunable).
>    - All driver messages, include debug and log messages are now traced
>      in kernel trace buffer.
> 
> Trace messages can be viewed by looking at the qla2xxx instance at:
>    /sys/kernel/tracing/instances/qla2xxx/trace
> 
^^^^^^^^
This should be /sys/kernel/debug/tracing/instances/qla2xxx/trace

> Trace tunable that takes the same bit mask as ql2xextended_error_logging
> is:
>    ql2xextended_error_logging_ktrace (default=1)
> 
> Suggested-by: Daniel Wagner <dwagner@suse.de>
> Suggested-by: Steven Rostedt <rostedt@goodmis.org>
> Signed-off-by: Arun Easi <aeasi@marvell.com>
> Signed-off-by: Nilesh Javali <njavali@marvell.com>
> ---
> drivers/scsi/qla2xxx/qla_dbg.c | 50 ++++++++++++++++++++++++----------
> drivers/scsi/qla2xxx/qla_dbg.h | 43 +++++++++++++++++++++++++++++
> drivers/scsi/qla2xxx/qla_gbl.h |  1 +
> drivers/scsi/qla2xxx/qla_os.c  | 35 ++++++++++++++++++++++++
> 4 files changed, 115 insertions(+), 14 deletions(-)
> 
> diff --git a/drivers/scsi/qla2xxx/qla_dbg.c b/drivers/scsi/qla2xxx/qla_dbg.c
> index 7cf1f78cbaee..d7e8454304ce 100644
> --- a/drivers/scsi/qla2xxx/qla_dbg.c
> +++ b/drivers/scsi/qla2xxx/qla_dbg.c
> @@ -2455,7 +2455,7 @@ qla83xx_fw_dump(scsi_qla_host_t *vha)
> /****************************************************************************/
> 
> /* Write the debug message prefix into @pbuf. */
> -static void ql_dbg_prefix(char *pbuf, int pbuf_size,
> +static void ql_dbg_prefix(char *pbuf, int pbuf_size, struct pci_dev *pdev,
> 			  const scsi_qla_host_t *vha, uint msg_id)
> {
> 	if (vha) {
> @@ -2464,6 +2464,9 @@ static void ql_dbg_prefix(char *pbuf, int pbuf_size,
> 		/* <module-name> [<dev-name>]-<msg-id>:<host>: */
> 		snprintf(pbuf, pbuf_size, "%s [%s]-%04x:%lu: ", QL_MSGHDR,
> 			 dev_name(&(pdev->dev)), msg_id, vha->host_no);
> +	} else if (pdev) {
> +		snprintf(pbuf, pbuf_size, "%s [%s]-%04x: : ", QL_MSGHDR,
> +			 dev_name(&pdev->dev), msg_id);
> 	} else {
> 		/* <module-name> [<dev-name>]-<msg-id>: : */
> 		snprintf(pbuf, pbuf_size, "%s [%s]-%04x: : ", QL_MSGHDR,
> @@ -2491,20 +2494,20 @@ ql_dbg(uint level, scsi_qla_host_t *vha, uint id, const char *fmt, ...)
> 	struct va_format vaf;
> 	char pbuf[64];
> 
> -	if (!ql_mask_match(level) && !trace_ql_dbg_log_enabled())
> +	ql_ktrace(1, level, pbuf, NULL, vha, id, fmt);
> +
> +	if (!ql_mask_match(level))
> 		return;
> 
> +	if (!pbuf[0]) /* set by ql_ktrace */
> +		ql_dbg_prefix(pbuf, ARRAY_SIZE(pbuf), NULL, vha, id);
> +
> 	va_start(va, fmt);
> 
> 	vaf.fmt = fmt;
> 	vaf.va = &va;
> 
> -	ql_dbg_prefix(pbuf, ARRAY_SIZE(pbuf), vha, id);
> -
> -	if (!ql_mask_match(level))
> -		trace_ql_dbg_log(pbuf, &vaf);
> -	else
> -		pr_warn("%s%pV", pbuf, &vaf);
> +	pr_warn("%s%pV", pbuf, &vaf);
> 
> 	va_end(va);
> 
> @@ -2533,6 +2536,9 @@ ql_dbg_pci(uint level, struct pci_dev *pdev, uint id, const char *fmt, ...)
> 
> 	if (pdev == NULL)
> 		return;
> +
> +	ql_ktrace(1, level, pbuf, pdev, NULL, id, fmt);
> +
> 	if (!ql_mask_match(level))
> 		return;
> 
> @@ -2541,7 +2547,9 @@ ql_dbg_pci(uint level, struct pci_dev *pdev, uint id, const char *fmt, ...)
> 	vaf.fmt = fmt;
> 	vaf.va = &va;
> 
> -	ql_dbg_prefix(pbuf, ARRAY_SIZE(pbuf), NULL, id + ql_dbg_offset);
> +	if (!pbuf[0]) /* set by ql_ktrace */
> +		ql_dbg_prefix(pbuf, ARRAY_SIZE(pbuf), pdev, NULL,
> +			      id + ql_dbg_offset);
> 	pr_warn("%s%pV", pbuf, &vaf);
> 
> 	va_end(va);
> @@ -2570,7 +2578,10 @@ ql_log(uint level, scsi_qla_host_t *vha, uint id, const char *fmt, ...)
> 	if (level > ql_errlev)
> 		return;
> 
> -	ql_dbg_prefix(pbuf, ARRAY_SIZE(pbuf), vha, id);
> +	ql_ktrace(0, level, pbuf, NULL, vha, id, fmt);
> +
> +	if (!pbuf[0]) /* set by ql_ktrace */
> +		ql_dbg_prefix(pbuf, ARRAY_SIZE(pbuf), NULL, vha, id);
> 
> 	va_start(va, fmt);
> 
> @@ -2621,7 +2632,10 @@ ql_log_pci(uint level, struct pci_dev *pdev, uint id, const char *fmt, ...)
> 	if (level > ql_errlev)
> 		return;
> 
> -	ql_dbg_prefix(pbuf, ARRAY_SIZE(pbuf), NULL, id);
> +	ql_ktrace(0, level, pbuf, pdev, NULL, id, fmt);
> +
> +	if (!pbuf[0]) /* set by ql_ktrace */
> +		ql_dbg_prefix(pbuf, ARRAY_SIZE(pbuf), pdev, NULL, id);
> 
> 	va_start(va, fmt);
> 
> @@ -2716,7 +2730,11 @@ ql_log_qp(uint32_t level, struct qla_qpair *qpair, int32_t id,
> 	if (level > ql_errlev)
> 		return;
> 
> -	ql_dbg_prefix(pbuf, ARRAY_SIZE(pbuf), qpair ? qpair->vha : NULL, id);
> +	ql_ktrace(0, level, pbuf, NULL, qpair ? qpair->vha : NULL, id, fmt);
> +
> +	if (!pbuf[0]) /* set by ql_ktrace */
> +		ql_dbg_prefix(pbuf, ARRAY_SIZE(pbuf), NULL,
> +			      qpair ? qpair->vha : NULL, id);
> 
> 	va_start(va, fmt);
> 
> @@ -2762,6 +2780,8 @@ ql_dbg_qp(uint32_t level, struct qla_qpair *qpair, int32_t id,
> 	struct va_format vaf;
> 	char pbuf[128];
> 
> +	ql_ktrace(1, level, pbuf, NULL, qpair ? qpair->vha : NULL, id, fmt);
> +
> 	if (!ql_mask_match(level))
> 		return;
> 
> @@ -2770,8 +2790,10 @@ ql_dbg_qp(uint32_t level, struct qla_qpair *qpair, int32_t id,
> 	vaf.fmt = fmt;
> 	vaf.va = &va;
> 
> -	ql_dbg_prefix(pbuf, ARRAY_SIZE(pbuf), qpair ? qpair->vha : NULL,
> -		      id + ql_dbg_offset);
> +	if (!pbuf[0]) /* set by ql_ktrace */
> +		ql_dbg_prefix(pbuf, ARRAY_SIZE(pbuf), NULL,
> +			      qpair ? qpair->vha : NULL, id + ql_dbg_offset);
> +
> 	pr_warn("%s%pV", pbuf, &vaf);
> 
> 	va_end(va);
> diff --git a/drivers/scsi/qla2xxx/qla_dbg.h b/drivers/scsi/qla2xxx/qla_dbg.h
> index feeb1666227f..70482b55d240 100644
> --- a/drivers/scsi/qla2xxx/qla_dbg.h
> +++ b/drivers/scsi/qla2xxx/qla_dbg.h
> @@ -385,3 +385,46 @@ ql_mask_match(uint level)
> 
> 	return level && ((level & ql2xextended_error_logging) == level);
> }
> +
> +static inline int
> +ql_mask_match_ext(uint level, int *log_tunable)
> +{
> +	if (*log_tunable == 1)
> +		*log_tunable = QL_DBG_DEFAULT1_MASK;
> +
> +	return (level & *log_tunable) == level;
> +}
> +
> +/* Assumes local variable pbuf and pbuf_ready present. */
> +#define ql_ktrace(dbg_msg, level, pbuf, pdev, vha, id, fmt) do {	\
> +	struct va_format _vaf;						\
> +	va_list _va;							\
> +	u32 dbg_off = dbg_msg ? ql_dbg_offset : 0;			\
> +									\
> +	pbuf[0] = 0;							\
> +	if (!trace_ql_dbg_log_enabled())				\
> +		break;							\
> +									\
> +	if (dbg_msg && !ql_mask_match_ext(level,			\
> +				&ql2xextended_error_logging_ktrace))	\
> +		break;							\
> +									\
> +	ql_dbg_prefix(pbuf, ARRAY_SIZE(pbuf), pdev, vha, id + dbg_off);	\
> +									\
> +	va_start(_va, fmt);						\
> +	_vaf.fmt = fmt;							\
> +	_vaf.va = &_va;							\
> +									\
> +	trace_ql_dbg_log(pbuf, &_vaf);					\
> +									\
> +	va_end(_va);							\
> +} while (0)
> +
> +#define QLA_ENABLE_KERNEL_TRACING
> +
> +#ifdef QLA_ENABLE_KERNEL_TRACING
> +#define QLA_TRACE_ENABLE(_tr) \
> +	trace_array_set_clr_event(_tr, "qla", NULL, true)
> +#else /* QLA_ENABLE_KERNEL_TRACING */
> +#define QLA_TRACE_ENABLE(_tr)
> +#endif /* QLA_ENABLE_KERNEL_TRACING */
> diff --git a/drivers/scsi/qla2xxx/qla_gbl.h b/drivers/scsi/qla2xxx/qla_gbl.h
> index bb69fa8b956a..2fc280e61306 100644
> --- a/drivers/scsi/qla2xxx/qla_gbl.h
> +++ b/drivers/scsi/qla2xxx/qla_gbl.h
> @@ -163,6 +163,7 @@ extern int ql2xrdpenable;
> extern int ql2xsmartsan;
> extern int ql2xallocfwdump;
> extern int ql2xextended_error_logging;
> +extern int ql2xextended_error_logging_ktrace;
> extern int ql2xiidmaenable;
> extern int ql2xmqsupport;
> extern int ql2xfwloadbin;
> diff --git a/drivers/scsi/qla2xxx/qla_os.c b/drivers/scsi/qla2xxx/qla_os.c
> index 1c7fb6484db2..4a55c1e81327 100644
> --- a/drivers/scsi/qla2xxx/qla_os.c
> +++ b/drivers/scsi/qla2xxx/qla_os.c
> @@ -15,6 +15,8 @@
> #include <linux/blk-mq-pci.h>
> #include <linux/refcount.h>
> #include <linux/crash_dump.h>
> +#include <linux/trace_events.h>
> +#include <linux/trace.h>
> 
> #include <scsi/scsi_tcq.h>
> #include <scsi/scsicam.h>
> @@ -35,6 +37,8 @@ static int apidev_major;
>  */
> struct kmem_cache *srb_cachep;
> 
> +struct trace_array *qla_trc_array;
> +
> int ql2xfulldump_on_mpifail;
> module_param(ql2xfulldump_on_mpifail, int, S_IRUGO | S_IWUSR);
> MODULE_PARM_DESC(ql2xfulldump_on_mpifail,
> @@ -117,6 +121,11 @@ MODULE_PARM_DESC(ql2xextended_error_logging,
> 		"ql2xextended_error_logging=1).\n"
> 		"\t\tDo LOGICAL OR of the value to enable more than one level");
> 
> +int ql2xextended_error_logging_ktrace = 1;
> +module_param(ql2xextended_error_logging_ktrace, int, S_IRUGO|S_IWUSR);
> +MODULE_PARM_DESC(ql2xextended_error_logging_ktrace,
> +		"Same BIT definiton as ql2xextended_error_logging, but used to control logging to kernel trace buffer (default=1).\n");
> +
> int ql2xshiftctondsd = 6;
> module_param(ql2xshiftctondsd, int, S_IRUGO);
> MODULE_PARM_DESC(ql2xshiftctondsd,
> @@ -2839,6 +2848,27 @@ static void qla2x00_iocb_work_fn(struct work_struct *work)
> 	spin_unlock_irqrestore(&vha->work_lock, flags);
> }
> 
> +static void
> +qla_trace_init(void)
> +{
> +	qla_trc_array = trace_array_get_by_name("qla2xxx");
> +	if (!qla_trc_array) {
> +		ql_log(ql_log_fatal, NULL, 0x0001,
> +		       "Unable to create qla2xxx trace instance, instance logging will be disabled.\n");
> +		return;
> +	}
> +
> +	QLA_TRACE_ENABLE(qla_trc_array);
> +}
> +
> +static void
> +qla_trace_uninit(void)
> +{
> +	if (!qla_trc_array)
> +		return;
> +	trace_array_put(qla_trc_array);
> +}
> +
> /*
>  * PCI driver interface
>  */
> @@ -8181,6 +8211,8 @@ qla2x00_module_init(void)
> 	BUILD_BUG_ON(sizeof(sw_info_t) != 32);
> 	BUILD_BUG_ON(sizeof(target_id_t) != 2);
> 
> +	qla_trace_init();
> +
> 	/* Allocate cache for SRBs. */
> 	srb_cachep = kmem_cache_create("qla2xxx_srbs", sizeof(srb_t), 0,
> 	    SLAB_HWCACHE_ALIGN, NULL);
> @@ -8259,6 +8291,8 @@ qla2x00_module_init(void)
> 
> destroy_cache:
> 	kmem_cache_destroy(srb_cachep);
> +
> +	qla_trace_uninit();
> 	return ret;
> }
> 
> @@ -8277,6 +8311,7 @@ qla2x00_module_exit(void)
> 	fc_release_transport(qla2xxx_transport_template);
> 	qlt_exit();
> 	kmem_cache_destroy(srb_cachep);
> +	qla_trace_uninit();
> }
> 
> module_init(qla2x00_module_init);
> -- 
> 2.19.0.rc0
> 

When you fix the commit message. 

Reviewed-by: Himanshu Madhani <himanshu.madhani@oracle.com>
Arun Easi Aug. 29, 2022, 4:59 p.m. UTC | #2 
Thanks for reviewing the code, Himanshu. Response inline..

On Mon, 29 Aug 2022, 9:24am, Himanshu Madhani wrote:

> Small nits
> 
> > On Aug 26, 2022, at 3:25 AM, Nilesh Javali <njavali@marvell.com> wrote:
> > 
> > From: Arun Easi <aeasi@marvell.com>
> > 
> > Older tracing of driver messages was to:
> >    - log only debug messages to kernel main trace buffer AND
> >    - log only if extended logging bits corresponding to this
> >      message is off
> > 
> > This has been modified and extended as follows:
> >    - Tracing is now controlled via ql2xextended_error_logging_ktrace
> >      module parameter. Bit usages same as ql2xextended_error_logging.
> >    - Tracing uses "qla2xxx" trace instance, unless instance creation
> >      have issues.
> >    - Tracing is enabled (compile time tunable).
> >    - All driver messages, include debug and log messages are now traced
> >      in kernel trace buffer.
> > 
> > Trace messages can be viewed by looking at the qla2xxx instance at:
> >    /sys/kernel/tracing/instances/qla2xxx/trace
> > 
> ^^^^^^^^
> This should be /sys/kernel/debug/tracing/instances/qla2xxx/trace
> 

With tracefs, the location is moved to:
	/sys/kernel/tracing

..with old location preserved.

Regards,
-Arun
PS: # grep -A 10 '^The File System' Documentation/trace/ftrace.rst
Himanshu Madhani Aug. 29, 2022, 7:25 p.m. UTC | #3 
> On Aug 29, 2022, at 9:59 AM, Arun Easi <aeasi@marvell.com> wrote:
> 
> Thanks for reviewing the code, Himanshu. Response inline..
> 
> On Mon, 29 Aug 2022, 9:24am, Himanshu Madhani wrote:
> 
>> Small nits
>> 
>>> On Aug 26, 2022, at 3:25 AM, Nilesh Javali <njavali@marvell.com> wrote:
>>> 
>>> From: Arun Easi <aeasi@marvell.com>
>>> 
>>> Older tracing of driver messages was to:
>>>   - log only debug messages to kernel main trace buffer AND
>>>   - log only if extended logging bits corresponding to this
>>>     message is off
>>> 
>>> This has been modified and extended as follows:
>>>   - Tracing is now controlled via ql2xextended_error_logging_ktrace
>>>     module parameter. Bit usages same as ql2xextended_error_logging.
>>>   - Tracing uses "qla2xxx" trace instance, unless instance creation
>>>     have issues.
>>>   - Tracing is enabled (compile time tunable).
>>>   - All driver messages, include debug and log messages are now traced
>>>     in kernel trace buffer.
>>> 
>>> Trace messages can be viewed by looking at the qla2xxx instance at:
>>>   /sys/kernel/tracing/instances/qla2xxx/trace
>>> 
>> ^^^^^^^^
>> This should be /sys/kernel/debug/tracing/instances/qla2xxx/trace
>> 
> 
> With tracefs, the location is moved to:
> 	/sys/kernel/tracing
> 
> ..with old location preserved.
> 

Okay got it... I think I got tripped by the nuance of tracefs to be mounted to see a new tracing directory to be populated.

Here’s what I had seen on my 6.0.0-rc1+ kernel,

I could not locate it at /sys/kernel/tracing instead old location which makes sense from the Documentation

root@tatoonie~6.0.0-rc1+:/# ls -l /sys/kernel/tracing/
total 0
root@tatoonie~6.0.0-rc1+:/# ls -l /sys/kernel/debug/tracing/instances/qla2xxx/trace
-rw-r----- 1 root root 0 Aug 29 08:54 /sys/kernel/debug/tracing/instances/qla2xxx/trace

maybe you can add a comment indicating tracefs should be mounted to see traces at 
/sys/kernel/tracing.

FYI.. you can also add 

Tested-by: Himanshu Madhani <himanshu.madhani@oracle.com>


> Regards,
> -Arun
> PS: # grep -A 10 '^The File System' Documentation/trace/ftrace.rst
Daniel Wagner Aug. 30, 2022, 7:55 a.m. UTC | #4 
On Mon, Aug 29, 2022 at 07:25:34PM +0000, Himanshu Madhani wrote:
> root@tatoonie~6.0.0-rc1+:/# ls -l /sys/kernel/tracing/
> total 0
> root@tatoonie~6.0.0-rc1+:/# ls -l /sys/kernel/debug/tracing/instances/qla2xxx/trace
> -rw-r----- 1 root root 0 Aug 29 08:54 /sys/kernel/debug/tracing/instances/qla2xxx/trace

IIRC, Steven's goal was to get all distros to move the mount point
from /sys/kernel/debug/tracing to /sys/kernel/tracing. Not sure where we
stand here.
Daniel Wagner Aug. 30, 2022, 8:07 a.m. UTC | #5 
On Fri, Aug 26, 2022 at 03:25:57AM -0700, Nilesh Javali wrote:
> From: Arun Easi <aeasi@marvell.com>
> 
> Older tracing of driver messages was to:
>     - log only debug messages to kernel main trace buffer AND
>     - log only if extended logging bits corresponding to this
>       message is off
> 
> This has been modified and extended as follows:
>     - Tracing is now controlled via ql2xextended_error_logging_ktrace
>       module parameter. Bit usages same as ql2xextended_error_logging.
>     - Tracing uses "qla2xxx" trace instance, unless instance creation
>       have issues.
>     - Tracing is enabled (compile time tunable).
>     - All driver messages, include debug and log messages are now traced
>       in kernel trace buffer.
> 
> Trace messages can be viewed by looking at the qla2xxx instance at:
>     /sys/kernel/tracing/instances/qla2xxx/trace

Nice! Thanks for getting this working.

> Trace tunable that takes the same bit mask as ql2xextended_error_logging
> is:
>     ql2xextended_error_logging_ktrace (default=1)
> 
> Suggested-by: Daniel Wagner <dwagner@suse.de>
> Suggested-by: Steven Rostedt <rostedt@goodmis.org>
> Signed-off-by: Arun Easi <aeasi@marvell.com>
> Signed-off-by: Nilesh Javali <njavali@marvell.com>

Reviewed-by: Daniel Wagner <dwagner@suse.de>
Steven Rostedt Sept. 1, 2022, 1:41 p.m. UTC | #6 
On Tue, 30 Aug 2022 09:55:54 +0200
Daniel Wagner <dwagner@suse.de> wrote:

> On Mon, Aug 29, 2022 at 07:25:34PM +0000, Himanshu Madhani wrote:
> > root@tatoonie~6.0.0-rc1+:/# ls -l /sys/kernel/tracing/
> > total 0
> > root@tatoonie~6.0.0-rc1+:/# ls -l /sys/kernel/debug/tracing/instances/qla2xxx/trace
> > -rw-r----- 1 root root 0 Aug 29 08:54 /sys/kernel/debug/tracing/instances/qla2xxx/trace  
> 
> IIRC, Steven's goal was to get all distros to move the mount point
> from /sys/kernel/debug/tracing to /sys/kernel/tracing. Not sure where we
> stand here.

I believe Fedora and Debian both have added it there.

Note, when mounting the debugfs file system to /sys/kernel/debug, tracefs
is automatically mounted at /sys/kernel/debug/tracing for backward
compatibility.

But the correct place to mount tracefs, is at /sys/kernel/tracing. Perhaps
I will remove the autmatic mounting of tracefs on debugfs when that becomes
the norm.

-- Steve
Guenter Roeck Sept. 19, 2022, 10:01 p.m. UTC | #7 
On Fri, Aug 26, 2022 at 03:25:57AM -0700, Nilesh Javali wrote:
> From: Arun Easi <aeasi@marvell.com>
> 
> Older tracing of driver messages was to:
>     - log only debug messages to kernel main trace buffer AND
>     - log only if extended logging bits corresponding to this
>       message is off
> 
> This has been modified and extended as follows:
>     - Tracing is now controlled via ql2xextended_error_logging_ktrace
>       module parameter. Bit usages same as ql2xextended_error_logging.
>     - Tracing uses "qla2xxx" trace instance, unless instance creation
>       have issues.
>     - Tracing is enabled (compile time tunable).
>     - All driver messages, include debug and log messages are now traced
>       in kernel trace buffer.
> 
> Trace messages can be viewed by looking at the qla2xxx instance at:
>     /sys/kernel/tracing/instances/qla2xxx/trace
> 
> Trace tunable that takes the same bit mask as ql2xextended_error_logging
> is:
>     ql2xextended_error_logging_ktrace (default=1)
> 
> Suggested-by: Daniel Wagner <dwagner@suse.de>
> Suggested-by: Steven Rostedt <rostedt@goodmis.org>
> Signed-off-by: Arun Easi <aeasi@marvell.com>
> Signed-off-by: Nilesh Javali <njavali@marvell.com>

I understand this has already been reported early September, but then
the problem disapppeared in next-20220912 and reappeared in next-20220919.

This patch results in various test build failures. Example:

Building powerpc:skiroot_defconfig ... failed
--------------
Error log:
drivers/scsi/qla2xxx/qla_os.c: In function 'qla_trace_init':
drivers/scsi/qla2xxx/qla_os.c:2854:25: error:
	implicit declaration of function 'trace_array_get_by_name'; did you mean 'trace_array_set_clr_event'?

Guenter
Arun Easi Sept. 19, 2022, 11:15 p.m. UTC | #8 
Hi Guenter,

On Mon, 19 Sep 2022, 3:01pm, Guenter Roeck wrote:

> On Fri, Aug 26, 2022 at 03:25:57AM -0700, Nilesh Javali wrote:
> > From: Arun Easi <aeasi@marvell.com>
> > 
> > Older tracing of driver messages was to:
> >     - log only debug messages to kernel main trace buffer AND
> >     - log only if extended logging bits corresponding to this
> >       message is off
> > 
> > This has been modified and extended as follows:
> >     - Tracing is now controlled via ql2xextended_error_logging_ktrace
> >       module parameter. Bit usages same as ql2xextended_error_logging.
> >     - Tracing uses "qla2xxx" trace instance, unless instance creation
> >       have issues.
> >     - Tracing is enabled (compile time tunable).
> >     - All driver messages, include debug and log messages are now traced
> >       in kernel trace buffer.
> > 
> > Trace messages can be viewed by looking at the qla2xxx instance at:
> >     /sys/kernel/tracing/instances/qla2xxx/trace
> > 
> > Trace tunable that takes the same bit mask as ql2xextended_error_logging
> > is:
> >     ql2xextended_error_logging_ktrace (default=1)
> > 
> > Suggested-by: Daniel Wagner <dwagner@suse.de>
> > Suggested-by: Steven Rostedt <rostedt@goodmis.org>
> > Signed-off-by: Arun Easi <aeasi@marvell.com>
> > Signed-off-by: Nilesh Javali <njavali@marvell.com>
> 
> I understand this has already been reported early September, but then
> the problem disapppeared in next-20220912 and reappeared in next-20220919.
> 
> This patch results in various test build failures. Example:
> 
> Building powerpc:skiroot_defconfig ... failed
> --------------
> Error log:
> drivers/scsi/qla2xxx/qla_os.c: In function 'qla_trace_init':
> drivers/scsi/qla2xxx/qla_os.c:2854:25: error:
> 	implicit declaration of function 'trace_array_get_by_name'; did you mean 'trace_array_set_clr_event'?
> 
> Guenter
> 

Apologies for the troubles this patch has caused.

A fix for this is already posted (in trace.h), but is awaiting a final 
approval from the maintainer:

https://lore.kernel.org/linux-scsi/20220907233308.4153-2-aeasi@marvell.com/

Martin,

In the interest of time, and with more people running into the build 
failures, if you want to pick up "Ren Zhijie"'s fix posted earlier today 
with the fix all contained within the qla2xxx driver, feel free to go 
ahead (I will NAK my NAK in that case :o )

Regards,
-Arun
diff mbox series

Patch

diff --git a/drivers/scsi/qla2xxx/qla_dbg.c b/drivers/scsi/qla2xxx/qla_dbg.c
index 7cf1f78cbaee..d7e8454304ce 100644
--- a/drivers/scsi/qla2xxx/qla_dbg.c
+++ b/drivers/scsi/qla2xxx/qla_dbg.c
@@ -2455,7 +2455,7 @@  qla83xx_fw_dump(scsi_qla_host_t *vha)
 /****************************************************************************/
 
 /* Write the debug message prefix into @pbuf. */
-static void ql_dbg_prefix(char *pbuf, int pbuf_size,
+static void ql_dbg_prefix(char *pbuf, int pbuf_size, struct pci_dev *pdev,
 			  const scsi_qla_host_t *vha, uint msg_id)
 {
 	if (vha) {
@@ -2464,6 +2464,9 @@  static void ql_dbg_prefix(char *pbuf, int pbuf_size,
 		/* <module-name> [<dev-name>]-<msg-id>:<host>: */
 		snprintf(pbuf, pbuf_size, "%s [%s]-%04x:%lu: ", QL_MSGHDR,
 			 dev_name(&(pdev->dev)), msg_id, vha->host_no);
+	} else if (pdev) {
+		snprintf(pbuf, pbuf_size, "%s [%s]-%04x: : ", QL_MSGHDR,
+			 dev_name(&pdev->dev), msg_id);
 	} else {
 		/* <module-name> [<dev-name>]-<msg-id>: : */
 		snprintf(pbuf, pbuf_size, "%s [%s]-%04x: : ", QL_MSGHDR,
@@ -2491,20 +2494,20 @@  ql_dbg(uint level, scsi_qla_host_t *vha, uint id, const char *fmt, ...)
 	struct va_format vaf;
 	char pbuf[64];
 
-	if (!ql_mask_match(level) && !trace_ql_dbg_log_enabled())
+	ql_ktrace(1, level, pbuf, NULL, vha, id, fmt);
+
+	if (!ql_mask_match(level))
 		return;
 
+	if (!pbuf[0]) /* set by ql_ktrace */
+		ql_dbg_prefix(pbuf, ARRAY_SIZE(pbuf), NULL, vha, id);
+
 	va_start(va, fmt);
 
 	vaf.fmt = fmt;
 	vaf.va = &va;
 
-	ql_dbg_prefix(pbuf, ARRAY_SIZE(pbuf), vha, id);
-
-	if (!ql_mask_match(level))
-		trace_ql_dbg_log(pbuf, &vaf);
-	else
-		pr_warn("%s%pV", pbuf, &vaf);
+	pr_warn("%s%pV", pbuf, &vaf);
 
 	va_end(va);
 
@@ -2533,6 +2536,9 @@  ql_dbg_pci(uint level, struct pci_dev *pdev, uint id, const char *fmt, ...)
 
 	if (pdev == NULL)
 		return;
+
+	ql_ktrace(1, level, pbuf, pdev, NULL, id, fmt);
+
 	if (!ql_mask_match(level))
 		return;
 
@@ -2541,7 +2547,9 @@  ql_dbg_pci(uint level, struct pci_dev *pdev, uint id, const char *fmt, ...)
 	vaf.fmt = fmt;
 	vaf.va = &va;
 
-	ql_dbg_prefix(pbuf, ARRAY_SIZE(pbuf), NULL, id + ql_dbg_offset);
+	if (!pbuf[0]) /* set by ql_ktrace */
+		ql_dbg_prefix(pbuf, ARRAY_SIZE(pbuf), pdev, NULL,
+			      id + ql_dbg_offset);
 	pr_warn("%s%pV", pbuf, &vaf);
 
 	va_end(va);
@@ -2570,7 +2578,10 @@  ql_log(uint level, scsi_qla_host_t *vha, uint id, const char *fmt, ...)
 	if (level > ql_errlev)
 		return;
 
-	ql_dbg_prefix(pbuf, ARRAY_SIZE(pbuf), vha, id);
+	ql_ktrace(0, level, pbuf, NULL, vha, id, fmt);
+
+	if (!pbuf[0]) /* set by ql_ktrace */
+		ql_dbg_prefix(pbuf, ARRAY_SIZE(pbuf), NULL, vha, id);
 
 	va_start(va, fmt);
 
@@ -2621,7 +2632,10 @@  ql_log_pci(uint level, struct pci_dev *pdev, uint id, const char *fmt, ...)
 	if (level > ql_errlev)
 		return;
 
-	ql_dbg_prefix(pbuf, ARRAY_SIZE(pbuf), NULL, id);
+	ql_ktrace(0, level, pbuf, pdev, NULL, id, fmt);
+
+	if (!pbuf[0]) /* set by ql_ktrace */
+		ql_dbg_prefix(pbuf, ARRAY_SIZE(pbuf), pdev, NULL, id);
 
 	va_start(va, fmt);
 
@@ -2716,7 +2730,11 @@  ql_log_qp(uint32_t level, struct qla_qpair *qpair, int32_t id,
 	if (level > ql_errlev)
 		return;
 
-	ql_dbg_prefix(pbuf, ARRAY_SIZE(pbuf), qpair ? qpair->vha : NULL, id);
+	ql_ktrace(0, level, pbuf, NULL, qpair ? qpair->vha : NULL, id, fmt);
+
+	if (!pbuf[0]) /* set by ql_ktrace */
+		ql_dbg_prefix(pbuf, ARRAY_SIZE(pbuf), NULL,
+			      qpair ? qpair->vha : NULL, id);
 
 	va_start(va, fmt);
 
@@ -2762,6 +2780,8 @@  ql_dbg_qp(uint32_t level, struct qla_qpair *qpair, int32_t id,
 	struct va_format vaf;
 	char pbuf[128];
 
+	ql_ktrace(1, level, pbuf, NULL, qpair ? qpair->vha : NULL, id, fmt);
+
 	if (!ql_mask_match(level))
 		return;
 
@@ -2770,8 +2790,10 @@  ql_dbg_qp(uint32_t level, struct qla_qpair *qpair, int32_t id,
 	vaf.fmt = fmt;
 	vaf.va = &va;
 
-	ql_dbg_prefix(pbuf, ARRAY_SIZE(pbuf), qpair ? qpair->vha : NULL,
-		      id + ql_dbg_offset);
+	if (!pbuf[0]) /* set by ql_ktrace */
+		ql_dbg_prefix(pbuf, ARRAY_SIZE(pbuf), NULL,
+			      qpair ? qpair->vha : NULL, id + ql_dbg_offset);
+
 	pr_warn("%s%pV", pbuf, &vaf);
 
 	va_end(va);
diff --git a/drivers/scsi/qla2xxx/qla_dbg.h b/drivers/scsi/qla2xxx/qla_dbg.h
index feeb1666227f..70482b55d240 100644
--- a/drivers/scsi/qla2xxx/qla_dbg.h
+++ b/drivers/scsi/qla2xxx/qla_dbg.h
@@ -385,3 +385,46 @@  ql_mask_match(uint level)
 
 	return level && ((level & ql2xextended_error_logging) == level);
 }
+
+static inline int
+ql_mask_match_ext(uint level, int *log_tunable)
+{
+	if (*log_tunable == 1)
+		*log_tunable = QL_DBG_DEFAULT1_MASK;
+
+	return (level & *log_tunable) == level;
+}
+
+/* Assumes local variable pbuf and pbuf_ready present. */
+#define ql_ktrace(dbg_msg, level, pbuf, pdev, vha, id, fmt) do {	\
+	struct va_format _vaf;						\
+	va_list _va;							\
+	u32 dbg_off = dbg_msg ? ql_dbg_offset : 0;			\
+									\
+	pbuf[0] = 0;							\
+	if (!trace_ql_dbg_log_enabled())				\
+		break;							\
+									\
+	if (dbg_msg && !ql_mask_match_ext(level,			\
+				&ql2xextended_error_logging_ktrace))	\
+		break;							\
+									\
+	ql_dbg_prefix(pbuf, ARRAY_SIZE(pbuf), pdev, vha, id + dbg_off);	\
+									\
+	va_start(_va, fmt);						\
+	_vaf.fmt = fmt;							\
+	_vaf.va = &_va;							\
+									\
+	trace_ql_dbg_log(pbuf, &_vaf);					\
+									\
+	va_end(_va);							\
+} while (0)
+
+#define QLA_ENABLE_KERNEL_TRACING
+
+#ifdef QLA_ENABLE_KERNEL_TRACING
+#define QLA_TRACE_ENABLE(_tr) \
+	trace_array_set_clr_event(_tr, "qla", NULL, true)
+#else /* QLA_ENABLE_KERNEL_TRACING */
+#define QLA_TRACE_ENABLE(_tr)
+#endif /* QLA_ENABLE_KERNEL_TRACING */
diff --git a/drivers/scsi/qla2xxx/qla_gbl.h b/drivers/scsi/qla2xxx/qla_gbl.h
index bb69fa8b956a..2fc280e61306 100644
--- a/drivers/scsi/qla2xxx/qla_gbl.h
+++ b/drivers/scsi/qla2xxx/qla_gbl.h
@@ -163,6 +163,7 @@  extern int ql2xrdpenable;
 extern int ql2xsmartsan;
 extern int ql2xallocfwdump;
 extern int ql2xextended_error_logging;
+extern int ql2xextended_error_logging_ktrace;
 extern int ql2xiidmaenable;
 extern int ql2xmqsupport;
 extern int ql2xfwloadbin;
diff --git a/drivers/scsi/qla2xxx/qla_os.c b/drivers/scsi/qla2xxx/qla_os.c
index 1c7fb6484db2..4a55c1e81327 100644
--- a/drivers/scsi/qla2xxx/qla_os.c
+++ b/drivers/scsi/qla2xxx/qla_os.c
@@ -15,6 +15,8 @@ 
 #include <linux/blk-mq-pci.h>
 #include <linux/refcount.h>
 #include <linux/crash_dump.h>
+#include <linux/trace_events.h>
+#include <linux/trace.h>
 
 #include <scsi/scsi_tcq.h>
 #include <scsi/scsicam.h>
@@ -35,6 +37,8 @@  static int apidev_major;
  */
 struct kmem_cache *srb_cachep;
 
+struct trace_array *qla_trc_array;
+
 int ql2xfulldump_on_mpifail;
 module_param(ql2xfulldump_on_mpifail, int, S_IRUGO | S_IWUSR);
 MODULE_PARM_DESC(ql2xfulldump_on_mpifail,
@@ -117,6 +121,11 @@  MODULE_PARM_DESC(ql2xextended_error_logging,
 		"ql2xextended_error_logging=1).\n"
 		"\t\tDo LOGICAL OR of the value to enable more than one level");
 
+int ql2xextended_error_logging_ktrace = 1;
+module_param(ql2xextended_error_logging_ktrace, int, S_IRUGO|S_IWUSR);
+MODULE_PARM_DESC(ql2xextended_error_logging_ktrace,
+		"Same BIT definiton as ql2xextended_error_logging, but used to control logging to kernel trace buffer (default=1).\n");
+
 int ql2xshiftctondsd = 6;
 module_param(ql2xshiftctondsd, int, S_IRUGO);
 MODULE_PARM_DESC(ql2xshiftctondsd,
@@ -2839,6 +2848,27 @@  static void qla2x00_iocb_work_fn(struct work_struct *work)
 	spin_unlock_irqrestore(&vha->work_lock, flags);
 }
 
+static void
+qla_trace_init(void)
+{
+	qla_trc_array = trace_array_get_by_name("qla2xxx");
+	if (!qla_trc_array) {
+		ql_log(ql_log_fatal, NULL, 0x0001,
+		       "Unable to create qla2xxx trace instance, instance logging will be disabled.\n");
+		return;
+	}
+
+	QLA_TRACE_ENABLE(qla_trc_array);
+}
+
+static void
+qla_trace_uninit(void)
+{
+	if (!qla_trc_array)
+		return;
+	trace_array_put(qla_trc_array);
+}
+
 /*
  * PCI driver interface
  */
@@ -8181,6 +8211,8 @@  qla2x00_module_init(void)
 	BUILD_BUG_ON(sizeof(sw_info_t) != 32);
 	BUILD_BUG_ON(sizeof(target_id_t) != 2);
 
+	qla_trace_init();
+
 	/* Allocate cache for SRBs. */
 	srb_cachep = kmem_cache_create("qla2xxx_srbs", sizeof(srb_t), 0,
 	    SLAB_HWCACHE_ALIGN, NULL);
@@ -8259,6 +8291,8 @@  qla2x00_module_init(void)
 
 destroy_cache:
 	kmem_cache_destroy(srb_cachep);
+
+	qla_trace_uninit();
 	return ret;
 }
 
@@ -8277,6 +8311,7 @@  qla2x00_module_exit(void)
 	fc_release_transport(qla2xxx_transport_template);
 	qlt_exit();
 	kmem_cache_destroy(srb_cachep);
+	qla_trace_uninit();
 }
 
 module_init(qla2x00_module_init);