This patch is not intended to be merged, it measures
and prints the time the 9p server spends on handling
a T_readdir request. It prints the total time it spent
on handling the request, and also the time it spent
on I/O (fs driver) only.
Signed-off-by: Christian Schoenebeck <qemu_...@crudebyte.com>
---
hw/9pfs/9p.c | 21 +++++++++++++++++++++
1 file changed, 21 insertions(+)
diff --git a/hw/9pfs/9p.c b/hw/9pfs/9p.c
index e0ca45d46b..9cd494edd7 100644
--- a/hw/9pfs/9p.c
+++ b/hw/9pfs/9p.c
@@ -2311,6 +2311,15 @@ static void v9fs_free_dirents(struct V9fsDirEnt *e)
}
}
+static double wall_time(void)
+{
+ struct timeval t;
+ struct timezone tz;
+ gettimeofday(&t, &tz);
+ return t.tv_sec + t.tv_usec * 0.000001;
+}
+
+
static int coroutine_fn v9fs_do_readdir(V9fsPDU *pdu, V9fsFidState *fidp,
int32_t max_count)
{
@@ -2330,6 +2339,8 @@ static int coroutine_fn v9fs_do_readdir(V9fsPDU *pdu,
V9fsFidState *fidp,
*/
const bool dostat = pdu->s->ctx.export_flags & V9FS_REMAP_INODES;
+ const double start = wall_time();
+
/*
* Fetch all required directory entries altogether on a background IO
* thread from fs driver. We don't want to do that for each entry
@@ -2344,6 +2355,10 @@ static int coroutine_fn v9fs_do_readdir(V9fsPDU *pdu,
V9fsFidState *fidp,
}
count = 0;
+ const double end = wall_time();
+ printf("\n\nTime 9p server spent on synth_readdir() I/O only (synth "
+ "driver): %fs\n", end - start);
+
for (struct V9fsDirEnt *e = entries; e; e = e->next) {
dent = e->dent;
@@ -2416,6 +2431,8 @@ static void coroutine_fn v9fs_readdir(void *opaque)
V9fsPDU *pdu = opaque;
V9fsState *s = pdu->s;
+ const double start = wall_time();
+
retval = pdu_unmarshal(pdu, offset, "dqd", &fid,
&initial_offset, &max_count);
if (retval < 0) {
@@ -2459,6 +2476,10 @@ out:
put_fid(pdu, fidp);
out_nofid:
pdu_complete(pdu, retval);
+
+ const double end = wall_time();
+ printf("Time 9p server spent on entire T_readdir request: %fs "
+ "[IMPORTANT]\n", end - start);
}
static int v9fs_xattr_write(V9fsState *s, V9fsPDU *pdu, V9fsFidState *fidp,
--
2.20.1
