Re: [PATCH 02/17] hw/block/nvme: additional tracing
Looks good, Reviewed-by: Dmitry Fomichev On Mon, 2020-06-29 at 20:26 +0200, Klaus Jensen wrote: > From: Klaus Jensen > > Add various additional tracing and streamline nvme_identify_ns and > nvme_identify_nslist (they do not need to repeat the command, it is > already in the trace name). > > Signed-off-by: Klaus Jensen > --- > hw/block/nvme.c | 19 +++ > hw/block/nvme.h | 14 ++ > hw/block/trace-events | 13 +++-- > 3 files changed, 44 insertions(+), 2 deletions(-) > > diff --git a/hw/block/nvme.c b/hw/block/nvme.c > index 71b388aa0e20..f5d9148f0936 100644 > --- a/hw/block/nvme.c > +++ b/hw/block/nvme.c > @@ -331,6 +331,8 @@ static void nvme_post_cqes(void *opaque) > static void nvme_enqueue_req_completion(NvmeCQueue *cq, NvmeRequest *req) > { > assert(cq->cqid == req->sq->cqid); > +trace_pci_nvme_enqueue_req_completion(nvme_cid(req), cq->cqid, > + req->status); > QTAILQ_REMOVE(&req->sq->out_req_list, req, entry); > QTAILQ_INSERT_TAIL(&cq->req_list, req, entry); > timer_mod(cq->timer, qemu_clock_get_ns(QEMU_CLOCK_VIRTUAL) + 500); > @@ -343,6 +345,8 @@ static void nvme_rw_cb(void *opaque, int ret) > NvmeCtrl *n = sq->ctrl; > NvmeCQueue *cq = n->cq[sq->cqid]; > > +trace_pci_nvme_rw_cb(nvme_cid(req)); > + > if (!ret) { > block_acct_done(blk_get_stats(n->conf.blk), &req->acct); > req->status = NVME_SUCCESS; > @@ -378,6 +382,8 @@ static uint16_t nvme_write_zeros(NvmeCtrl *n, > NvmeNamespace *ns, NvmeCmd *cmd, > uint64_t offset = slba << data_shift; > uint32_t count = nlb << data_shift; > > +trace_pci_nvme_write_zeroes(nvme_cid(req), slba, nlb); > + > if (unlikely(slba + nlb > ns->id_ns.nsze)) { > trace_pci_nvme_err_invalid_lba_range(slba, nlb, ns->id_ns.nsze); > return NVME_LBA_RANGE | NVME_DNR; > @@ -445,6 +451,8 @@ static uint16_t nvme_io_cmd(NvmeCtrl *n, NvmeCmd *cmd, > NvmeRequest *req) > NvmeNamespace *ns; > uint32_t nsid = le32_to_cpu(cmd->nsid); > > +trace_pci_nvme_io_cmd(nvme_cid(req), nsid, nvme_sqid(req), cmd->opcode); > + > if (unlikely(nsid == 0 || nsid > n->num_namespaces)) { > trace_pci_nvme_err_invalid_ns(nsid, n->num_namespaces); > return NVME_INVALID_NSID | NVME_DNR; > @@ -876,6 +884,8 @@ static uint16_t nvme_set_feature(NvmeCtrl *n, NvmeCmd > *cmd, NvmeRequest *req) > > static uint16_t nvme_admin_cmd(NvmeCtrl *n, NvmeCmd *cmd, NvmeRequest *req) > { > +trace_pci_nvme_admin_cmd(nvme_cid(req), nvme_sqid(req), cmd->opcode); > + > switch (cmd->opcode) { > case NVME_ADM_CMD_DELETE_SQ: > return nvme_del_sq(n, cmd); > @@ -1204,6 +1214,8 @@ static uint64_t nvme_mmio_read(void *opaque, hwaddr > addr, unsigned size) > uint8_t *ptr = (uint8_t *)&n->bar; > uint64_t val = 0; > > +trace_pci_nvme_mmio_read(addr); > + > if (unlikely(addr & (sizeof(uint32_t) - 1))) { > NVME_GUEST_ERR(pci_nvme_ub_mmiord_misaligned32, > "MMIO read not 32-bit aligned," > @@ -1273,6 +1285,8 @@ static void nvme_process_db(NvmeCtrl *n, hwaddr addr, > int val) > return; > } > > +trace_pci_nvme_mmio_doorbell_cq(cq->cqid, new_head); > + > start_sqs = nvme_cq_full(cq) ? 1 : 0; > cq->head = new_head; > if (start_sqs) { > @@ -1311,6 +1325,8 @@ static void nvme_process_db(NvmeCtrl *n, hwaddr addr, > int val) > return; > } > > +trace_pci_nvme_mmio_doorbell_sq(sq->sqid, new_tail); > + > sq->tail = new_tail; > timer_mod(sq->timer, qemu_clock_get_ns(QEMU_CLOCK_VIRTUAL) + 500); > } > @@ -1320,6 +1336,9 @@ static void nvme_mmio_write(void *opaque, hwaddr addr, > uint64_t data, > unsigned size) > { > NvmeCtrl *n = (NvmeCtrl *)opaque; > + > +trace_pci_nvme_mmio_write(addr, data); > + > if (addr < sizeof(n->bar)) { > nvme_write_bar(n, addr, data, size); > } else if (addr >= 0x1000) { > diff --git a/hw/block/nvme.h b/hw/block/nvme.h > index 1d30c0bca283..1bf5c80ed843 100644 > --- a/hw/block/nvme.h > +++ b/hw/block/nvme.h > @@ -115,4 +115,18 @@ static inline uint64_t nvme_ns_nlbas(NvmeCtrl *n, > NvmeNamespace *ns) > return n->ns_size >> nvme_ns_lbads(ns); > } > > +static inline uint16_t nvme_cid(NvmeRequest *req) > +{ > +if (req) { > +return le16_to_cpu(req->cqe.cid); > +} > + > +return 0x; > +} > + > +static inline uint16_t nvme_sqid(NvmeRequest *req) > +{ > +return le16_to_cpu(req->sq->sqid); > +} > + > #endif /* HW_NVME_H */ > diff --git a/hw/block/trace-events b/hw/block/trace-events > index 958fcc5508d1..c40c0d2e4b28 100644 > --- a/hw/block/trace-events > +++ b/hw/block/trace-events > @@ -33,19 +33,28 @@ pci_nvme_irq_msix(uint32_t vector) "raising MSI-X IRQ > vector %u" > pci_nvme_irq_pin(void) "pulsing IRQ pin" > pci_nvme_irq_masked(void)
[PATCH 02/17] hw/block/nvme: additional tracing
From: Klaus Jensen Add various additional tracing and streamline nvme_identify_ns and nvme_identify_nslist (they do not need to repeat the command, it is already in the trace name). Signed-off-by: Klaus Jensen --- hw/block/nvme.c | 19 +++ hw/block/nvme.h | 14 ++ hw/block/trace-events | 13 +++-- 3 files changed, 44 insertions(+), 2 deletions(-) diff --git a/hw/block/nvme.c b/hw/block/nvme.c index 71b388aa0e20..f5d9148f0936 100644 --- a/hw/block/nvme.c +++ b/hw/block/nvme.c @@ -331,6 +331,8 @@ static void nvme_post_cqes(void *opaque) static void nvme_enqueue_req_completion(NvmeCQueue *cq, NvmeRequest *req) { assert(cq->cqid == req->sq->cqid); +trace_pci_nvme_enqueue_req_completion(nvme_cid(req), cq->cqid, + req->status); QTAILQ_REMOVE(&req->sq->out_req_list, req, entry); QTAILQ_INSERT_TAIL(&cq->req_list, req, entry); timer_mod(cq->timer, qemu_clock_get_ns(QEMU_CLOCK_VIRTUAL) + 500); @@ -343,6 +345,8 @@ static void nvme_rw_cb(void *opaque, int ret) NvmeCtrl *n = sq->ctrl; NvmeCQueue *cq = n->cq[sq->cqid]; +trace_pci_nvme_rw_cb(nvme_cid(req)); + if (!ret) { block_acct_done(blk_get_stats(n->conf.blk), &req->acct); req->status = NVME_SUCCESS; @@ -378,6 +382,8 @@ static uint16_t nvme_write_zeros(NvmeCtrl *n, NvmeNamespace *ns, NvmeCmd *cmd, uint64_t offset = slba << data_shift; uint32_t count = nlb << data_shift; +trace_pci_nvme_write_zeroes(nvme_cid(req), slba, nlb); + if (unlikely(slba + nlb > ns->id_ns.nsze)) { trace_pci_nvme_err_invalid_lba_range(slba, nlb, ns->id_ns.nsze); return NVME_LBA_RANGE | NVME_DNR; @@ -445,6 +451,8 @@ static uint16_t nvme_io_cmd(NvmeCtrl *n, NvmeCmd *cmd, NvmeRequest *req) NvmeNamespace *ns; uint32_t nsid = le32_to_cpu(cmd->nsid); +trace_pci_nvme_io_cmd(nvme_cid(req), nsid, nvme_sqid(req), cmd->opcode); + if (unlikely(nsid == 0 || nsid > n->num_namespaces)) { trace_pci_nvme_err_invalid_ns(nsid, n->num_namespaces); return NVME_INVALID_NSID | NVME_DNR; @@ -876,6 +884,8 @@ static uint16_t nvme_set_feature(NvmeCtrl *n, NvmeCmd *cmd, NvmeRequest *req) static uint16_t nvme_admin_cmd(NvmeCtrl *n, NvmeCmd *cmd, NvmeRequest *req) { +trace_pci_nvme_admin_cmd(nvme_cid(req), nvme_sqid(req), cmd->opcode); + switch (cmd->opcode) { case NVME_ADM_CMD_DELETE_SQ: return nvme_del_sq(n, cmd); @@ -1204,6 +1214,8 @@ static uint64_t nvme_mmio_read(void *opaque, hwaddr addr, unsigned size) uint8_t *ptr = (uint8_t *)&n->bar; uint64_t val = 0; +trace_pci_nvme_mmio_read(addr); + if (unlikely(addr & (sizeof(uint32_t) - 1))) { NVME_GUEST_ERR(pci_nvme_ub_mmiord_misaligned32, "MMIO read not 32-bit aligned," @@ -1273,6 +1285,8 @@ static void nvme_process_db(NvmeCtrl *n, hwaddr addr, int val) return; } +trace_pci_nvme_mmio_doorbell_cq(cq->cqid, new_head); + start_sqs = nvme_cq_full(cq) ? 1 : 0; cq->head = new_head; if (start_sqs) { @@ -1311,6 +1325,8 @@ static void nvme_process_db(NvmeCtrl *n, hwaddr addr, int val) return; } +trace_pci_nvme_mmio_doorbell_sq(sq->sqid, new_tail); + sq->tail = new_tail; timer_mod(sq->timer, qemu_clock_get_ns(QEMU_CLOCK_VIRTUAL) + 500); } @@ -1320,6 +1336,9 @@ static void nvme_mmio_write(void *opaque, hwaddr addr, uint64_t data, unsigned size) { NvmeCtrl *n = (NvmeCtrl *)opaque; + +trace_pci_nvme_mmio_write(addr, data); + if (addr < sizeof(n->bar)) { nvme_write_bar(n, addr, data, size); } else if (addr >= 0x1000) { diff --git a/hw/block/nvme.h b/hw/block/nvme.h index 1d30c0bca283..1bf5c80ed843 100644 --- a/hw/block/nvme.h +++ b/hw/block/nvme.h @@ -115,4 +115,18 @@ static inline uint64_t nvme_ns_nlbas(NvmeCtrl *n, NvmeNamespace *ns) return n->ns_size >> nvme_ns_lbads(ns); } +static inline uint16_t nvme_cid(NvmeRequest *req) +{ +if (req) { +return le16_to_cpu(req->cqe.cid); +} + +return 0x; +} + +static inline uint16_t nvme_sqid(NvmeRequest *req) +{ +return le16_to_cpu(req->sq->sqid); +} + #endif /* HW_NVME_H */ diff --git a/hw/block/trace-events b/hw/block/trace-events index 958fcc5508d1..c40c0d2e4b28 100644 --- a/hw/block/trace-events +++ b/hw/block/trace-events @@ -33,19 +33,28 @@ pci_nvme_irq_msix(uint32_t vector) "raising MSI-X IRQ vector %u" pci_nvme_irq_pin(void) "pulsing IRQ pin" pci_nvme_irq_masked(void) "IRQ is masked" pci_nvme_dma_read(uint64_t prp1, uint64_t prp2) "DMA read, prp1=0x%"PRIx64" prp2=0x%"PRIx64"" +pci_nvme_io_cmd(uint16_t cid, uint32_t nsid, uint16_t sqid, uint8_t opcode) "cid %"PRIu16" nsid %"PRIu32" sqid %"PRIu16" opc 0x%"PRIx8"" +pci_nvme_admin_cmd(uint16_t cid, uint16_t sqid, uint8_t opcode) "cid %"PRIu16" sqid %"PRIu16" opc 0x%"PRIx8"" pci_nvme_r