[PATCH 1/6] usb: xhci: add xhci_log_cmd trace events
From: Lu Baolu
Date: Tue Feb 14 2017 - 21:37:08 EST
This patch creates a new event class called xhci_log_cmd, and
defines the events used for tracing the life cycle of commands
issued for various purposes.
This info can be used, later, to print, in a human readable way,
the life cycle of an xHCI command using the trace-cmd tool and
the appropriate plugin.
Signed-off-by: Lu Baolu <baolu.lu@xxxxxxxxxxxxxxx>
---
drivers/usb/host/xhci-hub.c | 2 +
drivers/usb/host/xhci-ring.c | 13 +++++--
drivers/usb/host/xhci-trace.h | 90 +++++++++++++++++++++++++++++++++++++++++++
drivers/usb/host/xhci.c | 7 ++++
4 files changed, 108 insertions(+), 4 deletions(-)
diff --git a/drivers/usb/host/xhci-hub.c b/drivers/usb/host/xhci-hub.c
index 3bddeaa..2c3f77f 100644
--- a/drivers/usb/host/xhci-hub.c
+++ b/drivers/usb/host/xhci-hub.c
@@ -411,9 +411,11 @@ static int xhci_stop_device(struct xhci_hcd *xhci, int slot_id, int suspend)
}
xhci_queue_stop_endpoint(xhci, command, slot_id, i,
suspend);
+ trace_cmd_xhci_stop_device(command);
}
}
xhci_queue_stop_endpoint(xhci, cmd, slot_id, 0, suspend);
+ trace_cmd_xhci_stop_device(cmd);
xhci_ring_cmd_db(xhci);
spin_unlock_irqrestore(&xhci->lock, flags);
diff --git a/drivers/usb/host/xhci-ring.c b/drivers/usb/host/xhci-ring.c
index d9936c7..4cdcd71 100644
--- a/drivers/usb/host/xhci-ring.c
+++ b/drivers/usb/host/xhci-ring.c
@@ -1124,6 +1124,7 @@ static void xhci_handle_cmd_reset_ep(struct xhci_hcd *xhci, int slot_id,
xhci_queue_configure_endpoint(xhci, command,
xhci->devs[slot_id]->in_ctx->dma, slot_id,
false);
+ trace_cmd_xhci_handle_cmd_reset_ep(command);
xhci_ring_cmd_db(xhci);
} else {
/* Clear our internal halted state */
@@ -1231,13 +1232,13 @@ static void xhci_handle_cmd_nec_get_fw(struct xhci_hcd *xhci,
static void xhci_complete_del_and_free_cmd(struct xhci_command *cmd, u32 status)
{
list_del(&cmd->cmd_list);
+ cmd->status = status;
+ trace_cmd_xhci_complete_del_and_free_cmd(cmd);
- if (cmd->completion) {
- cmd->status = status;
+ if (cmd->completion)
complete(cmd->completion);
- } else {
+ else
kfree(cmd);
- }
}
void xhci_cleanup_command_queue(struct xhci_hcd *xhci)
@@ -1268,6 +1269,7 @@ void xhci_handle_command_timeout(struct work_struct *work)
}
/* mark this command to be cancelled */
xhci->current_cmd->status = COMP_COMMAND_ABORTED;
+ trace_cmd_xhci_handle_command_timeout(xhci->current_cmd);
/* Make sure command ring is running before aborting it */
hw_ring_state = xhci_read_64(xhci, &xhci->op_regs->cmd_ring);
@@ -1432,6 +1434,7 @@ static void handle_cmd_completion(struct xhci_hcd *xhci,
}
event_handled:
+ trace_cmd_handle_cmd_completion(cmd);
xhci_complete_del_and_free_cmd(cmd, cmd_comp_code);
inc_deq(xhci, xhci->cmd_ring);
@@ -1773,6 +1776,7 @@ static void xhci_cleanup_halted_endpoint(struct xhci_hcd *xhci,
ep->stopped_stream = stream_id;
xhci_queue_reset_ep(xhci, command, slot_id, ep_index);
+ trace_cmd_xhci_cleanup_halted_endpoint(command);
xhci_cleanup_stalled_ring(xhci, ep_index, td);
ep->stopped_stream = 0;
@@ -3956,6 +3960,7 @@ void xhci_queue_new_dequeue_state(struct xhci_hcd *xhci,
xhci_free_command(xhci, cmd);
return;
}
+ trace_cmd_xhci_queue_new_dequeue_state(cmd);
/* Stop the TD queueing code from ringing the doorbell until
* this command completes. The HC won't set the dequeue pointer
diff --git a/drivers/usb/host/xhci-trace.h b/drivers/usb/host/xhci-trace.h
index 1ac2cdf..c31eeaf 100644
--- a/drivers/usb/host/xhci-trace.h
+++ b/drivers/usb/host/xhci-trace.h
@@ -285,6 +285,96 @@ DEFINE_EVENT(xhci_log_urb, xhci_urb_dequeue,
TP_ARGS(urb)
);
+DECLARE_EVENT_CLASS(xhci_log_cmd,
+ TP_PROTO(struct xhci_command *cmd),
+ TP_ARGS(cmd),
+ TP_STRUCT__entry(
+ __field(struct xhci_command *, cmd)
+ __field(struct xhci_container_ctx *, in_ctx)
+ __field(union xhci_trb *, cmd_trb)
+ __field(int, slot_id)
+ __field(int, status)
+ __field(int, type)
+ ),
+ TP_fast_assign(
+ __entry->cmd = cmd;
+ __entry->in_ctx = cmd->in_ctx;
+ __entry->cmd_trb = cmd->command_trb;
+ __entry->slot_id = cmd->slot_id;
+ __entry->status = cmd->status;
+ __entry->type = TRB_FIELD_TO_TYPE(le32_to_cpu(cmd->command_trb->generic.field[3]))
+ ),
+ TP_printk("cmd @%p: %s: in_ctx=@%p, slot_id=%d, cmd_trb=@%p, status=%d",
+ __entry->cmd, xhci_trb_type_string(__entry->type),
+ __entry->in_ctx, __entry->slot_id, __entry->cmd_trb,
+ __entry->status
+ )
+);
+
+DEFINE_EVENT(xhci_log_cmd, cmd_xhci_stop_device,
+ TP_PROTO(struct xhci_command *cmd),
+ TP_ARGS(cmd)
+);
+
+DEFINE_EVENT(xhci_log_cmd, cmd_xhci_handle_cmd_reset_ep,
+ TP_PROTO(struct xhci_command *cmd),
+ TP_ARGS(cmd)
+);
+
+DEFINE_EVENT(xhci_log_cmd, cmd_xhci_cleanup_halted_endpoint,
+ TP_PROTO(struct xhci_command *cmd),
+ TP_ARGS(cmd)
+);
+
+DEFINE_EVENT(xhci_log_cmd, cmd_xhci_queue_new_dequeue_state,
+ TP_PROTO(struct xhci_command *cmd),
+ TP_ARGS(cmd)
+);
+
+DEFINE_EVENT(xhci_log_cmd, cmd_xhci_urb_dequeue,
+ TP_PROTO(struct xhci_command *cmd),
+ TP_ARGS(cmd)
+);
+
+DEFINE_EVENT(xhci_log_cmd, cmd_xhci_configure_endpoint,
+ TP_PROTO(struct xhci_command *cmd),
+ TP_ARGS(cmd)
+);
+
+DEFINE_EVENT(xhci_log_cmd, cmd_xhci_discover_or_reset_device,
+ TP_PROTO(struct xhci_command *cmd),
+ TP_ARGS(cmd)
+);
+
+DEFINE_EVENT(xhci_log_cmd, cmd_xhci_free_dev,
+ TP_PROTO(struct xhci_command *cmd),
+ TP_ARGS(cmd)
+);
+
+DEFINE_EVENT(xhci_log_cmd, cmd_xhci_alloc_dev,
+ TP_PROTO(struct xhci_command *cmd),
+ TP_ARGS(cmd)
+);
+
+DEFINE_EVENT(xhci_log_cmd, cmd_xhci_setup_device,
+ TP_PROTO(struct xhci_command *cmd),
+ TP_ARGS(cmd)
+);
+
+DEFINE_EVENT(xhci_log_cmd, cmd_handle_cmd_completion,
+ TP_PROTO(struct xhci_command *cmd),
+ TP_ARGS(cmd)
+);
+
+DEFINE_EVENT(xhci_log_cmd, cmd_xhci_handle_command_timeout,
+ TP_PROTO(struct xhci_command *cmd),
+ TP_ARGS(cmd)
+);
+
+DEFINE_EVENT(xhci_log_cmd, cmd_xhci_complete_del_and_free_cmd,
+ TP_PROTO(struct xhci_command *cmd),
+ TP_ARGS(cmd)
+);
#endif /* __XHCI_TRACE_H */
/* this part must be outside header guard */
diff --git a/drivers/usb/host/xhci.c b/drivers/usb/host/xhci.c
index b3f7766..dff912e 100644
--- a/drivers/usb/host/xhci.c
+++ b/drivers/usb/host/xhci.c
@@ -1549,6 +1549,7 @@ int xhci_urb_dequeue(struct usb_hcd *hcd, struct urb *urb, int status)
add_timer(&ep->stop_cmd_timer);
xhci_queue_stop_endpoint(xhci, command, urb->dev->slot_id,
ep_index, 0);
+ trace_cmd_xhci_urb_dequeue(command);
xhci_ring_cmd_db(xhci);
}
done:
@@ -2631,6 +2632,7 @@ static int xhci_configure_endpoint(struct xhci_hcd *xhci,
"FIXME allocate a new ring segment");
return -ENOMEM;
}
+ trace_cmd_xhci_configure_endpoint(command);
xhci_ring_cmd_db(xhci);
spin_unlock_irqrestore(&xhci->lock, flags);
@@ -3458,6 +3460,7 @@ int xhci_discover_or_reset_device(struct usb_hcd *hcd, struct usb_device *udev)
spin_unlock_irqrestore(&xhci->lock, flags);
goto command_cleanup;
}
+ trace_cmd_xhci_discover_or_reset_device(reset_device_cmd);
xhci_ring_cmd_db(xhci);
spin_unlock_irqrestore(&xhci->lock, flags);
@@ -3604,6 +3607,7 @@ void xhci_free_dev(struct usb_hcd *hcd, struct usb_device *udev)
xhci_dbg(xhci, "FIXME: allocate a command ring segment\n");
return;
}
+ trace_cmd_xhci_free_dev(command);
xhci_ring_cmd_db(xhci);
spin_unlock_irqrestore(&xhci->lock, flags);
@@ -3662,6 +3666,7 @@ int xhci_alloc_dev(struct usb_hcd *hcd, struct usb_device *udev)
xhci_free_command(xhci, command);
return 0;
}
+ trace_cmd_xhci_alloc_dev(command);
xhci_ring_cmd_db(xhci);
spin_unlock_irqrestore(&xhci->lock, flags);
@@ -3724,6 +3729,7 @@ int xhci_alloc_dev(struct usb_hcd *hcd, struct usb_device *udev)
if (!xhci_queue_slot_control(xhci, command, TRB_DISABLE_SLOT,
udev->slot_id))
xhci_ring_cmd_db(xhci);
+ trace_cmd_xhci_alloc_dev(command);
spin_unlock_irqrestore(&xhci->lock, flags);
return 0;
}
@@ -3826,6 +3832,7 @@ static int xhci_setup_device(struct usb_hcd *hcd, struct usb_device *udev,
"FIXME: allocate a command ring segment");
goto out;
}
+ trace_cmd_xhci_setup_device(command);
xhci_ring_cmd_db(xhci);
spin_unlock_irqrestore(&xhci->lock, flags);
--
2.1.4