From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1751583AbdBOJ2D (ORCPT ); Wed, 15 Feb 2017 04:28:03 -0500 Received: from mga02.intel.com ([134.134.136.20]:63219 "EHLO mga02.intel.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1750987AbdBOJ2C (ORCPT ); Wed, 15 Feb 2017 04:28:02 -0500 X-ExtLoop1: 1 X-IronPort-AV: E=Sophos;i="5.35,165,1484035200"; d="scan'208";a="64930010" Subject: Re: [PATCH 1/6] usb: xhci: add xhci_log_cmd trace events To: Felipe Balbi , Mathias Nyman References: <1487126112-6069-1-git-send-email-baolu.lu@linux.intel.com> <1487126112-6069-2-git-send-email-baolu.lu@linux.intel.com> <8760kbq40y.fsf@linux.intel.com> <58A4102C.3020502@linux.intel.com> <87y3x7omrc.fsf@linux.intel.com> Cc: linux-usb@vger.kernel.org, linux-kernel@vger.kernel.org From: Lu Baolu Message-ID: <58A41F1E.3060808@linux.intel.com> Date: Wed, 15 Feb 2017 17:27:58 +0800 User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:38.0) Gecko/20100101 Thunderbird/38.5.1 MIME-Version: 1.0 In-Reply-To: <87y3x7omrc.fsf@linux.intel.com> Content-Type: text/plain; charset=windows-1252 Content-Transfer-Encoding: 7bit Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org Hi, On 02/15/2017 04:56 PM, Felipe Balbi wrote: > Hi, > > Lu Baolu writes: >>> Lu Baolu writes: >>>> 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 >>>> + ) >>>> +); >>> we already have a generic TRB tracer that decodes every single TRB. What >>> is this bringing that the previous doesn't provide? >> This tracer traces the life cycle of a command. It gives, >> >> 1) Which function started an xhci command? >> 2) What was name of that command? >> 3) Did hardware respond to it, or timed out? >> 4) If hardware responded, what was the execution result? >> 5) If timed out, did 'abort command ring operation' abort it successfully? >> 6) Was the command structure freed at last? > We already have all that, AFAICT. Command is enqueued, then an event > triggers for command completion, then we look at results. The TRB tracer can directly tell us above 2 and 4 by tracing the enqueue and dequeue of command trbs. It doesn't tell us 1 and 6. For 3 and 5, we might be able to get to know, but it needs deep understand of the driver code and many efforts to look through the trace log. This command tracer will make the life easier when we are debugging command related issues in xhci driver. > The only thing > missing for completeness is slot/EP context tracers (which I've pointed > you to) so we can see what changes each command cause to the different > contexts. > > Frankly, I don't think printing out context pointers brings > anything. What can you do with that address? :-p Same goes for cmd > pointer, it brings nothing; gives no insight into the problem > whatsoever. > > We certainly need to know which command was enqueued, the slot, etc. But > addresses... not so sure. My thought was 'if we find a command failed, we might want to know what parameters did we feed hardware'. The trb and ctx pointers will let us go through the trb and context trace log. For the command pointer, it can help us to grep the trace log of a single command, so we are able to know how did the command go. Best regards, Lu Baolu > >>> BTW, I also have >>> ready Slot and EP context tracers, I didn't send before because I >>> already had quite a large series pending for Mathias :-p >> Sorry for the duplication. > no need to apologize, you didn't know :-) >