[Qemu-devel] [RFC PATCH 0/2] Replace 9p debug infrastructure with Qemu Tracing

[Qemu-devel] [RFC PATCH 0/2] 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 becomes less meaningful after the
introduction of coroutines. 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 filtered using
analysis scripts.

Harsh Prateek Bora (2):
  Introduce tracing for 9p pdu handlers
  Remove virtio-9p-debug.* infra since we are using Qemu Tracing now.

 Makefile.objs             |    2 +-
 hw/9pfs/virtio-9p-debug.c |  646 ---------------------------------------------
 hw/9pfs/virtio-9p-debug.h |    6 -
 hw/9pfs/virtio-9p.c       |   70 +++++-
 trace-events              |   47 ++++
 5 files changed, 110 insertions(+), 661 deletions(-)
 delete mode 100644 hw/9pfs/virtio-9p-debug.c
 delete mode 100644 hw/9pfs/virtio-9p-debug.h

[Qemu-devel] [PATCH 1/2] 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 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..6ee498f 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, id); /* 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_version1(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_version2(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_attach1(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_attach2(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_stat1(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_stat2(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_getattr1(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_getattr2(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_walk1(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_walk2(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_open1(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_open2(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_lcreate1(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_lcreate2(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_read1(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_read2(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_readdir1(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_readdir2(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_write1(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_write2(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_create1(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_create2(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_symlink1(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_symlink2(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_mknod1(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_mknod2(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_lock1(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_lock2(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_getlock1(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_getlock2(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_mkdir1(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_mkdir2(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_xattrwalk1(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_xattrwalk2(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_readlink1(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_readlink2(pdu->tag, pdu->id, target.data);
     complete_pdu(pdu->s, pdu, err);
 }
 
diff --git a/trace-events b/trace-events
index a31d9aa..143c9f0 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, int8_t resp_id) "tag %d id %d response_id %d"
+v9fs_version1(uint16_t tag, uint8_t id, int32_t msize, char* version) "tag %d id %d msize %d version %s"
+v9fs_version2(uint16_t tag, uint8_t id, int32_t msize, char* version) "tag %d id %d msize %d version %s"
+v9fs_attach1(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_attach2(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_stat1(uint16_t tag, uint8_t id, int32_t fid) "tag %d id %d fid %d"
+v9fs_stat2(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_getattr1(uint16_t tag, uint8_t id, int32_t fid, uint64_t request_mask) "tag %d id %d fid %d request_mask %"PRIu64""
+v9fs_getattr2(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_walk1(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_walk2(uint16_t tag, uint8_t id, uint16_t nwnames, void* qids) "tag %d id %d nwnames %d qids %p"
+v9fs_open1(uint16_t tag, uint8_t id, int32_t fid, int32_t mode) "tag %d id %d fid %d mode %d"
+v9fs_open2(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_lcreate1(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_lcreate2(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"}"
+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_read1(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_read2(uint16_t tag, uint8_t id, int32_t count, ssize_t err) "tag %d id %d count %d err %zd"
+v9fs_readdir1(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_readdir2(uint16_t tag, uint8_t id, int32_t count, ssize_t retval) "tag %d id %d count %d retval %zd"
+v9fs_write1(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_write2(uint16_t tag, uint8_t id, int32_t total, ssize_t err) "tag %d id %d total %d err %zd"
+v9fs_create1(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_create2(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_symlink1(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_symlink2(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_mknod1(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_mknod2(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_lock1(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_lock2(uint16_t tag, uint8_t id, int8_t status) "tag %d id %d status %d"
+v9fs_getlock1(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_getlock2(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_mkdir1(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_mkdir2(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_xattrwalk1(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_xattrwalk2(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_readlink1(uint16_t tag, uint8_t id, int32_t fid) "tag %d id %d fid %d"
+v9fs_readlink2(uint16_t tag, uint8_t id, char* target) "tag %d id %d name %s"
-- 
1.7.1.1

[Qemu-devel] [PATCH 2/2] Remove virtio-9p-debug.* infra since we are using Qemu Tracing now.

[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 6ee498f..394c45c 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

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

[Stefan Hajnoczi]

On Thu, Sep 29, 2011 at 06:09:47PM +0530, Harsh Prateek Bora wrote:
> This patchset introduces Qemu Tracing to 9p pdu handlers and removes the
> existing debug infrastructure which becomes less meaningful after the
> introduction of coroutines. 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 filtered using
> analysis scripts.
> 
> Harsh Prateek Bora (2):
>   Introduce tracing for 9p pdu handlers
>   Remove virtio-9p-debug.* infra since we are using Qemu Tracing now.
> 
>  Makefile.objs             |    2 +-
>  hw/9pfs/virtio-9p-debug.c |  646 ---------------------------------------------
>  hw/9pfs/virtio-9p-debug.h |    6 -
>  hw/9pfs/virtio-9p.c       |   70 +++++-
>  trace-events              |   47 ++++
>  5 files changed, 110 insertions(+), 661 deletions(-)
>  delete mode 100644 hw/9pfs/virtio-9p-debug.c
>  delete mode 100644 hw/9pfs/virtio-9p-debug.h

Reviewed-by: Stefan Hajnoczi <stefanha@linux.vnet.ibm.com>

It would also be neat to wire up 9p pdu's to the pcap code in net/dump.c
so it's possible to capture 9p sessions and look at them with wireshark.

Stefan

Re: [Qemu-devel] [PATCH 1/2] Introduce tracing for 9p pdu handlers

[Aneesh Kumar K.V]

On Thu, 29 Sep 2011 18:09:48 +0530, Harsh Prateek Bora <harsh@linux.vnet.ibm.com> wrote:
> 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 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..6ee498f 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, id); /* 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_version1(pdu->tag, pdu->id, s->msize, version.data);

Can this be named trace_v9fs_version


> 
>      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_version2(pdu->tag, pdu->id, s->msize, version.data);
> +

and this one trace_v9fs_version_return

-aneesh

Re: [Qemu-devel] [PATCH 2/2] Remove virtio-9p-debug.* infra since we are using Qemu Tracing now.

[Aneesh Kumar K.V]

On Thu, 29 Sep 2011 18:09:49 +0530, Harsh Prateek Bora <harsh@linux.vnet.ibm.com> wrote:
> 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>

virtio-9p-debug give a symbolic name for different 9p operation. Can you
add a simple trace derived python script that look at id and print the
name of 9p operation. That helps in better debugging. Also it would be
nice to add some kind of filtering. But i guess that can go later.

-aneesh

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

[Harsh Bora]

On 09/29/2011 10:46 PM, Stefan Hajnoczi wrote:
> On Thu, Sep 29, 2011 at 06:09:47PM +0530, Harsh Prateek Bora wrote:
>> This patchset introduces Qemu Tracing to 9p pdu handlers and removes the
>> existing debug infrastructure which becomes less meaningful after the
>> introduction of coroutines. 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 filtered using
>> analysis scripts.
>>
>> Harsh Prateek Bora (2):
>>    Introduce tracing for 9p pdu handlers
>>    Remove virtio-9p-debug.* infra since we are using Qemu Tracing now.
>>
>>   Makefile.objs             |    2 +-
>>   hw/9pfs/virtio-9p-debug.c |  646 ---------------------------------------------
>>   hw/9pfs/virtio-9p-debug.h |    6 -
>>   hw/9pfs/virtio-9p.c       |   70 +++++-
>>   trace-events              |   47 ++++
>>   5 files changed, 110 insertions(+), 661 deletions(-)
>>   delete mode 100644 hw/9pfs/virtio-9p-debug.c
>>   delete mode 100644 hw/9pfs/virtio-9p-debug.h
>
> Reviewed-by: Stefan Hajnoczi<stefanha@linux.vnet.ibm.com>
>
> It would also be neat to wire up 9p pdu's to the pcap code in net/dump.c
> so it's possible to capture 9p sessions and look at them with wireshark.

Thanks Stefan for a quick response. I have sent a v2 for this patch 
incorporating aneesh's review comments with an additional patch to 
provide an analysis python script. I shall look into pcap code sometime 
soon.

Harsh

>
> Stefan
>