| Message ID | 20181207131732.21073-1-lvivier@redhat.com |
|---|---|
| State | New |
| Headers | show |
| Series | [1/2] scsi-disk: Convert from DPRINTF() macro to trace events | expand |
On 12/7/18 2:17 PM, Laurent Vivier wrote: > Signed-off-by: Laurent Vivier <lvivier@redhat.com> > --- > hw/scsi/scsi-disk.c | 105 +++++++++++++++++++++---------------------- > hw/scsi/trace-events | 29 ++++++++++++ > 2 files changed, 81 insertions(+), 53 deletions(-) > > diff --git a/hw/scsi/scsi-disk.c b/hw/scsi/scsi-disk.c > index 0e9027c8f3..29e541efdb 100644 > --- a/hw/scsi/scsi-disk.c > +++ b/hw/scsi/scsi-disk.c > @@ -19,15 +19,6 @@ > * the host adapter emulator. > */ > > -//#define DEBUG_SCSI > - > -#ifdef DEBUG_SCSI > -#define DPRINTF(fmt, ...) \ > -do { printf("scsi-disk: " fmt , ## __VA_ARGS__); } while (0) > -#else > -#define DPRINTF(fmt, ...) do {} while(0) > -#endif > - > #include "qemu/osdep.h" > #include "qemu/units.h" > #include "qapi/error.h" > @@ -41,6 +32,7 @@ do { printf("scsi-disk: " fmt , ## __VA_ARGS__); } while (0) > #include "hw/block/block.h" > #include "sysemu/dma.h" > #include "qemu/cutils.h" > +#include "trace.h" > > #ifdef __linux > #include <scsi/sg.h> > @@ -128,8 +120,8 @@ static void scsi_free_request(SCSIRequest *req) > /* Helper function for command completion with sense. */ > static void scsi_check_condition(SCSIDiskReq *r, SCSISense sense) > { > - DPRINTF("Command complete tag=0x%x sense=%d/%d/%d\n", > - r->req.tag, sense.key, sense.asc, sense.ascq); > + trace_scsi_disk_check_condition(r->req.tag, sense.key, sense.asc, > + sense.ascq); > scsi_req_build_sense(&r->req, sense); > scsi_req_complete(&r->req, CHECK_CONDITION); > } > @@ -317,7 +309,7 @@ static void scsi_read_complete(void * opaque, int ret) > } > > block_acct_done(blk_get_stats(s->qdev.conf.blk), &r->acct); > - DPRINTF("Data ready tag=0x%x len=%zd\n", r->req.tag, r->qiov.size); > + trace_scsi_disk_read_complete(r->req.tag, r->qiov.size); > > n = r->qiov.size / 512; > r->sector += n; > @@ -388,7 +380,7 @@ static void scsi_read_data(SCSIRequest *req) > SCSIDiskState *s = DO_UPCAST(SCSIDiskState, qdev, r->req.dev); > bool first; > > - DPRINTF("Read sector_count=%d\n", r->sector_count); > + trace_scsi_disk_read_data_count(r->sector_count); > if (r->sector_count == 0) { > /* This also clears the sense buffer for REQUEST SENSE. */ > scsi_req_complete(&r->req, GOOD); > @@ -401,7 +393,7 @@ static void scsi_read_data(SCSIRequest *req) > /* The request is used as the AIO opaque value, so add a ref. */ > scsi_req_ref(&r->req); > if (r->req.cmd.mode == SCSI_XFER_TO_DEV) { > - DPRINTF("Data transfer direction invalid\n"); > + trace_scsi_disk_read_data_invalid(); > scsi_read_complete(r, -EINVAL); > return; > } > @@ -502,7 +494,7 @@ static void scsi_write_complete_noio(SCSIDiskReq *r, int ret) > return; > } else { > scsi_init_iovec(r, SCSI_DMA_BUF_SIZE); > - DPRINTF("Write complete tag=0x%x more=%zd\n", r->req.tag, r->qiov.size); > + trace_scsi_disk_write_complete_noio(r->req.tag, r->qiov.size); > scsi_req_data(&r->req, r->qiov.size); > } > > @@ -540,7 +532,7 @@ static void scsi_write_data(SCSIRequest *req) > /* The request is used as the AIO opaque value, so add a ref. */ > scsi_req_ref(&r->req); > if (r->req.cmd.mode != SCSI_XFER_TO_DEV) { > - DPRINTF("Data transfer direction invalid\n"); > + trace_scsi_disk_write_data_invalid(); > scsi_write_complete_noio(r, -EINVAL); > return; > } > @@ -605,8 +597,7 @@ static int scsi_disk_emulate_vpd_page(SCSIRequest *req, uint8_t *outbuf) > switch (page_code) { > case 0x00: /* Supported page codes, mandatory */ > { > - DPRINTF("Inquiry EVPD[Supported pages] " > - "buffer size %zd\n", req->cmd.xfer); > + trace_scsi_disk_emulate_vpd_page_00(req->cmd.xfer); > outbuf[buflen++] = 0x00; /* list of supported pages (this page) */ > if (s->serial) { > outbuf[buflen++] = 0x80; /* unit serial number */ > @@ -624,7 +615,7 @@ static int scsi_disk_emulate_vpd_page(SCSIRequest *req, uint8_t *outbuf) > int l; > > if (!s->serial) { > - DPRINTF("Inquiry (EVPD[Serial number] not supported\n"); > + trace_scsi_disk_emulate_vpd_page_80_not_supported(); > return -1; > } > > @@ -633,8 +624,7 @@ static int scsi_disk_emulate_vpd_page(SCSIRequest *req, uint8_t *outbuf) > l = 36; > } > > - DPRINTF("Inquiry EVPD[Serial number] " > - "buffer size %zd\n", req->cmd.xfer); > + trace_scsi_disk_emulate_vpd_page_80(req->cmd.xfer); > memcpy(outbuf + buflen, s->serial, l); > buflen += l; > break; > @@ -649,8 +639,7 @@ static int scsi_disk_emulate_vpd_page(SCSIRequest *req, uint8_t *outbuf) > if (id_len > max_len) { > id_len = max_len; > } > - DPRINTF("Inquiry EVPD[Device identification] " > - "buffer size %zd\n", req->cmd.xfer); > + trace_scsi_disk_emulate_vpd_page_83(req->cmd.xfer); > > outbuf[buflen++] = 0x2; /* ASCII */ > outbuf[buflen++] = 0; /* not officially assigned */ > @@ -695,8 +684,7 @@ static int scsi_disk_emulate_vpd_page(SCSIRequest *req, uint8_t *outbuf) > SCSIBlockLimits bl = {}; > > if (s->qdev.type == TYPE_ROM) { > - DPRINTF("Inquiry (EVPD[%02X] not supported for CDROM\n", > - page_code); > + trace_scsi_disk_emulate_vpd_page_b0_not_supported(); > return -1; > } > bl.wsnz = 1; > @@ -1243,8 +1231,9 @@ static int scsi_disk_emulate_mode_sense(SCSIDiskReq *r, uint8_t *outbuf) > dbd = (r->req.cmd.buf[1] & 0x8) != 0; > page = r->req.cmd.buf[2] & 0x3f; > page_control = (r->req.cmd.buf[2] & 0xc0) >> 6; > - DPRINTF("Mode Sense(%d) (page %d, xfer %zd, page_control %d)\n", > - (r->req.cmd.buf[0] == MODE_SENSE) ? 6 : 10, page, r->req.cmd.xfer, page_control); > + > + trace_scsi_disk_emulate_mode_sense((r->req.cmd.buf[0] == MODE_SENSE) ? 6 : > + 10, page, r->req.cmd.xfer, page_control); > memset(outbuf, 0, r->req.cmd.xfer); > p = outbuf; > > @@ -1336,7 +1325,7 @@ static int scsi_disk_emulate_read_toc(SCSIRequest *req, uint8_t *outbuf) > format = req->cmd.buf[2] & 0xf; > start_track = req->cmd.buf[6]; > blk_get_geometry(s->qdev.conf.blk, &nb_sectors); > - DPRINTF("Read TOC (track %d format %d msf %d)\n", start_track, format, msf >> 1); > + trace_scsi_disk_emulate_read_toc(start_track, format, msf >> 1); > nb_sectors /= s->qdev.blocksize / 512; > switch (format) { > case 0: > @@ -1395,7 +1384,7 @@ static void scsi_disk_emulate_read_data(SCSIRequest *req) > int buflen = r->iov.iov_len; > > if (buflen) { > - DPRINTF("Read buf_len=%d\n", buflen); > + trace_scsi_disk_emulate_read_data(buflen); > r->iov.iov_len = 0; > r->started = true; > scsi_req_data(&r->req, buflen); > @@ -1814,7 +1803,7 @@ static void scsi_disk_emulate_write_data(SCSIRequest *req) > > if (r->iov.iov_len) { > int buflen = r->iov.iov_len; > - DPRINTF("Write buf_len=%d\n", buflen); > + trace_scsi_disk_emulate_write_data(buflen); > r->iov.iov_len = 0; > scsi_req_data(&r->req, buflen); > return; > @@ -2023,7 +2012,7 @@ static int32_t scsi_disk_emulate_command(SCSIRequest *req, uint8_t *buf) > case SERVICE_ACTION_IN_16: > /* Service Action In subcommands. */ > if ((req->cmd.buf[1] & 31) == SAI_READ_CAPACITY_16) { > - DPRINTF("SAI READ CAPACITY(16)\n"); > + trace_scsi_disk_emulate_command_SAI_16(); > memset(outbuf, 0, req->cmd.xfer); > blk_get_geometry(s->qdev.conf.blk, &nb_sectors); > if (!nb_sectors) { > @@ -2061,7 +2050,7 @@ static int32_t scsi_disk_emulate_command(SCSIRequest *req, uint8_t *buf) > /* Protection, exponent and lowest lba field left blank. */ > break; > } > - DPRINTF("Unsupported Service Action In\n"); > + trace_scsi_disk_emulate_command_SAI_unsupported(); > goto illegal_request; > case SYNCHRONIZE_CACHE: > /* The request is used as the AIO opaque value, so add a ref. */ > @@ -2071,37 +2060,36 @@ static int32_t scsi_disk_emulate_command(SCSIRequest *req, uint8_t *buf) > r->req.aiocb = blk_aio_flush(s->qdev.conf.blk, scsi_aio_complete, r); > return 0; > case SEEK_10: > - DPRINTF("Seek(10) (sector %" PRId64 ")\n", r->req.cmd.lba); > + trace_scsi_disk_emulate_command_SEEK_10(r->req.cmd.lba); > if (r->req.cmd.lba > s->qdev.max_lba) { > goto illegal_lba; > } > break; > case MODE_SELECT: > - DPRINTF("Mode Select(6) (len %lu)\n", (unsigned long)r->req.cmd.xfer); > + trace_scsi_disk_emulate_command_MODE_SELECT(r->req.cmd.xfer); > break; > case MODE_SELECT_10: > - DPRINTF("Mode Select(10) (len %lu)\n", (unsigned long)r->req.cmd.xfer); > + trace_scsi_disk_emulate_command_MODE_SELECT_10(r->req.cmd.xfer); > break; > case UNMAP: > - DPRINTF("Unmap (len %lu)\n", (unsigned long)r->req.cmd.xfer); > + trace_scsi_disk_emulate_command_UNMAP(r->req.cmd.xfer); > break; > case VERIFY_10: > case VERIFY_12: > case VERIFY_16: > - DPRINTF("Verify (bytchk %d)\n", (req->cmd.buf[1] >> 1) & 3); > + trace_scsi_disk_emulate_command_VERIFY((req->cmd.buf[1] >> 1) & 3); > if (req->cmd.buf[1] & 6) { > goto illegal_request; > } > break; > case WRITE_SAME_10: > case WRITE_SAME_16: > - DPRINTF("WRITE SAME %d (len %lu)\n", > - req->cmd.buf[0] == WRITE_SAME_10 ? 10 : 16, > - (unsigned long)r->req.cmd.xfer); > + trace_scsi_disk_emulate_command_WRITE_SAME( > + req->cmd.buf[0] == WRITE_SAME_10 ? 10 : 16, r->req.cmd.xfer); > break; > default: > - DPRINTF("Unknown SCSI command (%2.2x=%s)\n", buf[0], > - scsi_command_name(buf[0])); > + trace_scsi_disk_emulate_command_UNKNOWN(buf[0], > + scsi_command_name(buf[0])); > scsi_check_condition(r, SENSE_CODE(INVALID_OPCODE)); > return 0; > } > @@ -2154,7 +2142,7 @@ static int32_t scsi_disk_dma_command(SCSIRequest *req, uint8_t *buf) > case READ_10: > case READ_12: > case READ_16: > - DPRINTF("Read (sector %" PRId64 ", count %u)\n", r->req.cmd.lba, len); > + trace_scsi_disk_dma_command_READ(r->req.cmd.lba, len); > /* Protection information is not supported. For SCSI versions 2 and > * older (as determined by snooping the guest's INQUIRY commands), > * there is no RD/WR/VRPROTECT, so skip this check in these versions. > @@ -2179,7 +2167,7 @@ static int32_t scsi_disk_dma_command(SCSIRequest *req, uint8_t *buf) > scsi_check_condition(r, SENSE_CODE(WRITE_PROTECTED)); > return 0; > } > - DPRINTF("Write %s(sector %" PRId64 ", count %u)\n", > + trace_scsi_disk_dma_command_WRITE( > (command & 0xe) == 0xe ? "And Verify " : "", > r->req.cmd.lba, len); > /* fall through */ > @@ -2497,6 +2485,24 @@ static const SCSIReqOps *const scsi_disk_reqops_dispatch[256] = { > [WRITE_VERIFY_16] = &scsi_disk_dma_reqops, > }; > > +static void scsi_disk_new_request_dump(uint32_t lun, uint32_t tag, uint8_t *buf, > + void (*trace_fn)(uint32_t, uint32_t, > + char const *)) > +{ > + int i; > + int len = scsi_cdb_length(buf); > + char *line_buffer, *p; > + > + line_buffer = g_malloc(len * 5 + 1); > + > + for (i = 0, p = line_buffer; i < len; i++) { > + p += sprintf(p, " 0x%02x", buf[i]); > + } > + trace_fn(lun, tag, line_buffer); > + > + g_free(line_buffer); > +} > + > static SCSIRequest *scsi_new_request(SCSIDevice *d, uint32_t tag, uint32_t lun, > uint8_t *buf, void *hba_private) > { > @@ -2512,16 +2518,9 @@ static SCSIRequest *scsi_new_request(SCSIDevice *d, uint32_t tag, uint32_t lun, > } > req = scsi_req_alloc(ops, &s->qdev, tag, lun, hba_private); > > -#ifdef DEBUG_SCSI > - DPRINTF("Command: lun=%d tag=0x%x data=0x%02x", lun, tag, buf[0]); > - { > - int i; > - for (i = 1; i < scsi_cdb_length(buf); i++) { > - printf(" 0x%02x", buf[i]); > - } > - printf("\n"); > + if (trace_event_get_state_backends(TRACE_SCSI_DISK_NEW_REQUEST)) { > + scsi_disk_new_request_dump(lun, tag, buf, trace_scsi_disk_new_request); TIL about trace_event_get_state_backends(), I'll use it to clean other hexdump traces, thanks :) Reviewed-by: Philippe Mathieu-Daudé <philmd@redhat.com> Tested-by: Philippe Mathieu-Daudé <philmd@redhat.com> > } > -#endif > > return req; > } > diff --git a/hw/scsi/trace-events b/hw/scsi/trace-events > index 0fb6a99616..e9625f790c 100644 > --- a/hw/scsi/trace-events > +++ b/hw/scsi/trace-events > @@ -291,3 +291,32 @@ lsi_execute_script_stop(void) "SCRIPTS execution stopped" > lsi_awoken(void) "Woken by SIGP" > lsi_reg_read(const char *name, int offset, uint8_t ret) "Read reg %s 0x%x = 0x%02x" > lsi_reg_write(const char *name, int offset, uint8_t val) "Write reg %s 0x%x = 0x%02x" > + > +# hw/scsi/scsi-disk.c > +scsi_disk_check_condition(uint32_t tag, uint8_t key, uint8_t asc, uint8_t ascq) "Command complete tag=0x%x sense=%d/%d/%d" > +scsi_disk_read_complete(uint32_t tag, size_t size) "Data ready tag=0x%x len=%zd" > +scsi_disk_read_data_count(uint32_t sector_count) "Read sector_count=%d" > +scsi_disk_read_data_invalid(void) "Data transfer direction invalid" > +scsi_disk_write_complete_noio(uint32_t tag, size_t size) "Write complete tag=0x%x more=%zd" > +scsi_disk_write_data_invalid(void) "Data transfer direction invalid" > +scsi_disk_emulate_vpd_page_00(size_t xfer) "Inquiry EVPD[Supported pages] buffer size %zd" > +scsi_disk_emulate_vpd_page_80_not_supported(void) "Inquiry (EVPD[Serial number] not supported" > +scsi_disk_emulate_vpd_page_80(size_t xfer) "Inquiry EVPD[Serial number] buffer size %zd" > +scsi_disk_emulate_vpd_page_83(size_t xfer) "Inquiry EVPD[Device identification] buffer size %zd" > +scsi_disk_emulate_vpd_page_b0_not_supported(void) "Inquiry (EVPD[Block limits] not supported for CDROM" > +scsi_disk_emulate_mode_sense(int cmd, int page, size_t xfer, int control) "Mode Sense(%d) (page %d, xfer %zd, page_control %d)" > +scsi_disk_emulate_read_toc(int start_track, int format, int msf) "Read TOC (track %d format %d msf %d)" > +scsi_disk_emulate_read_data(int buflen) "Read buf_len=%d" > +scsi_disk_emulate_write_data(int buflen) "Write buf_len=%d" > +scsi_disk_emulate_command_SAI_16(void) "SAI READ CAPACITY(16)" > +scsi_disk_emulate_command_SAI_unsupported(void) "Unsupported Service Action In" > +scsi_disk_emulate_command_SEEK_10(uint64_t lba) "Seek(10) (sector %" PRId64 ")" > +scsi_disk_emulate_command_MODE_SELECT(size_t xfer) "Mode Select(6) (len %zd)" > +scsi_disk_emulate_command_MODE_SELECT_10(size_t xfer) "Mode Select(10) (len %zd)" > +scsi_disk_emulate_command_UNMAP(size_t xfer) "Unmap (len %zd)" > +scsi_disk_emulate_command_VERIFY(int bytchk) "Verify (bytchk %d)" > +scsi_disk_emulate_command_WRITE_SAME(int cmd, size_t xfer) "WRITE SAME %d (len %zd)" > +scsi_disk_emulate_command_UNKNOWN(int cmd, const char *name) "Unknown SCSI command (0x%2.2x=%s)" > +scsi_disk_dma_command_READ(uint64_t lba, uint32_t len) "Read (sector %" PRId64 ", count %u)" > +scsi_disk_dma_command_WRITE(const char *cmd, uint64_t lba, int len) "Write %s(sector %" PRId64 ", count %u)" > +scsi_disk_new_request(uint32_t lun, uint32_t tag, const char *line) "Command: lun=%d tag=0x%x data=%s" >
On 07/12/2018 16:37, Philippe Mathieu-Daudé wrote: > On 12/7/18 2:17 PM, Laurent Vivier wrote: >> Signed-off-by: Laurent Vivier <lvivier@redhat.com> >> --- >> hw/scsi/scsi-disk.c | 105 +++++++++++++++++++++---------------------- >> hw/scsi/trace-events | 29 ++++++++++++ >> 2 files changed, 81 insertions(+), 53 deletions(-) ... >> >> +static void scsi_disk_new_request_dump(uint32_t lun, uint32_t tag, uint8_t *buf, >> + void (*trace_fn)(uint32_t, uint32_t, >> + char const *)) >> +{ >> + int i; >> + int len = scsi_cdb_length(buf); >> + char *line_buffer, *p; >> + >> + line_buffer = g_malloc(len * 5 + 1); >> + >> + for (i = 0, p = line_buffer; i < len; i++) { >> + p += sprintf(p, " 0x%02x", buf[i]); >> + } >> + trace_fn(lun, tag, line_buffer); >> + >> + g_free(line_buffer); >> +} >> + >> static SCSIRequest *scsi_new_request(SCSIDevice *d, uint32_t tag, uint32_t lun, >> uint8_t *buf, void *hba_private) >> { >> @@ -2512,16 +2518,9 @@ static SCSIRequest *scsi_new_request(SCSIDevice *d, uint32_t tag, uint32_t lun, >> } >> req = scsi_req_alloc(ops, &s->qdev, tag, lun, hba_private); >> >> -#ifdef DEBUG_SCSI >> - DPRINTF("Command: lun=%d tag=0x%x data=0x%02x", lun, tag, buf[0]); >> - { >> - int i; >> - for (i = 1; i < scsi_cdb_length(buf); i++) { >> - printf(" 0x%02x", buf[i]); >> - } >> - printf("\n"); >> + if (trace_event_get_state_backends(TRACE_SCSI_DISK_NEW_REQUEST)) { >> + scsi_disk_new_request_dump(lun, tag, buf, trace_scsi_disk_new_request); > > TIL about trace_event_get_state_backends(), I'll use it to clean other > hexdump traces, thanks :) I've copied that from gdbstub.c where there is an hexdump() function using it. I'm going to send a v2 of this patch, because I think it is not needed in this case to pass the function in the parameters. Thanks, Laurent
On 12/7/18 10:37 AM, Laurent Vivier wrote: > On 07/12/2018 16:37, Philippe Mathieu-Daudé wrote: >> On 12/7/18 2:17 PM, Laurent Vivier wrote: >>> Signed-off-by: Laurent Vivier <lvivier@redhat.com> >>> --- >> >> TIL about trace_event_get_state_backends(), I'll use it to clean other >> hexdump traces, thanks :) > > I've copied that from gdbstub.c where there is an hexdump() function > using it. > > I'm going to send a v2 of this patch, because I think it is not needed > in this case to pass the function in the parameters. Don't forget the 0/2 cover letter in that case (all series of >1 patch are easier to process with a cover letter, even if it is just 2 patches)
On 12/7/18 7:17 AM, Laurent Vivier wrote: > Signed-off-by: Laurent Vivier <lvivier@redhat.com> > --- > hw/scsi/scsi-disk.c | 105 +++++++++++++++++++++---------------------- > hw/scsi/trace-events | 29 ++++++++++++ > 2 files changed, 81 insertions(+), 53 deletions(-) > > diff --git a/hw/scsi/scsi-disk.c b/hw/scsi/scsi-disk.c > index 0e9027c8f3..29e541efdb 100644 > --- a/hw/scsi/scsi-disk.c > +++ b/hw/scsi/scsi-disk.c > @@ -19,15 +19,6 @@ > * the host adapter emulator. > */ > > -//#define DEBUG_SCSI > - > -#ifdef DEBUG_SCSI > -#define DPRINTF(fmt, ...) \ > -do { printf("scsi-disk: " fmt , ## __VA_ARGS__); } while (0) > -#else > -#define DPRINTF(fmt, ...) do {} while(0) > -#endif > - Yay for getting rid of yet another bit-rottable debug statement.
On 07/12/18 14:17, Laurent Vivier wrote: > Signed-off-by: Laurent Vivier <lvivier@redhat.com> > --- > hw/scsi/scsi-disk.c | 105 +++++++++++++++++++++---------------------- > hw/scsi/trace-events | 29 ++++++++++++ > 2 files changed, 81 insertions(+), 53 deletions(-) > > diff --git a/hw/scsi/scsi-disk.c b/hw/scsi/scsi-disk.c > index 0e9027c8f3..29e541efdb 100644 > --- a/hw/scsi/scsi-disk.c > +++ b/hw/scsi/scsi-disk.c > @@ -19,15 +19,6 @@ > * the host adapter emulator. > */ > > -//#define DEBUG_SCSI > - > -#ifdef DEBUG_SCSI > -#define DPRINTF(fmt, ...) \ > -do { printf("scsi-disk: " fmt , ## __VA_ARGS__); } while (0) > -#else > -#define DPRINTF(fmt, ...) do {} while(0) > -#endif > - > #include "qemu/osdep.h" > #include "qemu/units.h" > #include "qapi/error.h" > @@ -41,6 +32,7 @@ do { printf("scsi-disk: " fmt , ## __VA_ARGS__); } while (0) > #include "hw/block/block.h" > #include "sysemu/dma.h" > #include "qemu/cutils.h" > +#include "trace.h" > > #ifdef __linux > #include <scsi/sg.h> > @@ -128,8 +120,8 @@ static void scsi_free_request(SCSIRequest *req) > /* Helper function for command completion with sense. */ > static void scsi_check_condition(SCSIDiskReq *r, SCSISense sense) > { > - DPRINTF("Command complete tag=0x%x sense=%d/%d/%d\n", > - r->req.tag, sense.key, sense.asc, sense.ascq); > + trace_scsi_disk_check_condition(r->req.tag, sense.key, sense.asc, > + sense.ascq); > scsi_req_build_sense(&r->req, sense); > scsi_req_complete(&r->req, CHECK_CONDITION); > } > @@ -317,7 +309,7 @@ static void scsi_read_complete(void * opaque, int ret) > } > > block_acct_done(blk_get_stats(s->qdev.conf.blk), &r->acct); > - DPRINTF("Data ready tag=0x%x len=%zd\n", r->req.tag, r->qiov.size); > + trace_scsi_disk_read_complete(r->req.tag, r->qiov.size); > > n = r->qiov.size / 512; > r->sector += n; > @@ -388,7 +380,7 @@ static void scsi_read_data(SCSIRequest *req) > SCSIDiskState *s = DO_UPCAST(SCSIDiskState, qdev, r->req.dev); > bool first; > > - DPRINTF("Read sector_count=%d\n", r->sector_count); > + trace_scsi_disk_read_data_count(r->sector_count); > if (r->sector_count == 0) { > /* This also clears the sense buffer for REQUEST SENSE. */ > scsi_req_complete(&r->req, GOOD); > @@ -401,7 +393,7 @@ static void scsi_read_data(SCSIRequest *req) > /* The request is used as the AIO opaque value, so add a ref. */ > scsi_req_ref(&r->req); > if (r->req.cmd.mode == SCSI_XFER_TO_DEV) { > - DPRINTF("Data transfer direction invalid\n"); > + trace_scsi_disk_read_data_invalid(); > scsi_read_complete(r, -EINVAL); > return; > } > @@ -502,7 +494,7 @@ static void scsi_write_complete_noio(SCSIDiskReq *r, int ret) > return; > } else { > scsi_init_iovec(r, SCSI_DMA_BUF_SIZE); > - DPRINTF("Write complete tag=0x%x more=%zd\n", r->req.tag, r->qiov.size); > + trace_scsi_disk_write_complete_noio(r->req.tag, r->qiov.size); > scsi_req_data(&r->req, r->qiov.size); > } > > @@ -540,7 +532,7 @@ static void scsi_write_data(SCSIRequest *req) > /* The request is used as the AIO opaque value, so add a ref. */ > scsi_req_ref(&r->req); > if (r->req.cmd.mode != SCSI_XFER_TO_DEV) { > - DPRINTF("Data transfer direction invalid\n"); > + trace_scsi_disk_write_data_invalid(); > scsi_write_complete_noio(r, -EINVAL); > return; > } > @@ -605,8 +597,7 @@ static int scsi_disk_emulate_vpd_page(SCSIRequest *req, uint8_t *outbuf) > switch (page_code) { > case 0x00: /* Supported page codes, mandatory */ > { > - DPRINTF("Inquiry EVPD[Supported pages] " > - "buffer size %zd\n", req->cmd.xfer); > + trace_scsi_disk_emulate_vpd_page_00(req->cmd.xfer); > outbuf[buflen++] = 0x00; /* list of supported pages (this page) */ > if (s->serial) { > outbuf[buflen++] = 0x80; /* unit serial number */ > @@ -624,7 +615,7 @@ static int scsi_disk_emulate_vpd_page(SCSIRequest *req, uint8_t *outbuf) > int l; > > if (!s->serial) { > - DPRINTF("Inquiry (EVPD[Serial number] not supported\n"); > + trace_scsi_disk_emulate_vpd_page_80_not_supported(); > return -1; > } > > @@ -633,8 +624,7 @@ static int scsi_disk_emulate_vpd_page(SCSIRequest *req, uint8_t *outbuf) > l = 36; > } > > - DPRINTF("Inquiry EVPD[Serial number] " > - "buffer size %zd\n", req->cmd.xfer); > + trace_scsi_disk_emulate_vpd_page_80(req->cmd.xfer); > memcpy(outbuf + buflen, s->serial, l); > buflen += l; > break; > @@ -649,8 +639,7 @@ static int scsi_disk_emulate_vpd_page(SCSIRequest *req, uint8_t *outbuf) > if (id_len > max_len) { > id_len = max_len; > } > - DPRINTF("Inquiry EVPD[Device identification] " > - "buffer size %zd\n", req->cmd.xfer); > + trace_scsi_disk_emulate_vpd_page_83(req->cmd.xfer); > > outbuf[buflen++] = 0x2; /* ASCII */ > outbuf[buflen++] = 0; /* not officially assigned */ > @@ -695,8 +684,7 @@ static int scsi_disk_emulate_vpd_page(SCSIRequest *req, uint8_t *outbuf) > SCSIBlockLimits bl = {}; > > if (s->qdev.type == TYPE_ROM) { > - DPRINTF("Inquiry (EVPD[%02X] not supported for CDROM\n", > - page_code); > + trace_scsi_disk_emulate_vpd_page_b0_not_supported(); > return -1; > } > bl.wsnz = 1; > @@ -1243,8 +1231,9 @@ static int scsi_disk_emulate_mode_sense(SCSIDiskReq *r, uint8_t *outbuf) > dbd = (r->req.cmd.buf[1] & 0x8) != 0; > page = r->req.cmd.buf[2] & 0x3f; > page_control = (r->req.cmd.buf[2] & 0xc0) >> 6; > - DPRINTF("Mode Sense(%d) (page %d, xfer %zd, page_control %d)\n", > - (r->req.cmd.buf[0] == MODE_SENSE) ? 6 : 10, page, r->req.cmd.xfer, page_control); > + > + trace_scsi_disk_emulate_mode_sense((r->req.cmd.buf[0] == MODE_SENSE) ? 6 : > + 10, page, r->req.cmd.xfer, page_control); > memset(outbuf, 0, r->req.cmd.xfer); > p = outbuf; > > @@ -1336,7 +1325,7 @@ static int scsi_disk_emulate_read_toc(SCSIRequest *req, uint8_t *outbuf) > format = req->cmd.buf[2] & 0xf; > start_track = req->cmd.buf[6]; > blk_get_geometry(s->qdev.conf.blk, &nb_sectors); > - DPRINTF("Read TOC (track %d format %d msf %d)\n", start_track, format, msf >> 1); > + trace_scsi_disk_emulate_read_toc(start_track, format, msf >> 1); > nb_sectors /= s->qdev.blocksize / 512; > switch (format) { > case 0: > @@ -1395,7 +1384,7 @@ static void scsi_disk_emulate_read_data(SCSIRequest *req) > int buflen = r->iov.iov_len; > > if (buflen) { > - DPRINTF("Read buf_len=%d\n", buflen); > + trace_scsi_disk_emulate_read_data(buflen); > r->iov.iov_len = 0; > r->started = true; > scsi_req_data(&r->req, buflen); > @@ -1814,7 +1803,7 @@ static void scsi_disk_emulate_write_data(SCSIRequest *req) > > if (r->iov.iov_len) { > int buflen = r->iov.iov_len; > - DPRINTF("Write buf_len=%d\n", buflen); > + trace_scsi_disk_emulate_write_data(buflen); > r->iov.iov_len = 0; > scsi_req_data(&r->req, buflen); > return; > @@ -2023,7 +2012,7 @@ static int32_t scsi_disk_emulate_command(SCSIRequest *req, uint8_t *buf) > case SERVICE_ACTION_IN_16: > /* Service Action In subcommands. */ > if ((req->cmd.buf[1] & 31) == SAI_READ_CAPACITY_16) { > - DPRINTF("SAI READ CAPACITY(16)\n"); > + trace_scsi_disk_emulate_command_SAI_16(); > memset(outbuf, 0, req->cmd.xfer); > blk_get_geometry(s->qdev.conf.blk, &nb_sectors); > if (!nb_sectors) { > @@ -2061,7 +2050,7 @@ static int32_t scsi_disk_emulate_command(SCSIRequest *req, uint8_t *buf) > /* Protection, exponent and lowest lba field left blank. */ > break; > } > - DPRINTF("Unsupported Service Action In\n"); > + trace_scsi_disk_emulate_command_SAI_unsupported(); > goto illegal_request; > case SYNCHRONIZE_CACHE: > /* The request is used as the AIO opaque value, so add a ref. */ > @@ -2071,37 +2060,36 @@ static int32_t scsi_disk_emulate_command(SCSIRequest *req, uint8_t *buf) > r->req.aiocb = blk_aio_flush(s->qdev.conf.blk, scsi_aio_complete, r); > return 0; > case SEEK_10: > - DPRINTF("Seek(10) (sector %" PRId64 ")\n", r->req.cmd.lba); > + trace_scsi_disk_emulate_command_SEEK_10(r->req.cmd.lba); > if (r->req.cmd.lba > s->qdev.max_lba) { > goto illegal_lba; > } > break; > case MODE_SELECT: > - DPRINTF("Mode Select(6) (len %lu)\n", (unsigned long)r->req.cmd.xfer); > + trace_scsi_disk_emulate_command_MODE_SELECT(r->req.cmd.xfer); > break; > case MODE_SELECT_10: > - DPRINTF("Mode Select(10) (len %lu)\n", (unsigned long)r->req.cmd.xfer); > + trace_scsi_disk_emulate_command_MODE_SELECT_10(r->req.cmd.xfer); > break; > case UNMAP: > - DPRINTF("Unmap (len %lu)\n", (unsigned long)r->req.cmd.xfer); > + trace_scsi_disk_emulate_command_UNMAP(r->req.cmd.xfer); > break; > case VERIFY_10: > case VERIFY_12: > case VERIFY_16: > - DPRINTF("Verify (bytchk %d)\n", (req->cmd.buf[1] >> 1) & 3); > + trace_scsi_disk_emulate_command_VERIFY((req->cmd.buf[1] >> 1) & 3); > if (req->cmd.buf[1] & 6) { > goto illegal_request; > } > break; > case WRITE_SAME_10: > case WRITE_SAME_16: > - DPRINTF("WRITE SAME %d (len %lu)\n", > - req->cmd.buf[0] == WRITE_SAME_10 ? 10 : 16, > - (unsigned long)r->req.cmd.xfer); > + trace_scsi_disk_emulate_command_WRITE_SAME( > + req->cmd.buf[0] == WRITE_SAME_10 ? 10 : 16, r->req.cmd.xfer); > break; > default: > - DPRINTF("Unknown SCSI command (%2.2x=%s)\n", buf[0], > - scsi_command_name(buf[0])); > + trace_scsi_disk_emulate_command_UNKNOWN(buf[0], > + scsi_command_name(buf[0])); > scsi_check_condition(r, SENSE_CODE(INVALID_OPCODE)); > return 0; > } > @@ -2154,7 +2142,7 @@ static int32_t scsi_disk_dma_command(SCSIRequest *req, uint8_t *buf) > case READ_10: > case READ_12: > case READ_16: > - DPRINTF("Read (sector %" PRId64 ", count %u)\n", r->req.cmd.lba, len); > + trace_scsi_disk_dma_command_READ(r->req.cmd.lba, len); > /* Protection information is not supported. For SCSI versions 2 and > * older (as determined by snooping the guest's INQUIRY commands), > * there is no RD/WR/VRPROTECT, so skip this check in these versions. > @@ -2179,7 +2167,7 @@ static int32_t scsi_disk_dma_command(SCSIRequest *req, uint8_t *buf) > scsi_check_condition(r, SENSE_CODE(WRITE_PROTECTED)); > return 0; > } > - DPRINTF("Write %s(sector %" PRId64 ", count %u)\n", > + trace_scsi_disk_dma_command_WRITE( > (command & 0xe) == 0xe ? "And Verify " : "", > r->req.cmd.lba, len); > /* fall through */ > @@ -2497,6 +2485,24 @@ static const SCSIReqOps *const scsi_disk_reqops_dispatch[256] = { > [WRITE_VERIFY_16] = &scsi_disk_dma_reqops, > }; > > +static void scsi_disk_new_request_dump(uint32_t lun, uint32_t tag, uint8_t *buf, > + void (*trace_fn)(uint32_t, uint32_t, > + char const *)) > +{ > + int i; > + int len = scsi_cdb_length(buf); > + char *line_buffer, *p; > + > + line_buffer = g_malloc(len * 5 + 1); > + > + for (i = 0, p = line_buffer; i < len; i++) { > + p += sprintf(p, " 0x%02x", buf[i]); > + } > + trace_fn(lun, tag, line_buffer); > + > + g_free(line_buffer); > +} > + > static SCSIRequest *scsi_new_request(SCSIDevice *d, uint32_t tag, uint32_t lun, > uint8_t *buf, void *hba_private) > { > @@ -2512,16 +2518,9 @@ static SCSIRequest *scsi_new_request(SCSIDevice *d, uint32_t tag, uint32_t lun, > } > req = scsi_req_alloc(ops, &s->qdev, tag, lun, hba_private); > > -#ifdef DEBUG_SCSI > - DPRINTF("Command: lun=%d tag=0x%x data=0x%02x", lun, tag, buf[0]); > - { > - int i; > - for (i = 1; i < scsi_cdb_length(buf); i++) { > - printf(" 0x%02x", buf[i]); > - } > - printf("\n"); > + if (trace_event_get_state_backends(TRACE_SCSI_DISK_NEW_REQUEST)) { > + scsi_disk_new_request_dump(lun, tag, buf, trace_scsi_disk_new_request); > } > -#endif > > return req; > } > diff --git a/hw/scsi/trace-events b/hw/scsi/trace-events > index 0fb6a99616..e9625f790c 100644 > --- a/hw/scsi/trace-events > +++ b/hw/scsi/trace-events > @@ -291,3 +291,32 @@ lsi_execute_script_stop(void) "SCRIPTS execution stopped" > lsi_awoken(void) "Woken by SIGP" > lsi_reg_read(const char *name, int offset, uint8_t ret) "Read reg %s 0x%x = 0x%02x" > lsi_reg_write(const char *name, int offset, uint8_t val) "Write reg %s 0x%x = 0x%02x" > + > +# hw/scsi/scsi-disk.c > +scsi_disk_check_condition(uint32_t tag, uint8_t key, uint8_t asc, uint8_t ascq) "Command complete tag=0x%x sense=%d/%d/%d" > +scsi_disk_read_complete(uint32_t tag, size_t size) "Data ready tag=0x%x len=%zd" > +scsi_disk_read_data_count(uint32_t sector_count) "Read sector_count=%d" > +scsi_disk_read_data_invalid(void) "Data transfer direction invalid" > +scsi_disk_write_complete_noio(uint32_t tag, size_t size) "Write complete tag=0x%x more=%zd" > +scsi_disk_write_data_invalid(void) "Data transfer direction invalid" > +scsi_disk_emulate_vpd_page_00(size_t xfer) "Inquiry EVPD[Supported pages] buffer size %zd" > +scsi_disk_emulate_vpd_page_80_not_supported(void) "Inquiry (EVPD[Serial number] not supported" > +scsi_disk_emulate_vpd_page_80(size_t xfer) "Inquiry EVPD[Serial number] buffer size %zd" > +scsi_disk_emulate_vpd_page_83(size_t xfer) "Inquiry EVPD[Device identification] buffer size %zd" > +scsi_disk_emulate_vpd_page_b0_not_supported(void) "Inquiry (EVPD[Block limits] not supported for CDROM" > +scsi_disk_emulate_mode_sense(int cmd, int page, size_t xfer, int control) "Mode Sense(%d) (page %d, xfer %zd, page_control %d)" > +scsi_disk_emulate_read_toc(int start_track, int format, int msf) "Read TOC (track %d format %d msf %d)" > +scsi_disk_emulate_read_data(int buflen) "Read buf_len=%d" > +scsi_disk_emulate_write_data(int buflen) "Write buf_len=%d" > +scsi_disk_emulate_command_SAI_16(void) "SAI READ CAPACITY(16)" > +scsi_disk_emulate_command_SAI_unsupported(void) "Unsupported Service Action In" > +scsi_disk_emulate_command_SEEK_10(uint64_t lba) "Seek(10) (sector %" PRId64 ")" > +scsi_disk_emulate_command_MODE_SELECT(size_t xfer) "Mode Select(6) (len %zd)" > +scsi_disk_emulate_command_MODE_SELECT_10(size_t xfer) "Mode Select(10) (len %zd)" > +scsi_disk_emulate_command_UNMAP(size_t xfer) "Unmap (len %zd)" > +scsi_disk_emulate_command_VERIFY(int bytchk) "Verify (bytchk %d)" > +scsi_disk_emulate_command_WRITE_SAME(int cmd, size_t xfer) "WRITE SAME %d (len %zd)" > +scsi_disk_emulate_command_UNKNOWN(int cmd, const char *name) "Unknown SCSI command (0x%2.2x=%s)" > +scsi_disk_dma_command_READ(uint64_t lba, uint32_t len) "Read (sector %" PRId64 ", count %u)" > +scsi_disk_dma_command_WRITE(const char *cmd, uint64_t lba, int len) "Write %s(sector %" PRId64 ", count %u)" > +scsi_disk_new_request(uint32_t lun, uint32_t tag, const char *line) "Command: lun=%d tag=0x%x data=%s" > Queued both, thanks. Paolo
On 07/12/18 17:37, Laurent Vivier wrote: >> TIL about trace_event_get_state_backends(), I'll use it to clean other >> hexdump traces, thanks :) > I've copied that from gdbstub.c where there is an hexdump() function > using it. > > I'm going to send a v2 of this patch, because I think it is not needed > in this case to pass the function in the parameters. I think it's better like this, you'd have to free the buffer in the caller and that's also ugly. Paolo
On 19/12/18 22:30, Paolo Bonzini wrote: > On 07/12/18 17:37, Laurent Vivier wrote: >>> TIL about trace_event_get_state_backends(), I'll use it to clean other >>> hexdump traces, thanks :) >> I've copied that from gdbstub.c where there is an hexdump() function >> using it. >> >> I'm going to send a v2 of this patch, because I think it is not needed >> in this case to pass the function in the parameters. > > I think it's better like this, you'd have to free the buffer in the > caller and that's also ugly. Nevermind, I diffed v1 and v2 and I see what I mean. I queued v2. Paolo
diff --git a/hw/scsi/scsi-disk.c b/hw/scsi/scsi-disk.c index 0e9027c8f3..29e541efdb 100644 --- a/hw/scsi/scsi-disk.c +++ b/hw/scsi/scsi-disk.c @@ -19,15 +19,6 @@ * the host adapter emulator. */ -//#define DEBUG_SCSI - -#ifdef DEBUG_SCSI -#define DPRINTF(fmt, ...) \ -do { printf("scsi-disk: " fmt , ## __VA_ARGS__); } while (0) -#else -#define DPRINTF(fmt, ...) do {} while(0) -#endif - #include "qemu/osdep.h" #include "qemu/units.h" #include "qapi/error.h" @@ -41,6 +32,7 @@ do { printf("scsi-disk: " fmt , ## __VA_ARGS__); } while (0) #include "hw/block/block.h" #include "sysemu/dma.h" #include "qemu/cutils.h" +#include "trace.h" #ifdef __linux #include <scsi/sg.h> @@ -128,8 +120,8 @@ static void scsi_free_request(SCSIRequest *req) /* Helper function for command completion with sense. */ static void scsi_check_condition(SCSIDiskReq *r, SCSISense sense) { - DPRINTF("Command complete tag=0x%x sense=%d/%d/%d\n", - r->req.tag, sense.key, sense.asc, sense.ascq); + trace_scsi_disk_check_condition(r->req.tag, sense.key, sense.asc, + sense.ascq); scsi_req_build_sense(&r->req, sense); scsi_req_complete(&r->req, CHECK_CONDITION); } @@ -317,7 +309,7 @@ static void scsi_read_complete(void * opaque, int ret) } block_acct_done(blk_get_stats(s->qdev.conf.blk), &r->acct); - DPRINTF("Data ready tag=0x%x len=%zd\n", r->req.tag, r->qiov.size); + trace_scsi_disk_read_complete(r->req.tag, r->qiov.size); n = r->qiov.size / 512; r->sector += n; @@ -388,7 +380,7 @@ static void scsi_read_data(SCSIRequest *req) SCSIDiskState *s = DO_UPCAST(SCSIDiskState, qdev, r->req.dev); bool first; - DPRINTF("Read sector_count=%d\n", r->sector_count); + trace_scsi_disk_read_data_count(r->sector_count); if (r->sector_count == 0) { /* This also clears the sense buffer for REQUEST SENSE. */ scsi_req_complete(&r->req, GOOD); @@ -401,7 +393,7 @@ static void scsi_read_data(SCSIRequest *req) /* The request is used as the AIO opaque value, so add a ref. */ scsi_req_ref(&r->req); if (r->req.cmd.mode == SCSI_XFER_TO_DEV) { - DPRINTF("Data transfer direction invalid\n"); + trace_scsi_disk_read_data_invalid(); scsi_read_complete(r, -EINVAL); return; } @@ -502,7 +494,7 @@ static void scsi_write_complete_noio(SCSIDiskReq *r, int ret) return; } else { scsi_init_iovec(r, SCSI_DMA_BUF_SIZE); - DPRINTF("Write complete tag=0x%x more=%zd\n", r->req.tag, r->qiov.size); + trace_scsi_disk_write_complete_noio(r->req.tag, r->qiov.size); scsi_req_data(&r->req, r->qiov.size); } @@ -540,7 +532,7 @@ static void scsi_write_data(SCSIRequest *req) /* The request is used as the AIO opaque value, so add a ref. */ scsi_req_ref(&r->req); if (r->req.cmd.mode != SCSI_XFER_TO_DEV) { - DPRINTF("Data transfer direction invalid\n"); + trace_scsi_disk_write_data_invalid(); scsi_write_complete_noio(r, -EINVAL); return; } @@ -605,8 +597,7 @@ static int scsi_disk_emulate_vpd_page(SCSIRequest *req, uint8_t *outbuf) switch (page_code) { case 0x00: /* Supported page codes, mandatory */ { - DPRINTF("Inquiry EVPD[Supported pages] " - "buffer size %zd\n", req->cmd.xfer); + trace_scsi_disk_emulate_vpd_page_00(req->cmd.xfer); outbuf[buflen++] = 0x00; /* list of supported pages (this page) */ if (s->serial) { outbuf[buflen++] = 0x80; /* unit serial number */ @@ -624,7 +615,7 @@ static int scsi_disk_emulate_vpd_page(SCSIRequest *req, uint8_t *outbuf) int l; if (!s->serial) { - DPRINTF("Inquiry (EVPD[Serial number] not supported\n"); + trace_scsi_disk_emulate_vpd_page_80_not_supported(); return -1; } @@ -633,8 +624,7 @@ static int scsi_disk_emulate_vpd_page(SCSIRequest *req, uint8_t *outbuf) l = 36; } - DPRINTF("Inquiry EVPD[Serial number] " - "buffer size %zd\n", req->cmd.xfer); + trace_scsi_disk_emulate_vpd_page_80(req->cmd.xfer); memcpy(outbuf + buflen, s->serial, l); buflen += l; break; @@ -649,8 +639,7 @@ static int scsi_disk_emulate_vpd_page(SCSIRequest *req, uint8_t *outbuf) if (id_len > max_len) { id_len = max_len; } - DPRINTF("Inquiry EVPD[Device identification] " - "buffer size %zd\n", req->cmd.xfer); + trace_scsi_disk_emulate_vpd_page_83(req->cmd.xfer); outbuf[buflen++] = 0x2; /* ASCII */ outbuf[buflen++] = 0; /* not officially assigned */ @@ -695,8 +684,7 @@ static int scsi_disk_emulate_vpd_page(SCSIRequest *req, uint8_t *outbuf) SCSIBlockLimits bl = {}; if (s->qdev.type == TYPE_ROM) { - DPRINTF("Inquiry (EVPD[%02X] not supported for CDROM\n", - page_code); + trace_scsi_disk_emulate_vpd_page_b0_not_supported(); return -1; } bl.wsnz = 1; @@ -1243,8 +1231,9 @@ static int scsi_disk_emulate_mode_sense(SCSIDiskReq *r, uint8_t *outbuf) dbd = (r->req.cmd.buf[1] & 0x8) != 0; page = r->req.cmd.buf[2] & 0x3f; page_control = (r->req.cmd.buf[2] & 0xc0) >> 6; - DPRINTF("Mode Sense(%d) (page %d, xfer %zd, page_control %d)\n", - (r->req.cmd.buf[0] == MODE_SENSE) ? 6 : 10, page, r->req.cmd.xfer, page_control); + + trace_scsi_disk_emulate_mode_sense((r->req.cmd.buf[0] == MODE_SENSE) ? 6 : + 10, page, r->req.cmd.xfer, page_control); memset(outbuf, 0, r->req.cmd.xfer); p = outbuf; @@ -1336,7 +1325,7 @@ static int scsi_disk_emulate_read_toc(SCSIRequest *req, uint8_t *outbuf) format = req->cmd.buf[2] & 0xf; start_track = req->cmd.buf[6]; blk_get_geometry(s->qdev.conf.blk, &nb_sectors); - DPRINTF("Read TOC (track %d format %d msf %d)\n", start_track, format, msf >> 1); + trace_scsi_disk_emulate_read_toc(start_track, format, msf >> 1); nb_sectors /= s->qdev.blocksize / 512; switch (format) { case 0: @@ -1395,7 +1384,7 @@ static void scsi_disk_emulate_read_data(SCSIRequest *req) int buflen = r->iov.iov_len; if (buflen) { - DPRINTF("Read buf_len=%d\n", buflen); + trace_scsi_disk_emulate_read_data(buflen); r->iov.iov_len = 0; r->started = true; scsi_req_data(&r->req, buflen); @@ -1814,7 +1803,7 @@ static void scsi_disk_emulate_write_data(SCSIRequest *req) if (r->iov.iov_len) { int buflen = r->iov.iov_len; - DPRINTF("Write buf_len=%d\n", buflen); + trace_scsi_disk_emulate_write_data(buflen); r->iov.iov_len = 0; scsi_req_data(&r->req, buflen); return; @@ -2023,7 +2012,7 @@ static int32_t scsi_disk_emulate_command(SCSIRequest *req, uint8_t *buf) case SERVICE_ACTION_IN_16: /* Service Action In subcommands. */ if ((req->cmd.buf[1] & 31) == SAI_READ_CAPACITY_16) { - DPRINTF("SAI READ CAPACITY(16)\n"); + trace_scsi_disk_emulate_command_SAI_16(); memset(outbuf, 0, req->cmd.xfer); blk_get_geometry(s->qdev.conf.blk, &nb_sectors); if (!nb_sectors) { @@ -2061,7 +2050,7 @@ static int32_t scsi_disk_emulate_command(SCSIRequest *req, uint8_t *buf) /* Protection, exponent and lowest lba field left blank. */ break; } - DPRINTF("Unsupported Service Action In\n"); + trace_scsi_disk_emulate_command_SAI_unsupported(); goto illegal_request; case SYNCHRONIZE_CACHE: /* The request is used as the AIO opaque value, so add a ref. */ @@ -2071,37 +2060,36 @@ static int32_t scsi_disk_emulate_command(SCSIRequest *req, uint8_t *buf) r->req.aiocb = blk_aio_flush(s->qdev.conf.blk, scsi_aio_complete, r); return 0; case SEEK_10: - DPRINTF("Seek(10) (sector %" PRId64 ")\n", r->req.cmd.lba); + trace_scsi_disk_emulate_command_SEEK_10(r->req.cmd.lba); if (r->req.cmd.lba > s->qdev.max_lba) { goto illegal_lba; } break; case MODE_SELECT: - DPRINTF("Mode Select(6) (len %lu)\n", (unsigned long)r->req.cmd.xfer); + trace_scsi_disk_emulate_command_MODE_SELECT(r->req.cmd.xfer); break; case MODE_SELECT_10: - DPRINTF("Mode Select(10) (len %lu)\n", (unsigned long)r->req.cmd.xfer); + trace_scsi_disk_emulate_command_MODE_SELECT_10(r->req.cmd.xfer); break; case UNMAP: - DPRINTF("Unmap (len %lu)\n", (unsigned long)r->req.cmd.xfer); + trace_scsi_disk_emulate_command_UNMAP(r->req.cmd.xfer); break; case VERIFY_10: case VERIFY_12: case VERIFY_16: - DPRINTF("Verify (bytchk %d)\n", (req->cmd.buf[1] >> 1) & 3); + trace_scsi_disk_emulate_command_VERIFY((req->cmd.buf[1] >> 1) & 3); if (req->cmd.buf[1] & 6) { goto illegal_request; } break; case WRITE_SAME_10: case WRITE_SAME_16: - DPRINTF("WRITE SAME %d (len %lu)\n", - req->cmd.buf[0] == WRITE_SAME_10 ? 10 : 16, - (unsigned long)r->req.cmd.xfer); + trace_scsi_disk_emulate_command_WRITE_SAME( + req->cmd.buf[0] == WRITE_SAME_10 ? 10 : 16, r->req.cmd.xfer); break; default: - DPRINTF("Unknown SCSI command (%2.2x=%s)\n", buf[0], - scsi_command_name(buf[0])); + trace_scsi_disk_emulate_command_UNKNOWN(buf[0], + scsi_command_name(buf[0])); scsi_check_condition(r, SENSE_CODE(INVALID_OPCODE)); return 0; } @@ -2154,7 +2142,7 @@ static int32_t scsi_disk_dma_command(SCSIRequest *req, uint8_t *buf) case READ_10: case READ_12: case READ_16: - DPRINTF("Read (sector %" PRId64 ", count %u)\n", r->req.cmd.lba, len); + trace_scsi_disk_dma_command_READ(r->req.cmd.lba, len); /* Protection information is not supported. For SCSI versions 2 and * older (as determined by snooping the guest's INQUIRY commands), * there is no RD/WR/VRPROTECT, so skip this check in these versions. @@ -2179,7 +2167,7 @@ static int32_t scsi_disk_dma_command(SCSIRequest *req, uint8_t *buf) scsi_check_condition(r, SENSE_CODE(WRITE_PROTECTED)); return 0; } - DPRINTF("Write %s(sector %" PRId64 ", count %u)\n", + trace_scsi_disk_dma_command_WRITE( (command & 0xe) == 0xe ? "And Verify " : "", r->req.cmd.lba, len); /* fall through */ @@ -2497,6 +2485,24 @@ static const SCSIReqOps *const scsi_disk_reqops_dispatch[256] = { [WRITE_VERIFY_16] = &scsi_disk_dma_reqops, }; +static void scsi_disk_new_request_dump(uint32_t lun, uint32_t tag, uint8_t *buf, + void (*trace_fn)(uint32_t, uint32_t, + char const *)) +{ + int i; + int len = scsi_cdb_length(buf); + char *line_buffer, *p; + + line_buffer = g_malloc(len * 5 + 1); + + for (i = 0, p = line_buffer; i < len; i++) { + p += sprintf(p, " 0x%02x", buf[i]); + } + trace_fn(lun, tag, line_buffer); + + g_free(line_buffer); +} + static SCSIRequest *scsi_new_request(SCSIDevice *d, uint32_t tag, uint32_t lun, uint8_t *buf, void *hba_private) { @@ -2512,16 +2518,9 @@ static SCSIRequest *scsi_new_request(SCSIDevice *d, uint32_t tag, uint32_t lun, } req = scsi_req_alloc(ops, &s->qdev, tag, lun, hba_private); -#ifdef DEBUG_SCSI - DPRINTF("Command: lun=%d tag=0x%x data=0x%02x", lun, tag, buf[0]); - { - int i; - for (i = 1; i < scsi_cdb_length(buf); i++) { - printf(" 0x%02x", buf[i]); - } - printf("\n"); + if (trace_event_get_state_backends(TRACE_SCSI_DISK_NEW_REQUEST)) { + scsi_disk_new_request_dump(lun, tag, buf, trace_scsi_disk_new_request); } -#endif return req; } diff --git a/hw/scsi/trace-events b/hw/scsi/trace-events index 0fb6a99616..e9625f790c 100644 --- a/hw/scsi/trace-events +++ b/hw/scsi/trace-events @@ -291,3 +291,32 @@ lsi_execute_script_stop(void) "SCRIPTS execution stopped" lsi_awoken(void) "Woken by SIGP" lsi_reg_read(const char *name, int offset, uint8_t ret) "Read reg %s 0x%x = 0x%02x" lsi_reg_write(const char *name, int offset, uint8_t val) "Write reg %s 0x%x = 0x%02x" + +# hw/scsi/scsi-disk.c +scsi_disk_check_condition(uint32_t tag, uint8_t key, uint8_t asc, uint8_t ascq) "Command complete tag=0x%x sense=%d/%d/%d" +scsi_disk_read_complete(uint32_t tag, size_t size) "Data ready tag=0x%x len=%zd" +scsi_disk_read_data_count(uint32_t sector_count) "Read sector_count=%d" +scsi_disk_read_data_invalid(void) "Data transfer direction invalid" +scsi_disk_write_complete_noio(uint32_t tag, size_t size) "Write complete tag=0x%x more=%zd" +scsi_disk_write_data_invalid(void) "Data transfer direction invalid" +scsi_disk_emulate_vpd_page_00(size_t xfer) "Inquiry EVPD[Supported pages] buffer size %zd" +scsi_disk_emulate_vpd_page_80_not_supported(void) "Inquiry (EVPD[Serial number] not supported" +scsi_disk_emulate_vpd_page_80(size_t xfer) "Inquiry EVPD[Serial number] buffer size %zd" +scsi_disk_emulate_vpd_page_83(size_t xfer) "Inquiry EVPD[Device identification] buffer size %zd" +scsi_disk_emulate_vpd_page_b0_not_supported(void) "Inquiry (EVPD[Block limits] not supported for CDROM" +scsi_disk_emulate_mode_sense(int cmd, int page, size_t xfer, int control) "Mode Sense(%d) (page %d, xfer %zd, page_control %d)" +scsi_disk_emulate_read_toc(int start_track, int format, int msf) "Read TOC (track %d format %d msf %d)" +scsi_disk_emulate_read_data(int buflen) "Read buf_len=%d" +scsi_disk_emulate_write_data(int buflen) "Write buf_len=%d" +scsi_disk_emulate_command_SAI_16(void) "SAI READ CAPACITY(16)" +scsi_disk_emulate_command_SAI_unsupported(void) "Unsupported Service Action In" +scsi_disk_emulate_command_SEEK_10(uint64_t lba) "Seek(10) (sector %" PRId64 ")" +scsi_disk_emulate_command_MODE_SELECT(size_t xfer) "Mode Select(6) (len %zd)" +scsi_disk_emulate_command_MODE_SELECT_10(size_t xfer) "Mode Select(10) (len %zd)" +scsi_disk_emulate_command_UNMAP(size_t xfer) "Unmap (len %zd)" +scsi_disk_emulate_command_VERIFY(int bytchk) "Verify (bytchk %d)" +scsi_disk_emulate_command_WRITE_SAME(int cmd, size_t xfer) "WRITE SAME %d (len %zd)" +scsi_disk_emulate_command_UNKNOWN(int cmd, const char *name) "Unknown SCSI command (0x%2.2x=%s)" +scsi_disk_dma_command_READ(uint64_t lba, uint32_t len) "Read (sector %" PRId64 ", count %u)" +scsi_disk_dma_command_WRITE(const char *cmd, uint64_t lba, int len) "Write %s(sector %" PRId64 ", count %u)" +scsi_disk_new_request(uint32_t lun, uint32_t tag, const char *line) "Command: lun=%d tag=0x%x data=%s"
Signed-off-by: Laurent Vivier <lvivier@redhat.com> --- hw/scsi/scsi-disk.c | 105 +++++++++++++++++++++---------------------- hw/scsi/trace-events | 29 ++++++++++++ 2 files changed, 81 insertions(+), 53 deletions(-)