Received-SPF: pass (google.com: best guess record for domain of linux-kernel-owner@vger.kernel.org designates 209.132.180.67 as permitted sender) client-ip=209.132.180.67;
Reply-To: mgandhi@redhat.com
Subject: Re: [PATCH] scsi: core: Log SCSI command age with errors
To:     Laurence Oberman <loberman@redhat.com>,
        linux-kernel@vger.kernel.org, linux-scsi@vger.kernel.org
Cc:     jejb@linux.ibm.com, martin.petersen@oracle.com
References: <20190923060122.GA9603@machine1>
 <8e9c537b7eaabd611968d22ec31f7cfb90e72efe.camel@redhat.com>
From:   "Milan P. Gandhi" <mgandhi@redhat.com>
Organization: Red Hat
Message-ID: <a1fadc48-b6b2-784a-d1ff-3d4dbe6df7eb@redhat.com>
Date:   Mon, 23 Sep 2019 18:54:08 +0530
User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:60.0) Gecko/20100101
 Thunderbird/60.6.1
MIME-Version: 1.0
In-Reply-To: <8e9c537b7eaabd611968d22ec31f7cfb90e72efe.camel@redhat.com>
Content-Type: text/plain; charset=utf-8
Content-Language: en-US
Content-Transfer-Encoding: 7bit
Sender: linux-kernel-owner@vger.kernel.org
Precedence: bulk

On 9/23/19 6:32 PM, Laurence Oberman wrote:
> On Mon, 2019-09-23 at 11:31 +0530, Milan P. Gandhi wrote:
>> Couple of users had requested to print the SCSI command age along 
>> with command failure errors. This is a small change, but allows 
>> users to get more important information about the command that was 
>> failed, it would help the users in debugging the command failures:
>>
>> Signed-off-by: Milan P. Gandhi <mgandhi@redhat.com>
>> ---
>> diff --git a/drivers/scsi/scsi_logging.c
>> b/drivers/scsi/scsi_logging.c
>> index ecc5918e372a..ca2182bc53c6 100644
>> --- a/drivers/scsi/scsi_logging.c
>> +++ b/drivers/scsi/scsi_logging.c
>> @@ -437,6 +437,7 @@ void scsi_print_result(const struct scsi_cmnd
>> *cmd, const char *msg,
>>  	const char *mlret_string = scsi_mlreturn_string(disposition);
>>  	const char *hb_string = scsi_hostbyte_string(cmd->result);
>>  	const char *db_string = scsi_driverbyte_string(cmd->result);
>> +	unsigned long cmd_age = (jiffies - cmd->jiffies_at_alloc) / HZ;
>>  
>>  	logbuf = scsi_log_reserve_buffer(&logbuf_len);
>>  	if (!logbuf)
>> @@ -478,10 +479,15 @@ void scsi_print_result(const struct scsi_cmnd
>> *cmd, const char *msg,
>>  
>>  	if (db_string)
>>  		off += scnprintf(logbuf + off, logbuf_len - off,
>> -				 "driverbyte=%s", db_string);
>> +				 "driverbyte=%s ", db_string);
>>  	else
>>  		off += scnprintf(logbuf + off, logbuf_len - off,
>> -				 "driverbyte=0x%02x", driver_byte(cmd-
>>> result));
>> +				 "driverbyte=0x%02x ",
>> +				 driver_byte(cmd->result));
>> +
>> +	off += scnprintf(logbuf + off, logbuf_len - off,
>> +			 "cmd-age=%lus", cmd_age);
>> +
>>  out_printk:
>>  	dev_printk(KERN_INFO, &cmd->device->sdev_gendev, "%s", logbuf);
>>  	scsi_log_release_buffer(logbuf);
>>
> 
> This looks to be a useful debug addition to me, and the code looks
> correct.
> I believe this has also been tested by Milan in our lab.
> 
> Reviewed-by: Laurence Oberman <loberman@redhat.com> 
> 
Yes, the patch was tested locally using scsi_debug as well as in real 
storage issues caused by bad disks in customer environment.

Thanks,
Milan.