Re: [PATCH Linux 2.6.12-rc5-mm1 06/06] blk: debug messages

Tejun Heo
2005-05-29T04:34:02Z

06_blk_flush_reimplementation_debug_messages.patch

These are debug messages I've used. If you are interested how
it works...

Signed-off-by: Tejun Heo <htejun@gmail.com>

elevator.c | 3 +++
ll_rw_blk.c | 36 ++++++++++++++++++++++++++++++++++--
2 files changed, 37 insertions(+), 2 deletions(-)

Index: blk-fixes/drivers/block/elevator.c
===================================================================
--- blk-fixes.orig/drivers/block/elevator.c 2005-05-29 13:20:31.000000000 +0900
+++ blk-fixes/drivers/block/elevator.c 2005-05-29 13:20:32.000000000 +0900
@@ -37,6 +37,8 @@

#include <asm/uaccess.h>

+#define pd(fmt, args...) printk("[%-21s]: " fmt, __FUNCTION__ , ##args);
+
static DEFINE_SPINLOCK(elv_list_lock);
static LIST_HEAD(elv_list);

@@ -55,6 +57,7 @@ static inline void elv_dec_inflight(requ
* kick the queue in the ass to start the flush sequence.
*/
if (q->flush_seq == QUEUE_FLUSH_DRAIN && q->in_flight == 0) {
+ pd("-> FLUSH_PRE\n");
q->flush_seq = QUEUE_FLUSH_PRE;
q->request_fn(q);
}
Index: blk-fixes/drivers/block/ll_rw_blk.c
===================================================================
--- blk-fixes.orig/drivers/block/ll_rw_blk.c 2005-05-29 13:20:31.000000000 +0900
+++ blk-fixes/drivers/block/ll_rw_blk.c 2005-05-29 13:20:32.000000000 +0900
@@ -30,6 +30,8 @@
#include <linux/writeback.h>
#include <linux/blkdev.h>

+#define pd(fmt, args...) printk("[%-21s]: " fmt, __FUNCTION__ , ##args);
+
/*
* for max sense size
*/
@@ -352,6 +354,7 @@ static void blk_finish_flush(request_que
struct request *rq = q->bar_rq;
struct bio *bio = q->bar_bio;

+ pd("ENTER, -> FLUSH_NONE, error=%d\n", error);
q->flush_seq = QUEUE_FLUSH_NONE;
q->bar_rq = NULL;
q->bar_bio = NULL;
@@ -382,9 +385,11 @@ static void blk_pre_flush_end_io(struct
request_queue_t *q = flush_rq->q;
struct request *rq = q->bar_rq;

+ pd("ENTER\n");
switch (error) {
case 0:
q->flush_seq = QUEUE_FLUSH_BAR;
+ pd("-> FLUSH_BAR\n");
elv_requeue_request(q, rq);
break;

@@ -399,6 +404,7 @@ static void blk_pre_flush_end_io(struct

static void blk_post_flush_end_io(struct request *flush_rq, int error)
{
+ pd("ENTER\n");
blk_finish_flush(flush_rq->q, error);
}

@@ -406,12 +412,20 @@ struct request *blk_start_pre_flush(requ
{
struct request *flush_rq = q->flush_rq;

+ pd("ENTER\n");
+ struct bio *bio;
+ for (bio = rq->bio; bio; bio = bio->bi_next)
+ pd("BIO %p %llu %u\n",
+ bio, (unsigned long long)bio->bi_sector, bio->bi_size);
+
/*
* prepare_flush returns 0 if no flush is needed, just perform
* the original barrier request in that case.
*/
- if (!blk_prep_flush(q, flush_rq, rq->rq_disk))
+ if (!blk_prep_flush(q, flush_rq, rq->rq_disk)) {
+ pd("Oh well, prep says it's unnecessary\n");
return rq;
+ }

blkdev_dequeue_request(rq);
q->bar_rq = rq;
@@ -425,9 +439,11 @@ struct request *blk_start_pre_flush(requ

if (q->in_flight == 0) {
q->flush_seq = QUEUE_FLUSH_PRE;
+ pd("-> FLUSH_PRE\n");
return flush_rq;
} else {
q->flush_seq = QUEUE_FLUSH_DRAIN;
+ pd("-> FLUSH_DRAIN, in_flight=%d\n", q->in_flight);
return NULL;
}
}
@@ -436,13 +452,18 @@ static void blk_start_post_flush(request
{
struct request *flush_rq = q->flush_rq;

+ pd("ENTER\n");
+
if (blk_prep_flush(q, flush_rq, q->bar_rq->rq_disk)) {
+ pd("-> FLUSH_POST\n");
flush_rq->end_io = blk_post_flush_end_io;
q->flush_seq = QUEUE_FLUSH_POST;
__elv_add_request(q, flush_rq, ELEVATOR_INSERT_FRONT, 0);
q->request_fn(q); /* is this necessary? - tj */
- } else
+ } else {
+ pd("wow, unnecessary?\n");
blk_finish_flush(q, 0);
+ }
}

int blk_do_barrier(request_queue_t *q, struct request **rqp)
@@ -453,6 +474,7 @@ int blk_do_barrier(request_queue_t *q, s
switch (q->ordered) {
case QUEUE_ORDERED_NONE:
if (is_barrier) {
+ pd("ORDERED_NONE, seen barrier\n");
/*
* This can happen when the queue switches to
* ORDERED_NONE while this request is on it.
@@ -473,6 +495,7 @@ int blk_do_barrier(request_queue_t *q, s
break;
case QUEUE_FLUSH_DRAIN:
*rqp = NULL;
+ pd("draining... deferring %p\n", rq);
break;
default:
/*
@@ -481,11 +504,14 @@ int blk_do_barrier(request_queue_t *q, s
*/
if (rq != q->flush_rq && rq != q->bar_rq)
*rqp = NULL;
+ pd("flush_seq == %d, %p->%p\n", q->flush_seq, rq, *rqp);
break;
}
return 1;

case QUEUE_ORDERED_TAG:
+ if (is_barrier)
+ pd("ORDERED_TAG, seen barrier\n");
return 1;

default:
@@ -512,6 +538,9 @@ static int flush_dry_bio_endio(struct bi
bio->bi_sector -= (q->bi_size >> 9);
q->bi_size = 0;

+ pd("%p %llu %u\n",
+ bio, (unsigned long long)bio->bi_sector, bio->bi_size);
+
return 0;
}

@@ -525,6 +554,7 @@ static inline int blk_flush_bio_endio(st
if (q->flush_seq != QUEUE_FLUSH_BAR || q->bar_rq != rq)
return 0;

+ pd("q->flush_error=%d error=%d\n", q->flush_error, error);
/*
* Okay, this is the barrier request in progress, dry finish it.
*/
@@ -551,6 +581,7 @@ static inline int blk_flush_end_request(
if (q->flush_seq != QUEUE_FLUSH_BAR || q->bar_rq != rq)
return 0;

+ pd("q->flush_error=%d\n", q->flush_error);
if (!q->flush_error)
blk_start_post_flush(q);
else
@@ -2601,6 +2632,7 @@ static int __make_request(request_queue_

barrier = bio_barrier(bio);
if (unlikely(barrier) && (q->ordered == QUEUE_ORDERED_NONE)) {
+ pd("ORDERED_NONE, seen barrier\n");
err = -EOPNOTSUPP;
goto end_io;
}