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(>sq->out_req_list, req, entry);
> QTAILQ_INSERT_TAIL(>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), >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 *)>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"
[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(>sq->out_req_list, req, entry);
QTAILQ_INSERT_TAIL(>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), >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 *)>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_rw(const char
