diff mbox

storvsc: add more logging for error and warning messages

Message ID 1449200865-20694-1-git-send-email-longli@microsoft.com (mailing list archive)
State New, archived
Headers show

Commit Message

Long Li Dec. 4, 2015, 3:47 a.m. UTC 
Introduce a logging level for storvsc to log certain error/warning messages. Those messages are helpful in some environments, e.g. Microsoft Azure, for customer support and troubleshooting purposes.

Signed-off-by: Long Li <longli@microsoft.com>
---
 drivers/scsi/storvsc_drv.c | 30 +++++++++++++++++++++++++++++-
 1 file changed, 29 insertions(+), 1 deletion(-)

Comments

Joe Perches Dec. 4, 2015, 2:28 a.m. UTC | #1 
On Thu, 2015-12-03 at 19:47 -0800, Long Li wrote:
> Introduce a logging level for storvsc to log certain error/warning
> messages. Those messages are helpful in some environments, e.g.
> Microsoft Azure, for customer support and troubleshooting purposes.
[]
> diff --git a/drivers/scsi/storvsc_drv.c b/drivers/scsi/storvsc_drv.c
[]
> +static inline bool do_logging(int level)
> +{
> +	return (logging_level >= level) ? true : false;

The ternary is not necessary

	return logging_level >= level;

is enough

> +}
> +
> +
>  struct vmscsi_win8_extension {
>  	/*
>  	 * The following were added in Windows 8
> @@ -1183,7 +1198,7 @@ static void storvsc_command_completion(struct storvsc_cmd_request *cmd_request)
>  
>  	scmnd->result = vm_srb->scsi_status;
>  
> -	if (scmnd->result) {
> +	if (scmnd->result && do_logging(STORVSC_LOGGING_ERROR)) {
>  		if (scsi_normalize_sense(scmnd->sense_buffer,
>  				SCSI_SENSE_BUFFERSIZE, &sense_hdr))
>  			scsi_print_sense_hdr(scmnd->device, "storvsc",

Is it appropriate to make this scsi_normalize_sense call
conditional on do_logging here?

> @@ -1239,12 +1254,25 @@ static void storvsc_on_io_completion(struct hv_device *device,
>  	stor_pkt->vm_srb.sense_info_length =
>  	vstor_packet->vm_srb.sense_info_length;
>  
> +	if (vstor_packet->vm_srb.scsi_status != 0 ||
> +		vstor_packet->vm_srb.srb_status != SRB_STATUS_SUCCESS)
> +		if (do_logging(STORVSC_LOGGING_WARN))
> +			dev_warn(&device->device,
> +				"cmd 0x%x scsi status 0x%x srb status 0x%x\n",
> +				stor_pkt->vm_srb.cdb[0],
> +				vstor_packet->vm_srb.scsi_status,
> +				vstor_packet->vm_srb.srb_status);

It might make some sense to use another macro indirection like

#define svc_log_warn(dev, level, fmt, ...)			\
do {								\
	if (do_logging(STORSVC_LOGGING_##level)			\
		dev_warn(&(dev)->device, fmt, ##__VA_ARGS__);	\
} while (0)

So a use could be:

	if (vstore_packet...)
		svc_log_warn(device, WARN, ...);

> 
--
To unsubscribe from this list: send the line "unsubscribe linux-scsi" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Long Li Dec. 4, 2015, 2:55 a.m. UTC | #2 
Thanks Joe.

I'll send out another patch.

> -----Original Message-----
> From: Joe Perches [mailto:joe@perches.com]
> Sent: Thursday, December 3, 2015 6:28 PM
> To: Long Li <longli@microsoft.com>; KY Srinivasan <kys@microsoft.com>;
> Haiyang Zhang <haiyangz@microsoft.com>; James E.J. Bottomley
> <JBottomley@odin.com>
> Cc: devel@linuxdriverproject.org; linux-scsi@vger.kernel.org; linux-
> kernel@vger.kernel.org
> Subject: Re: [PATCH] storvsc: add more logging for error and warning
> messages
> 
> On Thu, 2015-12-03 at 19:47 -0800, Long Li wrote:
> > Introduce a logging level for storvsc to log certain error/warning
> > messages. Those messages are helpful in some environments, e.g.
> > Microsoft Azure, for customer support and troubleshooting purposes.
> []
> > diff --git a/drivers/scsi/storvsc_drv.c b/drivers/scsi/storvsc_drv.c
> []
> > +static inline bool do_logging(int level) {
> > +	return (logging_level >= level) ? true : false;
> 
> The ternary is not necessary
> 
> 	return logging_level >= level;
> 
> is enough
> 
> > +}
> > +
> > +
> >  struct vmscsi_win8_extension {
> >  	/*
> >  	 * The following were added in Windows 8 @@ -1183,7 +1198,7 @@
> > static void storvsc_command_completion(struct storvsc_cmd_request
> > *cmd_request)
> >
> >  	scmnd->result = vm_srb->scsi_status;
> >
> > -	if (scmnd->result) {
> > +	if (scmnd->result && do_logging(STORVSC_LOGGING_ERROR)) {
> >  		if (scsi_normalize_sense(scmnd->sense_buffer,
> >  				SCSI_SENSE_BUFFERSIZE, &sense_hdr))
> >  			scsi_print_sense_hdr(scmnd->device, "storvsc",
> 
> Is it appropriate to make this scsi_normalize_sense call conditional on
> do_logging here?
> 
> > @@ -1239,12 +1254,25 @@ static void storvsc_on_io_completion(struct
> hv_device *device,
> >  	stor_pkt->vm_srb.sense_info_length =
> >  	vstor_packet->vm_srb.sense_info_length;
> >
> > +	if (vstor_packet->vm_srb.scsi_status != 0 ||
> > +		vstor_packet->vm_srb.srb_status != SRB_STATUS_SUCCESS)
> > +		if (do_logging(STORVSC_LOGGING_WARN))
> > +			dev_warn(&device->device,
> > +				"cmd 0x%x scsi status 0x%x srb status
> 0x%x\n",
> > +				stor_pkt->vm_srb.cdb[0],
> > +				vstor_packet->vm_srb.scsi_status,
> > +				vstor_packet->vm_srb.srb_status);
> 
> It might make some sense to use another macro indirection like
> 
> #define svc_log_warn(dev, level, fmt, ...)			\
> do {								\
> 	if (do_logging(STORSVC_LOGGING_##level)			\
> 		dev_warn(&(dev)->device, fmt, ##__VA_ARGS__);	\
> } while (0)
> 
> So a use could be:
> 
> 	if (vstore_packet...)
> 		svc_log_warn(device, WARN, ...);
> 
> >
--
To unsubscribe from this list: send the line "unsubscribe linux-scsi" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Vitaly Kuznetsov Dec. 4, 2015, 9:52 a.m. UTC | #3 
Long Li <longli@microsoft.com> writes:

> Introduce a logging level for storvsc to log certain error/warning
> messages. Those messages are helpful in some environments,
> e.g. Microsoft Azure, for customer support and troubleshooting
> purposes.

I have an alternative suggestion: let's use dynamic debug! Basically, we
need to convert all non-error logging to using dev_dbg() and this can be
enabled dynamically when needed, even reboot won't be required.

>
> Signed-off-by: Long Li <longli@microsoft.com>
> ---
>  drivers/scsi/storvsc_drv.c | 30 +++++++++++++++++++++++++++++-
>  1 file changed, 29 insertions(+), 1 deletion(-)
>
> diff --git a/drivers/scsi/storvsc_drv.c b/drivers/scsi/storvsc_drv.c
> index 40c43ae..afa1647 100644
> --- a/drivers/scsi/storvsc_drv.c
> +++ b/drivers/scsi/storvsc_drv.c
> @@ -164,6 +164,21 @@ static int sense_buffer_size = PRE_WIN8_STORVSC_SENSE_BUFFER_SIZE;
>  */
>  static int vmstor_proto_version;
>
> +#define STORVSC_LOGGING_NONE	0
> +#define STORVSC_LOGGING_ERROR	1
> +#define STORVSC_LOGGING_WARN	2
> +
> +static int logging_level = STORVSC_LOGGING_ERROR;
> +module_param(logging_level, int, S_IRUGO|S_IWUSR);
> +MODULE_PARM_DESC(logging_level,
> +	"Logging level, 0 - None, 1 - Error (default), 2 - Warning.");
> +
> +static inline bool do_logging(int level)
> +{
> +	return (logging_level >= level) ? true : false;
> +}
> +
> +
>  struct vmscsi_win8_extension {
>  	/*
>  	 * The following were added in Windows 8
> @@ -1183,7 +1198,7 @@ static void storvsc_command_completion(struct storvsc_cmd_request *cmd_request)
>
>  	scmnd->result = vm_srb->scsi_status;
>
> -	if (scmnd->result) {
> +	if (scmnd->result && do_logging(STORVSC_LOGGING_ERROR)) {
>  		if (scsi_normalize_sense(scmnd->sense_buffer,
>  				SCSI_SENSE_BUFFERSIZE, &sense_hdr))
>  			scsi_print_sense_hdr(scmnd->device, "storvsc",
> @@ -1239,12 +1254,25 @@ static void storvsc_on_io_completion(struct hv_device *device,
>  	stor_pkt->vm_srb.sense_info_length =
>  	vstor_packet->vm_srb.sense_info_length;
>
> +	if (vstor_packet->vm_srb.scsi_status != 0 ||
> +		vstor_packet->vm_srb.srb_status != SRB_STATUS_SUCCESS)
> +		if (do_logging(STORVSC_LOGGING_WARN))
> +			dev_warn(&device->device,
> +				"cmd 0x%x scsi status 0x%x srb status 0x%x\n",
> +				stor_pkt->vm_srb.cdb[0],
> +				vstor_packet->vm_srb.scsi_status,
> +				vstor_packet->vm_srb.srb_status);
>
>  	if ((vstor_packet->vm_srb.scsi_status & 0xFF) == 0x02) {
>  		/* CHECK_CONDITION */
>  		if (vstor_packet->vm_srb.srb_status &
>  			SRB_STATUS_AUTOSENSE_VALID) {
>  			/* autosense data available */
> +			if (do_logging(STORVSC_LOGGING_WARN))
> +				dev_warn(&device->device,
> +					"stor pkt %p autosense data valid - len %d\n",
> +					request,
> +					vstor_packet->vm_srb.sense_info_length);
>
>  			memcpy(request->cmd->sense_buffer,
>  			       vstor_packet->vm_srb.sense_data,
Long Li Dec. 4, 2015, 6:41 p.m. UTC | #4 
> -----Original Message-----
> From: Vitaly Kuznetsov [mailto:vkuznets@redhat.com]
> Sent: Friday, December 4, 2015 1:53 AM
> To: Long Li <longli@microsoft.com>
> Cc: KY Srinivasan <kys@microsoft.com>; Haiyang Zhang
> <haiyangz@microsoft.com>; James E.J. Bottomley <JBottomley@odin.com>;
> devel@linuxdriverproject.org; linux-kernel@vger.kernel.org; linux-
> scsi@vger.kernel.org
> Subject: Re: [PATCH] storvsc: add more logging for error and warning
> messages
> 
> Long Li <longli@microsoft.com> writes:
> 
> > Introduce a logging level for storvsc to log certain error/warning
> > messages. Those messages are helpful in some environments, e.g.
> > Microsoft Azure, for customer support and troubleshooting purposes.
> 
> I have an alternative suggestion: let's use dynamic debug! Basically, we need
> to convert all non-error logging to using dev_dbg() and this can be enabled
> dynamically when needed, even reboot won't be required.

This is great idea for debugging!

I think the messages (srb errors) we want to log in this patch are real errors. They are not for debugging, but for customer support in production environment.

Those errors can be ignored in certain specific storage configurations due to some quirks. They are real errors on Azure, so we want to always log them.
 
> 
> >
> > Signed-off-by: Long Li <longli@microsoft.com>
> > ---
> >  drivers/scsi/storvsc_drv.c | 30 +++++++++++++++++++++++++++++-
> >  1 file changed, 29 insertions(+), 1 deletion(-)
> >
> > diff --git a/drivers/scsi/storvsc_drv.c b/drivers/scsi/storvsc_drv.c
> > index 40c43ae..afa1647 100644
> > --- a/drivers/scsi/storvsc_drv.c
> > +++ b/drivers/scsi/storvsc_drv.c
> > @@ -164,6 +164,21 @@ static int sense_buffer_size =
> > PRE_WIN8_STORVSC_SENSE_BUFFER_SIZE;
> >  */
> >  static int vmstor_proto_version;
> >
> > +#define STORVSC_LOGGING_NONE	0
> > +#define STORVSC_LOGGING_ERROR	1
> > +#define STORVSC_LOGGING_WARN	2
> > +
> > +static int logging_level = STORVSC_LOGGING_ERROR;
> > +module_param(logging_level, int, S_IRUGO|S_IWUSR);
> > +MODULE_PARM_DESC(logging_level,
> > +	"Logging level, 0 - None, 1 - Error (default), 2 - Warning.");
> > +
> > +static inline bool do_logging(int level) {
> > +	return (logging_level >= level) ? true : false; }
> > +
> > +
> >  struct vmscsi_win8_extension {
> >  	/*
> >  	 * The following were added in Windows 8 @@ -1183,7 +1198,7 @@
> > static void storvsc_command_completion(struct storvsc_cmd_request
> > *cmd_request)
> >
> >  	scmnd->result = vm_srb->scsi_status;
> >
> > -	if (scmnd->result) {
> > +	if (scmnd->result && do_logging(STORVSC_LOGGING_ERROR)) {
> >  		if (scsi_normalize_sense(scmnd->sense_buffer,
> >  				SCSI_SENSE_BUFFERSIZE, &sense_hdr))
> >  			scsi_print_sense_hdr(scmnd->device, "storvsc", @@
> -1239,12
> > +1254,25 @@ static void storvsc_on_io_completion(struct hv_device
> *device,
> >  	stor_pkt->vm_srb.sense_info_length =
> >  	vstor_packet->vm_srb.sense_info_length;
> >
> > +	if (vstor_packet->vm_srb.scsi_status != 0 ||
> > +		vstor_packet->vm_srb.srb_status != SRB_STATUS_SUCCESS)
> > +		if (do_logging(STORVSC_LOGGING_WARN))
> > +			dev_warn(&device->device,
> > +				"cmd 0x%x scsi status 0x%x srb status
> 0x%x\n",
> > +				stor_pkt->vm_srb.cdb[0],
> > +				vstor_packet->vm_srb.scsi_status,
> > +				vstor_packet->vm_srb.srb_status);
> >
> >  	if ((vstor_packet->vm_srb.scsi_status & 0xFF) == 0x02) {
> >  		/* CHECK_CONDITION */
> >  		if (vstor_packet->vm_srb.srb_status &
> >  			SRB_STATUS_AUTOSENSE_VALID) {
> >  			/* autosense data available */
> > +			if (do_logging(STORVSC_LOGGING_WARN))
> > +				dev_warn(&device->device,
> > +					"stor pkt %p autosense data valid -
> len %d\n",
> > +					request,
> > +					vstor_packet-
> >vm_srb.sense_info_length);
> >
> >  			memcpy(request->cmd->sense_buffer,
> >  			       vstor_packet->vm_srb.sense_data,
> 
> --
>   Vitaly
--
To unsubscribe from this list: send the line "unsubscribe linux-scsi" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
diff mbox

Patch

diff --git a/drivers/scsi/storvsc_drv.c b/drivers/scsi/storvsc_drv.c
index 40c43ae..afa1647 100644
--- a/drivers/scsi/storvsc_drv.c
+++ b/drivers/scsi/storvsc_drv.c
@@ -164,6 +164,21 @@  static int sense_buffer_size = PRE_WIN8_STORVSC_SENSE_BUFFER_SIZE;
 */
 static int vmstor_proto_version;
 
+#define STORVSC_LOGGING_NONE	0
+#define STORVSC_LOGGING_ERROR	1
+#define STORVSC_LOGGING_WARN	2
+
+static int logging_level = STORVSC_LOGGING_ERROR;
+module_param(logging_level, int, S_IRUGO|S_IWUSR);
+MODULE_PARM_DESC(logging_level,
+	"Logging level, 0 - None, 1 - Error (default), 2 - Warning.");
+
+static inline bool do_logging(int level)
+{
+	return (logging_level >= level) ? true : false;
+}
+
+
 struct vmscsi_win8_extension {
 	/*
 	 * The following were added in Windows 8
@@ -1183,7 +1198,7 @@  static void storvsc_command_completion(struct storvsc_cmd_request *cmd_request)
 
 	scmnd->result = vm_srb->scsi_status;
 
-	if (scmnd->result) {
+	if (scmnd->result && do_logging(STORVSC_LOGGING_ERROR)) {
 		if (scsi_normalize_sense(scmnd->sense_buffer,
 				SCSI_SENSE_BUFFERSIZE, &sense_hdr))
 			scsi_print_sense_hdr(scmnd->device, "storvsc",
@@ -1239,12 +1254,25 @@  static void storvsc_on_io_completion(struct hv_device *device,
 	stor_pkt->vm_srb.sense_info_length =
 	vstor_packet->vm_srb.sense_info_length;
 
+	if (vstor_packet->vm_srb.scsi_status != 0 ||
+		vstor_packet->vm_srb.srb_status != SRB_STATUS_SUCCESS)
+		if (do_logging(STORVSC_LOGGING_WARN))
+			dev_warn(&device->device,
+				"cmd 0x%x scsi status 0x%x srb status 0x%x\n",
+				stor_pkt->vm_srb.cdb[0],
+				vstor_packet->vm_srb.scsi_status,
+				vstor_packet->vm_srb.srb_status);
 
 	if ((vstor_packet->vm_srb.scsi_status & 0xFF) == 0x02) {
 		/* CHECK_CONDITION */
 		if (vstor_packet->vm_srb.srb_status &
 			SRB_STATUS_AUTOSENSE_VALID) {
 			/* autosense data available */
+			if (do_logging(STORVSC_LOGGING_WARN))
+				dev_warn(&device->device,
+					"stor pkt %p autosense data valid - len %d\n",
+					request,
+					vstor_packet->vm_srb.sense_info_length);
 
 			memcpy(request->cmd->sense_buffer,
 			       vstor_packet->vm_srb.sense_data,