Add KTR_GEOM, which allows tracing of basic GEOM I/O events occuring

in the g_up and g_down threads.  Each time a bio is propelled up and
down the stack, an event is generating showing the provider, offset,
and length, as well as thread wakeup and work status information.
This commit is contained in:
rwatson 2004-10-21 18:35:24 +00:00
parent 1ad13251f1
commit 4d228039a9
2 changed files with 28 additions and 1 deletions

View File

@ -41,6 +41,7 @@ __FBSDID("$FreeBSD$");
#include <sys/kernel.h> #include <sys/kernel.h>
#include <sys/malloc.h> #include <sys/malloc.h>
#include <sys/bio.h> #include <sys/bio.h>
#include <sys/ktr.h>
#include <sys/errno.h> #include <sys/errno.h>
#include <geom/geom.h> #include <geom/geom.h>
@ -368,33 +369,50 @@ g_io_schedule_down(struct thread *tp __unused)
g_bioq_lock(&g_bio_run_down); g_bioq_lock(&g_bio_run_down);
bp = g_bioq_first(&g_bio_run_down); bp = g_bioq_first(&g_bio_run_down);
if (bp == NULL) { if (bp == NULL) {
CTR0(KTR_GEOM, "g_down going to sleep");
msleep(&g_wait_down, &g_bio_run_down.bio_queue_lock, msleep(&g_wait_down, &g_bio_run_down.bio_queue_lock,
PRIBIO | PDROP, "-", hz/10); PRIBIO | PDROP, "-", hz/10);
continue; continue;
} }
CTR0(KTR_GEOM, "g_down has work to do");
g_bioq_unlock(&g_bio_run_down); g_bioq_unlock(&g_bio_run_down);
if (pace > 0) { if (pace > 0) {
CTR1(KTR_GEOM, "g_down pacing self (pace %d)", pace);
msleep(&error, NULL, PRIBIO, "g_down", hz/10); msleep(&error, NULL, PRIBIO, "g_down", hz/10);
pace--; pace--;
} }
error = g_io_check(bp); error = g_io_check(bp);
if (error) { if (error) {
CTR3(KTR_GEOM, "g_down g_io_check on bp %p provider "
"%s returned %d", bp, bp->bio_to->name, error);
g_io_deliver(bp, error); g_io_deliver(bp, error);
continue; continue;
} }
CTR2(KTR_GEOM, "g_down processing bp %p provider %s", bp,
bp->bio_to->name);
switch (bp->bio_cmd) { switch (bp->bio_cmd) {
case BIO_READ: case BIO_READ:
case BIO_WRITE: case BIO_WRITE:
case BIO_DELETE: case BIO_DELETE:
/* Truncate requests to the end of providers media. */ /* Truncate requests to the end of providers media. */
/*
* XXX: What if we truncate because of offset being
* bad, not length?
*/
excess = bp->bio_offset + bp->bio_length; excess = bp->bio_offset + bp->bio_length;
if (excess > bp->bio_to->mediasize) { if (excess > bp->bio_to->mediasize) {
excess -= bp->bio_to->mediasize; excess -= bp->bio_to->mediasize;
bp->bio_length -= excess; bp->bio_length -= excess;
if (excess > 0)
CTR3(KTR_GEOM, "g_down truncated bio "
"%p provider %s by %d", bp,
bp->bio_to->name, excess);
} }
/* Deliver zero length transfers right here. */ /* Deliver zero length transfers right here. */
if (bp->bio_length == 0) { if (bp->bio_length == 0) {
g_io_deliver(bp, 0); g_io_deliver(bp, 0);
CTR2(KTR_GEOM, "g_down terminated 0-length "
"bp %p provider %s", bp, bp->bio_to->name);
continue; continue;
} }
break; break;
@ -404,6 +422,9 @@ g_io_schedule_down(struct thread *tp __unused)
#ifdef WITNESS #ifdef WITNESS
mtx_lock(&mymutex); mtx_lock(&mymutex);
#endif #endif
CTR4(KTR_GEOM, "g_down starting bp %p provider %s off %ld "
"len %ld", bp, bp->bio_to->name, bp->bio_offset,
bp->bio_length);
bp->bio_to->geom->start(bp); bp->bio_to->geom->start(bp);
#ifdef WITNESS #ifdef WITNESS
mtx_unlock(&mymutex); mtx_unlock(&mymutex);
@ -449,6 +470,7 @@ g_io_schedule_up(struct thread *tp __unused)
#ifdef WITNESS #ifdef WITNESS
mtx_lock(&mymutex); mtx_lock(&mymutex);
#endif #endif
CTR1(KTR_GEOM, "g_up processing task bp %p", bp);
bp->bio_task(bp->bio_task_arg); bp->bio_task(bp->bio_task_arg);
#ifdef WITNESS #ifdef WITNESS
mtx_unlock(&mymutex); mtx_unlock(&mymutex);
@ -461,12 +483,16 @@ g_io_schedule_up(struct thread *tp __unused)
#ifdef WITNESS #ifdef WITNESS
mtx_lock(&mymutex); mtx_lock(&mymutex);
#endif #endif
CTR4(KTR_GEOM, "g_up biodone bp %p provider %s off "
"%ld len %ld", bp, bp->bio_to->name,
bp->bio_offset, bp->bio_length);
biodone(bp); biodone(bp);
#ifdef WITNESS #ifdef WITNESS
mtx_unlock(&mymutex); mtx_unlock(&mymutex);
#endif #endif
continue; continue;
} }
CTR0(KTR_GEOM, "g_up going to sleep");
msleep(&g_wait_up, &g_bio_run_up.bio_queue_lock, msleep(&g_wait_up, &g_bio_run_up.bio_queue_lock,
PRIBIO | PDROP, "-", hz/10); PRIBIO | PDROP, "-", hz/10);
} }

View File

@ -74,7 +74,8 @@
#define KTR_CONTENTION 0x00800000 /* Lock contention */ #define KTR_CONTENTION 0x00800000 /* Lock contention */
#define KTR_UMA 0x01000000 /* UMA slab allocator */ #define KTR_UMA 0x01000000 /* UMA slab allocator */
#define KTR_CALLOUT 0x02000000 /* Callouts and timeouts */ #define KTR_CALLOUT 0x02000000 /* Callouts and timeouts */
#define KTR_ALL 0x02ffffff #define KTR_GEOM 0x04000000 /* GEOM I/O events */
#define KTR_ALL 0x04ffffff
/* /*
* Trace classes which can be assigned to particular use at compile time * Trace classes which can be assigned to particular use at compile time