hw/9pfs: Introduce tracing for 9p pdu handlers

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.

Reviewed-by: Stefan Hajnoczi <stefanha@linux.vnet.ibm.com>
Signed-off-by: Harsh Prateek Bora <harsh@linux.vnet.ibm.com>
Signed-off-by: Aneesh Kumar K.V <aneesh.kumar@linux.vnet.ibm.com>
This commit is contained in:
Harsh Prateek Bora 2011-10-12 19:11:25 +05:30 committed by Aneesh Kumar K.V
parent edb9eb7352
commit c572f23a3e
2 changed files with 118 additions and 0 deletions

View File

@ -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;
@ -973,6 +974,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 */
@ -1282,6 +1284,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;
@ -1292,6 +1295,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);
@ -1310,6 +1315,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) {
@ -1334,6 +1340,8 @@ 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);
@ -1351,6 +1359,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) {
@ -1371,6 +1380,9 @@ 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);
}
@ -1387,6 +1399,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) {
@ -1416,6 +1429,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);
}
@ -1543,6 +1560,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);
@ -1599,6 +1618,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++) {
@ -1649,6 +1669,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;
@ -1695,6 +1717,8 @@ 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);
}
@ -1713,6 +1737,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) {
@ -1742,6 +1767,8 @@ 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);
}
@ -1757,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;
@ -1781,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) {
@ -1897,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) {
@ -1955,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);
}
@ -2039,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;
@ -2064,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);
}
@ -2128,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) {
@ -2174,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);
}
@ -2198,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;
@ -2331,6 +2370,8 @@ 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);
@ -2351,6 +2392,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) {
@ -2367,6 +2409,8 @@ 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);
@ -2381,6 +2425,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) {
@ -2411,6 +2456,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) {
@ -2444,6 +2490,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) {
@ -2723,6 +2770,8 @@ 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) {
@ -2891,6 +2940,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) {
@ -2908,6 +2958,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);
}
@ -2935,6 +2986,10 @@ 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) */
@ -2957,6 +3012,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);
@ -2981,6 +3037,9 @@ 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;
@ -2998,6 +3057,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);
@ -3018,6 +3080,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;
@ -3033,6 +3097,8 @@ 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);
}
@ -3050,6 +3116,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;
@ -3126,6 +3194,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);
}
@ -3145,6 +3214,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) {
@ -3181,6 +3251,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;
@ -3198,6 +3269,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);
}

View File

@ -538,3 +538,49 @@ esp_mem_writeb_cmd_ensel(uint32_t val) "Enable selection (%2.2x)"
# monitor.c
handle_qmp_command(void *mon, const char *cmd_name) "mon %p cmd_name \"%s\""
monitor_protocol_emitter(void *mon) "mon %p"
# 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"