diff mbox series

[V2,2/2] block: add more debug data to print_req_err

Message ID 20190613141629.2893-3-chaitanya.kulkarni@wdc.com (mailing list archive)
State New, archived
Headers show
Series block: improve print_req_error | expand

Commit Message

Chaitanya Kulkarni June 13, 2019, 2:16 p.m. UTC
This patch adds more debug data on the top of the existing
print_req_error() where we enhance the print message with the printing
request operations in string format and other request fields.

Signed-off-by: Chaitanya Kulkarni <chaitanya.kulkarni@wdc.com>
---
 block/blk-core.c | 35 ++++++++++++++++++++++++++++++++---
 1 file changed, 32 insertions(+), 3 deletions(-)

Comments

Bart Van Assche June 13, 2019, 3:17 p.m. UTC | #1
On 6/13/19 7:16 AM, Chaitanya Kulkarni wrote:
> +#define REQ_OP_NAME(name) [REQ_OP_##name] = #name
> +static const char *const op_name[] = {
> +	REQ_OP_NAME(READ),
> +	REQ_OP_NAME(WRITE),
> +	REQ_OP_NAME(FLUSH),
> +	REQ_OP_NAME(DISCARD),
> +	REQ_OP_NAME(SECURE_ERASE),
> +	REQ_OP_NAME(ZONE_RESET),
> +	REQ_OP_NAME(WRITE_SAME),
> +	REQ_OP_NAME(WRITE_ZEROES),
> +	REQ_OP_NAME(SCSI_IN),
> +	REQ_OP_NAME(SCSI_OUT),
> +	REQ_OP_NAME(DRV_IN),
> +	REQ_OP_NAME(DRV_OUT),
> +};
> +
> +static inline const char *op_str(int op)
> +{
> +	const char *op_str = "REQ_OP_UNKNOWN";
> +
> +	if (op < ARRAY_SIZE(op_name) && op_name[op])
> +		op_str = op_name[op];
> +
> +	return op_str;
> +}

If this patch gets applied there will be three copies in the upstream 
code that convert a REQ_OP_* constant into a string: one in blk-core.c, 
one in blk-mq-debugfs.c and one in include/trace/events/f2fs.h. Is it 
possible to avoid that duplication and have only one function that does 
the number-to-string conversion?

Bart.
Chaitanya Kulkarni June 13, 2019, 4:09 p.m. UTC | #2
On 06/13/2019 08:17 AM, Bart Van Assche wrote:
> On 6/13/19 7:16 AM, Chaitanya Kulkarni wrote:
>> +#define REQ_OP_NAME(name) [REQ_OP_##name] = #name
>> +static const char *const op_name[] = {
>> +	REQ_OP_NAME(READ),
>> +	REQ_OP_NAME(WRITE),
>> +	REQ_OP_NAME(FLUSH),
>> +	REQ_OP_NAME(DISCARD),
>> +	REQ_OP_NAME(SECURE_ERASE),
>> +	REQ_OP_NAME(ZONE_RESET),
>> +	REQ_OP_NAME(WRITE_SAME),
>> +	REQ_OP_NAME(WRITE_ZEROES),
>> +	REQ_OP_NAME(SCSI_IN),
>> +	REQ_OP_NAME(SCSI_OUT),
>> +	REQ_OP_NAME(DRV_IN),
>> +	REQ_OP_NAME(DRV_OUT),
>> +};
>> +
>> +static inline const char *op_str(int op)
>> +{
>> +	const char *op_str = "REQ_OP_UNKNOWN";
>> +
>> +	if (op < ARRAY_SIZE(op_name) && op_name[op])
>> +		op_str = op_name[op];
>> +
>> +	return op_str;
>> +}
>
> If this patch gets applied there will be three copies in the upstream
> code that convert a REQ_OP_* constant into a string: one in blk-core.c,
> one in blk-mq-debugfs.c and one in include/trace/events/f2fs.h. Is it
> possible to avoid that duplication and have only one function that does
> the number-to-string conversion?
>
Okay let me work on this refactoring and send out V3.
> Bart.
>
Martin K. Petersen June 13, 2019, 4:53 p.m. UTC | #3
Bart,

> If this patch gets applied there will be three copies in the upstream
> code that convert a REQ_OP_* constant into a string: one in
> blk-core.c, one in blk-mq-debugfs.c and one in
> include/trace/events/f2fs.h. Is it possible to avoid that duplication
> and have only one function that does the number-to-string conversion?

People often have a hard time correlating SCSI and block error messages
with tracing output. So in general I'd like to see us not just trying to
standardize the helper functions, but the actual output.

I.e. I think it would be great to print exactly the same string for both
error log messages and tracepoints. Since Chaitanya is doing a lot of
work in this area anyway, that may be worth looking into?
Bart Van Assche June 13, 2019, 5:05 p.m. UTC | #4
On 6/13/19 9:53 AM, Martin K. Petersen wrote:
> 
> Bart,
> 
>> If this patch gets applied there will be three copies in the upstream
>> code that convert a REQ_OP_* constant into a string: one in
>> blk-core.c, one in blk-mq-debugfs.c and one in
>> include/trace/events/f2fs.h. Is it possible to avoid that duplication
>> and have only one function that does the number-to-string conversion?
> 
> People often have a hard time correlating SCSI and block error messages
> with tracing output. So in general I'd like to see us not just trying to
> standardize the helper functions, but the actual output.
> 
> I.e. I think it would be great to print exactly the same string for both
> error log messages and tracepoints. Since Chaitanya is doing a lot of
> work in this area anyway, that may be worth looking into?

Hi Martin,

I'm in favor of improving consistency. But are you sure that we can 
modify the tracing output format without breaking any applications?

Bart.
Martin K. Petersen June 13, 2019, 5:43 p.m. UTC | #5
Bart,

> I'm in favor of improving consistency. But are you sure that we can
> modify the tracing output format without breaking any applications?

Chaitanya is already working on enhancing tracing. I seem to recall
blktrace being fairly flexible with what it digests.

On top of that, we also have the option of changing the error path
output as opposed to changing the tracing ditto should that be an issue.

My main point is that there is probably going to be close to a 1:1
mapping between what you would want to see in an error message and what
you would want to see in tracing. So it would be good to use the same
plumbing for both.
diff mbox series

Patch

diff --git a/block/blk-core.c b/block/blk-core.c
index d1a227cfb72e..6a8a808309f0 100644
--- a/block/blk-core.c
+++ b/block/blk-core.c
@@ -144,6 +144,32 @@  static const struct {
 	[BLK_STS_IOERR]		= { -EIO,	"I/O" },
 };
 
+#define REQ_OP_NAME(name) [REQ_OP_##name] = #name
+static const char *const op_name[] = {
+	REQ_OP_NAME(READ),
+	REQ_OP_NAME(WRITE),
+	REQ_OP_NAME(FLUSH),
+	REQ_OP_NAME(DISCARD),
+	REQ_OP_NAME(SECURE_ERASE),
+	REQ_OP_NAME(ZONE_RESET),
+	REQ_OP_NAME(WRITE_SAME),
+	REQ_OP_NAME(WRITE_ZEROES),
+	REQ_OP_NAME(SCSI_IN),
+	REQ_OP_NAME(SCSI_OUT),
+	REQ_OP_NAME(DRV_IN),
+	REQ_OP_NAME(DRV_OUT),
+};
+
+static inline const char *op_str(int op)
+{
+	const char *op_str = "REQ_OP_UNKNOWN";
+
+	if (op < ARRAY_SIZE(op_name) && op_name[op])
+		op_str = op_name[op];
+
+	return op_str;
+}
+
 blk_status_t errno_to_blk_status(int errno)
 {
 	int i;
@@ -176,11 +202,14 @@  static void print_req_error(struct request *req, blk_status_t status,
 		return;
 
 	printk_ratelimited(KERN_ERR
-		"%s: %s error, dev %s, sector %llu op 0x%x flags 0x%x\n",
+		"%s: %s error, dev %s, sector %llu op 0x%x:(%s) flags 0x%x "
+		"phys_seg %u prio class %u\n",
 		caller, blk_errors[idx].name,
 		req->rq_disk ?  req->rq_disk->disk_name : "?",
-		blk_rq_pos(req), req_op(req),
-		req->cmd_flags & ~REQ_OP_MASK);
+		blk_rq_pos(req), req_op(req), op_str(req_op(req)),
+		req->cmd_flags & ~REQ_OP_MASK,
+		req->nr_phys_segments,
+		IOPRIO_PRIO_CLASS(req->ioprio));
 }
 
 static void req_bio_endio(struct request *rq, struct bio *bio,