qemu/hw/virtio-9p-debug.c

502 lines
14 KiB
C
Raw Normal View History

/*
* 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");
if (dotu) {
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_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");
}
virtio-9p: Avoid SEGV when log file couldn't be opened While running in debug mode if 9P server is unable to open the log file it results in a SEGV deep down in glibc: Program received signal SIGSEGV, Segmentation fault. 0x008fca8c in fwrite () from /lib/libc.so.6 (gdb) bt #0 0x008fca8c in fwrite () from /lib/libc.so.6 #1 0x081eb87e in pprint_pdu (pdu=0x89a52e1c) at /data/sripathi/code/qemu/new/qemu-next-upstream/hw/virtio-9p-debug.c:380 #2 0x0806dad8 in submit_pdu (s=0x897dc008, pdu=0x89a52e1c) at /data/sripathi/code/qemu/new/qemu-next-upstream/hw/virtio-9p.c:3092 #3 0x0806dc63 in handle_9p_output (vdev=0x897dc008, vq=0x86d8218) at /data/sripathi/code/qemu/new/qemu-next-upstream/hw/virtio-9p.c:3122 #4 0x081ac728 in virtio_queue_notify (vdev=0x897dc008, n=0) at /data/sripathi/code/qemu/new/qemu-next-upstream/hw/virtio.c:563 #5 0x08063876 in virtio_ioport_write (opaque=0x86d7b98, addr=16, val=0) at /data/sripathi/code/qemu/new/qemu-next-upstream/hw/virtio-pci.c:222 #6 0x08063e26 in virtio_pci_config_writew (opaque=0x86d7b98, addr=16, val=0) at /data/sripathi/code/qemu/new/qemu-next-upstream/hw/virtio-pci.c:357 #7 0x080c881a in ioport_write (index=1, address=49296, data=0) at ioport.c:80 #8 0x080c8d4c in cpu_outw (addr=49296, val=0) at ioport.c:204 #9 0x08073010 in kvm_handle_io (port=49296, data=0xab393000, direction=1, size=2, count=1) at /data/sripathi/code/qemu/new/qemu-next-upstream/kvm-all.c:735 ... ... This is ugly and misleading. The following patch adds a BUG_ON to catch this error. With this patch we get an abort message like the following, which makes it easier to analyze: f12-kvm login: qemu: /data/sripathi/code/qemu/new/qemu-next-upstream/hw/virtio-9p-debug.c:353: pprint_pdu: Assertion `!(!llogfile)' failed. Signed-off-by: Sripathi Kodi <sripathik@in.ibm.com> Signed-off-by: Anthony Liguori <aliguori@us.ibm.com>
2010-06-30 15:02:00 +04:00
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_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_TAUTH:
fprintf(llogfile, "TAUTH: (");
pprint_int32(pdu, 0, &offset, "afid");
pprint_str(pdu, 0, &offset, ", uname");
pprint_str(pdu, 0, &offset, ", aname");
if (dotu) {
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");
if (dotu) {
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");
if (dotu) {
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");
if (dotu) {
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_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_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;
default:
fprintf(llogfile, "unknown(%d): (", pdu->id);
break;
}
fprintf(llogfile, ")\n");
/* Flush the log message out */
fflush(llogfile);
}