[PATCH] scsi_debugfs: dump allocted field in more convenient format

[PATCH] scsi_debugfs: dump allocted field in more convenient format

[Dmitry Monakhov]

All request's data fields are formatted as key=val, the only exception is
allocated field, which complicates parsing.

With that patch request looks like follows:
0000000012a51451 {.op=WRITE, .cmd_flags=SYNC|IDLE, .rq_flags=STARTED|DONTPREP|ELVPRIV|IO_STAT, .state=in_flight, .tag=137, .internal_tag=188, .cmd=opcode=0x2a 2a 00 00 00 45 18 00 00 08 00, .retries=0, .result = 0x0, .flags=TAGGED|INITIALIZED|3, .timeout=30.000, .alloc_age=0.004}

Signed-off-by: Dmitry Monakhov <dmtrmonakhov@yandex-team.ru>
---
 drivers/scsi/scsi_debugfs.c | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/drivers/scsi/scsi_debugfs.c b/drivers/scsi/scsi_debugfs.c
index c19ea7a..6ce22b1 100644
--- a/drivers/scsi/scsi_debugfs.c
+++ b/drivers/scsi/scsi_debugfs.c
@@ -45,7 +45,7 @@ void scsi_show_rq(struct seq_file *m, struct request *rq)
 		   cmd->retries, cmd->result);
 	scsi_flags_show(m, cmd->flags, scsi_cmd_flags,
 			ARRAY_SIZE(scsi_cmd_flags));
-	seq_printf(m, ", .timeout=%d.%03d, allocated %d.%03d s ago",
+	seq_printf(m, ", .timeout=%d.%03d, .alloc_age=%d.%03d",
 		   timeout_ms / 1000, timeout_ms % 1000,
 		   alloc_ms / 1000, alloc_ms % 1000);
 }
-- 
2.7.4

Re: [PATCH] scsi_debugfs: dump allocted field in more convenient format

[Bart Van Assche]

On 2020-08-09 02:55, Dmitry Monakhov wrote:
> All request's data fields are formatted as key=val, the only exception is
> allocated field, which complicates parsing.
> 
> With that patch request looks like follows:
> 0000000012a51451 {.op=WRITE, .cmd_flags=SYNC|IDLE, .rq_flags=STARTED|DONTPREP|ELVPRIV|IO_STAT, .state=in_flight, .tag=137, .internal_tag=188, .cmd=opcode=0x2a 2a 00 00 00 45 18 00 00 08 00, .retries=0, .result = 0x0, .flags=TAGGED|INITIALIZED|3, .timeout=30.000, .alloc_age=0.004}
> 
> Signed-off-by: Dmitry Monakhov <dmtrmonakhov@yandex-team.ru>
> ---
>  drivers/scsi/scsi_debugfs.c | 2 +-
>  1 file changed, 1 insertion(+), 1 deletion(-)
> 
> diff --git a/drivers/scsi/scsi_debugfs.c b/drivers/scsi/scsi_debugfs.c
> index c19ea7a..6ce22b1 100644
> --- a/drivers/scsi/scsi_debugfs.c
> +++ b/drivers/scsi/scsi_debugfs.c
> @@ -45,7 +45,7 @@ void scsi_show_rq(struct seq_file *m, struct request *rq)
>  		   cmd->retries, cmd->result);
>  	scsi_flags_show(m, cmd->flags, scsi_cmd_flags,
>  			ARRAY_SIZE(scsi_cmd_flags));
> -	seq_printf(m, ", .timeout=%d.%03d, allocated %d.%03d s ago",
> +	seq_printf(m, ", .timeout=%d.%03d, .alloc_age=%d.%03d",
>  		   timeout_ms / 1000, timeout_ms % 1000,
>  		   alloc_ms / 1000, alloc_ms % 1000);
>  }

Hi Dmitry,

These messages are intended for humans and are not intended for processing
by any kind of software. I think the current message is easier to understand
by a human than the new message introduced by the above patch.

Thanks,

Bart.

Re: [PATCH] scsi_debugfs: dump allocted field in more convenient format

[Дмитрий Монахов]

11.08.2020, 02:22, "Bart Van Assche" <bvanassche@acm.org>:
> On 2020-08-09 02:55, Dmitry Monakhov wrote:
>>  All request's data fields are formatted as key=val, the only exception is
>>  allocated field, which complicates parsing.
>>
>>  With that patch request looks like follows:
>>  0000000012a51451 {.op=WRITE, .cmd_flags=SYNC|IDLE, .rq_flags=STARTED|DONTPREP|ELVPRIV|IO_STAT, .state=in_flight, .tag=137, .internal_tag=188, .cmd=opcode=0x2a 2a 00 00 00 45 18 00 00 08 00, .retries=0, .result = 0x0, .flags=TAGGED|INITIALIZED|3, .timeout=30.000, .alloc_age=0.004}
>>
>>  Signed-off-by: Dmitry Monakhov <dmtrmonakhov@yandex-team.ru>
>>  ---
>>   drivers/scsi/scsi_debugfs.c | 2 +-
>>   1 file changed, 1 insertion(+), 1 deletion(-)
>>
>>  diff --git a/drivers/scsi/scsi_debugfs.c b/drivers/scsi/scsi_debugfs.c
>>  index c19ea7a..6ce22b1 100644
>>  --- a/drivers/scsi/scsi_debugfs.c
>>  +++ b/drivers/scsi/scsi_debugfs.c
>>  @@ -45,7 +45,7 @@ void scsi_show_rq(struct seq_file *m, struct request *rq)
>>                      cmd->retries, cmd->result);
>>           scsi_flags_show(m, cmd->flags, scsi_cmd_flags,
>>                           ARRAY_SIZE(scsi_cmd_flags));
>>  - seq_printf(m, ", .timeout=%d.%03d, allocated %d.%03d s ago",
>>  + seq_printf(m, ", .timeout=%d.%03d, .alloc_age=%d.%03d",
>>                      timeout_ms / 1000, timeout_ms % 1000,
>>                      alloc_ms / 1000, alloc_ms % 1000);
>>   }
>
> Hi Dmitry,
>
> These messages are intended for humans and are not intended for processing
> by any kind of software. I think the current message is easier to understand
> by a human than the new message introduced by the above patch.

Let me disagree. I try to write test for issue like  [1]
My test does random fault injection and scan  /sys/kernel/debug/block/*/*/busy for stuck requests
The object's format looks sane and well structured for parsers, the only exception is "allocated" field, see below:
  0000000012a51451 {.op=WRITE, .state=in_flight, .tag=137.... .timeout=30.000, allocated 41255.568 s ago}

All I want to do is just make it looks unified with other fields, see below:
  0000000012a51451 {.op=WRITE, .state=in_flight, .tag=137.... .timeout=30.000, .alloc_age=41255.568}

If field name 'alloc_age' is not descriptive enough please suggest me a better one. But we definitely need
to unify  it  to .NAME=VALUE format.

Footnotes:
[1]  https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/commit/?id=b554db147feea39617b533ab6bca247c91c6198a




>
> Thanks,
>
> Bart.