Hi,
On 12/29/2016 07:01 PM, Felipe Balbi wrote:
> Let's start tracing at least part of an xhci_virt_device lifetime. We
> might want to extend this tracepoint class later, but for now it already
> exposes quite a bit of valuable information.
>
> Signed-off-by: Felipe Balbi <felipe.balbi@xxxxxxxxxxxxxxx>
> ---
> drivers/usb/host/xhci-hub.c | 2 ++
> drivers/usb/host/xhci-mem.c | 7 ++++++
> drivers/usb/host/xhci-trace.h | 57 +++++++++++++++++++++++++++++++++++++++++++
> drivers/usb/host/xhci.c | 1 +
> 4 files changed, 67 insertions(+)
>
> diff --git a/drivers/usb/host/xhci-hub.c b/drivers/usb/host/xhci-hub.c
> index b99f06f4c421..6fdea9e5e3a5 100644
> --- a/drivers/usb/host/xhci-hub.c
> +++ b/drivers/usb/host/xhci-hub.c
> @@ -389,6 +389,8 @@ static int xhci_stop_device(struct xhci_hcd *xhci, int slot_id, int suspend)
> if (!virt_dev)
> return -ENODEV;
>
> + trace_xhci_stop_device(virt_dev);
> +
I'd suggest move the trace down until all stop endpoint commands complete.
The state of a virt_device affects only after the command completes.
> cmd = xhci_alloc_command(xhci, false, true, GFP_NOIO);
> if (!cmd) {
> xhci_dbg(xhci, "Couldn't allocate command structure.\n");
> diff --git a/drivers/usb/host/xhci-mem.c b/drivers/usb/host/xhci-mem.c
> index b12631ef160b..2b7c3504a95a 100644
> --- a/drivers/usb/host/xhci-mem.c
> +++ b/drivers/usb/host/xhci-mem.c
> @@ -936,6 +936,9 @@ void xhci_free_virt_device(struct xhci_hcd *xhci, int slot_id)
> return;
>
> dev = xhci->devs[slot_id];
> +
> + trace_xhci_free_virt_device(dev);
> +
> xhci->dcbaa->dev_context_ptrs[slot_id] = 0;
> if (!dev)
> return;
> @@ -1041,6 +1044,8 @@ int xhci_alloc_virt_device(struct xhci_hcd *xhci, int slot_id,
> &xhci->dcbaa->dev_context_ptrs[slot_id],
> le64_to_cpu(xhci->dcbaa->dev_context_ptrs[slot_id]));
>
> + trace_xhci_alloc_virt_device(dev);
> +
> return 1;
> fail:
> xhci_free_virt_device(xhci, slot_id);
> @@ -1215,6 +1220,8 @@ int xhci_setup_addressable_virt_dev(struct xhci_hcd *xhci, struct usb_device *ud
> ep0_ctx->deq = cpu_to_le64(dev->eps[0].ring->first_seg->dma |
> dev->eps[0].ring->cycle_state);
>
> + trace_xhci_setup_addressable_virt_device(dev);
> +
> /* Steps 7 and 8 were done in xhci_alloc_virt_device() */
>
> return 0;
> diff --git a/drivers/usb/host/xhci-trace.h b/drivers/usb/host/xhci-trace.h
> index 08bed2f07e50..1e85c893247d 100644
> --- a/drivers/usb/host/xhci-trace.h
> +++ b/drivers/usb/host/xhci-trace.h
> @@ -158,6 +158,63 @@ DEFINE_EVENT(xhci_log_trb, xhci_queue_trb,
> TP_ARGS(ring, trb)
> );
>
> +DECLARE_EVENT_CLASS(xhci_log_virt_dev,
> + TP_PROTO(struct xhci_virt_device *vdev),
> + TP_ARGS(vdev),
> + TP_STRUCT__entry(
> + __field(void *, vdev)
> + __field(unsigned long long, out_ctx)
> + __field(unsigned long long, in_ctx)
> + __field(int, devnum)
> + __field(int, state)
> + __field(int, speed)
> + __field(u8, portnum)
> + __field(u8, level)
> + __field(int, slot_id)
> + ),
> + TP_fast_assign(
> + __entry->vdev = vdev;
> + __entry->in_ctx = (unsigned long long) vdev->in_ctx->dma;
> + __entry->out_ctx = (unsigned long long) vdev->out_ctx->dma;
> + __entry->devnum = vdev->udev->devnum;
> + __entry->state = vdev->udev->state;
> + __entry->speed = vdev->udev->speed;
> + __entry->portnum = vdev->udev->portnum;
> + __entry->level = vdev->udev->level;
> + __entry->slot_id = vdev->udev->slot_id;
> + ),
> + TP_printk("vdev %p ctx %llx | %llx num %d state %d speed %d port %d level %d slot %d",
> + __entry->vdev, __entry->in_ctx, __entry->out_ctx, __entry->devnum,
> + __entry->state, __entry->speed, __entry->portnum, __entry->level,
> + __entry->slot_id
> + )
> +);
> +
> +DEFINE_EVENT(xhci_log_virt_dev, xhci_alloc_virt_device,
> + TP_PROTO(struct xhci_virt_device *vdev),
> + TP_ARGS(vdev)
> +);
> +
> +DEFINE_EVENT(xhci_log_virt_dev, xhci_free_virt_device,
> + TP_PROTO(struct xhci_virt_device *vdev),
> + TP_ARGS(vdev)
> +);
> +
> +DEFINE_EVENT(xhci_log_virt_dev, xhci_setup_device,
> + TP_PROTO(struct xhci_virt_device *vdev),
> + TP_ARGS(vdev)
> +);
> +
> +DEFINE_EVENT(xhci_log_virt_dev, xhci_setup_addressable_virt_device,
> + TP_PROTO(struct xhci_virt_device *vdev),
> + TP_ARGS(vdev)
> +);
> +
> +DEFINE_EVENT(xhci_log_virt_dev, xhci_stop_device,
> + TP_PROTO(struct xhci_virt_device *vdev),
> + TP_ARGS(vdev)
> +);
The lifetime of a USB virtual device in xhci host is defined by
"Figure 10: Slot State Diagram" on spec page 83. These events
are partial of the life. It's okay to me as the commit message
has covered this anyway.
For long term purpose, since the states of a virt_device are driven
by the xhci commands, it's better to define the event names according
to 1) command name; 2) the new state after command.
I am still confused by the difference between xhci_setup_device
and xhci_setup_addressable_virt_device. It seems that these
two events traces "set address phase" at the same time.
> +
> DECLARE_EVENT_CLASS(xhci_log_urb,
> TP_PROTO(struct urb *urb),
> TP_ARGS(urb),
> diff --git a/drivers/usb/host/xhci.c b/drivers/usb/host/xhci.c
> index c0f3670e5a51..e5f095b276fc 100644
> --- a/drivers/usb/host/xhci.c
> +++ b/drivers/usb/host/xhci.c
> @@ -3860,6 +3860,7 @@ static int xhci_setup_device(struct usb_hcd *hcd, struct usb_device *udev,
> le32_to_cpu(slot_ctx->dev_info) >> 27);
>
> spin_lock_irqsave(&xhci->lock, flags);
> + trace_xhci_setup_device(virt_dev);
Same here.
Move the trace down until the address device command completes.
> ret = xhci_queue_address_device(xhci, command, virt_dev->in_ctx->dma,
> udev->slot_id, setup);
> if (ret) {
Best regards,
Lu Baolu
--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html
