xemu/hw/virtio-9p-debug.c
Harsh Prateek Bora d04e2826f5 hw/virtio9p: Use appropriate debug print functions in TLINK path
Running fsstress with debug enabled causes assertion failure
because of inappropriate usage of debug print functions.
With this patch, fsstress passes without assertion failure.

Signed-off-by: Harsh Prateek Bora <harsh@linux.vnet.ibm.com>
Signed-off-by: Venkateswararao Jujjuri <jvrao@linux.vnet.ibm.com>
2010-12-02 16:07:49 -08:00

646 lines
19 KiB
C

/*
* 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 "virtio.h"
#include "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);
}