Hi,
Lu Baolu <baolu.lu@xxxxxxxxxxxxxxx> writes:
> On 12/29/2016 07:01 PM, Felipe Balbi wrote:
>> instead of having a tracer that can only trace command completions,
>> let's promote this tracer so it can trace and decode any TRB.
>>
>> With that, it will be easier to extrapolate the lifetime of any TRB
>> which might help debugging certain issues.
>>
>> Signed-off-by: Felipe Balbi <felipe.balbi@xxxxxxxxxxxxxxx>
>> ---
>> drivers/usb/host/xhci-ring.c | 14 +-
>> drivers/usb/host/xhci-trace.h | 55 +++++---
>> drivers/usb/host/xhci.h | 311 ++++++++++++++++++++++++++++++++++++++++++
>> 3 files changed, 357 insertions(+), 23 deletions(-)
>>
>> diff --git a/drivers/usb/host/xhci-ring.c b/drivers/usb/host/xhci-ring.c
>> index 393c64f8acef..0ee7d358b812 100644
>> --- a/drivers/usb/host/xhci-ring.c
>> +++ b/drivers/usb/host/xhci-ring.c
>> @@ -1346,6 +1346,9 @@ static void handle_cmd_completion(struct xhci_hcd *xhci,
>>
>> cmd_dma = le64_to_cpu(event->cmd_trb);
>> cmd_trb = xhci->cmd_ring->dequeue;
>> +
>> + trace_xhci_handle_command(xhci->cmd_ring, &cmd_trb->generic);
>> +
>
> This is duplicated with trace_xhci_handle_event().
no it's not. They separate events from the same event class, but they're
different things.
>> @@ -2407,6 +2408,10 @@ static int handle_tx_event(struct xhci_hcd *xhci,
>>
>> ep_trb = &ep_seg->trbs[(ep_trb_dma - ep_seg->dma) /
>> sizeof(*ep_trb)];
>> +
>> + trace_xhci_handle_transfer(ep_ring,
>> + (struct xhci_generic_trb *) ep_trb);
>> +
>
> This is duplicated with trace_xhci_handle_event().
ditto
>> + __entry->type = ring->type;
>> + __entry->field0 = le32_to_cpu(trb->field[0]);
>> + __entry->field1 = le32_to_cpu(trb->field[1]);
>> + __entry->field2 = le32_to_cpu(trb->field[2]);
>> + __entry->field3 = le32_to_cpu(trb->field[3]);
>> ),
>> - TP_printk("\ntrb_dma=@%llx, trb_va=@%p, status=%08x, flags=%08x",
>> - (unsigned long long) __entry->dma, __entry->va,
>> - __entry->status, __entry->flags
>> + TP_printk("%s: %s", xhci_ring_type_string(__entry->type),
>
> How about moving the common fields of a TRB (like TRB type and
> the cycle bit) to the place between ring type and trb decoding string?
> And remove type and cycle decoding in xhci_decode_trb() as well.
>
> Something like:
>
> diff --git a/drivers/usb/host/xhci-trace.h b/drivers/usb/host/xhci-trace.h
> index d01524b..f8ef7b8 100644
> --- a/drivers/usb/host/xhci-trace.h
> +++ b/drivers/usb/host/xhci-trace.h
> @@ -132,9 +132,11 @@ DECLARE_EVENT_CLASS(xhci_log_trb,
> __entry->field2 = le32_to_cpu(trb->field[2]);
> __entry->field3 = le32_to_cpu(trb->field[3]);
> ),
> - TP_printk("%s: %s", xhci_ring_type_string(__entry->type),
> - xhci_decode_trb(__entry->field0, __entry->field1,
> - __entry->field2, __entry->field3)
> + TP_printk("%s: %s: %c: %s", xhci_ring_type_string(__entry->type),
> + xhci_trb_type_string(TRB_FIELD_TO_TYPE(__entry->field3)),
> + __entry->field3 & TRB_CYCLE ? 'C' : 'c',
> + xhci_decode_trb(__entry->field0, __entry->field1,
> + __entry->field2, __entry->field3)
and what do I get with that? What's the actual benefit?
> )
> );
>
>
>> + xhci_decode_trb(__entry->field0, __entry->field1,
>> + __entry->field2, __entry->field3)
>> )
>> );
>>
>> -DEFINE_EVENT(xhci_log_event, xhci_cmd_completion,
>> - TP_PROTO(void *trb_va, struct xhci_generic_trb *ev),
>> - TP_ARGS(trb_va, ev)
>> +DEFINE_EVENT(xhci_log_trb, xhci_handle_event,
>> + TP_PROTO(struct xhci_ring *ring, struct xhci_generic_trb *trb),
>> + TP_ARGS(ring, trb)
>> +);
>> +
>> +DEFINE_EVENT(xhci_log_trb, xhci_handle_command,
>> + TP_PROTO(struct xhci_ring *ring, struct xhci_generic_trb *trb),
>> + TP_ARGS(ring, trb)
>> +);
>> +
>> +DEFINE_EVENT(xhci_log_trb, xhci_handle_transfer,
>> + TP_PROTO(struct xhci_ring *ring, struct xhci_generic_trb *trb),
>> + TP_ARGS(ring, trb)
>> +);
>> +
>> +DEFINE_EVENT(xhci_log_trb, xhci_queue_trb,
>> + TP_PROTO(struct xhci_ring *ring, struct xhci_generic_trb *trb),
>> + TP_ARGS(ring, trb)
>> );
>
> xhci_handle_command and xhci_handle_transfer are duplications
> of xhci_handle_event. I suggest to remove them.
no, they are not. They give us more granularity into which events we
want to enable. They also make it clear where the even is coming
from. Imagine how the trace would look like if I had a single event and
just called trace_xhci_handle_event() from all locations. How would you
differentiate from all possible call sites?
> How about adding an event for the link TRBs. Something like,
>
> diff --git a/drivers/usb/host/xhci-ring.c b/drivers/usb/host/xhci-ring.c
> index 4bad432..6dc8efb 100644
> --- a/drivers/usb/host/xhci-ring.c
> +++ b/drivers/usb/host/xhci-ring.c
> @@ -173,6 +173,7 @@ static void inc_deq(struct xhci_hcd *xhci, struct xhci_ring *ring)
> ring->num_trbs_free++;
> }
> while (trb_is_link(ring->dequeue)) {
> + trace_xhci_link_trb(ring, ring->dequeue);
> ring->deq_seg = ring->deq_seg->next;
> ring->dequeue = ring->deq_seg->trbs;
> }
> @@ -211,6 +212,7 @@ static void inc_enq(struct xhci_hcd *xhci, struct xhci_ring *ring,
> ring->enq_updates++;
> /* Update the dequeue pointer further if that was a link TRB */
> while (trb_is_link(next)) {
> + trace_xhci_link_trb(ring, next);
>
> /*
> * If the caller doesn't plan on enqueueing more TDs before
> diff --git a/drivers/usb/host/xhci-trace.h b/drivers/usb/host/xhci-trace.h
> index d01524b..f1a06b5 100644
> --- a/drivers/usb/host/xhci-trace.h
> +++ b/drivers/usb/host/xhci-trace.h
> @@ -158,6 +158,10 @@ DEFINE_EVENT(xhci_log_trb, xhci_queue_trb,
> TP_ARGS(ring, trb)
> );
>
> +DEFINE_EVENT(xhci_log_trb, xhci_link_trb,
> + TP_PROTO(struct xhci_ring *ring, struct xhci_generic_trb *trb),
> + TP_ARGS(ring, trb)
> +);
> #endif /* __XHCI_TRACE_H */
what are you trying to achieve with this?
>> +static inline const char *xhci_decode_trb(u32 field0, u32 field1, u32 field2,
>> + u32 field3)
>> +{
>> + static char str[256];
>> + int type = TRB_FIELD_TO_TYPE(field3);
>> +
>> + switch (type) {
>> + case TRB_LINK:
>> + sprintf(str, "TRB %08x%08x status '%s' len %d slot %d ep %d type '%s' flags %c:%c",
>
> How about using snprintf() to avoid buffer over flow?
sure
>> + field1, field0,
>> + xhci_trb_comp_code_string(GET_COMP_CODE(field2)),
>> + EVENT_TRB_LEN(field2), TRB_TO_SLOT_ID(field3),
>> + /* Macro decrements 1, maybe it shouldn't?!? */
>> + TRB_TO_EP_INDEX(field3) + 1,
>> + xhci_trb_type_string(TRB_FIELD_TO_TYPE(field3)),
>
> "TRB_FIELD_TO_TYPE(field3)" could be replaced with "type". The same for other
> places in this function.
good catch
>> + field3 & EVENT_DATA ? 'E' : 'e',
>> + field3 & TRB_CYCLE ? 'C' : 'c');
>
> This decoding seems not for a link trb, but an event one. :-)
copy paste error
--
balbi
--
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
