@@ -42,19 +42,10 @@
#include "hw/ppc/spapr.h"
#include "hw/ppc/spapr_vio.h"
#include "viosrp.h"
+#include "trace.h"
#include <libfdt.h>
-/*#define DEBUG_VSCSI*/
-
-#ifdef DEBUG_VSCSI
-#define DPRINTF(fmt, ...) \
- do { fprintf(stderr, fmt, ## __VA_ARGS__); } while (0)
-#else
-#define DPRINTF(fmt, ...) \
- do { } while (0)
-#endif
-
/*
* Virtual SCSI device
*/
@@ -237,8 +228,7 @@ static int vscsi_send_rsp(VSCSIState *s, vscsi_req *req,
int total_len = sizeof(iu->srp.rsp);
uint8_t sol_not = iu->srp.cmd.sol_not;
- DPRINTF("VSCSI: Sending resp status: 0x%x, "
- "res_in: %d, res_out: %d\n", status, res_in, res_out);
+ trace_spapr_vscsi_send_rsp(status, res_in, res_out);
memset(iu, 0, sizeof(struct srp_rsp));
iu->srp.rsp.opcode = SRP_RSP;
@@ -298,13 +288,13 @@ static int vscsi_fetch_desc(VSCSIState *s, struct vscsi_req *req,
switch (req->dma_fmt) {
case SRP_NO_DATA_DESC: {
- DPRINTF("VSCSI: no data descriptor\n");
+ trace_spapr_vscsi_fetch_desc_no_data();
return 0;
}
case SRP_DATA_DESC_DIRECT: {
memcpy(ret, cmd->add_data + req->cdb_offset, sizeof(*ret));
assert(req->cur_desc_num == 0);
- DPRINTF("VSCSI: direct segment\n");
+ trace_spapr_vscsi_fetch_desc_direct();
break;
}
case SRP_DATA_DESC_INDIRECT: {
@@ -312,30 +302,29 @@ static int vscsi_fetch_desc(VSCSIState *s, struct vscsi_req *req,
(cmd->add_data + req->cdb_offset);
if (n < req->local_desc) {
*ret = tmp->desc_list[n];
- DPRINTF("VSCSI: indirect segment local tag=0x%x desc#%d/%d\n",
- req->qtag, n, req->local_desc);
-
+ trace_spapr_vscsi_fetch_desc_indirect(req->qtag, n,
+ req->local_desc);
} else if (n < req->total_desc) {
int rc;
struct srp_direct_buf tbl_desc = vscsi_swap_desc(tmp->table_desc);
unsigned desc_offset = n * sizeof(struct srp_direct_buf);
if (desc_offset >= tbl_desc.len) {
- DPRINTF("VSCSI: #%d is ouf of range (%d bytes)\n",
- n, desc_offset);
+ trace_spapr_vscsi_fetch_desc_out_of_range(n, desc_offset);
return -1;
}
rc = spapr_vio_dma_read(&s->vdev, tbl_desc.va + desc_offset,
ret, sizeof(struct srp_direct_buf));
if (rc) {
- DPRINTF("VSCSI: spapr_vio_dma_read -> %d reading ext_desc\n",
- rc);
+ trace_spapr_vscsi_fetch_desc_dma_read_error(rc);
return -1;
}
- DPRINTF("VSCSI: indirect segment ext. tag=0x%x desc#%d/%d { va=%"PRIx64" len=%x }\n",
- req->qtag, n, req->total_desc, tbl_desc.va, tbl_desc.len);
+ trace_spapr_vscsi_fetch_desc_indirect_seg_ext(req->qtag, n,
+ req->total_desc,
+ tbl_desc.va,
+ tbl_desc.len);
} else {
- DPRINTF("VSCSI: Out of descriptors !\n");
+ trace_spapr_vscsi_fetch_desc_out_of_desc();
return 0;
}
break;
@@ -347,15 +336,16 @@ static int vscsi_fetch_desc(VSCSIState *s, struct vscsi_req *req,
*ret = vscsi_swap_desc(*ret);
if (buf_offset > ret->len) {
- DPRINTF(" offset=%x is out of a descriptor #%d boundary=%x\n",
- buf_offset, req->cur_desc_num, ret->len);
+ trace_spapr_vscsi_fetch_desc_out_of_desc_boundary(buf_offset,
+ req->cur_desc_num,
+ ret->len);
return -1;
}
ret->va += buf_offset;
ret->len -= buf_offset;
- DPRINTF(" cur=%d offs=%x ret { va=%"PRIx64" len=%x }\n",
- req->cur_desc_num, req->cur_desc_offset, ret->va, ret->len);
+ trace_spapr_vscsi_fetch_desc_done(req->cur_desc_num, req->cur_desc_offset,
+ ret->va, ret->len);
return ret->len ? 1 : 0;
}
@@ -398,7 +388,7 @@ static int vscsi_srp_indirect_data(VSCSIState *s, vscsi_req *req,
int rc = 0;
uint32_t llen, total = 0;
- DPRINTF("VSCSI: indirect segment 0x%x bytes\n", len);
+ trace_spapr_vscsi_srp_indirect_data(len);
/* While we have data ... */
while (len) {
@@ -417,11 +407,10 @@ static int vscsi_srp_indirect_data(VSCSIState *s, vscsi_req *req,
rc = spapr_vio_dma_write(&s->vdev, md.va, buf, llen);
}
if (rc) {
- DPRINTF("VSCSI: spapr_vio_dma_r/w(%d) -> %d\n", req->writing, rc);
+ trace_spapr_vscsi_srp_indirect_data_rw(req->writing, rc);
break;
}
- DPRINTF("VSCSI: data: %02x %02x %02x %02x...\n",
- buf[0], buf[1], buf[2], buf[3]);
+ trace_spapr_vscsi_srp_indirect_data_buf(buf[0], buf[1], buf[2], buf[3]);
len -= llen;
buf += llen;
@@ -447,7 +436,7 @@ static int vscsi_srp_transfer_data(VSCSIState *s, vscsi_req *req,
switch (req->dma_fmt) {
case SRP_NO_DATA_DESC:
- DPRINTF("VSCSI: no data desc transfer, skipping 0x%x bytes\n", len);
+ trace_spapr_vscsi_srp_transfer_data(len);
break;
case SRP_DATA_DESC_DIRECT:
err = vscsi_srp_direct_data(s, req, buf, len);
@@ -527,8 +516,7 @@ static void vscsi_transfer_data(SCSIRequest *sreq, uint32_t len)
uint8_t *buf;
int rc = 0;
- DPRINTF("VSCSI: SCSI xfer complete tag=0x%x len=0x%x, req=%p\n",
- sreq->tag, len, req);
+ trace_spapr_vscsi_transfer_data(sreq->tag, len, req);
if (req == NULL) {
fprintf(stderr, "VSCSI: Can't find request for tag 0x%x\n", sreq->tag);
return;
@@ -557,8 +545,7 @@ static void vscsi_command_complete(SCSIRequest *sreq, uint32_t status, size_t re
vscsi_req *req = sreq->hba_private;
int32_t res_in = 0, res_out = 0;
- DPRINTF("VSCSI: SCSI cmd complete, tag=0x%x status=0x%x, req=%p\n",
- sreq->tag, status, req);
+ trace_spapr_vscsi_command_complete(sreq->tag, status, req);
if (req == NULL) {
fprintf(stderr, "VSCSI: Can't find request for tag 0x%x\n", sreq->tag);
return;
@@ -567,16 +554,14 @@ static void vscsi_command_complete(SCSIRequest *sreq, uint32_t status, size_t re
if (status == CHECK_CONDITION) {
req->senselen = scsi_req_get_sense(req->sreq, req->sense,
sizeof(req->sense));
- DPRINTF("VSCSI: Sense data, %d bytes:\n", req->senselen);
- DPRINTF(" %02x %02x %02x %02x %02x %02x %02x %02x\n",
+ trace_spapr_vscsi_command_complete_sense_data(req->senselen,
req->sense[0], req->sense[1], req->sense[2], req->sense[3],
- req->sense[4], req->sense[5], req->sense[6], req->sense[7]);
- DPRINTF(" %02x %02x %02x %02x %02x %02x %02x %02x\n",
+ req->sense[4], req->sense[5], req->sense[6], req->sense[7],
req->sense[8], req->sense[9], req->sense[10], req->sense[11],
req->sense[12], req->sense[13], req->sense[14], req->sense[15]);
}
- DPRINTF("VSCSI: Command complete err=%d\n", status);
+ trace_spapr_vscsi_command_complete_status(status);
if (status == 0) {
/* We handle overflows, not underflows for normal commands,
* but hopefully nobody cares
@@ -635,8 +620,8 @@ static void vscsi_save_request(QEMUFile *f, SCSIRequest *sreq)
vmstate_save_state(f, &vmstate_spapr_vscsi_req, req, NULL);
- DPRINTF("VSCSI: saving tag=%u, current desc#%d, offset=%x\n",
- req->qtag, req->cur_desc_num, req->cur_desc_offset);
+ trace_spapr_vscsi_save_request(req->qtag, req->cur_desc_num,
+ req->cur_desc_offset);
}
static void *vscsi_load_request(QEMUFile *f, SCSIRequest *sreq)
@@ -660,8 +645,8 @@ static void *vscsi_load_request(QEMUFile *f, SCSIRequest *sreq)
req->sreq = scsi_req_ref(sreq);
- DPRINTF("VSCSI: restoring tag=%u, current desc#%d, offset=%x\n",
- req->qtag, req->cur_desc_num, req->cur_desc_offset);
+ trace_spapr_vscsi_load_request(req->qtag, req->cur_desc_num,
+ req->cur_desc_offset);
return req;
}
@@ -672,7 +657,7 @@ static void vscsi_process_login(VSCSIState *s, vscsi_req *req)
struct srp_login_rsp *rsp = &iu->srp.login_rsp;
uint64_t tag = iu->srp.rsp.tag;
- DPRINTF("VSCSI: Got login, sendin response !\n");
+ trace_spapr_vscsi__process_login();
/* TODO handle case that requested size is wrong and
* buffer format is wrong
@@ -795,8 +780,7 @@ static int vscsi_queue_cmd(VSCSIState *s, vscsi_req *req)
sdev = vscsi_device_find(&s->bus, be64_to_cpu(srp->cmd.lun), &lun);
if (!sdev) {
- DPRINTF("VSCSI: Command for lun %08" PRIx64 " with no drive\n",
- be64_to_cpu(srp->cmd.lun));
+ trace_spapr_vscsi_queue_cmd_no_drive(be64_to_cpu(srp->cmd.lun));
if (srp->cmd.cdb[0] == INQUIRY) {
vscsi_inquiry_no_target(s, req);
} else {
@@ -808,9 +792,8 @@ static int vscsi_queue_cmd(VSCSIState *s, vscsi_req *req)
req->sreq = scsi_req_new(sdev, req->qtag, lun, srp->cmd.cdb, req);
n = scsi_req_enqueue(req->sreq);
- DPRINTF("VSCSI: Queued command tag 0x%x CMD 0x%x=%s LUN %d ret: %d\n",
- req->qtag, srp->cmd.cdb[0], scsi_command_name(srp->cmd.cdb[0]),
- lun, n);
+ trace_spapr_vscsi_queue_cmd(req->qtag, srp->cmd.cdb[0],
+ scsi_command_name(srp->cmd.cdb[0]), lun, n);
if (n) {
/* Transfer direction must be set before preprocessing the
@@ -1141,7 +1124,7 @@ static int vscsi_do_crq(struct VIOsPAPRDevice *dev, uint8_t *crq_data)
crq.s.IU_length = be16_to_cpu(crq.s.IU_length);
crq.s.IU_data_ptr = be64_to_cpu(crq.s.IU_data_ptr);
- DPRINTF("VSCSI: do_crq %02x %02x ...\n", crq.raw[0], crq.raw[1]);
+ trace_spapr_vscsi_do_crq(crq.raw[0], crq.raw[1]);
switch (crq.s.valid) {
case 0xc0: /* Init command/response */
@@ -202,3 +202,30 @@ esp_pci_dma_abort(uint32_t val) "ABORT (%.8x)"
esp_pci_dma_start(uint32_t val) "START (%.8x)"
esp_pci_sbac_read(uint32_t reg) "sbac: 0x%8.8x"
esp_pci_sbac_write(uint32_t reg, uint32_t val) "sbac: 0x%8.8x -> 0x%8.8x"
+
+# hw/scsi/spapr_vscsi.c
+
+spapr_vscsi_send_rsp(uint8_t status, int32_t res_in, int32_t res_out) "status: 0x%x, res_in: %"PRId32", res_out: %"PRId32
+spapr_vscsi_fetch_desc_no_data(void) "no data descriptor"
+spapr_vscsi_fetch_desc_direct(void) "direct segment"
+spapr_vscsi_fetch_desc_indirect(uint32_t qtag, unsigned desc, unsigned local_desc) "indirect segment local tag=0x%"PRIx32" desc#%u/%u"
+spapr_vscsi_fetch_desc_out_of_range(unsigned desc, unsigned desc_offset) "#%u is ouf of range (%u bytes)"
+spapr_vscsi_fetch_desc_dma_read_error(int rc) "spapr_vio_dma_read -> %d reading ext_desc"
+spapr_vscsi_fetch_desc_indirect_seg_ext(uint32_t qtag, unsigned n, unsigned desc, uint64_t va, uint32_t len) "indirect segment ext. tag=0x%"PRIx32" desc#%u/%u { va=0x%"PRIx64" len=0x%"PRIx32" }"
+spapr_vscsi_fetch_desc_out_of_desc(void) "Out of descriptors !"
+spapr_vscsi_fetch_desc_out_of_desc_boundary(unsigned offset, unsigned desc, uint32_t len) " offset=0x%x is out of a descriptor #%u boundary=%"PRIx32
+spapr_vscsi_fetch_desc_done(unsigned desc_num, unsigned desc_offset, uint64_t va, uint32_t len) " cur=%u offs=0x%x ret { va=0x%"PRIx64" len=0x%"PRIx32" }"
+spapr_vscsi_srp_indirect_data(uint32_t len) "indirect segment 0x%"PRIx32" bytes"
+spapr_vscsi_srp_indirect_data_rw(int writing, int rc) "spapr_vio_dma_r/w(%d) -> %d"
+spapr_vscsi_srp_indirect_data_buf(unsigned a, unsigned b, unsigned c, unsigned d) " data: %02x %02x %02x %02x..."
+spapr_vscsi_srp_transfer_data(uint32_t len) "no data desc transfer, skipping 0x%"PRIx32" bytes"
+spapr_vscsi_transfer_data(uint32_t tag, uint32_t len, void *req) "SCSI xfer complete tag=0x%"PRIx32" len=0x%"PRIx32", req=%p"
+spapr_vscsi_command_complete(uint32_t tag, uint32_t status, void *req) "SCSI cmd complete, tag=0x%"PRIx32" status=0x%"PRIx32", req=%p"
+spapr_vscsi_command_complete_sense_data(uint32_t len, unsigned s0, unsigned s1, unsigned s2, unsigned s3, unsigned s4, unsigned s5, unsigned s6, unsigned s7, unsigned s8, unsigned s9, unsigned s10, unsigned s11, unsigned s12, unsigned s13, unsigned s14, unsigned s15) "Sense data, %d bytes: %02x %02x %02x %02x %02x %02x %02x %02x %02x %02x %02x %02x %02x %02x %02x %02x"
+spapr_vscsi_command_complete_status(uint32_t status) "Command complete err=%"PRIu32
+spapr_vscsi_save_request(uint32_t qtag, unsigned desc, unsigned offset) "saving tag=%"PRIu32", current desc#%u, offset=0x%x"
+spapr_vscsi_load_request(uint32_t qtag, unsigned desc, unsigned offset) "restoring tag=%"PRIu32", current desc#%u, offset=0x%x"
+spapr_vscsi__process_login(void) "Got login, sending response !"
+spapr_vscsi_queue_cmd_no_drive(uint64_t lun) "Command for lun %08" PRIx64 " with no drive"
+spapr_vscsi_queue_cmd(uint32_t qtag, unsigned cdb, const char *cmd, int lun, int ret) "Queued command tag 0x%"PRIx32" CMD 0x%x=%s LUN %d ret: %d"
+spapr_vscsi_do_crq(unsigned c0, unsigned c1) "crq: %02x %02x ..."
Signed-off-by: Laurent Vivier <lvivier@redhat.com> --- hw/scsi/spapr_vscsi.c | 89 +++++++++++++++++++++------------------------------ hw/scsi/trace-events | 27 ++++++++++++++++ 2 files changed, 63 insertions(+), 53 deletions(-)