[Qemu-devel] [PATCH v2 0/3] Replace 9p debug infrastructure with Qemu Tracing

[Qemu-devel] [PATCH v2 0/3] Replace 9p debug infrastructure with Qemu Tracing

[Harsh Prateek Bora]

This patchset introduces Qemu Tracing to 9p pdu handlers and removes the
existing debug infrastructure which became less meaningful after the
introduction of coroutines. With the existing debug infra, parallel
operations creates a messy output and filtering becomes difficult.

With Qemu tracing in place, we can selectively enable/disable trace-events
and the trace log can be further pretty-printed/filtered using an analysis
script.

Harsh Prateek Bora (3):
  hw/9pfs: Introduce tracing for 9p pdu handlers
  hw/9pfs: Remove virtio-9p-debug.* infra to be replaced by Qemu
    Tracing.
  scripts: Simpletrace log analysis script for pretty-printing 9p log.

 Makefile.objs                     |    2 +-
 hw/9pfs/virtio-9p-debug.c         |  646 -------------------------------------
 hw/9pfs/virtio-9p-debug.h         |    6 -
 hw/9pfs/virtio-9p.c               |   70 ++++-
 scripts/analyse-9p-simpletrace.py |  142 ++++++++
 trace-events                      |   47 +++
 6 files changed, 252 insertions(+), 661 deletions(-)
 delete mode 100644 hw/9pfs/virtio-9p-debug.c
 delete mode 100644 hw/9pfs/virtio-9p-debug.h
 create mode 100755 scripts/analyse-9p-simpletrace.py

[Qemu-devel] [PATCH v2 1/3] hw/9pfs: Introduce tracing for 9p pdu handlers

[Harsh Prateek Bora]

Plan is to replace the existing debug infrastructure with Qemu tracing
infrastructure so that user can dynamically enable/disable trace events and
therefore a meaningful trace log can be generated which can be further
filtered using an analysis script.

Note: Because of current simpletrace limitations, the trace events are
logging at max 6 args, however, once the more args are supported, we can
change trace events to log more info as well. Also, This initial patch only
provides a replacement for existing debug infra. More trace events to be
added later for newly added handlers and sub-routines.

Signed-off-by: Harsh Prateek Bora <harsh@linux.vnet.ibm.com>
---
 hw/9pfs/virtio-9p.c |   62 +++++++++++++++++++++++++++++++++++++++++++++++++++
 trace-events        |   47 ++++++++++++++++++++++++++++++++++++++
 2 files changed, 109 insertions(+), 0 deletions(-)

diff --git a/hw/9pfs/virtio-9p.c b/hw/9pfs/virtio-9p.c
index 1d1933f..cdb73da 100644
--- a/hw/9pfs/virtio-9p.c
+++ b/hw/9pfs/virtio-9p.c
@@ -20,6 +20,7 @@
 #include "virtio-9p-debug.h"
 #include "virtio-9p-xattr.h"
 #include "virtio-9p-coth.h"
+#include "trace.h"
 
 int debug_9p_pdu;
 int open_fd_hw;
@@ -977,6 +978,7 @@ static void complete_pdu(V9fsState *s, V9fsPDU *pdu, ssize_t len)
         if (s->proto_version == V9FS_PROTO_2000L) {
             id = P9_RLERROR;
         }
+        trace_complete_pdu(pdu->tag, pdu->id, err); /* Trace ERROR */
     }
 
     /* fill out the header */
@@ -1286,6 +1288,7 @@ static void v9fs_version(void *opaque)
     size_t offset = 7;
 
     pdu_unmarshal(pdu, offset, "ds", &s->msize, &version);
+    trace_v9fs_version(pdu->tag, pdu->id, s->msize, version.data);
 
     if (!strcmp(version.data, "9P2000.u")) {
         s->proto_version = V9FS_PROTO_2000U;
@@ -1296,6 +1299,8 @@ static void v9fs_version(void *opaque)
     }
 
     offset += pdu_marshal(pdu, offset, "ds", s->msize, &version);
+    trace_v9fs_version_return(pdu->tag, pdu->id, s->msize, version.data);
+
     complete_pdu(s, pdu, offset);
 
     v9fs_string_free(&version);
@@ -1314,6 +1319,7 @@ static void v9fs_attach(void *opaque)
     ssize_t err;
 
     pdu_unmarshal(pdu, offset, "ddssd", &fid, &afid, &uname, &aname, &n_uname);
+    trace_v9fs_attach(pdu->tag, pdu->id, fid, afid, uname.data, aname.data);
 
     fidp = alloc_fid(s, fid);
     if (fidp == NULL) {
@@ -1338,6 +1344,7 @@ static void v9fs_attach(void *opaque)
 out:
     put_fid(pdu, fidp);
 out_nofid:
+    trace_v9fs_attach_return(pdu->tag, pdu->id, qid.type, qid.version, qid.path);
     complete_pdu(s, pdu, err);
     v9fs_string_free(&uname);
     v9fs_string_free(&aname);
@@ -1355,6 +1362,7 @@ static void v9fs_stat(void *opaque)
     V9fsState *s = pdu->s;
 
     pdu_unmarshal(pdu, offset, "d", &fid);
+    trace_v9fs_stat(pdu->tag, pdu->id, fid);
 
     fidp = get_fid(pdu, fid);
     if (fidp == NULL) {
@@ -1375,6 +1383,8 @@ static void v9fs_stat(void *opaque)
 out:
     put_fid(pdu, fidp);
 out_nofid:
+    trace_v9fs_stat_return(pdu->tag, pdu->id, v9stat.mode, v9stat.atime, v9stat.mtime, v9stat.length);
+
     complete_pdu(s, pdu, err);
 }
 
@@ -1391,6 +1401,7 @@ static void v9fs_getattr(void *opaque)
     V9fsState *s = pdu->s;
 
     pdu_unmarshal(pdu, offset, "dq", &fid, &request_mask);
+    trace_v9fs_getattr(pdu->tag, pdu->id, fid, request_mask);
 
     fidp = get_fid(pdu, fid);
     if (fidp == NULL) {
@@ -1420,6 +1431,10 @@ static void v9fs_getattr(void *opaque)
 out:
     put_fid(pdu, fidp);
 out_nofid:
+    trace_v9fs_getattr_return(pdu->tag, pdu->id, v9stat_dotl.st_result_mask,
+			v9stat_dotl.st_mode, v9stat_dotl.st_uid,
+			v9stat_dotl.st_gid);
+
     complete_pdu(s, pdu, retval);
 }
 
@@ -1547,6 +1562,8 @@ static void v9fs_walk(void *opaque)
     offset += pdu_unmarshal(pdu, offset, "ddw", &fid,
                             &newfid, &nwnames);
 
+    trace_v9fs_walk(pdu->tag, pdu->id, fid, newfid, nwnames);
+
     if (nwnames && nwnames <= P9_MAXWELEM) {
         wnames = g_malloc0(sizeof(wnames[0]) * nwnames);
         qids   = g_malloc0(sizeof(qids[0]) * nwnames);
@@ -1603,6 +1620,7 @@ out:
     v9fs_path_free(&dpath);
     v9fs_path_free(&path);
 out_nofid:
+    trace_v9fs_walk_return(pdu->tag, pdu->id, nwnames, qids);
     complete_pdu(s, pdu, err);
     if (nwnames && nwnames <= P9_MAXWELEM) {
         for (name_idx = 0; name_idx < nwnames; name_idx++) {
@@ -1653,6 +1671,8 @@ static void v9fs_open(void *opaque)
     } else {
         pdu_unmarshal(pdu, offset, "db", &fid, &mode);
     }
+    trace_v9fs_open(pdu->tag, pdu->id, fid, mode);
+
     fidp = get_fid(pdu, fid);
     if (fidp == NULL) {
         err = -ENOENT;
@@ -1699,6 +1719,7 @@ static void v9fs_open(void *opaque)
 out:
     put_fid(pdu, fidp);
 out_nofid:
+    trace_v9fs_open_return(pdu->tag, pdu->id, qid.type, qid.version, qid.path, iounit);
     complete_pdu(s, pdu, err);
 }
 
@@ -1717,6 +1738,7 @@ static void v9fs_lcreate(void *opaque)
 
     pdu_unmarshal(pdu, offset, "dsddd", &dfid, &name, &flags,
                   &mode, &gid);
+    trace_v9fs_lcreate(pdu->tag, pdu->id, dfid, flags, mode, gid);
 
     fidp = get_fid(pdu, dfid);
     if (fidp == NULL) {
@@ -1746,6 +1768,7 @@ static void v9fs_lcreate(void *opaque)
 out:
     put_fid(pdu, fidp);
 out_nofid:
+    trace_v9fs_lcreate_return(pdu->tag, pdu->id, qid.type, qid.version, qid.path, iounit);
     complete_pdu(pdu->s, pdu, err);
     v9fs_string_free(&name);
 }
@@ -1761,6 +1784,8 @@ static void v9fs_fsync(void *opaque)
     V9fsState *s = pdu->s;
 
     pdu_unmarshal(pdu, offset, "dd", &fid, &datasync);
+    trace_v9fs_fsync(pdu->tag, pdu->id, fid, datasync);
+
     fidp = get_fid(pdu, fid);
     if (fidp == NULL) {
         err = -ENOENT;
@@ -1785,6 +1810,7 @@ static void v9fs_clunk(void *opaque)
     V9fsState *s = pdu->s;
 
     pdu_unmarshal(pdu, offset, "d", &fid);
+    trace_v9fs_clunk(pdu->tag, pdu->id, fid);
 
     fidp = clunk_fid(s, fid);
     if (fidp == NULL) {
@@ -1901,6 +1927,7 @@ static void v9fs_read(void *opaque)
     V9fsState *s = pdu->s;
 
     pdu_unmarshal(pdu, offset, "dqd", &fid, &off, &max_count);
+    trace_v9fs_read(pdu->tag, pdu->id, fid, off, max_count);
 
     fidp = get_fid(pdu, fid);
     if (fidp == NULL) {
@@ -1959,6 +1986,7 @@ static void v9fs_read(void *opaque)
 out:
     put_fid(pdu, fidp);
 out_nofid:
+    trace_v9fs_read_return(pdu->tag, pdu->id, count, err);
     complete_pdu(s, pdu, err);
 }
 
@@ -2043,6 +2071,8 @@ static void v9fs_readdir(void *opaque)
 
     pdu_unmarshal(pdu, offset, "dqd", &fid, &initial_offset, &max_count);
 
+    trace_v9fs_readdir(pdu->tag, pdu->id, fid, initial_offset, max_count);
+
     fidp = get_fid(pdu, fid);
     if (fidp == NULL) {
         retval = -EINVAL;
@@ -2068,6 +2098,7 @@ static void v9fs_readdir(void *opaque)
 out:
     put_fid(pdu, fidp);
 out_nofid:
+    trace_v9fs_readdir_return(pdu->tag, pdu->id, count, retval);
     complete_pdu(s, pdu, retval);
 }
 
@@ -2132,6 +2163,7 @@ static void v9fs_write(void *opaque)
     V9fsState *s = pdu->s;
 
     pdu_unmarshal(pdu, offset, "dqdv", &fid, &off, &count, sg, &cnt);
+    trace_v9fs_write(pdu->tag, pdu->id, fid, off, count, cnt);
 
     fidp = get_fid(pdu, fid);
     if (fidp == NULL) {
@@ -2178,6 +2210,7 @@ static void v9fs_write(void *opaque)
 out:
     put_fid(pdu, fidp);
 out_nofid:
+    trace_v9fs_write_return(pdu->tag, pdu->id, total, err);
     complete_pdu(s, pdu, err);
 }
 
@@ -2202,6 +2235,8 @@ static void v9fs_create(void *opaque)
     pdu_unmarshal(pdu, offset, "dsdbs", &fid, &name,
                   &perm, &mode, &extension);
 
+    trace_v9fs_create(pdu->tag, pdu->id, fid, name.data, perm, mode);
+
     fidp = get_fid(pdu, fid);
     if (fidp == NULL) {
         err = -EINVAL;
@@ -2335,6 +2370,7 @@ static void v9fs_create(void *opaque)
 out:
     put_fid(pdu, fidp);
 out_nofid:
+   trace_v9fs_create_return(pdu->tag, pdu->id, qid.type, qid.version, qid.path, iounit);
    complete_pdu(pdu->s, pdu, err);
    v9fs_string_free(&name);
    v9fs_string_free(&extension);
@@ -2355,6 +2391,7 @@ static void v9fs_symlink(void *opaque)
     size_t offset = 7;
 
     pdu_unmarshal(pdu, offset, "dssd", &dfid, &name, &symname, &gid);
+    trace_v9fs_symlink(pdu->tag, pdu->id, dfid, name.data, symname.data, gid);
 
     dfidp = get_fid(pdu, dfid);
     if (dfidp == NULL) {
@@ -2371,6 +2408,7 @@ static void v9fs_symlink(void *opaque)
 out:
     put_fid(pdu, dfidp);
 out_nofid:
+    trace_v9fs_symlink_return(pdu->tag, pdu->id, qid.type, qid.version, qid.path);
     complete_pdu(pdu->s, pdu, err);
     v9fs_string_free(&name);
     v9fs_string_free(&symname);
@@ -2385,6 +2423,7 @@ static void v9fs_flush(void *opaque)
     V9fsState *s = pdu->s;
 
     pdu_unmarshal(pdu, offset, "w", &tag);
+    trace_v9fs_flush(pdu->tag, pdu->id, tag);
 
     QLIST_FOREACH(cancel_pdu, &s->active_list, next) {
         if (cancel_pdu->tag == tag) {
@@ -2415,6 +2454,7 @@ static void v9fs_link(void *opaque)
     int err = 0;
 
     pdu_unmarshal(pdu, offset, "dds", &dfid, &oldfid, &name);
+    trace_v9fs_link(pdu->tag, pdu->id, dfid, oldfid, name.data);
 
     dfidp = get_fid(pdu, dfid);
     if (dfidp == NULL) {
@@ -2448,6 +2488,7 @@ static void v9fs_remove(void *opaque)
     V9fsPDU *pdu = opaque;
 
     pdu_unmarshal(pdu, offset, "d", &fid);
+    trace_v9fs_remove(pdu->tag, pdu->id, fid);
 
     fidp = get_fid(pdu, fid);
     if (fidp == NULL) {
@@ -2727,6 +2768,7 @@ static void v9fs_wstat(void *opaque)
     V9fsState *s = pdu->s;
 
     pdu_unmarshal(pdu, offset, "dwS", &fid, &unused, &v9stat);
+    trace_v9fs_wstat(pdu->tag, pdu->id, fid, v9stat.mode, v9stat.atime, v9stat.mtime);
 
     fidp = get_fid(pdu, fid);
     if (fidp == NULL) {
@@ -2895,6 +2937,7 @@ static void v9fs_mknod(void *opaque)
 
     pdu_unmarshal(pdu, offset, "dsdddd", &fid, &name, &mode,
                   &major, &minor, &gid);
+    trace_v9fs_mknod(pdu->tag, pdu->id, fid, mode, major, minor);
 
     fidp = get_fid(pdu, fid);
     if (fidp == NULL) {
@@ -2912,6 +2955,7 @@ static void v9fs_mknod(void *opaque)
 out:
     put_fid(pdu, fidp);
 out_nofid:
+    trace_v9fs_mknod_return(pdu->tag, pdu->id, qid.type, qid.version, qid.path);
     complete_pdu(s, pdu, err);
     v9fs_string_free(&name);
 }
@@ -2939,6 +2983,9 @@ static void v9fs_lock(void *opaque)
     pdu_unmarshal(pdu, offset, "dbdqqds", &fid, &flock->type,
                   &flock->flags, &flock->start, &flock->length,
                   &flock->proc_id, &flock->client_id);
+
+    trace_v9fs_lock(pdu->tag, pdu->id, fid, flock->type, flock->start, flock->length);
+
     status = P9_LOCK_ERROR;
 
     /* We support only block flag now (that too ignored currently) */
@@ -2961,6 +3008,7 @@ out:
 out_nofid:
     err = offset;
     err += pdu_marshal(pdu, offset, "b", status);
+    trace_v9fs_lock_return(pdu->tag, pdu->id, status);
     complete_pdu(s, pdu, err);
     v9fs_string_free(&flock->client_id);
     g_free(flock);
@@ -2985,6 +3033,8 @@ static void v9fs_getlock(void *opaque)
                   &glock->start, &glock->length, &glock->proc_id,
                   &glock->client_id);
 
+    trace_v9fs_getlock(pdu->tag, pdu->id, fid, glock->type, glock->start, glock->length);
+
     fidp = get_fid(pdu, fid);
     if (fidp == NULL) {
         err = -ENOENT;
@@ -3002,6 +3052,9 @@ static void v9fs_getlock(void *opaque)
 out:
     put_fid(pdu, fidp);
 out_nofid:
+    trace_v9fs_getlock_return(pdu->tag, pdu->id, glock->type, glock->start,
+                        glock->length, glock->proc_id);
+
     complete_pdu(s, pdu, err);
     v9fs_string_free(&glock->client_id);
     g_free(glock);
@@ -3022,6 +3075,8 @@ static void v9fs_mkdir(void *opaque)
 
     pdu_unmarshal(pdu, offset, "dsdd", &fid, &name, &mode, &gid);
 
+    trace_v9fs_mkdir(pdu->tag, pdu->id, fid, name.data, mode, gid);
+
     fidp = get_fid(pdu, fid);
     if (fidp == NULL) {
         err = -ENOENT;
@@ -3037,6 +3092,7 @@ static void v9fs_mkdir(void *opaque)
 out:
     put_fid(pdu, fidp);
 out_nofid:
+    trace_v9fs_mkdir_return(pdu->tag, pdu->id, qid.type, qid.version, qid.path, err);
     complete_pdu(pdu->s, pdu, err);
     v9fs_string_free(&name);
 }
@@ -3054,6 +3110,8 @@ static void v9fs_xattrwalk(void *opaque)
     V9fsState *s = pdu->s;
 
     pdu_unmarshal(pdu, offset, "dds", &fid, &newfid, &name);
+    trace_v9fs_xattrwalk(pdu->tag, pdu->id, fid, newfid, name.data);
+
     file_fidp = get_fid(pdu, fid);
     if (file_fidp == NULL) {
         err = -ENOENT;
@@ -3130,6 +3188,7 @@ out:
         put_fid(pdu, xattr_fidp);
     }
 out_nofid:
+    trace_v9fs_xattrwalk_return(pdu->tag, pdu->id, size);
     complete_pdu(s, pdu, err);
     v9fs_string_free(&name);
 }
@@ -3149,6 +3208,7 @@ static void v9fs_xattrcreate(void *opaque)
 
     pdu_unmarshal(pdu, offset, "dsqd",
                   &fid, &name, &size, &flags);
+    trace_v9fs_xattrcreate(pdu->tag, pdu->id, fid, name.data, size, flags);
 
     file_fidp = get_fid(pdu, fid);
     if (file_fidp == NULL) {
@@ -3185,6 +3245,7 @@ static void v9fs_readlink(void *opaque)
     V9fsFidState *fidp;
 
     pdu_unmarshal(pdu, offset, "d", &fid);
+    trace_v9fs_readlink(pdu->tag, pdu->id, fid);
     fidp = get_fid(pdu, fid);
     if (fidp == NULL) {
         err = -ENOENT;
@@ -3202,6 +3263,7 @@ static void v9fs_readlink(void *opaque)
 out:
     put_fid(pdu, fidp);
 out_nofid:
+    trace_v9fs_readlink_return(pdu->tag, pdu->id, target.data);
     complete_pdu(pdu->s, pdu, err);
 }
 
diff --git a/trace-events b/trace-events
index a31d9aa..889e911 100644
--- a/trace-events
+++ b/trace-events
@@ -502,3 +502,50 @@ escc_sunkbd_event_in(int ch) "Untranslated keycode %2.2x"
 escc_sunkbd_event_out(int ch) "Translated keycode %2.2x"
 escc_kbd_command(int val) "Command %d"
 escc_sunmouse_event(int dx, int dy, int buttons_state) "dx=%d dy=%d buttons=%01x"
+
+
+# hw/9pfs/virtio-9p.c
+complete_pdu(uint16_t tag, uint8_t id, int err) "tag %d id %d err %d"
+v9fs_version(uint16_t tag, uint8_t id, int32_t msize, char* version) "tag %d id %d msize %d version %s"
+v9fs_version_return(uint16_t tag, uint8_t id, int32_t msize, char* version) "tag %d id %d msize %d version %s"
+v9fs_attach(uint16_t tag, uint8_t id, int32_t fid, int32_t afid, char* uname, char* aname) "tag %d id %d fid %d afid %d aname %s"
+v9fs_attach_return(uint16_t tag, uint8_t id, int8_t type, int32_t version, int64_t path) "tag %d id %d type %d version %d path %"PRId64""
+v9fs_stat(uint16_t tag, uint8_t id, int32_t fid) "tag %d id %d fid %d"
+v9fs_stat_return(uint16_t tag, uint8_t id, int32_t mode, int32_t atime, int32_t mtime, int64_t length) "tag %d id %d stat={mode %d atime %d mtime %d length %"PRId64"}"
+v9fs_getattr(uint16_t tag, uint8_t id, int32_t fid, uint64_t request_mask) "tag %d id %d fid %d request_mask %"PRIu64""
+v9fs_getattr_return(uint16_t tag, uint8_t id, uint64_t result_mask, uint32_t mode, uint32_t uid, uint32_t gid) "tag %d id %d getattr={result_mask %"PRId64" mode %u uid %u gid %u}"
+v9fs_walk(uint16_t tag, uint8_t id, int32_t fid, int32_t newfid, uint16_t nwnames) "tag %d id %d fid %d newfid %d nwnames %d"
+v9fs_walk_return(uint16_t tag, uint8_t id, uint16_t nwnames, void* qids) "tag %d id %d nwnames %d qids %p"
+v9fs_open(uint16_t tag, uint8_t id, int32_t fid, int32_t mode) "tag %d id %d fid %d mode %d"
+v9fs_open_return(uint16_t tag, uint8_t id, int8_t type, int32_t version, int64_t path, int iounit) "tag %d id %d qid={type %d version %d path %"PRId64"} iounit %d"
+v9fs_lcreate(uint16_t tag, uint8_t id, int32_t dfid, int32_t flags, int32_t mode, uint32_t gid) "tag %d id %d dfid %d flags %d mode %d gid %u"
+v9fs_lcreate_return(uint16_t tag, uint8_t id, int8_t type, int32_t version, int64_t path, int32_t iounit) "tag %d id %d qid={type %d version %d path %"PRId64"} iounit %d"
+v9fs_fsync(uint16_t tag, uint8_t id, int32_t fid, int datasync) "tag %d id %d fid %d datasync %d"
+v9fs_clunk(uint16_t tag, uint8_t id, int32_t fid) "tag %d id %d fid %d"
+v9fs_read(uint16_t tag, uint8_t id, int32_t fid, int64_t off, int32_t max_count) "tag %d id %d fid %d off %"PRId64" max_count %d"
+v9fs_read_return(uint16_t tag, uint8_t id, int32_t count, ssize_t err) "tag %d id %d count %d err %zd"
+v9fs_readdir(uint16_t tag, uint8_t id, int32_t fid, int64_t offset, int32_t max_count) "tag %d id %d fid %d offset %"PRId64" max_count %d"
+v9fs_readdir_return(uint16_t tag, uint8_t id, int32_t count, ssize_t retval) "tag %d id %d count %d retval %zd"
+v9fs_write(uint16_t tag, uint8_t id, int32_t fid, int64_t off, int32_t count, int cnt) "tag %d id %d fid %d off %"PRId64" count %d cnt %d"
+v9fs_write_return(uint16_t tag, uint8_t id, int32_t total, ssize_t err) "tag %d id %d total %d err %zd"
+v9fs_create(uint16_t tag, uint8_t id, int32_t fid, char* name, int32_t perm, int8_t mode) "tag %d id %d fid %d name %s perm %d mode %d"
+v9fs_create_return(uint16_t tag, uint8_t id, int8_t type, int32_t version, int64_t path, int iounit) "tag %d id %d qid={type %d version %d path %"PRId64"} iounit %d"
+v9fs_symlink(uint16_t tag, uint8_t id, int32_t fid,  char* name, char* symname, uint32_t gid) "tag %d id %d fid %d name %s symname %s gid %u"
+v9fs_symlink_return(uint16_t tag, uint8_t id, int8_t type, int32_t version, int64_t path) "tag %d id %d qid={type %d version %d path %"PRId64"}"
+v9fs_flush(uint16_t tag, uint8_t id, int16_t flush_tag) "tag %d id %d flush_tag %d"
+v9fs_link(uint16_t tag, uint8_t id, int32_t dfid, int32_t oldfid, char* name) "tag %d id %d dfid %d oldfid %d name %s"
+v9fs_remove(uint16_t tag, uint8_t id, int32_t fid) "tag %d id %d fid %d"
+v9fs_wstat(uint16_t tag, uint8_t id, int32_t fid, int32_t mode, int32_t atime, int32_t mtime) "tag %d id %d fid %d stat={mode %d atime %d mtime}"
+v9fs_mknod(uint16_t tag, uint8_t id, int32_t fid, int mode, int major, int minor) "tag %d id %d fid %d mode %d major %d minor %d"
+v9fs_mknod_return(uint16_t tag, uint8_t id, int8_t type, int32_t version, int64_t path) "tag %d id %d qid={type %d version %d path %"PRId64"}"
+v9fs_lock(uint16_t tag, uint8_t id, int32_t fid, uint8_t type, uint64_t start, uint64_t length) "tag %d id %d fid %d type %d start %"PRIu64" length %"PRIu64""
+v9fs_lock_return(uint16_t tag, uint8_t id, int8_t status) "tag %d id %d status %d"
+v9fs_getlock(uint16_t tag, uint8_t id, int32_t fid, uint8_t type, uint64_t start, uint64_t length)"tag %d id %d fid %d type %d start %"PRIu64" length %"PRIu64""
+v9fs_getlock_return(uint16_t tag, uint8_t id, uint8_t type, uint64_t start, uint64_t length, uint32_t proc_id) "tag %d id %d type %d start %"PRIu64" length %"PRIu64" proc_id %u"
+v9fs_mkdir(uint16_t tag, uint8_t id, int32_t fid, char* name, int mode, uint32_t gid) "tag %d id %d fid %d name %s mode %d"
+v9fs_mkdir_return(uint16_t tag, uint8_t id, int8_t type, int32_t version, int64_t path, int err) "tag %d id %d qid={type %d version %d path %"PRId64"}"
+v9fs_xattrwalk(uint16_t tag, uint8_t id, int32_t fid, int32_t newfid, char* name) "tag %d id %d fid %d newfid %d name %s"
+v9fs_xattrwalk_return(uint16_t tag, uint8_t id, int64_t size) "tag %d id %d size %"PRId64""
+v9fs_xattrcreate(uint16_t tag, uint8_t id, int32_t fid, char* name, int64_t size, int flags) "tag %d id %d fid %d name %s size %"PRId64" flags %d"
+v9fs_readlink(uint16_t tag, uint8_t id, int32_t fid) "tag %d id %d fid %d"
+v9fs_readlink_return(uint16_t tag, uint8_t id, char* target) "tag %d id %d name %s"
-- 
1.7.1.1

[Qemu-devel] [PATCH v2 2/3] hw/9pfs: Remove virtio-9p-debug.* infra to be replaced by Qemu Tracing.

[Harsh Prateek Bora]

Removing the existing debug infrastrucure as proposed to be replaced by
Qemu Tracing infrastructure.

Signed-off-by: Harsh Prateek Bora <harsh@linux.vnet.ibm.com>
---
 Makefile.objs             |    2 +-
 hw/9pfs/virtio-9p-debug.c |  646 ---------------------------------------------
 hw/9pfs/virtio-9p-debug.h |    6 -
 hw/9pfs/virtio-9p.c       |    8 -
 4 files changed, 1 insertions(+), 661 deletions(-)
 delete mode 100644 hw/9pfs/virtio-9p-debug.c
 delete mode 100644 hw/9pfs/virtio-9p-debug.h

diff --git a/Makefile.objs b/Makefile.objs
index 4a76acc..b14a417 100644
--- a/Makefile.objs
+++ b/Makefile.objs
@@ -304,7 +304,7 @@ sound-obj-$(CONFIG_HDA) += intel-hda.o hda-audio.o
 adlib.o fmopl.o: QEMU_CFLAGS += -DBUILD_Y8950=0
 hw-obj-$(CONFIG_SOUND) += $(sound-obj-y)
 
-9pfs-nested-$(CONFIG_VIRTFS)  = virtio-9p.o virtio-9p-debug.o
+9pfs-nested-$(CONFIG_VIRTFS)  = virtio-9p.o
 9pfs-nested-$(CONFIG_VIRTFS) += virtio-9p-local.o virtio-9p-xattr.o
 9pfs-nested-$(CONFIG_VIRTFS) += virtio-9p-xattr-user.o virtio-9p-posix-acl.o
 9pfs-nested-$(CONFIG_VIRTFS) += virtio-9p-coth.o cofs.o codir.o cofile.o
diff --git a/hw/9pfs/virtio-9p-debug.c b/hw/9pfs/virtio-9p-debug.c
deleted file mode 100644
index 96925f0..0000000
--- a/hw/9pfs/virtio-9p-debug.c
+++ /dev/null
@@ -1,646 +0,0 @@
-/*
- * Virtio 9p PDU debug
- *
- * Copyright IBM, Corp. 2010
- *
- * Authors:
- *  Anthony Liguori   <aliguori@us.ibm.com>
- *
- * This work is licensed under the terms of the GNU GPL, version 2.  See
- * the COPYING file in the top-level directory.
- *
- */
-
-#include "hw/virtio.h"
-#include "hw/pc.h"
-#include "virtio-9p.h"
-#include "virtio-9p-debug.h"
-
-#define BUG_ON(cond) assert(!(cond))
-
-static FILE *llogfile;
-
-static struct iovec *get_sg(V9fsPDU *pdu, int rx)
-{
-    if (rx) {
-        return pdu->elem.in_sg;
-    }
-    return pdu->elem.out_sg;
-}
-
-static int get_sg_count(V9fsPDU *pdu, int rx)
-{
-    if (rx) {
-        return pdu->elem.in_num;
-    }
-    return pdu->elem.out_num;
-
-}
-
-static void pprint_int8(V9fsPDU *pdu, int rx, size_t *offsetp,
-                        const char *name)
-{
-    size_t copied;
-    int count = get_sg_count(pdu, rx);
-    size_t offset = *offsetp;
-    struct iovec *sg = get_sg(pdu, rx);
-    int8_t value;
-
-    copied = do_pdu_unpack(&value, sg, count, offset, sizeof(value));
-
-    BUG_ON(copied != sizeof(value));
-    offset += sizeof(value);
-    fprintf(llogfile, "%s=0x%x", name, value);
-    *offsetp = offset;
-}
-
-static void pprint_int16(V9fsPDU *pdu, int rx, size_t *offsetp,
-                        const char *name)
-{
-    size_t copied;
-    int count = get_sg_count(pdu, rx);
-    struct iovec *sg = get_sg(pdu, rx);
-    size_t offset = *offsetp;
-    int16_t value;
-
-
-    copied = do_pdu_unpack(&value, sg, count, offset, sizeof(value));
-
-    BUG_ON(copied != sizeof(value));
-    offset += sizeof(value);
-    fprintf(llogfile, "%s=0x%x", name, value);
-    *offsetp = offset;
-}
-
-static void pprint_int32(V9fsPDU *pdu, int rx, size_t *offsetp,
-                        const char *name)
-{
-    size_t copied;
-    int count = get_sg_count(pdu, rx);
-    struct iovec *sg = get_sg(pdu, rx);
-    size_t offset = *offsetp;
-    int32_t value;
-
-
-    copied = do_pdu_unpack(&value, sg, count, offset, sizeof(value));
-
-    BUG_ON(copied != sizeof(value));
-    offset += sizeof(value);
-    fprintf(llogfile, "%s=0x%x", name, value);
-    *offsetp = offset;
-}
-
-static void pprint_int64(V9fsPDU *pdu, int rx, size_t *offsetp,
-                        const char *name)
-{
-    size_t copied;
-    int count = get_sg_count(pdu, rx);
-    struct iovec *sg = get_sg(pdu, rx);
-    size_t offset = *offsetp;
-    int64_t value;
-
-
-    copied = do_pdu_unpack(&value, sg, count, offset, sizeof(value));
-
-    BUG_ON(copied != sizeof(value));
-    offset += sizeof(value);
-    fprintf(llogfile, "%s=0x%" PRIx64, name, value);
-    *offsetp = offset;
-}
-
-static void pprint_str(V9fsPDU *pdu, int rx, size_t *offsetp, const char *name)
-{
-    int sg_count = get_sg_count(pdu, rx);
-    struct iovec *sg = get_sg(pdu, rx);
-    size_t offset = *offsetp;
-    uint16_t tmp_size, size;
-    size_t result;
-    size_t copied = 0;
-    int i = 0;
-
-    /* get the size */
-    copied = do_pdu_unpack(&tmp_size, sg, sg_count, offset, sizeof(tmp_size));
-    BUG_ON(copied != sizeof(tmp_size));
-    size = le16_to_cpupu(&tmp_size);
-    offset += copied;
-
-    fprintf(llogfile, "%s=", name);
-    for (i = 0; size && i < sg_count; i++) {
-        size_t len;
-        if (offset >= sg[i].iov_len) {
-            /* skip this sg */
-            offset -= sg[i].iov_len;
-            continue;
-        } else {
-            len = MIN(sg[i].iov_len - offset, size);
-            result = fwrite(sg[i].iov_base + offset, 1, len, llogfile);
-            BUG_ON(result != len);
-            size -= len;
-            copied += len;
-            if (size) {
-                offset = 0;
-                continue;
-            }
-        }
-    }
-    *offsetp += copied;
-}
-
-static void pprint_qid(V9fsPDU *pdu, int rx, size_t *offsetp, const char *name)
-{
-    fprintf(llogfile, "%s={", name);
-    pprint_int8(pdu, rx, offsetp, "type");
-    pprint_int32(pdu, rx, offsetp, ", version");
-    pprint_int64(pdu, rx, offsetp, ", path");
-    fprintf(llogfile, "}");
-}
-
-static void pprint_stat(V9fsPDU *pdu, int rx, size_t *offsetp, const char *name)
-{
-    fprintf(llogfile, "%s={", name);
-    pprint_int16(pdu, rx, offsetp, "size");
-    pprint_int16(pdu, rx, offsetp, ", type");
-    pprint_int32(pdu, rx, offsetp, ", dev");
-    pprint_qid(pdu, rx, offsetp, ", qid");
-    pprint_int32(pdu, rx, offsetp, ", mode");
-    pprint_int32(pdu, rx, offsetp, ", atime");
-    pprint_int32(pdu, rx, offsetp, ", mtime");
-    pprint_int64(pdu, rx, offsetp, ", length");
-    pprint_str(pdu, rx, offsetp, ", name");
-    pprint_str(pdu, rx, offsetp, ", uid");
-    pprint_str(pdu, rx, offsetp, ", gid");
-    pprint_str(pdu, rx, offsetp, ", muid");
-    pprint_str(pdu, rx, offsetp, ", extension");
-    pprint_int32(pdu, rx, offsetp, ", uid");
-    pprint_int32(pdu, rx, offsetp, ", gid");
-    pprint_int32(pdu, rx, offsetp, ", muid");
-    fprintf(llogfile, "}");
-}
-
-static void pprint_stat_dotl(V9fsPDU *pdu, int rx, size_t *offsetp,
-                                                  const char *name)
-{
-    fprintf(llogfile, "%s={", name);
-    pprint_qid(pdu, rx, offsetp, "qid");
-    pprint_int32(pdu, rx, offsetp, ", st_mode");
-    pprint_int64(pdu, rx, offsetp, ", st_nlink");
-    pprint_int32(pdu, rx, offsetp, ", st_uid");
-    pprint_int32(pdu, rx, offsetp, ", st_gid");
-    pprint_int64(pdu, rx, offsetp, ", st_rdev");
-    pprint_int64(pdu, rx, offsetp, ", st_size");
-    pprint_int64(pdu, rx, offsetp, ", st_blksize");
-    pprint_int64(pdu, rx, offsetp, ", st_blocks");
-    pprint_int64(pdu, rx, offsetp, ", atime");
-    pprint_int64(pdu, rx, offsetp, ", atime_nsec");
-    pprint_int64(pdu, rx, offsetp, ", mtime");
-    pprint_int64(pdu, rx, offsetp, ", mtime_nsec");
-    pprint_int64(pdu, rx, offsetp, ", ctime");
-    pprint_int64(pdu, rx, offsetp, ", ctime_nsec");
-    fprintf(llogfile, "}");
-}
-
-
-
-static void pprint_strs(V9fsPDU *pdu, int rx, size_t *offsetp, const char *name)
-{
-    int sg_count = get_sg_count(pdu, rx);
-    struct iovec *sg = get_sg(pdu, rx);
-    size_t offset = *offsetp;
-    uint16_t tmp_count, count, i;
-    size_t copied = 0;
-
-    fprintf(llogfile, "%s={", name);
-
-    /* Get the count */
-    copied = do_pdu_unpack(&tmp_count, sg, sg_count, offset, sizeof(tmp_count));
-    BUG_ON(copied != sizeof(tmp_count));
-    count = le16_to_cpupu(&tmp_count);
-    offset += copied;
-
-    for (i = 0; i < count; i++) {
-        char str[512];
-        if (i) {
-            fprintf(llogfile, ", ");
-        }
-        snprintf(str, sizeof(str), "[%d]", i);
-        pprint_str(pdu, rx, &offset, str);
-    }
-
-    fprintf(llogfile, "}");
-
-    *offsetp = offset;
-}
-
-static void pprint_qids(V9fsPDU *pdu, int rx, size_t *offsetp, const char *name)
-{
-    int sg_count = get_sg_count(pdu, rx);
-    struct iovec *sg = get_sg(pdu, rx);
-    size_t offset = *offsetp;
-    uint16_t tmp_count, count, i;
-    size_t copied = 0;
-
-    fprintf(llogfile, "%s={", name);
-
-    copied = do_pdu_unpack(&tmp_count, sg, sg_count, offset, sizeof(tmp_count));
-    BUG_ON(copied != sizeof(tmp_count));
-    count = le16_to_cpupu(&tmp_count);
-    offset += copied;
-
-    for (i = 0; i < count; i++) {
-        char str[512];
-        if (i) {
-            fprintf(llogfile, ", ");
-        }
-        snprintf(str, sizeof(str), "[%d]", i);
-        pprint_qid(pdu, rx, &offset, str);
-    }
-
-    fprintf(llogfile, "}");
-
-    *offsetp = offset;
-}
-
-static void pprint_sg(V9fsPDU *pdu, int rx, size_t *offsetp, const char *name)
-{
-    struct iovec *sg = get_sg(pdu, rx);
-    unsigned int count;
-    int i;
-
-    if (rx) {
-        count = pdu->elem.in_num;
-    } else {
-        count = pdu->elem.out_num;
-    }
-
-    fprintf(llogfile, "%s={", name);
-    for (i = 0; i < count; i++) {
-        if (i) {
-            fprintf(llogfile, ", ");
-        }
-        fprintf(llogfile, "(%p, 0x%zx)", sg[i].iov_base, sg[i].iov_len);
-    }
-    fprintf(llogfile, "}");
-}
-
-/* FIXME: read from a directory fid returns serialized stat_t's */
-#ifdef DEBUG_DATA
-static void pprint_data(V9fsPDU *pdu, int rx, size_t *offsetp, const char *name)
-{
-    struct iovec *sg = get_sg(pdu, rx);
-    size_t offset = *offsetp;
-    unsigned int count;
-    int32_t size;
-    int total, i, j;
-    ssize_t len;
-
-    if (rx) {
-        count = pdu->elem.in_num;
-    } else {
-        count = pdu->elem.out_num;
-    }
-
-    BUG_ON((offset + sizeof(size)) > sg[0].iov_len);
-
-    memcpy(&size, sg[0].iov_base + offset, sizeof(size));
-    offset += sizeof(size);
-
-    fprintf(llogfile, "size: %x\n", size);
-
-    sg[0].iov_base += 11; /* skip header */
-    sg[0].iov_len -= 11;
-
-    total = 0;
-    for (i = 0; i < count; i++) {
-        total += sg[i].iov_len;
-        if (total >= size) {
-            /* trim sg list so writev does the right thing */
-            sg[i].iov_len -= (total - size);
-            i++;
-            break;
-        }
-    }
-
-    fprintf(llogfile, "%s={\"", name);
-    fflush(llogfile);
-    for (j = 0; j < i; j++) {
-        if (j) {
-            fprintf(llogfile, "\", \"");
-            fflush(llogfile);
-        }
-
-        do {
-            len = writev(fileno(llogfile), &sg[j], 1);
-        } while (len == -1 && errno == EINTR);
-        fprintf(llogfile, "len == %ld: %m\n", len);
-        BUG_ON(len != sg[j].iov_len);
-    }
-    fprintf(llogfile, "\"}");
-
-    sg[0].iov_base -= 11;
-    sg[0].iov_len += 11;
-
-}
-#endif
-
-void pprint_pdu(V9fsPDU *pdu)
-{
-    size_t offset = 7;
-
-    if (llogfile == NULL) {
-        llogfile = fopen("/tmp/pdu.log", "w");
-    }
-
-    BUG_ON(!llogfile);
-
-    switch (pdu->id) {
-    case P9_TREADDIR:
-        fprintf(llogfile, "TREADDIR: (");
-        pprint_int32(pdu, 0, &offset, "fid");
-        pprint_int64(pdu, 0, &offset, ", initial offset");
-        pprint_int32(pdu, 0, &offset, ", max count");
-        break;
-    case P9_RREADDIR:
-        fprintf(llogfile, "RREADDIR: (");
-        pprint_int32(pdu, 1, &offset, "count");
-#ifdef DEBUG_DATA
-        pprint_data(pdu, 1, &offset, ", data");
-#endif
-        break;
-    case P9_TMKDIR:
-        fprintf(llogfile, "TMKDIR: (");
-        pprint_int32(pdu, 0, &offset, "fid");
-        pprint_str(pdu, 0, &offset, "name");
-        pprint_int32(pdu, 0, &offset, "mode");
-        pprint_int32(pdu, 0, &offset, "gid");
-        break;
-    case P9_RMKDIR:
-        fprintf(llogfile, "RMKDIR: (");
-        pprint_qid(pdu, 0, &offset, "qid");
-        break;
-    case P9_TVERSION:
-        fprintf(llogfile, "TVERSION: (");
-        pprint_int32(pdu, 0, &offset, "msize");
-        pprint_str(pdu, 0, &offset, ", version");
-        break;
-    case P9_RVERSION:
-        fprintf(llogfile, "RVERSION: (");
-        pprint_int32(pdu, 1, &offset, "msize");
-        pprint_str(pdu, 1, &offset, ", version");
-        break;
-    case P9_TGETATTR:
-        fprintf(llogfile, "TGETATTR: (");
-        pprint_int32(pdu, 0, &offset, "fid");
-        break;
-    case P9_RGETATTR:
-        fprintf(llogfile, "RGETATTR: (");
-        pprint_stat_dotl(pdu, 1, &offset, "getattr");
-        break;
-    case P9_TAUTH:
-        fprintf(llogfile, "TAUTH: (");
-        pprint_int32(pdu, 0, &offset, "afid");
-        pprint_str(pdu, 0, &offset, ", uname");
-        pprint_str(pdu, 0, &offset, ", aname");
-        pprint_int32(pdu, 0, &offset, ", n_uname");
-        break;
-    case P9_RAUTH:
-        fprintf(llogfile, "RAUTH: (");
-        pprint_qid(pdu, 1, &offset, "qid");
-        break;
-    case P9_TATTACH:
-        fprintf(llogfile, "TATTACH: (");
-        pprint_int32(pdu, 0, &offset, "fid");
-        pprint_int32(pdu, 0, &offset, ", afid");
-        pprint_str(pdu, 0, &offset, ", uname");
-        pprint_str(pdu, 0, &offset, ", aname");
-        pprint_int32(pdu, 0, &offset, ", n_uname");
-        break;
-    case P9_RATTACH:
-        fprintf(llogfile, "RATTACH: (");
-        pprint_qid(pdu, 1, &offset, "qid");
-        break;
-    case P9_TERROR:
-        fprintf(llogfile, "TERROR: (");
-        break;
-    case P9_RERROR:
-        fprintf(llogfile, "RERROR: (");
-        pprint_str(pdu, 1, &offset, "ename");
-        pprint_int32(pdu, 1, &offset, ", ecode");
-        break;
-    case P9_TFLUSH:
-        fprintf(llogfile, "TFLUSH: (");
-        pprint_int16(pdu, 0, &offset, "oldtag");
-        break;
-    case P9_RFLUSH:
-        fprintf(llogfile, "RFLUSH: (");
-        break;
-    case P9_TWALK:
-        fprintf(llogfile, "TWALK: (");
-        pprint_int32(pdu, 0, &offset, "fid");
-        pprint_int32(pdu, 0, &offset, ", newfid");
-        pprint_strs(pdu, 0, &offset, ", wnames");
-        break;
-    case P9_RWALK:
-        fprintf(llogfile, "RWALK: (");
-        pprint_qids(pdu, 1, &offset, "wqids");
-        break;
-    case P9_TOPEN:
-        fprintf(llogfile, "TOPEN: (");
-        pprint_int32(pdu, 0, &offset, "fid");
-        pprint_int8(pdu, 0, &offset, ", mode");
-        break;
-    case P9_ROPEN:
-        fprintf(llogfile, "ROPEN: (");
-        pprint_qid(pdu, 1, &offset, "qid");
-        pprint_int32(pdu, 1, &offset, ", iounit");
-        break;
-    case P9_TCREATE:
-        fprintf(llogfile, "TCREATE: (");
-        pprint_int32(pdu, 0, &offset, "fid");
-        pprint_str(pdu, 0, &offset, ", name");
-        pprint_int32(pdu, 0, &offset, ", perm");
-        pprint_int8(pdu, 0, &offset, ", mode");
-        pprint_str(pdu, 0, &offset, ", extension");
-        break;
-    case P9_RCREATE:
-        fprintf(llogfile, "RCREATE: (");
-        pprint_qid(pdu, 1, &offset, "qid");
-        pprint_int32(pdu, 1, &offset, ", iounit");
-        break;
-    case P9_TSYMLINK:
-        fprintf(llogfile, "TSYMLINK: (");
-        pprint_int32(pdu, 0, &offset, "fid");
-        pprint_str(pdu, 0, &offset, ", name");
-        pprint_str(pdu, 0, &offset, ", symname");
-        pprint_int32(pdu, 0, &offset, ", gid");
-        break;
-    case P9_RSYMLINK:
-        fprintf(llogfile, "RSYMLINK: (");
-        pprint_qid(pdu, 1, &offset, "qid");
-        break;
-    case P9_TLCREATE:
-        fprintf(llogfile, "TLCREATE: (");
-        pprint_int32(pdu, 0, &offset, "dfid");
-        pprint_str(pdu, 0, &offset, ", name");
-        pprint_int32(pdu, 0, &offset, ", flags");
-        pprint_int32(pdu, 0, &offset, ", mode");
-        pprint_int32(pdu, 0, &offset, ", gid");
-        break;
-    case P9_RLCREATE:
-        fprintf(llogfile, "RLCREATE: (");
-        pprint_qid(pdu, 1, &offset, "qid");
-        pprint_int32(pdu, 1, &offset, ", iounit");
-        break;
-    case P9_TMKNOD:
-	fprintf(llogfile, "TMKNOD: (");
-        pprint_int32(pdu, 0, &offset, "fid");
-        pprint_str(pdu, 0, &offset, "name");
-        pprint_int32(pdu, 0, &offset, "mode");
-        pprint_int32(pdu, 0, &offset, "major");
-        pprint_int32(pdu, 0, &offset, "minor");
-        pprint_int32(pdu, 0, &offset, "gid");
-        break;
-    case P9_RMKNOD:
-        fprintf(llogfile, "RMKNOD: )");
-        pprint_qid(pdu, 0, &offset, "qid");
-        break;
-    case P9_TREADLINK:
-	fprintf(llogfile, "TREADLINK: (");
-        pprint_int32(pdu, 0, &offset, "fid");
-        break;
-    case P9_RREADLINK:
-	fprintf(llogfile, "RREADLINK: (");
-        pprint_str(pdu, 0, &offset, "target");
-        break;
-    case P9_TREAD:
-        fprintf(llogfile, "TREAD: (");
-        pprint_int32(pdu, 0, &offset, "fid");
-        pprint_int64(pdu, 0, &offset, ", offset");
-        pprint_int32(pdu, 0, &offset, ", count");
-        pprint_sg(pdu, 0, &offset, ", sg");
-        break;
-    case P9_RREAD:
-        fprintf(llogfile, "RREAD: (");
-        pprint_int32(pdu, 1, &offset, "count");
-        pprint_sg(pdu, 1, &offset, ", sg");
-        offset = 7;
-#ifdef DEBUG_DATA
-        pprint_data(pdu, 1, &offset, ", data");
-#endif
-        break;
-    case P9_TWRITE:
-        fprintf(llogfile, "TWRITE: (");
-        pprint_int32(pdu, 0, &offset, "fid");
-        pprint_int64(pdu, 0, &offset, ", offset");
-        pprint_int32(pdu, 0, &offset, ", count");
-        break;
-    case P9_RWRITE:
-        fprintf(llogfile, "RWRITE: (");
-        pprint_int32(pdu, 1, &offset, "count");
-        break;
-    case P9_TCLUNK:
-        fprintf(llogfile, "TCLUNK: (");
-        pprint_int32(pdu, 0, &offset, "fid");
-        break;
-    case P9_RCLUNK:
-        fprintf(llogfile, "RCLUNK: (");
-        break;
-    case P9_TFSYNC:
-        fprintf(llogfile, "TFSYNC: (");
-        pprint_int32(pdu, 0, &offset, "fid");
-        break;
-    case P9_RFSYNC:
-        fprintf(llogfile, "RFSYNC: (");
-        break;
-    case P9_TLINK:
-        fprintf(llogfile, "TLINK: (");
-        pprint_int32(pdu, 0, &offset, "dfid");
-        pprint_int32(pdu, 0, &offset, ", fid");
-        pprint_str(pdu, 0, &offset, ", newpath");
-        break;
-    case P9_RLINK:
-        fprintf(llogfile, "RLINK: (");
-        break;
-    case P9_TREMOVE:
-        fprintf(llogfile, "TREMOVE: (");
-        pprint_int32(pdu, 0, &offset, "fid");
-        break;
-    case P9_RREMOVE:
-        fprintf(llogfile, "RREMOVE: (");
-        break;
-    case P9_TSTAT:
-        fprintf(llogfile, "TSTAT: (");
-        pprint_int32(pdu, 0, &offset, "fid");
-        break;
-    case P9_RSTAT:
-        fprintf(llogfile, "RSTAT: (");
-        offset += 2; /* ignored */
-        pprint_stat(pdu, 1, &offset, "stat");
-        break;
-    case P9_TWSTAT:
-        fprintf(llogfile, "TWSTAT: (");
-        pprint_int32(pdu, 0, &offset, "fid");
-        offset += 2; /* ignored */
-        pprint_stat(pdu, 0, &offset, ", stat");
-        break;
-    case P9_RWSTAT:
-        fprintf(llogfile, "RWSTAT: (");
-        break;
-    case P9_TXATTRWALK:
-        fprintf(llogfile, "TXATTRWALK: (");
-        pprint_int32(pdu, 0, &offset, "fid");
-        pprint_int32(pdu, 0, &offset, ", newfid");
-        pprint_str(pdu, 0, &offset, ", xattr name");
-        break;
-    case P9_RXATTRWALK:
-        fprintf(llogfile, "RXATTRWALK: (");
-        pprint_int64(pdu, 1, &offset, "xattrsize");
-    case P9_TXATTRCREATE:
-        fprintf(llogfile, "TXATTRCREATE: (");
-        pprint_int32(pdu, 0, &offset, "fid");
-        pprint_str(pdu, 0, &offset, ", name");
-        pprint_int64(pdu, 0, &offset, ", xattrsize");
-        pprint_int32(pdu, 0, &offset, ", flags");
-        break;
-    case P9_RXATTRCREATE:
-        fprintf(llogfile, "RXATTRCREATE: (");
-        break;
-    case P9_TLOCK:
-        fprintf(llogfile, "TLOCK: (");
-        pprint_int32(pdu, 0, &offset, "fid");
-        pprint_int8(pdu, 0, &offset, ", type");
-        pprint_int32(pdu, 0, &offset, ", flags");
-        pprint_int64(pdu, 0, &offset, ", start");
-        pprint_int64(pdu, 0, &offset, ", length");
-        pprint_int32(pdu, 0, &offset, ", proc_id");
-        pprint_str(pdu, 0, &offset, ", client_id");
-        break;
-    case P9_RLOCK:
-        fprintf(llogfile, "RLOCK: (");
-        pprint_int8(pdu, 0, &offset, "status");
-        break;
-    case P9_TGETLOCK:
-        fprintf(llogfile, "TGETLOCK: (");
-        pprint_int32(pdu, 0, &offset, "fid");
-        pprint_int8(pdu, 0, &offset, ", type");
-        pprint_int64(pdu, 0, &offset, ", start");
-        pprint_int64(pdu, 0, &offset, ", length");
-        pprint_int32(pdu, 0, &offset, ", proc_id");
-        pprint_str(pdu, 0, &offset, ", client_id");
-        break;
-    case P9_RGETLOCK:
-        fprintf(llogfile, "RGETLOCK: (");
-        pprint_int8(pdu, 0, &offset, "type");
-        pprint_int64(pdu, 0, &offset, ", start");
-        pprint_int64(pdu, 0, &offset, ", length");
-        pprint_int32(pdu, 0, &offset, ", proc_id");
-        pprint_str(pdu, 0, &offset, ", client_id");
-        break;
-    default:
-        fprintf(llogfile, "unknown(%d): (", pdu->id);
-        break;
-    }
-
-    fprintf(llogfile, ")\n");
-    /* Flush the log message out */
-    fflush(llogfile);
-}
diff --git a/hw/9pfs/virtio-9p-debug.h b/hw/9pfs/virtio-9p-debug.h
deleted file mode 100644
index d9a2491..0000000
--- a/hw/9pfs/virtio-9p-debug.h
+++ /dev/null
@@ -1,6 +0,0 @@
-#ifndef _QEMU_VIRTIO_9P_DEBUG_H
-#define _QEMU_VIRTIO_9P_DEBUG_H
-
-void pprint_pdu(V9fsPDU *pdu);
-
-#endif
diff --git a/hw/9pfs/virtio-9p.c b/hw/9pfs/virtio-9p.c
index cdb73da..5b6ca10 100644
--- a/hw/9pfs/virtio-9p.c
+++ b/hw/9pfs/virtio-9p.c
@@ -17,12 +17,10 @@
 #include "hw/virtio-pci.h"
 #include "virtio-9p.h"
 #include "fsdev/qemu-fsdev.h"
-#include "virtio-9p-debug.h"
 #include "virtio-9p-xattr.h"
 #include "virtio-9p-coth.h"
 #include "trace.h"
 
-int debug_9p_pdu;
 int open_fd_hw;
 int total_open_fd;
 static int open_fd_rc;
@@ -690,9 +688,6 @@ static V9fsPDU *alloc_pdu(V9fsState *s)
 static void free_pdu(V9fsState *s, V9fsPDU *pdu)
 {
     if (pdu) {
-        if (debug_9p_pdu) {
-            pprint_pdu(pdu);
-        }
         /*
          * Cancelled pdu are added back to the freelist
          * by flush request .
@@ -3315,9 +3310,6 @@ static void submit_pdu(V9fsState *s, V9fsPDU *pdu)
     Coroutine *co;
     CoroutineEntry *handler;
 
-    if (debug_9p_pdu) {
-        pprint_pdu(pdu);
-    }
     if (pdu->id >= ARRAY_SIZE(pdu_co_handlers) ||
         (pdu_co_handlers[pdu->id] == NULL)) {
         handler = v9fs_op_not_supp;
-- 
1.7.1.1

[Qemu-devel] [PATCH v2 3/3] scripts: Simpletrace log analysis script for pretty-printing 9p log.

[Harsh Prateek Bora]

This python script allows to pretty print 9p simpletrace logs and can be
further enhanced to filter 9p logs based on command line arguments.

Signed-off-by: Harsh Prateek Bora <harsh@linux.vnet.ibm.com>
---
 scripts/analyse-9p-simpletrace.py |  142 +++++++++++++++++++++++++++++++++++++
 1 files changed, 142 insertions(+), 0 deletions(-)
 create mode 100755 scripts/analyse-9p-simpletrace.py

diff --git a/scripts/analyse-9p-simpletrace.py b/scripts/analyse-9p-simpletrace.py
new file mode 100755
index 0000000..4358d6b
--- /dev/null
+++ b/scripts/analyse-9p-simpletrace.py
@@ -0,0 +1,142 @@
+#!/usr/bin/env python
+# Pretty print 9p simpletrace log
+# Usage: ./analyse-9p-simpletrace <trace-events> <trace-pid>
+#
+# Author: Harsh Prateek Bora
+
+import simpletrace
+
+class VirtFSRequestTracker(simpletrace.Analyzer):
+	def begin(self):
+		print "Pretty printing 9p simpletrace log ..."
+
+        def complete_pdu(self, tag, id, err):
+                print "ERROR (tag =", tag, ", id =", id, ",err =", err, ")"
+
+        def v9fs_version(self, tag, id, msize, version):
+                print "TVERSION (tag =", tag, ", msize =", msize, ", version =", version, ")"
+
+        def v9fs_version_return(self, tag, id, msize, version):
+                print "RVERSION (tag =", tag, ", msize =", msize, ", version =", version, ")"
+
+        def v9fs_attach(self, tag, id, fid, afid, uname, aname):
+                print "TATTACH (tag =", tag, ", fid =", fid, ", afid =", afid, ", uname =", uname, ", aname =", aname, ")"
+
+	def v9fs_attach_return(self, tag, id, type, verison, path):
+		print "RATTACH (tag =", tag, ", qid={type =", type, ", version =", version, ", path =", path, "})"
+
+	def v9fs_stat(self, tag, id, fid):
+		print "TSTAT (tag =", tag, ", fid =", fid, ")"
+
+	def v9fs_stat_return(self, tag, id, mode, atime, mtime, length):
+		print "RSTAT (tag =", tag, ", mode =", mode, ", atime =", atime, ", mtime =", mtime, ", length =", length, ")"
+
+	def v9fs_getattr(self, tag, id, fid, request_mask):
+		print "TGETATTR (tag =", tag, ", fid =", fid, ", request_mask =", hex(request_mask), ")"
+
+	def v9fs_getattr_return(self, tag, id, result_mask, mode, uid, gid):
+		print "RGETATTR (tag =", tag, ", result_mask =", hex(result_mask), ", mode =", oct(mode), ", uid =", uid, ", gid =", gid, ")"
+
+	def v9fs_walk(self, tag, id, fid, newfid, nwnames):
+		print "TWALK (tag =", tag, ", fid =", fid, ", newfid =", newfid, ", nwnames =", nwnames, ")"
+
+	def v9fs_walk_return(self, tag, id, nwnames, qids):
+		print "RWALK (tag =", tag, ", nwnames =", nwnames, ", qids =", hex(qids), ")"
+
+	def v9fs_open(self, tag, id, fid, mode):
+		print "TOPEN (tag =", tag, ", fid =", fid, ", mode =", oct(mode), ")"
+
+	def v9fs_open_return(self, tag, id, type, version, path, iounit):
+		print "ROPEN (tag =", tag,  ", qid={type =", type, ", version =", version, ", path =", path, "}, iounit =", iounit, ")"
+
+	def v9fs_lcreate(self, tag, id, dfid, flags, mode, gid):
+		print "TLCREATE (tag =", tag, ", dfid =", dfid, ", flags =", oct(flags), ", mode =", oct(mode), ", gid =", gid, ")"
+
+	def v9fs_lcreate_return(self, id, type, version, path, iounit):
+		print "RLCREATE (tag =", tag,  ", qid={type =", type, ", version =", version, ", path =", path, "}, iounit =", iounit, ")"
+
+	def v9fs_fsync(self, tag, id, fid, datasync):
+		print "TFSYNC (tag =", tag, ", fid =", fid, ", datasync =", datasync, ")"
+
+	def v9fs_clunk(self, tag, id, fid):
+		print "TCLUNK (tag =", tag, ", fid =", fid, ")"
+
+	def v9fs_read(self, tag, id, fid, off, max_count):
+		print "TREAD (tag =", tag, ", fid =", fid, ", off =", off, ", max_count =", max_count, ")"
+
+	def v9fs_read_return(self, tag, id, count, err):
+		print "RREAD (tag =", tag, ", count =", count, ", err =", err, ")"
+
+	def v9fs_readdir(self, tag, id, fid, offset, max_count):
+		print "TREADDIR (tag =", tag, ", fid =", fid, ", offset =", offset, ", max_count =", max_count, ")"
+
+	def v9fs_readdir_return(self, tag, id, count, retval):
+		print "RREADDIR (tag =", tag, ", count =", count, ", retval =", retval, ")"
+
+	def v9fs_write(self, tag, id, fid, off, count, cnt):
+		print "TWRITE (tag =", tag, ", fid =", fid, ", off =", off, ", count =", count, ", cnt =", cnt, ")"
+
+	def v9fs_write_return(self, tag, id, total, err):
+		print "RWRITE (tag =", tag, ", total =", total, ", err =", err, ")"
+
+	def v9fs_create(self, tag, id, fid, perm, name, mode):
+		print "TCREATE (tag =", tag, ", fid =", fid, ", perm =", oct(perm), ", name =", name, ", mode =", oct(mode), ")"
+
+	def v9fs_create_return(self, tag, id, type, verison, path, iounit):
+		print "RCREATE (tag =", tag,  ", qid={type =", type, ", version =", version, ", path =", path, "}, iounit =", iounit, ")"
+
+	def v9fs_symlink(self, tag, id, fid, name, symname, gid):
+		print "TSYMLINK (tag =", tag, ", fid =", fid, ", name =", name, ", symname =", symname, ", gid =", gid, ")"
+
+	def v9fs_symlink_return(self, tag, id, type, version, path):
+		print "RSYMLINK (tag =", tag,  ", qid={type =", type, ", version =", version, ", path =", path, "})"
+
+	def v9fs_flush(self, tag, id, flush_tag):
+		print "TFLUSH (tag =", tag, ", flush_tag =", flush_tag, ")"
+
+	def v9fs_link(self, tag, id, dfid, oldfid, name):
+		print "TLINK (tag =", tag, ", dfid =", dfid, ", oldfid =", oldfid, ", name =", name, ")"
+
+	def v9fs_remove(self, tag, id, fid):
+		print "TREMOVE (tag =", tag, ", fid =", fid, ")"
+
+	def v9fs_wstat(self, tag, id, fid, mode, atime, mtime):
+		print "TWSTAT (tag =", tag, ", fid =", fid, ", mode =", oct(mode), ", atime =", atime, "mtime =", mtime, ")"
+
+	def v9fs_mknod(self, tag, id, fid, mode, major, minor):
+		print "TMKNOD (tag =", tag, ", fid =", fid, ", mode =", oct(mode), ", major =", major, ", minor =", minor, ")"
+
+	def v9fs_lock(self, tag, id, fid, type, start, length):
+		print "TLOCK (tag =", tag, ", fid =", fid, "type =", type, ", start =", start, ", length =", length, ")"
+
+	def v9fs_lock_return(self, tag, id, status):
+		print "RLOCK (tag =", tag, ", status =", status, ")"
+
+	def v9fs_getlock(self, tag, id, fid, type, start, length):
+		print "TGETLOCK (tag =", tag, ", fid =", fid, "type =", type, ", start =", start, ", length =", length, ")"
+
+	def v9fs_getlock_return(self, tag, id, type, start, length, proc_id):
+		print "RGETLOCK (tag =", tag, "type =", type, ", start =", start, ", length =", length, ", proc_id =", proc_id,  ")"
+
+	def v9fs_mkdir(self, tag, id, fid, name, mode, gid):
+		print "TMKDIR (tag =", tag, ", fid =", fid, ", name =", name, ", mode =", mode, ", gid =", gid, ")"
+
+	def v9fs_mkdir_return(self, tag, id, type, version, path, err):
+		print "RMKDIR (tag =", tag,  ", qid={type =", type, ", version =", version, ", path =", path, "}, err =", err, ")"
+
+	def v9fs_xattrwalk(self, tag, id, fid, newfid, name):
+		print "TXATTRWALK (tag =", tag, ", fid =", fid, ", newfid =", newfid, ", xattr name =", name, ")"
+
+	def v9fs_xattrwalk_return(self, tag, id, size):
+		print "RXATTRWALK (tag =", tag, ", xattrsize  =", size, ")"
+
+	def v9fs_xattrcreate(self, tag, id, fid, name, size, flags):
+		print "TXATTRCREATE (tag =", tag, ", fid =", fid, ", name =", name, ", xattrsize =", size, ", flags =", flags, ")"
+
+	def v9fs_readlink(self, tag, id, fid):
+		print "TREADLINK (tag =", tag, ", fid =", fid, ")"
+
+	def v9fs_readlink_return(self, tag, id, target):
+		print "RREADLINK (tag =", tag, ", target =", target, ")"
+
+simpletrace.run(VirtFSRequestTracker())
-- 
1.7.1.1

Re: [Qemu-devel] [PATCH v2 3/3] scripts: Simpletrace log analysis script for pretty-printing 9p log.

[Harsh Bora]

On 09/30/2011 04:06 PM, Harsh Prateek Bora wrote:
> This python script allows to pretty print 9p simpletrace logs and can be
> further enhanced to filter 9p logs based on command line arguments.

     Sample ouput of this analysis script (will be added in commit log):

     Pretty printing 9p simpletrace log ...
     TGETATTR (tag = 1 , fid = 0 , request_mask = 0x7ff )
     RGETATTR (tag = 1 , result_mask = 0x7ff , mode = 040777 , uid = 500 
, gid = 500 )
     TXATTRWALK (tag = 1 , fid = 0 , newfid = 1 , xattr name = 36832096 )
     RXATTRWALK (tag = 1 , xattrsize  = 18446744073709551555 )
     TXATTRWALK (tag = 1 , fid = 0 , newfid = 1 , xattr name = 36744768 )
     RXATTRWALK (tag = 1 , xattrsize  = 18446744073709551555 )
     TGETATTR (tag = 1 , fid = 1 , request_mask = 0x3fff )
     RGETATTR (tag = 1 , result_mask = 0x17ff , mode = 040777 , uid = 
500 , gid = 500 )
     TWALK (tag = 1 , fid = 1 , newfid = 2 , nwnames = 1 )
     RWALK (tag = 1 , nwnames = 1 , qids = 0x230aea0 )

>
> Signed-off-by: Harsh Prateek Bora<harsh@linux.vnet.ibm.com>
> ---
>   scripts/analyse-9p-simpletrace.py |  142 +++++++++++++++++++++++++++++++++++++
>   1 files changed, 142 insertions(+), 0 deletions(-)
>   create mode 100755 scripts/analyse-9p-simpletrace.py
>
> diff --git a/scripts/analyse-9p-simpletrace.py b/scripts/analyse-9p-simpletrace.py
> new file mode 100755
> index 0000000..4358d6b
> --- /dev/null
> +++ b/scripts/analyse-9p-simpletrace.py
> @@ -0,0 +1,142 @@
> +#!/usr/bin/env python
> +# Pretty print 9p simpletrace log
> +# Usage: ./analyse-9p-simpletrace<trace-events>  <trace-pid>
> +#
> +# Author: Harsh Prateek Bora
> +
> +import simpletrace
> +
> +class VirtFSRequestTracker(simpletrace.Analyzer):
> +	def begin(self):
> +		print "Pretty printing 9p simpletrace log ..."
> +
> +        def complete_pdu(self, tag, id, err):
> +                print "ERROR (tag =", tag, ", id =", id, ",err =", err, ")"
> +
> +        def v9fs_version(self, tag, id, msize, version):
> +                print "TVERSION (tag =", tag, ", msize =", msize, ", version =", version, ")"
> +
> +        def v9fs_version_return(self, tag, id, msize, version):
> +                print "RVERSION (tag =", tag, ", msize =", msize, ", version =", version, ")"
> +
> +        def v9fs_attach(self, tag, id, fid, afid, uname, aname):
> +                print "TATTACH (tag =", tag, ", fid =", fid, ", afid =", afid, ", uname =", uname, ", aname =", aname, ")"
> +
> +	def v9fs_attach_return(self, tag, id, type, verison, path):
> +		print "RATTACH (tag =", tag, ", qid={type =", type, ", version =", version, ", path =", path, "})"
> +
> +	def v9fs_stat(self, tag, id, fid):
> +		print "TSTAT (tag =", tag, ", fid =", fid, ")"
> +
> +	def v9fs_stat_return(self, tag, id, mode, atime, mtime, length):
> +		print "RSTAT (tag =", tag, ", mode =", mode, ", atime =", atime, ", mtime =", mtime, ", length =", length, ")"
> +
> +	def v9fs_getattr(self, tag, id, fid, request_mask):
> +		print "TGETATTR (tag =", tag, ", fid =", fid, ", request_mask =", hex(request_mask), ")"
> +
> +	def v9fs_getattr_return(self, tag, id, result_mask, mode, uid, gid):
> +		print "RGETATTR (tag =", tag, ", result_mask =", hex(result_mask), ", mode =", oct(mode), ", uid =", uid, ", gid =", gid, ")"
> +
> +	def v9fs_walk(self, tag, id, fid, newfid, nwnames):
> +		print "TWALK (tag =", tag, ", fid =", fid, ", newfid =", newfid, ", nwnames =", nwnames, ")"
> +
> +	def v9fs_walk_return(self, tag, id, nwnames, qids):
> +		print "RWALK (tag =", tag, ", nwnames =", nwnames, ", qids =", hex(qids), ")"
> +
> +	def v9fs_open(self, tag, id, fid, mode):
> +		print "TOPEN (tag =", tag, ", fid =", fid, ", mode =", oct(mode), ")"
> +
> +	def v9fs_open_return(self, tag, id, type, version, path, iounit):
> +		print "ROPEN (tag =", tag,  ", qid={type =", type, ", version =", version, ", path =", path, "}, iounit =", iounit, ")"
> +
> +	def v9fs_lcreate(self, tag, id, dfid, flags, mode, gid):
> +		print "TLCREATE (tag =", tag, ", dfid =", dfid, ", flags =", oct(flags), ", mode =", oct(mode), ", gid =", gid, ")"
> +
> +	def v9fs_lcreate_return(self, id, type, version, path, iounit):
> +		print "RLCREATE (tag =", tag,  ", qid={type =", type, ", version =", version, ", path =", path, "}, iounit =", iounit, ")"
> +
> +	def v9fs_fsync(self, tag, id, fid, datasync):
> +		print "TFSYNC (tag =", tag, ", fid =", fid, ", datasync =", datasync, ")"
> +
> +	def v9fs_clunk(self, tag, id, fid):
> +		print "TCLUNK (tag =", tag, ", fid =", fid, ")"
> +
> +	def v9fs_read(self, tag, id, fid, off, max_count):
> +		print "TREAD (tag =", tag, ", fid =", fid, ", off =", off, ", max_count =", max_count, ")"
> +
> +	def v9fs_read_return(self, tag, id, count, err):
> +		print "RREAD (tag =", tag, ", count =", count, ", err =", err, ")"
> +
> +	def v9fs_readdir(self, tag, id, fid, offset, max_count):
> +		print "TREADDIR (tag =", tag, ", fid =", fid, ", offset =", offset, ", max_count =", max_count, ")"
> +
> +	def v9fs_readdir_return(self, tag, id, count, retval):
> +		print "RREADDIR (tag =", tag, ", count =", count, ", retval =", retval, ")"
> +
> +	def v9fs_write(self, tag, id, fid, off, count, cnt):
> +		print "TWRITE (tag =", tag, ", fid =", fid, ", off =", off, ", count =", count, ", cnt =", cnt, ")"
> +
> +	def v9fs_write_return(self, tag, id, total, err):
> +		print "RWRITE (tag =", tag, ", total =", total, ", err =", err, ")"
> +
> +	def v9fs_create(self, tag, id, fid, perm, name, mode):
> +		print "TCREATE (tag =", tag, ", fid =", fid, ", perm =", oct(perm), ", name =", name, ", mode =", oct(mode), ")"
> +
> +	def v9fs_create_return(self, tag, id, type, verison, path, iounit):
> +		print "RCREATE (tag =", tag,  ", qid={type =", type, ", version =", version, ", path =", path, "}, iounit =", iounit, ")"
> +
> +	def v9fs_symlink(self, tag, id, fid, name, symname, gid):
> +		print "TSYMLINK (tag =", tag, ", fid =", fid, ", name =", name, ", symname =", symname, ", gid =", gid, ")"
> +
> +	def v9fs_symlink_return(self, tag, id, type, version, path):
> +		print "RSYMLINK (tag =", tag,  ", qid={type =", type, ", version =", version, ", path =", path, "})"
> +
> +	def v9fs_flush(self, tag, id, flush_tag):
> +		print "TFLUSH (tag =", tag, ", flush_tag =", flush_tag, ")"
> +
> +	def v9fs_link(self, tag, id, dfid, oldfid, name):
> +		print "TLINK (tag =", tag, ", dfid =", dfid, ", oldfid =", oldfid, ", name =", name, ")"
> +
> +	def v9fs_remove(self, tag, id, fid):
> +		print "TREMOVE (tag =", tag, ", fid =", fid, ")"
> +
> +	def v9fs_wstat(self, tag, id, fid, mode, atime, mtime):
> +		print "TWSTAT (tag =", tag, ", fid =", fid, ", mode =", oct(mode), ", atime =", atime, "mtime =", mtime, ")"
> +
> +	def v9fs_mknod(self, tag, id, fid, mode, major, minor):
> +		print "TMKNOD (tag =", tag, ", fid =", fid, ", mode =", oct(mode), ", major =", major, ", minor =", minor, ")"
> +
> +	def v9fs_lock(self, tag, id, fid, type, start, length):
> +		print "TLOCK (tag =", tag, ", fid =", fid, "type =", type, ", start =", start, ", length =", length, ")"
> +
> +	def v9fs_lock_return(self, tag, id, status):
> +		print "RLOCK (tag =", tag, ", status =", status, ")"
> +
> +	def v9fs_getlock(self, tag, id, fid, type, start, length):
> +		print "TGETLOCK (tag =", tag, ", fid =", fid, "type =", type, ", start =", start, ", length =", length, ")"
> +
> +	def v9fs_getlock_return(self, tag, id, type, start, length, proc_id):
> +		print "RGETLOCK (tag =", tag, "type =", type, ", start =", start, ", length =", length, ", proc_id =", proc_id,  ")"
> +
> +	def v9fs_mkdir(self, tag, id, fid, name, mode, gid):
> +		print "TMKDIR (tag =", tag, ", fid =", fid, ", name =", name, ", mode =", mode, ", gid =", gid, ")"
> +
> +	def v9fs_mkdir_return(self, tag, id, type, version, path, err):
> +		print "RMKDIR (tag =", tag,  ", qid={type =", type, ", version =", version, ", path =", path, "}, err =", err, ")"
> +
> +	def v9fs_xattrwalk(self, tag, id, fid, newfid, name):
> +		print "TXATTRWALK (tag =", tag, ", fid =", fid, ", newfid =", newfid, ", xattr name =", name, ")"
> +
> +	def v9fs_xattrwalk_return(self, tag, id, size):
> +		print "RXATTRWALK (tag =", tag, ", xattrsize  =", size, ")"
> +
> +	def v9fs_xattrcreate(self, tag, id, fid, name, size, flags):
> +		print "TXATTRCREATE (tag =", tag, ", fid =", fid, ", name =", name, ", xattrsize =", size, ", flags =", flags, ")"
> +
> +	def v9fs_readlink(self, tag, id, fid):
> +		print "TREADLINK (tag =", tag, ", fid =", fid, ")"
> +
> +	def v9fs_readlink_return(self, tag, id, target):
> +		print "RREADLINK (tag =", tag, ", target =", target, ")"
> +
> +simpletrace.run(VirtFSRequestTracker())

Re: [Qemu-devel] [PATCH v2 0/3] Replace 9p debug infrastructure with Qemu Tracing

[Aneesh Kumar K.V]

On Fri, 30 Sep 2011 16:06:12 +0530, Harsh Prateek Bora <harsh@linux.vnet.ibm.com> wrote:
> This patchset introduces Qemu Tracing to 9p pdu handlers and removes the
> existing debug infrastructure which became less meaningful after the
> introduction of coroutines. With the existing debug infra, parallel
> operations creates a messy output and filtering becomes difficult.
> 
> With Qemu tracing in place, we can selectively enable/disable trace-events
> and the trace log can be further pretty-printed/filtered using an analysis
> script.
> 
> Harsh Prateek Bora (3):
>   hw/9pfs: Introduce tracing for 9p pdu handlers
>   hw/9pfs: Remove virtio-9p-debug.* infra to be replaced by Qemu
>     Tracing.
>   scripts: Simpletrace log analysis script for pretty-printing 9p log.
> 

applied to v9fs tree with sample output added to patch 3

thanks
-aneesh