Re: [RFC] xhci: add trace for debug messages related to changing contexts

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 



Hi Xenia!

On Tue, Jul 23, 2013 at 06:14:55AM +0300, Xenia Ragiadakou wrote:
> This patch defines a new trace event, which is called xhci_dbg_context_change
> and belongs in the event class xhci_log_msg, and adds tracepoints for tracing
> the debug messages related to context updates performed with Configure Endpoint
> and Evaluate Context commands.

The patch looks good in general, but there's some print statements that
I want to be associated with a different trace point for host controller
"quirks".  A quirk is hardware behavior that violates the hardware
specification, and software needs to work around that behavior.  It
means the xHCI driver behaves differently when it runs on a quirky host.

Can you make a separate trace event for these functions?  Perhaps called
xhci_dbg_quirks?

In the xHCI driver, there's quirks code that handles the Intel Panther
Point bandwidth calculations.  Basically, that's any code that's wrapped
in if statements checking whether the XHCI_EP_LIMIT_QUIRK or
XHCI_SW_BW_CHECKING bit is set in xhci->quirks.  That also includes
functions like xhci_reserve_bandwidth() and all the functions it calls.

For Fresco Logic hosts, there's print statements associated with
XHCI_RESET_EP_QUIRK in xhci_cleanup_stalled_ring().  There's probably
other print statements associated with quirky hosts, so look for print
statements after testing xhci->quirks, and I'll let you know which ones
should be included in the quirks tracepoint.

Basically, look around for code that is only called when a bit is set in
xhci->quirks, and add any print statements to the xhci_dbg_quirks trace
point.

Comments on specific statements are below:

> Signed-off-by: Xenia Ragiadakou <burzalodowa@xxxxxxxxx>
> ---
>  drivers/usb/host/xhci-mem.c   |  4 +++-
>  drivers/usb/host/xhci-ring.c  | 10 +++++++---
>  drivers/usb/host/xhci-trace.h |  5 +++++
>  drivers/usb/host/xhci.c       | 36 ++++++++++++++++++++++++------------
>  4 files changed, 39 insertions(+), 16 deletions(-)
> 
> diff --git a/drivers/usb/host/xhci-mem.c b/drivers/usb/host/xhci-mem.c
> index b881bc1..03aa32d 100644
> --- a/drivers/usb/host/xhci-mem.c
> +++ b/drivers/usb/host/xhci-mem.c
> @@ -26,6 +26,7 @@
>  #include <linux/dmapool.h>
>  
>  #include "xhci.h"
> +#include "xhci-trace.h"
>  
>  /*
>   * Allocates a generic ring segment from the ring pool, sets the dma address,
> @@ -661,7 +662,8 @@ void xhci_setup_streams_ep_input_ctx(struct xhci_hcd *xhci,
>  	 * fls(0) = 0, fls(0x1) = 1, fls(0x10) = 2, fls(0x100) = 3, etc.
>  	 */
>  	max_primary_streams = fls(stream_info->num_stream_ctxs) - 2;
> -	xhci_dbg(xhci, "Setting number of stream ctx array entries to %u\n",
> +	xhci_dbg_trace(xhci,  trace_xhci_dbg_context_change,
> +			"Setting number of stream ctx array entries to %u\n",
>  			1 << (max_primary_streams + 1));
>  	ep_ctx->ep_info &= cpu_to_le32(~EP_MAXPSTREAMS_MASK);
>  	ep_ctx->ep_info |= cpu_to_le32(EP_MAXPSTREAMS(max_primary_streams)
> diff --git a/drivers/usb/host/xhci-ring.c b/drivers/usb/host/xhci-ring.c
> index 1e57eaf..6adf293 100644
> --- a/drivers/usb/host/xhci-ring.c
> +++ b/drivers/usb/host/xhci-ring.c
> @@ -67,6 +67,7 @@
>  #include <linux/scatterlist.h>
>  #include <linux/slab.h>
>  #include "xhci.h"
> +#include "xhci-trace.h"
>  
>  static int handle_cmd_in_cmd_wait_list(struct xhci_hcd *xhci,
>  		struct xhci_virt_device *virt_dev,
> @@ -1158,7 +1159,8 @@ static void handle_reset_ep_completion(struct xhci_hcd *xhci,
>  	 * because the HW can't handle two commands being queued in a row.
>  	 */
>  	if (xhci->quirks & XHCI_RESET_EP_QUIRK) {
> -		xhci_dbg(xhci, "Queueing configure endpoint command\n");
> +		xhci_dbg_trace(xhci, trace_xhci_dbg_context_change,
> +				"Queueing configure endpoint command\n");
>  		xhci_queue_configure_endpoint(xhci,
>  				xhci->devs[slot_id]->in_ctx->dma, slot_id,
>  				false);

This should be part of the quirks tracepoint.

> @@ -1444,7 +1446,8 @@ static void handle_cmd_completion(struct xhci_hcd *xhci,
>  			ep_state = xhci->devs[slot_id]->eps[ep_index].ep_state;
>  			if (!(ep_state & EP_HALTED))
>  				goto bandwidth_change;
> -			xhci_dbg(xhci, "Completed config ep cmd - "
> +			xhci_dbg_trace(xhci,  trace_xhci_dbg_context_change,
> +					"Completed config ep cmd - "
>  					"last ep index = %d, state = %d\n",
>  					ep_index, ep_state);
>  			/* Clear internal halted state and restart ring(s) */
> @@ -1454,7 +1457,8 @@ static void handle_cmd_completion(struct xhci_hcd *xhci,
>  			break;
>  		}
>  bandwidth_change:
> -		xhci_dbg(xhci, "Completed config ep cmd\n");
> +		xhci_dbg_trace(xhci,  trace_xhci_dbg_context_change,
> +				"Completed config ep cmd\n");
>  		xhci->devs[slot_id]->cmd_status =
>  			GET_COMP_CODE(le32_to_cpu(event->status));
>  		complete(&xhci->devs[slot_id]->cmd_completion);
> diff --git a/drivers/usb/host/xhci-trace.h b/drivers/usb/host/xhci-trace.h
> index 432aa67..6286243 100644
> --- a/drivers/usb/host/xhci-trace.h
> +++ b/drivers/usb/host/xhci-trace.h
> @@ -36,6 +36,11 @@ DEFINE_EVENT(xhci_log_msg, xhci_dbg_address,
>  	TP_ARGS(vaf)
>  );
>  
> +DEFINE_EVENT(xhci_log_msg, xhci_dbg_context_change,
> +	TP_PROTO(struct va_format *vaf),
> +	TP_ARGS(vaf)
> +);
> +
>  #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 081b5b5..8b4a087 100644
> --- a/drivers/usb/host/xhci.c
> +++ b/drivers/usb/host/xhci.c
> @@ -1153,12 +1153,16 @@ static int xhci_check_maxpacket(struct xhci_hcd *xhci, unsigned int slot_id,
>  	hw_max_packet_size = MAX_PACKET_DECODED(le32_to_cpu(ep_ctx->ep_info2));
>  	max_packet_size = usb_endpoint_maxp(&urb->dev->ep0.desc);
>  	if (hw_max_packet_size != max_packet_size) {
> -		xhci_dbg(xhci, "Max Packet Size for ep 0 changed.\n");
> -		xhci_dbg(xhci, "Max packet size in usb_device = %d\n",
> +		xhci_dbg_trace(xhci,  trace_xhci_dbg_context_change,
> +				"Max Packet Size for ep 0 changed.\n");
> +		xhci_dbg_trace(xhci,  trace_xhci_dbg_context_change,
> +				"Max packet size in usb_device = %d\n",
>  				max_packet_size);
> -		xhci_dbg(xhci, "Max packet size in xHCI HW = %d\n",
> +		xhci_dbg_trace(xhci,  trace_xhci_dbg_context_change,
> +				"Max packet size in xHCI HW = %d\n",
>  				hw_max_packet_size);
> -		xhci_dbg(xhci, "Issuing evaluate context command.\n");
> +		xhci_dbg_trace(xhci,  trace_xhci_dbg_context_change,
> +				"Issuing evaluate context command.\n");
>  
>  		/* Set up the input context flags for the command */
>  		/* FIXME: This won't work if a non-default control endpoint
> @@ -1776,7 +1780,8 @@ static int xhci_configure_endpoint_result(struct xhci_hcd *xhci,
>  		ret = -ENODEV;
>  		break;
>  	case COMP_SUCCESS:
> -		dev_dbg(&udev->dev, "Successful Endpoint Configure command\n");
> +		xhci_dbg_trace(xhci, trace_xhci_dbg_context_change,
> +				"Successful Endpoint Configure command\n");
>  		ret = 0;
>  		break;
>  	default:
> @@ -1822,7 +1827,8 @@ static int xhci_evaluate_context_result(struct xhci_hcd *xhci,
>  		ret = -EINVAL;
>  		break;
>  	case COMP_SUCCESS:
> -		dev_dbg(&udev->dev, "Successful evaluate context command\n");
> +		xhci_dbg_trace(xhci, trace_xhci_dbg_context_change,
> +				"Successful evaluate context command\n");
>  		ret = 0;
>  		break;
>  	default:
> @@ -1888,14 +1894,16 @@ static int xhci_reserve_host_resources(struct xhci_hcd *xhci,
>  
>  	added_eps = xhci_count_num_new_endpoints(xhci, ctrl_ctx);
>  	if (xhci->num_active_eps + added_eps > xhci->limit_active_eps) {
> -		xhci_dbg(xhci, "Not enough ep ctxs: "
> +		xhci_dbg_trace(xhci, trace_xhci_dbg_context_change,
> +				"Not enough ep ctxs: "
>  				"%u active, need to add %u, limit is %u.\n",
>  				xhci->num_active_eps, added_eps,
>  				xhci->limit_active_eps);
>  		return -ENOMEM;
>  	}
>  	xhci->num_active_eps += added_eps;
> -	xhci_dbg(xhci, "Adding %u ep ctxs, %u now active.\n", added_eps,
> +	xhci_dbg_trace(xhci, trace_xhci_dbg_context_change,
> +			"Adding %u ep ctxs, %u now active.\n", added_eps,
>  			xhci->num_active_eps);
>  	return 0;
>  }

This should also be part of the quirks tracepoint because it's only
called when the host has the XHCI_EP_LIMIT_QUIRK quirk.

> @@ -1913,7 +1921,8 @@ static void xhci_free_host_resources(struct xhci_hcd *xhci,
>  
>  	num_failed_eps = xhci_count_num_new_endpoints(xhci, ctrl_ctx);
>  	xhci->num_active_eps -= num_failed_eps;
> -	xhci_dbg(xhci, "Removing %u failed ep ctxs, %u now active.\n",
> +	xhci_dbg_trace(xhci, trace_xhci_dbg_context_change,
> +			"Removing %u failed ep ctxs, %u now active.\n",
>  			num_failed_eps,
>  			xhci->num_active_eps);
>  }

This should also be a quirks tracepoint.

> @@ -1932,7 +1941,8 @@ static void xhci_finish_resource_reservation(struct xhci_hcd *xhci,
>  	num_dropped_eps = xhci_count_num_dropped_endpoints(xhci, ctrl_ctx);
>  	xhci->num_active_eps -= num_dropped_eps;
>  	if (num_dropped_eps)
> -		xhci_dbg(xhci, "Removing %u dropped ep ctxs, %u now active.\n",
> +		xhci_dbg_trace(xhci, trace_xhci_dbg_context_change,
> +				"Removing %u dropped ep ctxs, %u now active.\n",
>  				num_dropped_eps,
>  				xhci->num_active_eps);
>  }

Same here.

> @@ -2583,7 +2593,8 @@ static int xhci_configure_endpoint(struct xhci_hcd *xhci,
>  		if ((xhci->quirks & XHCI_EP_LIMIT_QUIRK))
>  			xhci_free_host_resources(xhci, ctrl_ctx);
>  		spin_unlock_irqrestore(&xhci->lock, flags);
> -		xhci_dbg(xhci, "FIXME allocate a new ring segment\n");
> +		xhci_dbg_trace(xhci,  trace_xhci_dbg_context_change,
> +				"FIXME allocate a new ring segment\n");
>  		return -ENOMEM;
>  	}
>  	xhci_ring_cmd_db(xhci);
> @@ -3863,7 +3874,8 @@ static int xhci_change_max_exit_latency(struct xhci_hcd *xhci,
>  	slot_ctx->dev_info2 &= cpu_to_le32(~((u32) MAX_EXIT));
>  	slot_ctx->dev_info2 |= cpu_to_le32(max_exit_latency);
>  
> -	xhci_dbg(xhci, "Set up evaluate context for LPM MEL change.\n");
> +	xhci_dbg_trace(xhci, trace_xhci_dbg_context_change,
> +			"Set up evaluate context for LPM MEL change.\n");
>  	xhci_dbg(xhci, "Slot %u Input Context:\n", udev->slot_id);
>  	xhci_dbg_ctx(xhci, command->in_ctx, 0);
>  
> -- 
> 1.8.3.2
> 

Sarah Sharp
--
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




[Index of Archives]     [Linux Media]     [Linux Input]     [Linux Audio Users]     [Yosemite News]     [Linux Kernel]     [Linux SCSI]     [Old Linux USB Devel Archive]

  Powered by Linux