a03c54f16e
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>
489 lines
13 KiB
C
489 lines
13 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");
|
|
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");
|
|
}
|
|
|
|
BUG_ON(!llogfile);
|
|
|
|
switch (pdu->id) {
|
|
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);
|
|
}
|