From 1fe6c4524f765734d376c39d0f41e25519f6235d Mon Sep 17 00:00:00 2001 From: Al Cooper Date: Thu, 25 Jul 2013 19:04:44 -0400 Subject: [PATCH 01/14] usb: Add Device Tree support to XHCI Platform driver Add Device Tree match table to xhci-plat.c. Add DT bindings document. Signed-off-by: Al Cooper Cc: Sergei Shtylyov Cc: Felipe Balbi Signed-off-by: Sarah Sharp --- Documentation/devicetree/bindings/usb/usb-xhci.txt | 14 ++++++++++++++ drivers/usb/host/xhci-plat.c | 10 ++++++++++ 2 files changed, 24 insertions(+) create mode 100644 Documentation/devicetree/bindings/usb/usb-xhci.txt diff --git a/Documentation/devicetree/bindings/usb/usb-xhci.txt b/Documentation/devicetree/bindings/usb/usb-xhci.txt new file mode 100644 index 000000000000..5752df0e17a2 --- /dev/null +++ b/Documentation/devicetree/bindings/usb/usb-xhci.txt @@ -0,0 +1,14 @@ +USB xHCI controllers + +Required properties: + - compatible: should be "xhci-platform". + - reg: should contain address and length of the standard XHCI + register set for the device. + - interrupts: one XHCI interrupt should be described here. + +Example: + usb@f0931000 { + compatible = "xhci-platform"; + reg = <0xf0931000 0x8c8>; + interrupts = <0x0 0x4e 0x0>; + }; diff --git a/drivers/usb/host/xhci-plat.c b/drivers/usb/host/xhci-plat.c index 412fe8d167cf..3fcdaea21e24 100644 --- a/drivers/usb/host/xhci-plat.c +++ b/drivers/usb/host/xhci-plat.c @@ -14,6 +14,7 @@ #include #include #include +#include #include "xhci.h" @@ -211,12 +212,21 @@ static const struct dev_pm_ops xhci_plat_pm_ops = { #define DEV_PM_OPS NULL #endif /* CONFIG_PM */ +#ifdef CONFIG_OF +static const struct of_device_id usb_xhci_of_match[] = { + { .compatible = "xhci-platform" }, + { }, +}; +MODULE_DEVICE_TABLE(of, usb_xhci_of_match); +#endif + static struct platform_driver usb_xhci_driver = { .probe = xhci_plat_probe, .remove = xhci_plat_remove, .driver = { .name = "xhci-hcd", .pm = DEV_PM_OPS, + .of_match_table = of_match_ptr(usb_xhci_of_match), }, }; MODULE_ALIAS("platform:xhci-hcd"); From 38a532a621ad8533d8839ef0ff8bd15dc08b8eab Mon Sep 17 00:00:00 2001 From: Xenia Ragiadakou Date: Tue, 2 Jul 2013 17:49:25 +0300 Subject: [PATCH 02/14] xhci: replace xhci_info() with xhci_dbg() This patch replaces the calls to xhci_info() with calls to xhci_dbg() and removes the unused xhci_info() definition from xhci-hcd. By replacing the xhci_info() with xhci_dbg(), the calls to dev_info() are replaced with calls to dev_dbg() so that their output can be dynamically controlled via the dynamic debugging mechanism. Signed-off-by: Xenia Ragiadakou Signed-off-by: Sarah Sharp --- drivers/usb/host/xhci.c | 4 ++-- drivers/usb/host/xhci.h | 2 -- 2 files changed, 2 insertions(+), 4 deletions(-) diff --git a/drivers/usb/host/xhci.c b/drivers/usb/host/xhci.c index c8d7199eefa0..c3b8f1481aaf 100644 --- a/drivers/usb/host/xhci.c +++ b/drivers/usb/host/xhci.c @@ -3508,10 +3508,10 @@ int xhci_discover_or_reset_device(struct usb_hcd *hcd, struct usb_device *udev) switch (ret) { case COMP_EBADSLT: /* 0.95 completion code for bad slot ID */ case COMP_CTX_STATE: /* 0.96 completion code for same thing */ - xhci_info(xhci, "Can't reset device (slot ID %u) in %s state\n", + xhci_dbg(xhci, "Can't reset device (slot ID %u) in %s state\n", slot_id, xhci_get_slot_state(xhci, virt_dev->out_ctx)); - xhci_info(xhci, "Not freeing device rings.\n"); + xhci_dbg(xhci, "Not freeing device rings.\n"); /* Don't treat this as an error. May change my mind later. */ ret = 0; goto command_cleanup; diff --git a/drivers/usb/host/xhci.h b/drivers/usb/host/xhci.h index c338741a675d..0a74d10be8a1 100644 --- a/drivers/usb/host/xhci.h +++ b/drivers/usb/host/xhci.h @@ -1587,8 +1587,6 @@ static inline struct usb_hcd *xhci_to_hcd(struct xhci_hcd *xhci) #define xhci_dbg(xhci, fmt, args...) \ do { if (XHCI_DEBUG) dev_dbg(xhci_to_hcd(xhci)->self.controller , fmt , ## args); } while (0) -#define xhci_info(xhci, fmt, args...) \ - do { if (XHCI_DEBUG) dev_info(xhci_to_hcd(xhci)->self.controller , fmt , ## args); } while (0) #define xhci_err(xhci, fmt, args...) \ dev_err(xhci_to_hcd(xhci)->self.controller , fmt , ## args) #define xhci_warn(xhci, fmt, args...) \ From 5c1127d320e02fccebf10ec3d8bce13317bb4d3c Mon Sep 17 00:00:00 2001 From: Xenia Ragiadakou Date: Tue, 2 Jul 2013 17:49:26 +0300 Subject: [PATCH 03/14] xhci: replace printk(KERN_DEBUG ...) This patch replaces the calls to printk(KERN_DEBUG ...) with either calls to xhci_dbg() or calls to pr_debug(), depending on whether the xhci_hcd structure is available at callsite, so that the correspoding debugging messages are not enabled by default when CONFIG_DYNAMIC_DEBUG option is set but rather can be enabled dynamically taking advantage of the dynamic debugging feature. Also, it adds a newline at the end of debugging messages in case there is not, so that messages don't appear broken when printed. Signed-off-by: Xenia Ragiadakou Signed-off-by: Sarah Sharp --- drivers/usb/host/xhci.c | 16 +++++++--------- 1 file changed, 7 insertions(+), 9 deletions(-) diff --git a/drivers/usb/host/xhci.c b/drivers/usb/host/xhci.c index c3b8f1481aaf..0208ffff99dc 100644 --- a/drivers/usb/host/xhci.c +++ b/drivers/usb/host/xhci.c @@ -1170,27 +1170,25 @@ static int xhci_check_args(struct usb_hcd *hcd, struct usb_device *udev, struct xhci_virt_device *virt_dev; if (!hcd || (check_ep && !ep) || !udev) { - printk(KERN_DEBUG "xHCI %s called with invalid args\n", - func); + pr_debug("xHCI %s called with invalid args\n", func); return -EINVAL; } if (!udev->parent) { - printk(KERN_DEBUG "xHCI %s called for root hub\n", - func); + pr_debug("xHCI %s called for root hub\n", func); return 0; } xhci = hcd_to_xhci(hcd); if (check_virt_dev) { if (!udev->slot_id || !xhci->devs[udev->slot_id]) { - printk(KERN_DEBUG "xHCI %s called with unaddressed " - "device\n", func); + xhci_dbg(xhci, "xHCI %s called with unaddressed device\n", + func); return -EINVAL; } virt_dev = xhci->devs[udev->slot_id]; if (virt_dev->udev != udev) { - printk(KERN_DEBUG "xHCI %s called with udev and " + xhci_dbg(xhci, "xHCI %s called with udev and " "virt_dev does not match\n", func); return -EINVAL; } @@ -4941,12 +4939,12 @@ static int __init xhci_hcd_init(void) retval = xhci_register_pci(); if (retval < 0) { - printk(KERN_DEBUG "Problem registering PCI driver."); + pr_debug("Problem registering PCI driver.\n"); return retval; } retval = xhci_register_plat(); if (retval < 0) { - printk(KERN_DEBUG "Problem registering platform driver."); + pr_debug("Problem registering platform driver.\n"); goto unreg_pci; } /* From b2497509df002e9a09c8550cd0ecd2f77c9640d8 Mon Sep 17 00:00:00 2001 From: Xenia Ragiadakou Date: Tue, 2 Jul 2013 17:49:27 +0300 Subject: [PATCH 04/14] xhci: remove CONFIG_USB_XHCI_HCD_DEBUGGING and unused code CONFIG_USB_XHCI_HCD_DEBUGGING option is used to enable verbose debugging output for the xHCI host controller driver. In the current version of the xhci-hcd driver, this option must be turned on, in order for the debugging log messages to be displayed, and users may need to recompile the linux kernel to obtain debugging information that will help them track down problems. This patch removes the above debug option to enable debugging log messages at all times. The aim of this is to rely on the debugfs and the dynamic debugging feature for fine-grained management of debugging messages and to not force users to set the debug config option and compile the linux kernel in order to have access in that information. This patch, also, removes the XHCI_DEBUG symbol and the functions dma_to_stream_ring(), xhci_test_radix_tree() and xhci_event_ring_work() that are not useful anymore. Signed-off-by: Xenia Ragiadakou Signed-off-by: Sarah Sharp --- drivers/usb/host/Kconfig | 9 ----- drivers/usb/host/xhci-mem.c | 70 ----------------------------------- drivers/usb/host/xhci.c | 74 ------------------------------------- drivers/usb/host/xhci.h | 13 +------ 4 files changed, 1 insertion(+), 165 deletions(-) diff --git a/drivers/usb/host/Kconfig b/drivers/usb/host/Kconfig index cf521d6551dd..28bc5befeae3 100644 --- a/drivers/usb/host/Kconfig +++ b/drivers/usb/host/Kconfig @@ -29,15 +29,6 @@ if USB_XHCI_HCD config USB_XHCI_PLATFORM tristate -config USB_XHCI_HCD_DEBUGGING - bool "Debugging for the xHCI host controller" - ---help--- - Say 'Y' to turn on debugging for the xHCI host controller driver. - This will spew debugging output, even in interrupt context. - This should only be used for debugging xHCI driver bugs. - - If unsure, say N. - endif # USB_XHCI_HCD config USB_EHCI_HCD diff --git a/drivers/usb/host/xhci-mem.c b/drivers/usb/host/xhci-mem.c index df6978abd7e6..b881bc1697f9 100644 --- a/drivers/usb/host/xhci-mem.c +++ b/drivers/usb/host/xhci-mem.c @@ -481,17 +481,6 @@ struct xhci_ring *xhci_dma_to_transfer_ring( return ep->ring; } -/* Only use this when you know stream_info is valid */ -#ifdef CONFIG_USB_XHCI_HCD_DEBUGGING -static struct xhci_ring *dma_to_stream_ring( - struct xhci_stream_info *stream_info, - u64 address) -{ - return radix_tree_lookup(&stream_info->trb_address_map, - address >> TRB_SEGMENT_SHIFT); -} -#endif /* CONFIG_USB_XHCI_HCD_DEBUGGING */ - struct xhci_ring *xhci_stream_id_to_ring( struct xhci_virt_device *dev, unsigned int ep_index, @@ -509,58 +498,6 @@ struct xhci_ring *xhci_stream_id_to_ring( return ep->stream_info->stream_rings[stream_id]; } -#ifdef CONFIG_USB_XHCI_HCD_DEBUGGING -static int xhci_test_radix_tree(struct xhci_hcd *xhci, - unsigned int num_streams, - struct xhci_stream_info *stream_info) -{ - u32 cur_stream; - struct xhci_ring *cur_ring; - u64 addr; - - for (cur_stream = 1; cur_stream < num_streams; cur_stream++) { - struct xhci_ring *mapped_ring; - int trb_size = sizeof(union xhci_trb); - - cur_ring = stream_info->stream_rings[cur_stream]; - for (addr = cur_ring->first_seg->dma; - addr < cur_ring->first_seg->dma + TRB_SEGMENT_SIZE; - addr += trb_size) { - mapped_ring = dma_to_stream_ring(stream_info, addr); - if (cur_ring != mapped_ring) { - xhci_warn(xhci, "WARN: DMA address 0x%08llx " - "didn't map to stream ID %u; " - "mapped to ring %p\n", - (unsigned long long) addr, - cur_stream, - mapped_ring); - return -EINVAL; - } - } - /* One TRB after the end of the ring segment shouldn't return a - * pointer to the current ring (although it may be a part of a - * different ring). - */ - mapped_ring = dma_to_stream_ring(stream_info, addr); - if (mapped_ring != cur_ring) { - /* One TRB before should also fail */ - addr = cur_ring->first_seg->dma - trb_size; - mapped_ring = dma_to_stream_ring(stream_info, addr); - } - if (mapped_ring == cur_ring) { - xhci_warn(xhci, "WARN: Bad DMA address 0x%08llx " - "mapped to valid stream ID %u; " - "mapped ring = %p\n", - (unsigned long long) addr, - cur_stream, - mapped_ring); - return -EINVAL; - } - } - return 0; -} -#endif /* CONFIG_USB_XHCI_HCD_DEBUGGING */ - /* * Change an endpoint's internal structure so it supports stream IDs. The * number of requested streams includes stream 0, which cannot be used by device @@ -687,13 +624,6 @@ struct xhci_stream_info *xhci_alloc_stream_info(struct xhci_hcd *xhci, * was any other way, the host controller would assume the ring is * "empty" and wait forever for data to be queued to that stream ID). */ -#if XHCI_DEBUG - /* Do a little test on the radix tree to make sure it returns the - * correct values. - */ - if (xhci_test_radix_tree(xhci, num_streams, stream_info)) - goto cleanup_rings; -#endif return stream_info; diff --git a/drivers/usb/host/xhci.c b/drivers/usb/host/xhci.c index 0208ffff99dc..b87404535c29 100644 --- a/drivers/usb/host/xhci.c +++ b/drivers/usb/host/xhci.c @@ -528,57 +528,6 @@ int xhci_init(struct usb_hcd *hcd) /*-------------------------------------------------------------------------*/ -#ifdef CONFIG_USB_XHCI_HCD_DEBUGGING -static void xhci_event_ring_work(unsigned long arg) -{ - unsigned long flags; - int temp; - u64 temp_64; - struct xhci_hcd *xhci = (struct xhci_hcd *) arg; - int i, j; - - xhci_dbg(xhci, "Poll event ring: %lu\n", jiffies); - - spin_lock_irqsave(&xhci->lock, flags); - temp = xhci_readl(xhci, &xhci->op_regs->status); - xhci_dbg(xhci, "op reg status = 0x%x\n", temp); - if (temp == 0xffffffff || (xhci->xhc_state & XHCI_STATE_DYING) || - (xhci->xhc_state & XHCI_STATE_HALTED)) { - xhci_dbg(xhci, "HW died, polling stopped.\n"); - spin_unlock_irqrestore(&xhci->lock, flags); - return; - } - - temp = xhci_readl(xhci, &xhci->ir_set->irq_pending); - xhci_dbg(xhci, "ir_set 0 pending = 0x%x\n", temp); - xhci_dbg(xhci, "HC error bitmask = 0x%x\n", xhci->error_bitmask); - xhci->error_bitmask = 0; - xhci_dbg(xhci, "Event ring:\n"); - xhci_debug_segment(xhci, xhci->event_ring->deq_seg); - xhci_dbg_ring_ptrs(xhci, xhci->event_ring); - temp_64 = xhci_read_64(xhci, &xhci->ir_set->erst_dequeue); - temp_64 &= ~ERST_PTR_MASK; - xhci_dbg(xhci, "ERST deq = 64'h%0lx\n", (long unsigned int) temp_64); - xhci_dbg(xhci, "Command ring:\n"); - xhci_debug_segment(xhci, xhci->cmd_ring->deq_seg); - xhci_dbg_ring_ptrs(xhci, xhci->cmd_ring); - xhci_dbg_cmd_ptrs(xhci); - for (i = 0; i < MAX_HC_SLOTS; ++i) { - if (!xhci->devs[i]) - continue; - for (j = 0; j < 31; ++j) { - xhci_dbg_ep_rings(xhci, i, j, &xhci->devs[i]->eps[j]); - } - } - spin_unlock_irqrestore(&xhci->lock, flags); - - if (!xhci->zombie) - mod_timer(&xhci->event_ring_timer, jiffies + POLL_TIMEOUT * HZ); - else - xhci_dbg(xhci, "Quit polling the event ring.\n"); -} -#endif - static int xhci_run_finished(struct xhci_hcd *xhci) { if (xhci_start(xhci)) { @@ -628,17 +577,6 @@ int xhci_run(struct usb_hcd *hcd) if (ret) return ret; -#ifdef CONFIG_USB_XHCI_HCD_DEBUGGING - init_timer(&xhci->event_ring_timer); - xhci->event_ring_timer.data = (unsigned long) xhci; - xhci->event_ring_timer.function = xhci_event_ring_work; - /* Poll the event ring */ - xhci->event_ring_timer.expires = jiffies + POLL_TIMEOUT * HZ; - xhci->zombie = 0; - xhci_dbg(xhci, "Setting event ring polling timer\n"); - add_timer(&xhci->event_ring_timer); -#endif - xhci_dbg(xhci, "Command ring memory map follows:\n"); xhci_debug_ring(xhci, xhci->cmd_ring); xhci_dbg_ring_ptrs(xhci, xhci->cmd_ring); @@ -725,12 +663,6 @@ void xhci_stop(struct usb_hcd *hcd) xhci_cleanup_msix(xhci); -#ifdef CONFIG_USB_XHCI_HCD_DEBUGGING - /* Tell the event ring poll function not to reschedule */ - xhci->zombie = 1; - del_timer_sync(&xhci->event_ring_timer); -#endif - /* Deleting Compliance Mode Recovery Timer */ if ((xhci->quirks & XHCI_COMP_MODE_QUIRK) && (!(xhci_all_ports_seen_u0(xhci)))) { @@ -1011,12 +943,6 @@ int xhci_resume(struct xhci_hcd *xhci, bool hibernated) spin_unlock_irq(&xhci->lock); xhci_cleanup_msix(xhci); -#ifdef CONFIG_USB_XHCI_HCD_DEBUGGING - /* Tell the event ring poll function not to reschedule */ - xhci->zombie = 1; - del_timer_sync(&xhci->event_ring_timer); -#endif - xhci_dbg(xhci, "// Disabling event ring interrupts\n"); temp = xhci_readl(xhci, &xhci->op_regs->status); xhci_writel(xhci, temp & ~STS_EINT, &xhci->op_regs->status); diff --git a/drivers/usb/host/xhci.h b/drivers/usb/host/xhci.h index 0a74d10be8a1..4d43531f5fcf 100644 --- a/drivers/usb/host/xhci.h +++ b/drivers/usb/host/xhci.h @@ -1490,11 +1490,6 @@ struct xhci_hcd { struct dma_pool *small_streams_pool; struct dma_pool *medium_streams_pool; -#ifdef CONFIG_USB_XHCI_HCD_DEBUGGING - /* Poll the rings - for debugging */ - struct timer_list event_ring_timer; - int zombie; -#endif /* Host controller watchdog timer structures */ unsigned int xhc_state; @@ -1579,14 +1574,8 @@ static inline struct usb_hcd *xhci_to_hcd(struct xhci_hcd *xhci) return xhci->main_hcd; } -#ifdef CONFIG_USB_XHCI_HCD_DEBUGGING -#define XHCI_DEBUG 1 -#else -#define XHCI_DEBUG 0 -#endif - #define xhci_dbg(xhci, fmt, args...) \ - do { if (XHCI_DEBUG) dev_dbg(xhci_to_hcd(xhci)->self.controller , fmt , ## args); } while (0) + dev_dbg(xhci_to_hcd(xhci)->self.controller , fmt , ## args) #define xhci_err(xhci, fmt, args...) \ dev_err(xhci_to_hcd(xhci)->self.controller , fmt , ## args) #define xhci_warn(xhci, fmt, args...) \ From 84a99f6fc5d4a2b7583aa287979268a8bb926367 Mon Sep 17 00:00:00 2001 From: Xenia Ragiadakou Date: Tue, 6 Aug 2013 00:22:15 +0300 Subject: [PATCH 05/14] xhci: add traces for debug messages in xhci_address_device() This patch declares an event class for trace events that trace messages with variadic arguments, called xhci_log_msg, and defines a trace event for tracing the debug messages in xhci_address_device() function, called xhci_dbg_address. In order to implement this type of trace events, a wrapper function, called xhci_dbg_trace(), was created that records the format string and variadic arguments into a va_format structure which is passed as argument to the tracepoints of the class xhci_log_msg. All the xhci_dbg() calls in xhci_address_device() are replaced with calls to xhci_dbg_trace(). The functionality of xhci_dbg() log messages was not removed though, but it is placed inside xhci_dbg_trace(). This trace event aims to give the ability to the user or the developper to isolate and trace the debug messages generated when an Address Device Command is issued to xHC. Signed-off-by: Xenia Ragiadakou Signed-off-by: Sarah Sharp --- drivers/usb/host/Makefile | 4 +++ drivers/usb/host/xhci-dbg.c | 14 ++++++++++ drivers/usb/host/xhci-trace.c | 15 +++++++++++ drivers/usb/host/xhci-trace.h | 49 +++++++++++++++++++++++++++++++++++ drivers/usb/host/xhci.c | 30 +++++++++++++-------- drivers/usb/host/xhci.h | 2 ++ 6 files changed, 103 insertions(+), 11 deletions(-) create mode 100644 drivers/usb/host/xhci-trace.c create mode 100644 drivers/usb/host/xhci-trace.h diff --git a/drivers/usb/host/Makefile b/drivers/usb/host/Makefile index 829a3397882a..50b0041c09a9 100644 --- a/drivers/usb/host/Makefile +++ b/drivers/usb/host/Makefile @@ -4,6 +4,9 @@ ccflags-$(CONFIG_USB_DEBUG) := -DDEBUG +# tell define_trace.h where to find the xhci trace header +CFLAGS_xhci-trace.o := -I$(src) + isp1760-y := isp1760-hcd.o isp1760-if.o fhci-y := fhci-hcd.o fhci-hub.o fhci-q.o @@ -13,6 +16,7 @@ fhci-$(CONFIG_FHCI_DEBUG) += fhci-dbg.o xhci-hcd-y := xhci.o xhci-mem.o xhci-hcd-y += xhci-ring.o xhci-hub.o xhci-dbg.o +xhci-hcd-y += xhci-trace.o xhci-hcd-$(CONFIG_PCI) += xhci-pci.o ifneq ($(CONFIG_USB_XHCI_PLATFORM), ) diff --git a/drivers/usb/host/xhci-dbg.c b/drivers/usb/host/xhci-dbg.c index 5d5e58fdeccc..73503a81ee81 100644 --- a/drivers/usb/host/xhci-dbg.c +++ b/drivers/usb/host/xhci-dbg.c @@ -580,3 +580,17 @@ void xhci_dbg_ctx(struct xhci_hcd *xhci, xhci_dbg_slot_ctx(xhci, ctx); xhci_dbg_ep_ctx(xhci, ctx, last_ep); } + +void xhci_dbg_trace(struct xhci_hcd *xhci, void (*trace)(struct va_format *), + const char *fmt, ...) +{ + struct va_format vaf; + va_list args; + + va_start(args, fmt); + vaf.fmt = fmt; + vaf.va = &args; + xhci_dbg(xhci, "%pV\n", &vaf); + trace(&vaf); + va_end(args); +} diff --git a/drivers/usb/host/xhci-trace.c b/drivers/usb/host/xhci-trace.c new file mode 100644 index 000000000000..7cf30c83dcf3 --- /dev/null +++ b/drivers/usb/host/xhci-trace.c @@ -0,0 +1,15 @@ +/* + * xHCI host controller driver + * + * Copyright (C) 2013 Xenia Ragiadakou + * + * Author: Xenia Ragiadakou + * Email : burzalodowa@gmail.com + * + * This program is free software; you can redistribute it and/or modify + * it under the terms of the GNU General Public License version 2 as + * published by the Free Software Foundation. + */ + +#define CREATE_TRACE_POINTS +#include "xhci-trace.h" diff --git a/drivers/usb/host/xhci-trace.h b/drivers/usb/host/xhci-trace.h new file mode 100644 index 000000000000..432aa675966c --- /dev/null +++ b/drivers/usb/host/xhci-trace.h @@ -0,0 +1,49 @@ +/* + * xHCI host controller driver + * + * Copyright (C) 2013 Xenia Ragiadakou + * + * Author: Xenia Ragiadakou + * Email : burzalodowa@gmail.com + * + * This program is free software; you can redistribute it and/or modify + * it under the terms of the GNU General Public License version 2 as + * published by the Free Software Foundation. + */ + +#undef TRACE_SYSTEM +#define TRACE_SYSTEM xhci-hcd + +#if !defined(__XHCI_TRACE_H) || defined(TRACE_HEADER_MULTI_READ) +#define __XHCI_TRACE_H + +#include + +#define XHCI_MSG_MAX 500 + +DECLARE_EVENT_CLASS(xhci_log_msg, + TP_PROTO(struct va_format *vaf), + TP_ARGS(vaf), + TP_STRUCT__entry(__dynamic_array(char, msg, XHCI_MSG_MAX)), + TP_fast_assign( + vsnprintf(__get_str(msg), XHCI_MSG_MAX, vaf->fmt, *vaf->va); + ), + TP_printk("%s", __get_str(msg)) +); + +DEFINE_EVENT(xhci_log_msg, xhci_dbg_address, + TP_PROTO(struct va_format *vaf), + TP_ARGS(vaf) +); + +#endif /* __XHCI_TRACE_H */ + +/* this part must be outside header guard */ + +#undef TRACE_INCLUDE_PATH +#define TRACE_INCLUDE_PATH . + +#undef TRACE_INCLUDE_FILE +#define TRACE_INCLUDE_FILE xhci-trace + +#include diff --git a/drivers/usb/host/xhci.c b/drivers/usb/host/xhci.c index b87404535c29..d57dc6cbd428 100644 --- a/drivers/usb/host/xhci.c +++ b/drivers/usb/host/xhci.c @@ -29,6 +29,7 @@ #include #include "xhci.h" +#include "xhci-trace.h" #define DRIVER_AUTHOR "Sarah Sharp" #define DRIVER_DESC "'eXtensible' Host Controller (xHC) Driver" @@ -3666,7 +3667,8 @@ int xhci_address_device(struct usb_hcd *hcd, struct usb_device *udev) union xhci_trb *cmd_trb; if (!udev->slot_id) { - xhci_dbg(xhci, "Bad Slot ID %d\n", udev->slot_id); + xhci_dbg_trace(xhci, trace_xhci_dbg_address, + "Bad Slot ID %d", udev->slot_id); return -EINVAL; } @@ -3712,7 +3714,8 @@ int xhci_address_device(struct usb_hcd *hcd, struct usb_device *udev) udev->slot_id); if (ret) { spin_unlock_irqrestore(&xhci->lock, flags); - xhci_dbg(xhci, "FIXME: allocate a command ring segment\n"); + xhci_dbg_trace(xhci, trace_xhci_dbg_address, + "FIXME: allocate a command ring segment"); return ret; } xhci_ring_cmd_db(xhci); @@ -3752,7 +3755,8 @@ int xhci_address_device(struct usb_hcd *hcd, struct usb_device *udev) ret = -ENODEV; break; case COMP_SUCCESS: - xhci_dbg(xhci, "Successful Address Device command\n"); + xhci_dbg_trace(xhci, trace_xhci_dbg_address, + "Successful Address Device command"); break; default: xhci_err(xhci, "ERROR: unexpected command completion " @@ -3766,13 +3770,16 @@ int xhci_address_device(struct usb_hcd *hcd, struct usb_device *udev) return ret; } temp_64 = xhci_read_64(xhci, &xhci->op_regs->dcbaa_ptr); - xhci_dbg(xhci, "Op regs DCBAA ptr = %#016llx\n", temp_64); - xhci_dbg(xhci, "Slot ID %d dcbaa entry @%p = %#016llx\n", - udev->slot_id, - &xhci->dcbaa->dev_context_ptrs[udev->slot_id], - (unsigned long long) - le64_to_cpu(xhci->dcbaa->dev_context_ptrs[udev->slot_id])); - xhci_dbg(xhci, "Output Context DMA address = %#08llx\n", + xhci_dbg_trace(xhci, trace_xhci_dbg_address, + "Op regs DCBAA ptr = %#016llx", temp_64); + xhci_dbg_trace(xhci, trace_xhci_dbg_address, + "Slot ID %d dcbaa entry @%p = %#016llx", + udev->slot_id, + &xhci->dcbaa->dev_context_ptrs[udev->slot_id], + (unsigned long long) + le64_to_cpu(xhci->dcbaa->dev_context_ptrs[udev->slot_id])); + xhci_dbg_trace(xhci, trace_xhci_dbg_address, + "Output Context DMA address = %#08llx", (unsigned long long)virt_dev->out_ctx->dma); xhci_dbg(xhci, "Slot ID %d Input Context:\n", udev->slot_id); xhci_dbg_ctx(xhci, virt_dev->in_ctx, 2); @@ -3791,7 +3798,8 @@ int xhci_address_device(struct usb_hcd *hcd, struct usb_device *udev) ctrl_ctx->add_flags = 0; ctrl_ctx->drop_flags = 0; - xhci_dbg(xhci, "Internal device address = %d\n", virt_dev->address); + xhci_dbg_trace(xhci, trace_xhci_dbg_address, + "Internal device address = %d", virt_dev->address); return 0; } diff --git a/drivers/usb/host/xhci.h b/drivers/usb/host/xhci.h index 4d43531f5fcf..d2045916531b 100644 --- a/drivers/usb/host/xhci.h +++ b/drivers/usb/host/xhci.h @@ -1647,6 +1647,8 @@ char *xhci_get_slot_state(struct xhci_hcd *xhci, void xhci_dbg_ep_rings(struct xhci_hcd *xhci, unsigned int slot_id, unsigned int ep_index, struct xhci_virt_ep *ep); +void xhci_dbg_trace(struct xhci_hcd *xhci, void (*trace)(struct va_format *), + const char *fmt, ...); /* xHCI memory management */ void xhci_mem_cleanup(struct xhci_hcd *xhci); From 3a7fa5bef06e1757d1aded8d78afd041b4552e11 Mon Sep 17 00:00:00 2001 From: Xenia Ragiadakou Date: Wed, 31 Jul 2013 07:35:27 +0300 Subject: [PATCH 06/14] xhci: add trace for debug messages related to changing contexts 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. Signed-off-by: Xenia Ragiadakou Signed-off-by: Sarah Sharp --- drivers/usb/host/xhci-mem.c | 4 +++- drivers/usb/host/xhci-ring.c | 4 +++- drivers/usb/host/xhci-trace.h | 5 +++++ drivers/usb/host/xhci.c | 24 ++++++++++++++++-------- 4 files changed, 27 insertions(+), 10 deletions(-) diff --git a/drivers/usb/host/xhci-mem.c b/drivers/usb/host/xhci-mem.c index b881bc1697f9..b1bb59b58b25 100644 --- a/drivers/usb/host/xhci-mem.c +++ b/drivers/usb/host/xhci-mem.c @@ -26,6 +26,7 @@ #include #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", 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 5b08cd85f8e7..ba5fd5a8c9bc 100644 --- a/drivers/usb/host/xhci-ring.c +++ b/drivers/usb/host/xhci-ring.c @@ -67,6 +67,7 @@ #include #include #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, @@ -1454,7 +1455,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"); 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 432aa675966c..628624306f38 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 d57dc6cbd428..fa7b6f43642f 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."); + xhci_dbg_trace(xhci, trace_xhci_dbg_context_change, + "Max packet size in usb_device = %d", 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", 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."); /* 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"); 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"); ret = 0; break; default: @@ -2583,7 +2589,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"); return -ENOMEM; } xhci_ring_cmd_db(xhci); @@ -3865,7 +3872,8 @@ static int __maybe_unused 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."); xhci_dbg(xhci, "Slot %u Input Context:\n", udev->slot_id); xhci_dbg_ctx(xhci, command->in_ctx, 0); From 4bdfe4c38fd5b06da558050a3288a0a48825a3e7 Mon Sep 17 00:00:00 2001 From: Xenia Ragiadakou Date: Tue, 6 Aug 2013 07:52:45 +0300 Subject: [PATCH 07/14] xhci: add trace for debug messages related to quirks This patch defines a new trace event, which is called xhci_dbg_quirks and belongs in the event class xhci_log_msg, and adds tracepoints that trace the debug messages associated with xHCs' quirks. Signed-off-by: Xenia Ragiadakou Signed-off-by: Sarah Sharp --- drivers/usb/host/xhci-hub.c | 7 ++-- drivers/usb/host/xhci-pci.c | 14 +++++--- drivers/usb/host/xhci-ring.c | 11 +++--- drivers/usb/host/xhci-trace.h | 5 +++ drivers/usb/host/xhci.c | 67 ++++++++++++++++++++++------------- 5 files changed, 69 insertions(+), 35 deletions(-) diff --git a/drivers/usb/host/xhci-hub.c b/drivers/usb/host/xhci-hub.c index 93f3fdf0ff0a..fae697ed0b70 100644 --- a/drivers/usb/host/xhci-hub.c +++ b/drivers/usb/host/xhci-hub.c @@ -24,6 +24,7 @@ #include #include "xhci.h" +#include "xhci-trace.h" #define PORT_WAKE_BITS (PORT_WKOC_E | PORT_WKDISC_E | PORT_WKCONN_E) #define PORT_RWC_BITS (PORT_CSC | PORT_PEC | PORT_WRC | PORT_OCC | \ @@ -535,8 +536,10 @@ void xhci_del_comp_mod_timer(struct xhci_hcd *xhci, u32 status, u16 wIndex) xhci->port_status_u0 |= 1 << wIndex; if (xhci->port_status_u0 == all_ports_seen_u0) { del_timer_sync(&xhci->comp_mode_recovery_timer); - xhci_dbg(xhci, "All USB3 ports have entered U0 already!\n"); - xhci_dbg(xhci, "Compliance Mode Recovery Timer Deleted.\n"); + xhci_dbg_trace(xhci, trace_xhci_dbg_quirks, + "All USB3 ports have entered U0 already!"); + xhci_dbg_trace(xhci, trace_xhci_dbg_quirks, + "Compliance Mode Recovery Timer Deleted."); } } } diff --git a/drivers/usb/host/xhci-pci.c b/drivers/usb/host/xhci-pci.c index 72960684a942..c2d495057eb5 100644 --- a/drivers/usb/host/xhci-pci.c +++ b/drivers/usb/host/xhci-pci.c @@ -25,6 +25,7 @@ #include #include "xhci.h" +#include "xhci-trace.h" /* Device for a quirk */ #define PCI_VENDOR_ID_FRESCO_LOGIC 0x1b73 @@ -64,16 +65,18 @@ static void xhci_pci_quirks(struct device *dev, struct xhci_hcd *xhci) if (pdev->device == PCI_DEVICE_ID_FRESCO_LOGIC_PDK && pdev->revision == 0x0) { xhci->quirks |= XHCI_RESET_EP_QUIRK; - xhci_dbg(xhci, "QUIRK: Fresco Logic xHC needs configure" - " endpoint cmd after reset endpoint\n"); + xhci_dbg_trace(xhci, trace_xhci_dbg_quirks, + "QUIRK: Fresco Logic xHC needs configure" + " endpoint cmd after reset endpoint"); } /* Fresco Logic confirms: all revisions of this chip do not * support MSI, even though some of them claim to in their PCI * capabilities. */ xhci->quirks |= XHCI_BROKEN_MSI; - xhci_dbg(xhci, "QUIRK: Fresco Logic revision %u " - "has broken MSI implementation\n", + xhci_dbg_trace(xhci, trace_xhci_dbg_quirks, + "QUIRK: Fresco Logic revision %u " + "has broken MSI implementation", pdev->revision); xhci->quirks |= XHCI_TRUST_TX_LENGTH; } @@ -110,7 +113,8 @@ static void xhci_pci_quirks(struct device *dev, struct xhci_hcd *xhci) if (pdev->vendor == PCI_VENDOR_ID_ETRON && pdev->device == PCI_DEVICE_ID_ASROCK_P67) { xhci->quirks |= XHCI_RESET_ON_RESUME; - xhci_dbg(xhci, "QUIRK: Resetting on resume\n"); + xhci_dbg_trace(xhci, trace_xhci_dbg_quirks, + "QUIRK: Resetting on resume"); xhci->quirks |= XHCI_TRUST_TX_LENGTH; } if (pdev->vendor == PCI_VENDOR_ID_VIA) diff --git a/drivers/usb/host/xhci-ring.c b/drivers/usb/host/xhci-ring.c index ba5fd5a8c9bc..e88e8772ab5d 100644 --- a/drivers/usb/host/xhci-ring.c +++ b/drivers/usb/host/xhci-ring.c @@ -1159,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_quirks, + "Queueing configure endpoint command"); xhci_queue_configure_endpoint(xhci, xhci->devs[slot_id]->in_ctx->dma, slot_id, false); @@ -1445,8 +1446,9 @@ 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 - " - "last ep index = %d, state = %d\n", + xhci_dbg_trace(xhci, trace_xhci_dbg_quirks, + "Completed config ep cmd - " + "last ep index = %d, state = %d", ep_index, ep_state); /* Clear internal halted state and restart ring(s) */ xhci->devs[slot_id]->eps[ep_index].ep_state &= @@ -1499,7 +1501,8 @@ bandwidth_change: xhci->error_bitmask |= 1 << 6; break; } - xhci_dbg(xhci, "NEC firmware version %2x.%02x\n", + xhci_dbg_trace(xhci, trace_xhci_dbg_quirks, + "NEC firmware version %2x.%02x", NEC_FW_MAJOR(le32_to_cpu(event->status)), NEC_FW_MINOR(le32_to_cpu(event->status))); break; diff --git a/drivers/usb/host/xhci-trace.h b/drivers/usb/host/xhci-trace.h index 628624306f38..f0447c6cb29b 100644 --- a/drivers/usb/host/xhci-trace.h +++ b/drivers/usb/host/xhci-trace.h @@ -41,6 +41,11 @@ DEFINE_EVENT(xhci_log_msg, xhci_dbg_context_change, TP_ARGS(vaf) ); +DEFINE_EVENT(xhci_log_msg, xhci_dbg_quirks, + 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 fa7b6f43642f..ffb3ed09eb0d 100644 --- a/drivers/usb/host/xhci.c +++ b/drivers/usb/host/xhci.c @@ -418,9 +418,11 @@ static void compliance_mode_recovery(unsigned long arg) * Compliance Mode Detected. Letting USB Core * handle the Warm Reset */ - xhci_dbg(xhci, "Compliance mode detected->port %d\n", + xhci_dbg_trace(xhci, trace_xhci_dbg_quirks, + "Compliance mode detected->port %d", i + 1); - xhci_dbg(xhci, "Attempting compliance mode recovery\n"); + xhci_dbg_trace(xhci, trace_xhci_dbg_quirks, + "Attempting compliance mode recovery"); hcd = xhci->shared_hcd; if (hcd->state == HC_STATE_SUSPENDED) @@ -458,7 +460,8 @@ static void compliance_mode_recovery_timer_init(struct xhci_hcd *xhci) set_timer_slack(&xhci->comp_mode_recovery_timer, msecs_to_jiffies(COMP_MODE_RCVRY_MSECS)); add_timer(&xhci->comp_mode_recovery_timer); - xhci_dbg(xhci, "Compliance mode recovery timer initialized\n"); + xhci_dbg_trace(xhci, trace_xhci_dbg_quirks, + "Compliance mode recovery timer initialized"); } /* @@ -509,7 +512,8 @@ int xhci_init(struct usb_hcd *hcd) xhci_dbg(xhci, "xhci_init\n"); spin_lock_init(&xhci->lock); if (xhci->hci_version == 0x95 && link_quirk) { - xhci_dbg(xhci, "QUIRK: Not clearing Link TRB chain bits.\n"); + xhci_dbg_trace(xhci, trace_xhci_dbg_quirks, + "QUIRK: Not clearing Link TRB chain bits."); xhci->quirks |= XHCI_LINK_TRB_QUIRK; } else { xhci_dbg(xhci, "xHCI doesn't need link TRB QUIRK\n"); @@ -668,7 +672,8 @@ void xhci_stop(struct usb_hcd *hcd) if ((xhci->quirks & XHCI_COMP_MODE_QUIRK) && (!(xhci_all_ports_seen_u0(xhci)))) { del_timer_sync(&xhci->comp_mode_recovery_timer); - xhci_dbg(xhci, "%s: compliance mode recovery timer deleted\n", + xhci_dbg_trace(xhci, trace_xhci_dbg_quirks, + "%s: compliance mode recovery timer deleted", __func__); } @@ -866,7 +871,8 @@ int xhci_suspend(struct xhci_hcd *xhci) if ((xhci->quirks & XHCI_COMP_MODE_QUIRK) && (!(xhci_all_ports_seen_u0(xhci)))) { del_timer_sync(&xhci->comp_mode_recovery_timer); - xhci_dbg(xhci, "%s: compliance mode recovery timer deleted\n", + xhci_dbg_trace(xhci, trace_xhci_dbg_quirks, + "%s: compliance mode recovery timer deleted", __func__); } @@ -931,7 +937,8 @@ int xhci_resume(struct xhci_hcd *xhci, bool hibernated) if ((xhci->quirks & XHCI_COMP_MODE_QUIRK) && !(xhci_all_ports_seen_u0(xhci))) { del_timer_sync(&xhci->comp_mode_recovery_timer); - xhci_dbg(xhci, "Compliance Mode Recovery Timer deleted!\n"); + xhci_dbg_trace(xhci, trace_xhci_dbg_quirks, + "Compliance Mode Recovery Timer deleted!"); } /* Let the USB core know _both_ roothubs lost power. */ @@ -1894,14 +1901,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: " - "%u active, need to add %u, limit is %u.\n", + xhci_dbg_trace(xhci, trace_xhci_dbg_quirks, + "Not enough ep ctxs: " + "%u active, need to add %u, limit is %u.", 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_quirks, + "Adding %u ep ctxs, %u now active.", added_eps, xhci->num_active_eps); return 0; } @@ -1919,7 +1928,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_quirks, + "Removing %u failed ep ctxs, %u now active.", num_failed_eps, xhci->num_active_eps); } @@ -1938,7 +1948,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_quirks, + "Removing %u dropped ep ctxs, %u now active.", num_dropped_eps, xhci->num_active_eps); } @@ -2099,18 +2110,21 @@ static int xhci_check_bw_table(struct xhci_hcd *xhci, * that the HS bus has enough bandwidth if we are activing a new TT. */ if (virt_dev->tt_info) { - xhci_dbg(xhci, "Recalculating BW for rootport %u\n", + xhci_dbg_trace(xhci, trace_xhci_dbg_quirks, + "Recalculating BW for rootport %u", virt_dev->real_port); if (xhci_check_tt_bw_table(xhci, virt_dev, old_active_eps)) { xhci_warn(xhci, "Not enough bandwidth on HS bus for " "newly activated TT.\n"); return -ENOMEM; } - xhci_dbg(xhci, "Recalculating BW for TT slot %u port %u\n", + xhci_dbg_trace(xhci, trace_xhci_dbg_quirks, + "Recalculating BW for TT slot %u port %u", virt_dev->tt_info->slot_id, virt_dev->tt_info->ttport); } else { - xhci_dbg(xhci, "Recalculating BW for rootport %u\n", + xhci_dbg_trace(xhci, trace_xhci_dbg_quirks, + "Recalculating BW for rootport %u", virt_dev->real_port); } @@ -2218,8 +2232,9 @@ static int xhci_check_bw_table(struct xhci_hcd *xhci, xhci->rh_bw[port_index].num_active_tts; } - xhci_dbg(xhci, "Final bandwidth: %u, Limit: %u, Reserved: %u, " - "Available: %u " "percent\n", + xhci_dbg_trace(xhci, trace_xhci_dbg_quirks, + "Final bandwidth: %u, Limit: %u, Reserved: %u, " + "Available: %u " "percent", bw_used, max_bandwidth, bw_reserved, (max_bandwidth - bw_used - bw_reserved) * 100 / max_bandwidth); @@ -2825,8 +2840,9 @@ void xhci_cleanup_stalled_ring(struct xhci_hcd *xhci, * XXX: No idea how this hardware will react when stream rings * are enabled. */ - xhci_dbg(xhci, "Setting up input context for " - "configure endpoint command\n"); + xhci_dbg_trace(xhci, trace_xhci_dbg_quirks, + "Setting up input context for " + "configure endpoint command"); xhci_setup_input_ctx_for_quirk(xhci, udev->slot_id, ep_index, &deq_state); } @@ -3305,8 +3321,9 @@ void xhci_free_device_endpoint_resources(struct xhci_hcd *xhci, } xhci->num_active_eps -= num_dropped_eps; if (num_dropped_eps) - xhci_dbg(xhci, "Dropped %u ep ctxs, flags = 0x%x, " - "%u now active.\n", + xhci_dbg_trace(xhci, trace_xhci_dbg_quirks, + "Dropped %u ep ctxs, flags = 0x%x, " + "%u now active.", num_dropped_eps, drop_flags, xhci->num_active_eps); } @@ -3568,13 +3585,15 @@ void xhci_free_dev(struct usb_hcd *hcd, struct usb_device *udev) static int xhci_reserve_host_control_ep_resources(struct xhci_hcd *xhci) { if (xhci->num_active_eps + 1 > xhci->limit_active_eps) { - xhci_dbg(xhci, "Not enough ep ctxs: " - "%u active, need to add 1, limit is %u.\n", + xhci_dbg_trace(xhci, trace_xhci_dbg_quirks, + "Not enough ep ctxs: " + "%u active, need to add 1, limit is %u.", xhci->num_active_eps, xhci->limit_active_eps); return -ENOMEM; } xhci->num_active_eps += 1; - xhci_dbg(xhci, "Adding 1 ep ctx, %u now active.\n", + xhci_dbg_trace(xhci, trace_xhci_dbg_quirks, + "Adding 1 ep ctx, %u now active.", xhci->num_active_eps); return 0; } From a0254324eeea3b00676eeb54ba80774a46cb8afb Mon Sep 17 00:00:00 2001 From: Xenia Ragiadakou Date: Tue, 6 Aug 2013 07:52:46 +0300 Subject: [PATCH 08/14] xhci: add trace for debug messages related to endpoint reset This patch defines a new trace event, which is called xhci_dbg_reset_ep and belongs in the event class xhci_log_msg, and adds tracepoints that trace the debug messages associated with resetting an endpoint after the reception of a STALL packet. Signed-off-by: Xenia Ragiadakou Signed-off-by: Sarah Sharp --- drivers/usb/host/xhci-ring.c | 3 ++- drivers/usb/host/xhci-trace.h | 5 +++++ drivers/usb/host/xhci.c | 17 +++++++++++------ 3 files changed, 18 insertions(+), 7 deletions(-) diff --git a/drivers/usb/host/xhci-ring.c b/drivers/usb/host/xhci-ring.c index e88e8772ab5d..3393ce755b15 100644 --- a/drivers/usb/host/xhci-ring.c +++ b/drivers/usb/host/xhci-ring.c @@ -1151,7 +1151,8 @@ static void handle_reset_ep_completion(struct xhci_hcd *xhci, /* This command will only fail if the endpoint wasn't halted, * but we don't care. */ - xhci_dbg(xhci, "Ignoring reset ep completion code of %u\n", + xhci_dbg_trace(xhci, trace_xhci_dbg_reset_ep, + "Ignoring reset ep completion code of %u", GET_COMP_CODE(le32_to_cpu(event->status))); /* HW with the reset endpoint quirk needs to have a configure endpoint diff --git a/drivers/usb/host/xhci-trace.h b/drivers/usb/host/xhci-trace.h index f0447c6cb29b..757b26f6e37b 100644 --- a/drivers/usb/host/xhci-trace.h +++ b/drivers/usb/host/xhci-trace.h @@ -46,6 +46,11 @@ DEFINE_EVENT(xhci_log_msg, xhci_dbg_quirks, TP_ARGS(vaf) ); +DEFINE_EVENT(xhci_log_msg, xhci_dbg_reset_ep, + 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 ffb3ed09eb0d..18c710dc68dc 100644 --- a/drivers/usb/host/xhci.c +++ b/drivers/usb/host/xhci.c @@ -2818,7 +2818,8 @@ void xhci_cleanup_stalled_ring(struct xhci_hcd *xhci, struct xhci_dequeue_state deq_state; struct xhci_virt_ep *ep; - xhci_dbg(xhci, "Cleaning up stalled endpoint ring\n"); + xhci_dbg_trace(xhci, trace_xhci_dbg_reset_ep, + "Cleaning up stalled endpoint ring"); ep = &xhci->devs[udev->slot_id]->eps[ep_index]; /* We need to move the HW's dequeue pointer past this TD, * or it will attempt to resend it on the next doorbell ring. @@ -2831,7 +2832,8 @@ void xhci_cleanup_stalled_ring(struct xhci_hcd *xhci, * issue a configure endpoint command later. */ if (!(xhci->quirks & XHCI_RESET_EP_QUIRK)) { - xhci_dbg(xhci, "Queueing new dequeue state\n"); + xhci_dbg_trace(xhci, trace_xhci_dbg_reset_ep, + "Queueing new dequeue state"); xhci_queue_new_dequeue_state(xhci, udev->slot_id, ep_index, ep->stopped_stream, &deq_state); } else { @@ -2874,16 +2876,19 @@ void xhci_endpoint_reset(struct usb_hcd *hcd, ep_index = xhci_get_endpoint_index(&ep->desc); virt_ep = &xhci->devs[udev->slot_id]->eps[ep_index]; if (!virt_ep->stopped_td) { - xhci_dbg(xhci, "Endpoint 0x%x not halted, refusing to reset.\n", - ep->desc.bEndpointAddress); + xhci_dbg_trace(xhci, trace_xhci_dbg_reset_ep, + "Endpoint 0x%x not halted, refusing to reset.", + ep->desc.bEndpointAddress); return; } if (usb_endpoint_xfer_control(&ep->desc)) { - xhci_dbg(xhci, "Control endpoint stall already handled.\n"); + xhci_dbg_trace(xhci, trace_xhci_dbg_reset_ep, + "Control endpoint stall already handled."); return; } - xhci_dbg(xhci, "Queueing reset endpoint command\n"); + xhci_dbg_trace(xhci, trace_xhci_dbg_reset_ep, + "Queueing reset endpoint command"); spin_lock_irqsave(&xhci->lock, flags); ret = xhci_queue_reset_ep(xhci, udev->slot_id, ep_index); /* From 1d27fabec068a204186c6af10e05f23911c0c902 Mon Sep 17 00:00:00 2001 From: Xenia Ragiadakou Date: Tue, 6 Aug 2013 07:52:47 +0300 Subject: [PATCH 09/14] xhci: add xhci_address_ctx trace event This patch defines a new event class, called xhci_log_ctx, that records in the ring buffer the context data, the context type (input or output), the context dma and virtual addresses, the context endpoint entries, the slot ID and whether the xHC uses 64 byte context data structures. This information can be used, later, to parse and display the context data fields with the appropriate plugin using the trace-cmd tool. Also, this patch defines a trace event, called xhci_address_ctx, to trace the contexts related to the Address Device command and adds the associated tracepoints in xhci_address_device(). Signed-off-by: Xenia Ragiadakou Signed-off-by: Sarah Sharp --- drivers/usb/host/xhci-trace.h | 42 +++++++++++++++++++++++++++++++++++ drivers/usb/host/xhci.c | 7 ++++++ 2 files changed, 49 insertions(+) diff --git a/drivers/usb/host/xhci-trace.h b/drivers/usb/host/xhci-trace.h index 757b26f6e37b..c653ddfc0211 100644 --- a/drivers/usb/host/xhci-trace.h +++ b/drivers/usb/host/xhci-trace.h @@ -18,6 +18,7 @@ #define __XHCI_TRACE_H #include +#include "xhci.h" #define XHCI_MSG_MAX 500 @@ -51,6 +52,47 @@ DEFINE_EVENT(xhci_log_msg, xhci_dbg_reset_ep, TP_ARGS(vaf) ); +DECLARE_EVENT_CLASS(xhci_log_ctx, + TP_PROTO(struct xhci_hcd *xhci, struct xhci_container_ctx *ctx, + unsigned int ep_num), + TP_ARGS(xhci, ctx, ep_num), + TP_STRUCT__entry( + __field(int, ctx_64) + __field(unsigned, ctx_type) + __field(dma_addr_t, ctx_dma) + __field(u8 *, ctx_va) + __field(unsigned, ctx_ep_num) + __field(int, slot_id) + __dynamic_array(u32, ctx_data, + ((HCC_64BYTE_CONTEXT(xhci->hcc_params) + 1) * 8) * + ((ctx->type == XHCI_CTX_TYPE_INPUT) + ep_num + 1)) + ), + TP_fast_assign( + struct usb_device *udev; + + udev = to_usb_device(xhci_to_hcd(xhci)->self.controller); + __entry->ctx_64 = HCC_64BYTE_CONTEXT(xhci->hcc_params); + __entry->ctx_type = ctx->type; + __entry->ctx_dma = ctx->dma; + __entry->ctx_va = ctx->bytes; + __entry->slot_id = udev->slot_id; + __entry->ctx_ep_num = ep_num; + memcpy(__get_dynamic_array(ctx_data), ctx->bytes, + ((HCC_64BYTE_CONTEXT(xhci->hcc_params) + 1) * 32) * + ((ctx->type == XHCI_CTX_TYPE_INPUT) + ep_num + 1)); + ), + TP_printk("\nctx_64=%d, ctx_type=%u, ctx_dma=@%llx, ctx_va=@%p", + __entry->ctx_64, __entry->ctx_type, + (unsigned long long) __entry->ctx_dma, __entry->ctx_va + ) +); + +DEFINE_EVENT(xhci_log_ctx, xhci_address_ctx, + TP_PROTO(struct xhci_hcd *xhci, struct xhci_container_ctx *ctx, + unsigned int ep_num), + TP_ARGS(xhci, ctx, ep_num) +); + #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 18c710dc68dc..9f4f73bfd01b 100644 --- a/drivers/usb/host/xhci.c +++ b/drivers/usb/host/xhci.c @@ -3738,6 +3738,8 @@ int xhci_address_device(struct usb_hcd *hcd, struct usb_device *udev) xhci_dbg(xhci, "Slot ID %d Input Context:\n", udev->slot_id); xhci_dbg_ctx(xhci, virt_dev->in_ctx, 2); + trace_xhci_address_ctx(xhci, virt_dev->in_ctx, + slot_ctx->dev_info >> 27); spin_lock_irqsave(&xhci->lock, flags); cmd_trb = xhci->cmd_ring->dequeue; @@ -3794,6 +3796,7 @@ int xhci_address_device(struct usb_hcd *hcd, struct usb_device *udev) "code 0x%x.\n", virt_dev->cmd_status); xhci_dbg(xhci, "Slot ID %d Output Context:\n", udev->slot_id); xhci_dbg_ctx(xhci, virt_dev->out_ctx, 2); + trace_xhci_address_ctx(xhci, virt_dev->out_ctx, 1); ret = -EINVAL; break; } @@ -3814,6 +3817,8 @@ int xhci_address_device(struct usb_hcd *hcd, struct usb_device *udev) (unsigned long long)virt_dev->out_ctx->dma); xhci_dbg(xhci, "Slot ID %d Input Context:\n", udev->slot_id); xhci_dbg_ctx(xhci, virt_dev->in_ctx, 2); + trace_xhci_address_ctx(xhci, virt_dev->in_ctx, + slot_ctx->dev_info >> 27); xhci_dbg(xhci, "Slot ID %d Output Context:\n", udev->slot_id); xhci_dbg_ctx(xhci, virt_dev->out_ctx, 2); /* @@ -3821,6 +3826,8 @@ int xhci_address_device(struct usb_hcd *hcd, struct usb_device *udev) * address given back to us by the HC. */ slot_ctx = xhci_get_slot_ctx(xhci, virt_dev->out_ctx); + trace_xhci_address_ctx(xhci, virt_dev->out_ctx, + slot_ctx->dev_info >> 27); /* Use kernel assigned address for devices; store xHC assigned * address locally. */ virt_dev->address = (le32_to_cpu(slot_ctx->dev_state) & DEV_ADDR_MASK) From 63a23b9a7451660525c90b08219e14e701e294f1 Mon Sep 17 00:00:00 2001 From: Xenia Ragiadakou Date: Tue, 6 Aug 2013 07:52:48 +0300 Subject: [PATCH 10/14] xhci: add xhci_cmd_completion trace event This patch creates a new event class, called xhci_log_event, and defines the xhci_cmd_completion trace event used for tracing the commands issued to xHC that generate a completion event in the event ring. This info can be used, later, to print, in a human readable way, the completion status and flags as well as the command's type and fields using the trace-cmd tool and the appropriate plugin. Also, a tracepoint is added in handle_cmd_completion(). Signed-off-by: Xenia Ragiadakou Signed-off-by: Sarah Sharp --- drivers/usb/host/xhci-ring.c | 3 +++ drivers/usb/host/xhci-trace.h | 30 ++++++++++++++++++++++++++++++ 2 files changed, 33 insertions(+) diff --git a/drivers/usb/host/xhci-ring.c b/drivers/usb/host/xhci-ring.c index 3393ce755b15..86971ac5851b 100644 --- a/drivers/usb/host/xhci-ring.c +++ b/drivers/usb/host/xhci-ring.c @@ -1380,6 +1380,9 @@ static void handle_cmd_completion(struct xhci_hcd *xhci, return; } + trace_xhci_cmd_completion(&xhci->cmd_ring->dequeue->generic, + (struct xhci_generic_trb *) event); + if ((GET_COMP_CODE(le32_to_cpu(event->status)) == COMP_CMD_ABORT) || (GET_COMP_CODE(le32_to_cpu(event->status)) == COMP_CMD_STOP)) { /* If the return value is 0, we think the trb pointed by diff --git a/drivers/usb/host/xhci-trace.h b/drivers/usb/host/xhci-trace.h index c653ddfc0211..d6c222916858 100644 --- a/drivers/usb/host/xhci-trace.h +++ b/drivers/usb/host/xhci-trace.h @@ -93,6 +93,36 @@ DEFINE_EVENT(xhci_log_ctx, xhci_address_ctx, TP_ARGS(xhci, ctx, ep_num) ); +DECLARE_EVENT_CLASS(xhci_log_event, + TP_PROTO(void *trb_va, struct xhci_generic_trb *ev), + TP_ARGS(trb_va, ev), + TP_STRUCT__entry( + __field(void *, va) + __field(u64, dma) + __field(u32, status) + __field(u32, flags) + __dynamic_array(__le32, trb, 4) + ), + TP_fast_assign( + __entry->va = trb_va; + __entry->dma = le64_to_cpu(((u64)ev->field[1]) << 32 | + ev->field[0]); + __entry->status = le32_to_cpu(ev->field[2]); + __entry->flags = le32_to_cpu(ev->field[3]); + memcpy(__get_dynamic_array(trb), trb_va, + sizeof(struct xhci_generic_trb)); + ), + TP_printk("\ntrb_dma=@%llx, trb_va=@%p, status=%08x, flags=%08x", + (unsigned long long) __entry->dma, __entry->va, + __entry->status, __entry->flags + ) +); + +DEFINE_EVENT(xhci_log_event, xhci_cmd_completion, + TP_PROTO(void *trb_va, struct xhci_generic_trb *ev), + TP_ARGS(trb_va, ev) +); + #endif /* __XHCI_TRACE_H */ /* this part must be outside header guard */ From aa50b29061d3df896c494d92e9c8c2e1f295cc6e Mon Sep 17 00:00:00 2001 From: Xenia Ragiadakou Date: Wed, 14 Aug 2013 06:33:54 +0300 Subject: [PATCH 11/14] xhci: trace debug statements for urb cancellation This patch defines a new trace event, which is called xhci_dbg_cancel_urb and belongs to the event class xhci_log_msg, and adds tracepoints that trace the debug messages related to the removal of a cancelled URB from the endpoint's transfer ring. Signed-off-by: Xenia Ragiadakou Signed-off-by: Sarah Sharp --- drivers/usb/host/xhci-ring.c | 64 ++++++++++++++++++++++------------- drivers/usb/host/xhci-trace.h | 5 +++ drivers/usb/host/xhci.c | 13 ++++--- 3 files changed, 54 insertions(+), 28 deletions(-) diff --git a/drivers/usb/host/xhci-ring.c b/drivers/usb/host/xhci-ring.c index 86971ac5851b..f908e205f7d5 100644 --- a/drivers/usb/host/xhci-ring.c +++ b/drivers/usb/host/xhci-ring.c @@ -556,7 +556,8 @@ void xhci_find_new_dequeue_state(struct xhci_hcd *xhci, return; } state->new_cycle_state = 0; - xhci_dbg(xhci, "Finding segment containing stopped TRB.\n"); + xhci_dbg_trace(xhci, trace_xhci_dbg_cancel_urb, + "Finding segment containing stopped TRB."); state->new_deq_seg = find_trb_seg(cur_td->start_seg, dev->eps[ep_index].stopped_trb, &state->new_cycle_state); @@ -566,12 +567,14 @@ void xhci_find_new_dequeue_state(struct xhci_hcd *xhci, } /* Dig out the cycle state saved by the xHC during the stop ep cmd */ - xhci_dbg(xhci, "Finding endpoint context\n"); + xhci_dbg_trace(xhci, trace_xhci_dbg_cancel_urb, + "Finding endpoint context"); ep_ctx = xhci_get_ep_ctx(xhci, dev->out_ctx, ep_index); state->new_cycle_state = 0x1 & le64_to_cpu(ep_ctx->deq); state->new_deq_ptr = cur_td->last_trb; - xhci_dbg(xhci, "Finding segment containing last TRB in TD.\n"); + xhci_dbg_trace(xhci, trace_xhci_dbg_cancel_urb, + "Finding segment containing last TRB in TD."); state->new_deq_seg = find_trb_seg(state->new_deq_seg, state->new_deq_ptr, &state->new_cycle_state); @@ -598,13 +601,16 @@ void xhci_find_new_dequeue_state(struct xhci_hcd *xhci, if (ep_ring->first_seg == ep_ring->first_seg->next && state->new_deq_ptr < dev->eps[ep_index].stopped_trb) state->new_cycle_state ^= 0x1; - xhci_dbg(xhci, "Cycle state = 0x%x\n", state->new_cycle_state); + xhci_dbg_trace(xhci, trace_xhci_dbg_cancel_urb, + "Cycle state = 0x%x", state->new_cycle_state); /* Don't update the ring cycle state for the producer (us). */ - xhci_dbg(xhci, "New dequeue segment = %p (virtual)\n", + xhci_dbg_trace(xhci, trace_xhci_dbg_cancel_urb, + "New dequeue segment = %p (virtual)", state->new_deq_seg); addr = xhci_trb_virt_to_dma(state->new_deq_seg, state->new_deq_ptr); - xhci_dbg(xhci, "New dequeue pointer = 0x%llx (DMA)\n", + xhci_dbg_trace(xhci, trace_xhci_dbg_cancel_urb, + "New dequeue pointer = 0x%llx (DMA)", (unsigned long long) addr); } @@ -632,9 +638,11 @@ static void td_to_noop(struct xhci_hcd *xhci, struct xhci_ring *ep_ring, if (flip_cycle) cur_trb->generic.field[3] ^= cpu_to_le32(TRB_CYCLE); - xhci_dbg(xhci, "Cancel (unchain) link TRB\n"); - xhci_dbg(xhci, "Address = %p (0x%llx dma); " - "in seg %p (0x%llx dma)\n", + xhci_dbg_trace(xhci, trace_xhci_dbg_cancel_urb, + "Cancel (unchain) link TRB"); + xhci_dbg_trace(xhci, trace_xhci_dbg_cancel_urb, + "Address = %p (0x%llx dma); " + "in seg %p (0x%llx dma)", cur_trb, (unsigned long long)xhci_trb_virt_to_dma(cur_seg, cur_trb), cur_seg, @@ -652,7 +660,8 @@ static void td_to_noop(struct xhci_hcd *xhci, struct xhci_ring *ep_ring, cpu_to_le32(TRB_CYCLE); cur_trb->generic.field[3] |= cpu_to_le32( TRB_TYPE(TRB_TR_NOOP)); - xhci_dbg(xhci, "TRB to noop at offset 0x%llx\n", + xhci_dbg_trace(xhci, trace_xhci_dbg_cancel_urb, + "TRB to noop at offset 0x%llx", (unsigned long long) xhci_trb_virt_to_dma(cur_seg, cur_trb)); } @@ -673,8 +682,9 @@ void xhci_queue_new_dequeue_state(struct xhci_hcd *xhci, { struct xhci_virt_ep *ep = &xhci->devs[slot_id]->eps[ep_index]; - xhci_dbg(xhci, "Set TR Deq Ptr cmd, new deq seg = %p (0x%llx dma), " - "new deq ptr = %p (0x%llx dma), new cycle = %u\n", + xhci_dbg_trace(xhci, trace_xhci_dbg_cancel_urb, + "Set TR Deq Ptr cmd, new deq seg = %p (0x%llx dma), " + "new deq ptr = %p (0x%llx dma), new cycle = %u", deq_state->new_deq_seg, (unsigned long long)deq_state->new_deq_seg->dma, deq_state->new_deq_ptr, @@ -794,7 +804,8 @@ static void handle_stopped_endpoint(struct xhci_hcd *xhci, */ list_for_each(entry, &ep->cancelled_td_list) { cur_td = list_entry(entry, struct xhci_td, cancelled_td_list); - xhci_dbg(xhci, "Removing canceled TD starting at 0x%llx (dma).\n", + xhci_dbg_trace(xhci, trace_xhci_dbg_cancel_urb, + "Removing canceled TD starting at 0x%llx (dma).", (unsigned long long)xhci_trb_virt_to_dma( cur_td->start_seg, cur_td->first_trb)); ep_ring = xhci_urb_to_transfer_ring(xhci, cur_td->urb); @@ -914,14 +925,16 @@ void xhci_stop_endpoint_command_watchdog(unsigned long arg) ep->stop_cmds_pending--; if (xhci->xhc_state & XHCI_STATE_DYING) { - xhci_dbg(xhci, "Stop EP timer ran, but another timer marked " - "xHCI as DYING, exiting.\n"); + xhci_dbg_trace(xhci, trace_xhci_dbg_cancel_urb, + "Stop EP timer ran, but another timer marked " + "xHCI as DYING, exiting."); spin_unlock_irqrestore(&xhci->lock, flags); return; } if (!(ep->stop_cmds_pending == 0 && (ep->ep_state & EP_HALT_PENDING))) { - xhci_dbg(xhci, "Stop EP timer ran, but no command pending, " - "exiting.\n"); + xhci_dbg_trace(xhci, trace_xhci_dbg_cancel_urb, + "Stop EP timer ran, but no command pending, " + "exiting."); spin_unlock_irqrestore(&xhci->lock, flags); return; } @@ -963,8 +976,9 @@ void xhci_stop_endpoint_command_watchdog(unsigned long arg) ring = temp_ep->ring; if (!ring) continue; - xhci_dbg(xhci, "Killing URBs for slot ID %u, " - "ep index %u\n", i, j); + xhci_dbg_trace(xhci, trace_xhci_dbg_cancel_urb, + "Killing URBs for slot ID %u, " + "ep index %u", i, j); while (!list_empty(&ring->td_list)) { cur_td = list_first_entry(&ring->td_list, struct xhci_td, @@ -987,9 +1001,11 @@ void xhci_stop_endpoint_command_watchdog(unsigned long arg) } } spin_unlock_irqrestore(&xhci->lock, flags); - xhci_dbg(xhci, "Calling usb_hc_died()\n"); + xhci_dbg_trace(xhci, trace_xhci_dbg_cancel_urb, + "Calling usb_hc_died()"); usb_hc_died(xhci_to_hcd(xhci)->primary_hcd); - xhci_dbg(xhci, "xHCI host controller is dead.\n"); + xhci_dbg_trace(xhci, trace_xhci_dbg_cancel_urb, + "xHCI host controller is dead."); } @@ -1093,7 +1109,8 @@ static void handle_set_deq_completion(struct xhci_hcd *xhci, ep_state &= EP_STATE_MASK; slot_state = le32_to_cpu(slot_ctx->dev_state); slot_state = GET_SLOT_STATE(slot_state); - xhci_dbg(xhci, "Slot state = %u, EP state = %u\n", + xhci_dbg_trace(xhci, trace_xhci_dbg_cancel_urb, + "Slot state = %u, EP state = %u", slot_state, ep_state); break; case COMP_EBADSLT: @@ -1113,7 +1130,8 @@ static void handle_set_deq_completion(struct xhci_hcd *xhci, * cancelling URBs, which might not be an error... */ } else { - xhci_dbg(xhci, "Successful Set TR Deq Ptr cmd, deq = @%08llx\n", + xhci_dbg_trace(xhci, trace_xhci_dbg_cancel_urb, + "Successful Set TR Deq Ptr cmd, deq = @%08llx", le64_to_cpu(ep_ctx->deq)); if (xhci_trb_virt_to_dma(dev->eps[ep_index].queued_deq_seg, dev->eps[ep_index].queued_deq_ptr) == diff --git a/drivers/usb/host/xhci-trace.h b/drivers/usb/host/xhci-trace.h index d6c222916858..c0eaccc10a3c 100644 --- a/drivers/usb/host/xhci-trace.h +++ b/drivers/usb/host/xhci-trace.h @@ -52,6 +52,11 @@ DEFINE_EVENT(xhci_log_msg, xhci_dbg_reset_ep, TP_ARGS(vaf) ); +DEFINE_EVENT(xhci_log_msg, xhci_dbg_cancel_urb, + TP_PROTO(struct va_format *vaf), + TP_ARGS(vaf) +); + DECLARE_EVENT_CLASS(xhci_log_ctx, TP_PROTO(struct xhci_hcd *xhci, struct xhci_container_ctx *ctx, unsigned int ep_num), diff --git a/drivers/usb/host/xhci.c b/drivers/usb/host/xhci.c index 9f4f73bfd01b..4adf5e19918a 100644 --- a/drivers/usb/host/xhci.c +++ b/drivers/usb/host/xhci.c @@ -1434,7 +1434,8 @@ int xhci_urb_dequeue(struct usb_hcd *hcd, struct urb *urb, int status) goto done; temp = xhci_readl(xhci, &xhci->op_regs->status); if (temp == 0xffffffff || (xhci->xhc_state & XHCI_STATE_HALTED)) { - xhci_dbg(xhci, "HW died, freeing TD.\n"); + xhci_dbg_trace(xhci, trace_xhci_dbg_cancel_urb, + "HW died, freeing TD."); urb_priv = urb->hcpriv; for (i = urb_priv->td_cnt; i < urb_priv->length; i++) { td = urb_priv->td[i]; @@ -1452,8 +1453,9 @@ int xhci_urb_dequeue(struct usb_hcd *hcd, struct urb *urb, int status) } if ((xhci->xhc_state & XHCI_STATE_DYING) || (xhci->xhc_state & XHCI_STATE_HALTED)) { - xhci_dbg(xhci, "Ep 0x%x: URB %p to be canceled on " - "non-responsive xHCI host.\n", + xhci_dbg_trace(xhci, trace_xhci_dbg_cancel_urb, + "Ep 0x%x: URB %p to be canceled on " + "non-responsive xHCI host.", urb->ep->desc.bEndpointAddress, urb); /* Let the stop endpoint command watchdog timer (which set this * state) finish cleaning up the endpoint TD lists. We must @@ -1474,8 +1476,9 @@ int xhci_urb_dequeue(struct usb_hcd *hcd, struct urb *urb, int status) urb_priv = urb->hcpriv; i = urb_priv->td_cnt; if (i < urb_priv->length) - xhci_dbg(xhci, "Cancel URB %p, dev %s, ep 0x%x, " - "starting at offset 0x%llx\n", + xhci_dbg_trace(xhci, trace_xhci_dbg_cancel_urb, + "Cancel URB %p, dev %s, ep 0x%x, " + "starting at offset 0x%llx", urb, urb->dev->devpath, urb->ep->desc.bEndpointAddress, (unsigned long long) xhci_trb_virt_to_dma( From d195fcffe4c82cc813cc43df5f27ab99ab38bc07 Mon Sep 17 00:00:00 2001 From: Xenia Ragiadakou Date: Wed, 14 Aug 2013 06:33:55 +0300 Subject: [PATCH 12/14] xhci: trace debug messages related to driver initialization and unload This patch defines a new trace event, which is called xhci_dbg_init and belongs to the event class xhci_log_msg, and adds tracepoints that trace the debug statements in the functions used to start and stop the xhci-hcd driver. Also, it removes an unnecessary cast of variable val to unsigned int in xhci_mem_init(), since val is already declared as unsigned int. Signed-off-by: Xenia Ragiadakou Signed-off-by: Sarah Sharp --- drivers/usb/host/xhci-mem.c | 110 +++++++++++++++++++++------------- drivers/usb/host/xhci-trace.h | 5 ++ drivers/usb/host/xhci.c | 66 ++++++++++++-------- 3 files changed, 113 insertions(+), 68 deletions(-) diff --git a/drivers/usb/host/xhci-mem.c b/drivers/usb/host/xhci-mem.c index b1bb59b58b25..ef27470b99e3 100644 --- a/drivers/usb/host/xhci-mem.c +++ b/drivers/usb/host/xhci-mem.c @@ -1545,7 +1545,8 @@ static int scratchpad_alloc(struct xhci_hcd *xhci, gfp_t flags) struct device *dev = xhci_to_hcd(xhci)->self.controller; int num_sp = HCS_MAX_SCRATCHPAD(xhci->hcs_params2); - xhci_dbg(xhci, "Allocating %d scratchpad buffers\n", num_sp); + xhci_dbg_trace(xhci, trace_xhci_dbg_init, + "Allocating %d scratchpad buffers", num_sp); if (!num_sp) return 0; @@ -1702,11 +1703,11 @@ void xhci_mem_cleanup(struct xhci_hcd *xhci) dma_free_coherent(&pdev->dev, size, xhci->erst.entries, xhci->erst.erst_dma_addr); xhci->erst.entries = NULL; - xhci_dbg(xhci, "Freed ERST\n"); + xhci_dbg_trace(xhci, trace_xhci_dbg_init, "Freed ERST"); if (xhci->event_ring) xhci_ring_free(xhci, xhci->event_ring); xhci->event_ring = NULL; - xhci_dbg(xhci, "Freed event ring\n"); + xhci_dbg_trace(xhci, trace_xhci_dbg_init, "Freed event ring"); if (xhci->lpm_command) xhci_free_command(xhci, xhci->lpm_command); @@ -1714,7 +1715,7 @@ void xhci_mem_cleanup(struct xhci_hcd *xhci) if (xhci->cmd_ring) xhci_ring_free(xhci, xhci->cmd_ring); xhci->cmd_ring = NULL; - xhci_dbg(xhci, "Freed command ring\n"); + xhci_dbg_trace(xhci, trace_xhci_dbg_init, "Freed command ring"); list_for_each_entry_safe(cur_cd, next_cd, &xhci->cancel_cmd_list, cancel_cmd_list) { list_del(&cur_cd->cancel_cmd_list); @@ -1727,22 +1728,24 @@ void xhci_mem_cleanup(struct xhci_hcd *xhci) if (xhci->segment_pool) dma_pool_destroy(xhci->segment_pool); xhci->segment_pool = NULL; - xhci_dbg(xhci, "Freed segment pool\n"); + xhci_dbg_trace(xhci, trace_xhci_dbg_init, "Freed segment pool"); if (xhci->device_pool) dma_pool_destroy(xhci->device_pool); xhci->device_pool = NULL; - xhci_dbg(xhci, "Freed device context pool\n"); + xhci_dbg_trace(xhci, trace_xhci_dbg_init, "Freed device context pool"); if (xhci->small_streams_pool) dma_pool_destroy(xhci->small_streams_pool); xhci->small_streams_pool = NULL; - xhci_dbg(xhci, "Freed small stream array pool\n"); + xhci_dbg_trace(xhci, trace_xhci_dbg_init, + "Freed small stream array pool"); if (xhci->medium_streams_pool) dma_pool_destroy(xhci->medium_streams_pool); xhci->medium_streams_pool = NULL; - xhci_dbg(xhci, "Freed medium stream array pool\n"); + xhci_dbg_trace(xhci, trace_xhci_dbg_init, + "Freed medium stream array pool"); if (xhci->dcbaa) dma_free_coherent(&pdev->dev, sizeof(*xhci->dcbaa), @@ -1968,8 +1971,9 @@ static void xhci_set_hc_event_deq(struct xhci_hcd *xhci) * there might be more events to service. */ temp &= ~ERST_EHB; - xhci_dbg(xhci, "// Write event ring dequeue pointer, " - "preserving EHB bit\n"); + xhci_dbg_trace(xhci, trace_xhci_dbg_init, + "// Write event ring dequeue pointer, " + "preserving EHB bit"); xhci_write_64(xhci, ((u64) deq & (u64) ~ERST_PTR_MASK) | temp, &xhci->ir_set->erst_dequeue); } @@ -1992,8 +1996,9 @@ static void xhci_add_in_port(struct xhci_hcd *xhci, unsigned int num_ports, temp = xhci_readl(xhci, addr + 2); port_offset = XHCI_EXT_PORT_OFF(temp); port_count = XHCI_EXT_PORT_COUNT(temp); - xhci_dbg(xhci, "Ext Cap %p, port offset = %u, " - "count = %u, revision = 0x%x\n", + xhci_dbg_trace(xhci, trace_xhci_dbg_init, + "Ext Cap %p, port offset = %u, " + "count = %u, revision = 0x%x", addr, port_offset, port_count, major_revision); /* Port count includes the current port offset */ if (port_offset == 0 || (port_offset + port_count - 1) > num_ports) @@ -2007,15 +2012,18 @@ static void xhci_add_in_port(struct xhci_hcd *xhci, unsigned int num_ports, /* Check the host's USB2 LPM capability */ if ((xhci->hci_version == 0x96) && (major_revision != 0x03) && (temp & XHCI_L1C)) { - xhci_dbg(xhci, "xHCI 0.96: support USB2 software lpm\n"); + xhci_dbg_trace(xhci, trace_xhci_dbg_init, + "xHCI 0.96: support USB2 software lpm"); xhci->sw_lpm_support = 1; } if ((xhci->hci_version >= 0x100) && (major_revision != 0x03)) { - xhci_dbg(xhci, "xHCI 1.0: support USB2 software lpm\n"); + xhci_dbg_trace(xhci, trace_xhci_dbg_init, + "xHCI 1.0: support USB2 software lpm"); xhci->sw_lpm_support = 1; if (temp & XHCI_HLC) { - xhci_dbg(xhci, "xHCI 1.0: support USB2 hardware lpm\n"); + xhci_dbg_trace(xhci, trace_xhci_dbg_init, + "xHCI 1.0: support USB2 hardware lpm"); xhci->hw_lpm_support = 1; } } @@ -2139,18 +2147,21 @@ static int xhci_setup_port_arrays(struct xhci_hcd *xhci, gfp_t flags) xhci_warn(xhci, "No ports on the roothubs?\n"); return -ENODEV; } - xhci_dbg(xhci, "Found %u USB 2.0 ports and %u USB 3.0 ports.\n", + xhci_dbg_trace(xhci, trace_xhci_dbg_init, + "Found %u USB 2.0 ports and %u USB 3.0 ports.", xhci->num_usb2_ports, xhci->num_usb3_ports); /* Place limits on the number of roothub ports so that the hub * descriptors aren't longer than the USB core will allocate. */ if (xhci->num_usb3_ports > 15) { - xhci_dbg(xhci, "Limiting USB 3.0 roothub ports to 15.\n"); + xhci_dbg_trace(xhci, trace_xhci_dbg_init, + "Limiting USB 3.0 roothub ports to 15."); xhci->num_usb3_ports = 15; } if (xhci->num_usb2_ports > USB_MAXCHILDREN) { - xhci_dbg(xhci, "Limiting USB 2.0 roothub ports to %u.\n", + xhci_dbg_trace(xhci, trace_xhci_dbg_init, + "Limiting USB 2.0 roothub ports to %u.", USB_MAXCHILDREN); xhci->num_usb2_ports = USB_MAXCHILDREN; } @@ -2175,8 +2186,9 @@ static int xhci_setup_port_arrays(struct xhci_hcd *xhci, gfp_t flags) xhci->usb2_ports[port_index] = &xhci->op_regs->port_status_base + NUM_PORT_REGS*i; - xhci_dbg(xhci, "USB 2.0 port at index %u, " - "addr = %p\n", i, + xhci_dbg_trace(xhci, trace_xhci_dbg_init, + "USB 2.0 port at index %u, " + "addr = %p", i, xhci->usb2_ports[port_index]); port_index++; if (port_index == xhci->num_usb2_ports) @@ -2195,8 +2207,9 @@ static int xhci_setup_port_arrays(struct xhci_hcd *xhci, gfp_t flags) xhci->usb3_ports[port_index] = &xhci->op_regs->port_status_base + NUM_PORT_REGS*i; - xhci_dbg(xhci, "USB 3.0 port at index %u, " - "addr = %p\n", i, + xhci_dbg_trace(xhci, trace_xhci_dbg_init, + "USB 3.0 port at index %u, " + "addr = %p", i, xhci->usb3_ports[port_index]); port_index++; if (port_index == xhci->num_usb3_ports) @@ -2220,32 +2233,35 @@ int xhci_mem_init(struct xhci_hcd *xhci, gfp_t flags) INIT_LIST_HEAD(&xhci->cancel_cmd_list); page_size = xhci_readl(xhci, &xhci->op_regs->page_size); - xhci_dbg(xhci, "Supported page size register = 0x%x\n", page_size); + xhci_dbg_trace(xhci, trace_xhci_dbg_init, + "Supported page size register = 0x%x", page_size); for (i = 0; i < 16; i++) { if ((0x1 & page_size) != 0) break; page_size = page_size >> 1; } if (i < 16) - xhci_dbg(xhci, "Supported page size of %iK\n", (1 << (i+12)) / 1024); + xhci_dbg_trace(xhci, trace_xhci_dbg_init, + "Supported page size of %iK", (1 << (i+12)) / 1024); else xhci_warn(xhci, "WARN: no supported page size\n"); /* Use 4K pages, since that's common and the minimum the HC supports */ xhci->page_shift = 12; xhci->page_size = 1 << xhci->page_shift; - xhci_dbg(xhci, "HCD page size set to %iK\n", xhci->page_size / 1024); + xhci_dbg_trace(xhci, trace_xhci_dbg_init, + "HCD page size set to %iK", xhci->page_size / 1024); /* * Program the Number of Device Slots Enabled field in the CONFIG * register with the max value of slots the HC can handle. */ val = HCS_MAX_SLOTS(xhci_readl(xhci, &xhci->cap_regs->hcs_params1)); - xhci_dbg(xhci, "// xHC can handle at most %d device slots.\n", - (unsigned int) val); + xhci_dbg_trace(xhci, trace_xhci_dbg_init, + "// xHC can handle at most %d device slots.", val); val2 = xhci_readl(xhci, &xhci->op_regs->config_reg); val |= (val2 & ~HCS_SLOTS_MASK); - xhci_dbg(xhci, "// Setting Max device slots reg = 0x%x.\n", - (unsigned int) val); + xhci_dbg_trace(xhci, trace_xhci_dbg_init, + "// Setting Max device slots reg = 0x%x.", val); xhci_writel(xhci, val, &xhci->op_regs->config_reg); /* @@ -2258,7 +2274,8 @@ int xhci_mem_init(struct xhci_hcd *xhci, gfp_t flags) goto fail; memset(xhci->dcbaa, 0, sizeof *(xhci->dcbaa)); xhci->dcbaa->dma = dma; - xhci_dbg(xhci, "// Device context base array address = 0x%llx (DMA), %p (virt)\n", + xhci_dbg_trace(xhci, trace_xhci_dbg_init, + "// Device context base array address = 0x%llx (DMA), %p (virt)", (unsigned long long)xhci->dcbaa->dma, xhci->dcbaa); xhci_write_64(xhci, dma, &xhci->op_regs->dcbaa_ptr); @@ -2297,8 +2314,9 @@ int xhci_mem_init(struct xhci_hcd *xhci, gfp_t flags) xhci->cmd_ring = xhci_ring_alloc(xhci, 1, 1, TYPE_COMMAND, flags); if (!xhci->cmd_ring) goto fail; - xhci_dbg(xhci, "Allocated command ring at %p\n", xhci->cmd_ring); - xhci_dbg(xhci, "First segment DMA is 0x%llx\n", + xhci_dbg_trace(xhci, trace_xhci_dbg_init, + "Allocated command ring at %p", xhci->cmd_ring); + xhci_dbg_trace(xhci, trace_xhci_dbg_init, "First segment DMA is 0x%llx", (unsigned long long)xhci->cmd_ring->first_seg->dma); /* Set the address in the Command Ring Control register */ @@ -2306,7 +2324,8 @@ int xhci_mem_init(struct xhci_hcd *xhci, gfp_t flags) val_64 = (val_64 & (u64) CMD_RING_RSVD_BITS) | (xhci->cmd_ring->first_seg->dma & (u64) ~CMD_RING_RSVD_BITS) | xhci->cmd_ring->cycle_state; - xhci_dbg(xhci, "// Setting command ring address to 0x%x\n", val); + xhci_dbg_trace(xhci, trace_xhci_dbg_init, + "// Setting command ring address to 0x%x", val); xhci_write_64(xhci, val_64, &xhci->op_regs->cmd_ring); xhci_dbg_cmd_ptrs(xhci); @@ -2322,8 +2341,9 @@ int xhci_mem_init(struct xhci_hcd *xhci, gfp_t flags) val = xhci_readl(xhci, &xhci->cap_regs->db_off); val &= DBOFF_MASK; - xhci_dbg(xhci, "// Doorbell array is located at offset 0x%x" - " from cap regs base addr\n", val); + xhci_dbg_trace(xhci, trace_xhci_dbg_init, + "// Doorbell array is located at offset 0x%x" + " from cap regs base addr", val); xhci->dba = (void __iomem *) xhci->cap_regs + val; xhci_dbg_regs(xhci); xhci_print_run_regs(xhci); @@ -2334,7 +2354,7 @@ int xhci_mem_init(struct xhci_hcd *xhci, gfp_t flags) * Event ring setup: Allocate a normal ring, but also setup * the event ring segment table (ERST). Section 4.9.3. */ - xhci_dbg(xhci, "// Allocating event ring\n"); + xhci_dbg_trace(xhci, trace_xhci_dbg_init, "// Allocating event ring"); xhci->event_ring = xhci_ring_alloc(xhci, ERST_NUM_SEGS, 1, TYPE_EVENT, flags); if (!xhci->event_ring) @@ -2347,13 +2367,15 @@ int xhci_mem_init(struct xhci_hcd *xhci, gfp_t flags) GFP_KERNEL); if (!xhci->erst.entries) goto fail; - xhci_dbg(xhci, "// Allocated event ring segment table at 0x%llx\n", + xhci_dbg_trace(xhci, trace_xhci_dbg_init, + "// Allocated event ring segment table at 0x%llx", (unsigned long long)dma); memset(xhci->erst.entries, 0, sizeof(struct xhci_erst_entry)*ERST_NUM_SEGS); xhci->erst.num_entries = ERST_NUM_SEGS; xhci->erst.erst_dma_addr = dma; - xhci_dbg(xhci, "Set ERST to 0; private num segs = %i, virt addr = %p, dma addr = 0x%llx\n", + xhci_dbg_trace(xhci, trace_xhci_dbg_init, + "Set ERST to 0; private num segs = %i, virt addr = %p, dma addr = 0x%llx", xhci->erst.num_entries, xhci->erst.entries, (unsigned long long)xhci->erst.erst_dma_addr); @@ -2371,13 +2393,16 @@ int xhci_mem_init(struct xhci_hcd *xhci, gfp_t flags) val = xhci_readl(xhci, &xhci->ir_set->erst_size); val &= ERST_SIZE_MASK; val |= ERST_NUM_SEGS; - xhci_dbg(xhci, "// Write ERST size = %i to ir_set 0 (some bits preserved)\n", + xhci_dbg_trace(xhci, trace_xhci_dbg_init, + "// Write ERST size = %i to ir_set 0 (some bits preserved)", val); xhci_writel(xhci, val, &xhci->ir_set->erst_size); - xhci_dbg(xhci, "// Set ERST entries to point to event ring.\n"); + xhci_dbg_trace(xhci, trace_xhci_dbg_init, + "// Set ERST entries to point to event ring."); /* set the segment table base address */ - xhci_dbg(xhci, "// Set ERST base address for ir_set 0 = 0x%llx\n", + xhci_dbg_trace(xhci, trace_xhci_dbg_init, + "// Set ERST base address for ir_set 0 = 0x%llx", (unsigned long long)xhci->erst.erst_dma_addr); val_64 = xhci_read_64(xhci, &xhci->ir_set->erst_base); val_64 &= ERST_PTR_MASK; @@ -2386,7 +2411,8 @@ int xhci_mem_init(struct xhci_hcd *xhci, gfp_t flags) /* Set the event ring dequeue address */ xhci_set_hc_event_deq(xhci); - xhci_dbg(xhci, "Wrote ERST address to ir_set 0.\n"); + xhci_dbg_trace(xhci, trace_xhci_dbg_init, + "Wrote ERST address to ir_set 0."); xhci_print_ir_set(xhci, 0); /* diff --git a/drivers/usb/host/xhci-trace.h b/drivers/usb/host/xhci-trace.h index c0eaccc10a3c..11025fe6ebba 100644 --- a/drivers/usb/host/xhci-trace.h +++ b/drivers/usb/host/xhci-trace.h @@ -57,6 +57,11 @@ DEFINE_EVENT(xhci_log_msg, xhci_dbg_cancel_urb, TP_ARGS(vaf) ); +DEFINE_EVENT(xhci_log_msg, xhci_dbg_init, + TP_PROTO(struct va_format *vaf), + TP_ARGS(vaf) +); + DECLARE_EVENT_CLASS(xhci_log_ctx, TP_PROTO(struct xhci_hcd *xhci, struct xhci_container_ctx *ctx, unsigned int ep_num), diff --git a/drivers/usb/host/xhci.c b/drivers/usb/host/xhci.c index 4adf5e19918a..eeb94d109059 100644 --- a/drivers/usb/host/xhci.c +++ b/drivers/usb/host/xhci.c @@ -101,7 +101,7 @@ void xhci_quiesce(struct xhci_hcd *xhci) int xhci_halt(struct xhci_hcd *xhci) { int ret; - xhci_dbg(xhci, "// Halt the HC\n"); + xhci_dbg_trace(xhci, trace_xhci_dbg_init, "// Halt the HC"); xhci_quiesce(xhci); ret = xhci_handshake(xhci, &xhci->op_regs->status, @@ -125,7 +125,7 @@ static int xhci_start(struct xhci_hcd *xhci) temp = xhci_readl(xhci, &xhci->op_regs->command); temp |= (CMD_RUN); - xhci_dbg(xhci, "// Turn on HC, cmd = 0x%x.\n", + xhci_dbg_trace(xhci, trace_xhci_dbg_init, "// Turn on HC, cmd = 0x%x.", temp); xhci_writel(xhci, temp, &xhci->op_regs->command); @@ -163,7 +163,7 @@ int xhci_reset(struct xhci_hcd *xhci) return 0; } - xhci_dbg(xhci, "// Reset the HC\n"); + xhci_dbg_trace(xhci, trace_xhci_dbg_init, "// Reset the HC"); command = xhci_readl(xhci, &xhci->op_regs->command); command |= CMD_RESET; xhci_writel(xhci, command, &xhci->op_regs->command); @@ -173,7 +173,8 @@ int xhci_reset(struct xhci_hcd *xhci) if (ret) return ret; - xhci_dbg(xhci, "Wait for controller to be ready for doorbell rings\n"); + xhci_dbg_trace(xhci, trace_xhci_dbg_init, + "Wait for controller to be ready for doorbell rings"); /* * xHCI cannot write to any doorbells or operational registers other * than status until the "Controller Not Ready" flag is cleared. @@ -215,14 +216,16 @@ static int xhci_setup_msi(struct xhci_hcd *xhci) ret = pci_enable_msi(pdev); if (ret) { - xhci_dbg(xhci, "failed to allocate MSI entry\n"); + xhci_dbg_trace(xhci, trace_xhci_dbg_init, + "failed to allocate MSI entry"); return ret; } ret = request_irq(pdev->irq, xhci_msi_irq, 0, "xhci_hcd", xhci_to_hcd(xhci)); if (ret) { - xhci_dbg(xhci, "disable MSI interrupt\n"); + xhci_dbg_trace(xhci, trace_xhci_dbg_init, + "disable MSI interrupt"); pci_disable_msi(pdev); } @@ -285,7 +288,8 @@ static int xhci_setup_msix(struct xhci_hcd *xhci) ret = pci_enable_msix(pdev, xhci->msix_entries, xhci->msix_count); if (ret) { - xhci_dbg(xhci, "Failed to enable MSI-X\n"); + xhci_dbg_trace(xhci, trace_xhci_dbg_init, + "Failed to enable MSI-X"); goto free_entries; } @@ -301,7 +305,7 @@ static int xhci_setup_msix(struct xhci_hcd *xhci) return ret; disable_msix: - xhci_dbg(xhci, "disable MSI-X interrupt\n"); + xhci_dbg_trace(xhci, trace_xhci_dbg_init, "disable MSI-X interrupt"); xhci_free_irq(xhci); pci_disable_msix(pdev); free_entries: @@ -509,17 +513,18 @@ int xhci_init(struct usb_hcd *hcd) struct xhci_hcd *xhci = hcd_to_xhci(hcd); int retval = 0; - xhci_dbg(xhci, "xhci_init\n"); + xhci_dbg_trace(xhci, trace_xhci_dbg_init, "xhci_init"); spin_lock_init(&xhci->lock); if (xhci->hci_version == 0x95 && link_quirk) { xhci_dbg_trace(xhci, trace_xhci_dbg_quirks, "QUIRK: Not clearing Link TRB chain bits."); xhci->quirks |= XHCI_LINK_TRB_QUIRK; } else { - xhci_dbg(xhci, "xHCI doesn't need link TRB QUIRK\n"); + xhci_dbg_trace(xhci, trace_xhci_dbg_init, + "xHCI doesn't need link TRB QUIRK"); } retval = xhci_mem_init(xhci, GFP_KERNEL); - xhci_dbg(xhci, "Finished xhci_init\n"); + xhci_dbg_trace(xhci, trace_xhci_dbg_init, "Finished xhci_init"); /* Initializing Compliance Mode Recovery Data If Needed */ if (xhci_compliance_mode_recovery_timer_quirk_check()) { @@ -545,7 +550,8 @@ static int xhci_run_finished(struct xhci_hcd *xhci) if (xhci->quirks & XHCI_NEC_HOST) xhci_ring_cmd_db(xhci); - xhci_dbg(xhci, "Finished xhci_run for USB3 roothub\n"); + xhci_dbg_trace(xhci, trace_xhci_dbg_init, + "Finished xhci_run for USB3 roothub"); return 0; } @@ -576,7 +582,7 @@ int xhci_run(struct usb_hcd *hcd) if (!usb_hcd_is_primary_hcd(hcd)) return xhci_run_finished(xhci); - xhci_dbg(xhci, "xhci_run\n"); + xhci_dbg_trace(xhci, trace_xhci_dbg_init, "xhci_run"); ret = xhci_try_enable_msi(hcd); if (ret) @@ -594,9 +600,11 @@ int xhci_run(struct usb_hcd *hcd) xhci_dbg_ring_ptrs(xhci, xhci->event_ring); temp_64 = xhci_read_64(xhci, &xhci->ir_set->erst_dequeue); temp_64 &= ~ERST_PTR_MASK; - xhci_dbg(xhci, "ERST deq = 64'h%0lx\n", (long unsigned int) temp_64); + xhci_dbg_trace(xhci, trace_xhci_dbg_init, + "ERST deq = 64'h%0lx", (long unsigned int) temp_64); - xhci_dbg(xhci, "// Set the interrupt modulation register\n"); + xhci_dbg_trace(xhci, trace_xhci_dbg_init, + "// Set the interrupt modulation register"); temp = xhci_readl(xhci, &xhci->ir_set->irq_control); temp &= ~ER_IRQ_INTERVAL_MASK; temp |= (u32) 160; @@ -605,12 +613,13 @@ int xhci_run(struct usb_hcd *hcd) /* Set the HCD state before we enable the irqs */ temp = xhci_readl(xhci, &xhci->op_regs->command); temp |= (CMD_EIE); - xhci_dbg(xhci, "// Enable interrupts, cmd = 0x%x.\n", - temp); + xhci_dbg_trace(xhci, trace_xhci_dbg_init, + "// Enable interrupts, cmd = 0x%x.", temp); xhci_writel(xhci, temp, &xhci->op_regs->command); temp = xhci_readl(xhci, &xhci->ir_set->irq_pending); - xhci_dbg(xhci, "// Enabling event ring interrupter %p by writing 0x%x to irq_pending\n", + xhci_dbg_trace(xhci, trace_xhci_dbg_init, + "// Enabling event ring interrupter %p by writing 0x%x to irq_pending", xhci->ir_set, (unsigned int) ER_IRQ_ENABLE(temp)); xhci_writel(xhci, ER_IRQ_ENABLE(temp), &xhci->ir_set->irq_pending); @@ -620,7 +629,8 @@ int xhci_run(struct usb_hcd *hcd) xhci_queue_vendor_command(xhci, 0, 0, 0, TRB_TYPE(TRB_NEC_GET_FW)); - xhci_dbg(xhci, "Finished xhci_run for USB2 roothub\n"); + xhci_dbg_trace(xhci, trace_xhci_dbg_init, + "Finished xhci_run for USB2 roothub"); return 0; } @@ -680,7 +690,8 @@ void xhci_stop(struct usb_hcd *hcd) if (xhci->quirks & XHCI_AMD_PLL_FIX) usb_amd_dev_put(); - xhci_dbg(xhci, "// Disabling event ring interrupts\n"); + xhci_dbg_trace(xhci, trace_xhci_dbg_init, + "// Disabling event ring interrupts"); temp = xhci_readl(xhci, &xhci->op_regs->status); xhci_writel(xhci, temp & ~STS_EINT, &xhci->op_regs->status); temp = xhci_readl(xhci, &xhci->ir_set->irq_pending); @@ -688,10 +699,11 @@ void xhci_stop(struct usb_hcd *hcd) &xhci->ir_set->irq_pending); xhci_print_ir_set(xhci, 0); - xhci_dbg(xhci, "cleaning up memory\n"); + xhci_dbg_trace(xhci, trace_xhci_dbg_init, "cleaning up memory"); xhci_mem_cleanup(xhci); - xhci_dbg(xhci, "xhci_stop completed - status = %x\n", - xhci_readl(xhci, &xhci->op_regs->status)); + xhci_dbg_trace(xhci, trace_xhci_dbg_init, + "xhci_stop completed - status = %x", + xhci_readl(xhci, &xhci->op_regs->status)); } /* @@ -716,8 +728,9 @@ void xhci_shutdown(struct usb_hcd *hcd) xhci_cleanup_msix(xhci); - xhci_dbg(xhci, "xhci_shutdown completed - status = %x\n", - xhci_readl(xhci, &xhci->op_regs->status)); + xhci_dbg_trace(xhci, trace_xhci_dbg_init, + "xhci_shutdown completed - status = %x", + xhci_readl(xhci, &xhci->op_regs->status)); } #ifdef CONFIG_PM @@ -758,7 +771,8 @@ static void xhci_set_cmd_ring_deq(struct xhci_hcd *xhci) xhci->cmd_ring->dequeue) & (u64) ~CMD_RING_RSVD_BITS) | xhci->cmd_ring->cycle_state; - xhci_dbg(xhci, "// Setting command ring address to 0x%llx\n", + xhci_dbg_trace(xhci, trace_xhci_dbg_init, + "// Setting command ring address to 0x%llx", (long unsigned long) val_64); xhci_write_64(xhci, val_64, &xhci->op_regs->cmd_ring); } From 68ffb01111500c769ceac055bdc2fb000322b2d7 Mon Sep 17 00:00:00 2001 From: Xenia Ragiadakou Date: Wed, 14 Aug 2013 06:33:56 +0300 Subject: [PATCH 13/14] xhci: trace debug statements related to ring expansion This patch defines a new trace event, which is called xhci_dbg_ring_expansion and belongs to the event class xhci_log_msg, and adds tracepoints that trace the debug messages associated with the expansion of endpoint ring when there is not enough space allocated to hold all pending TRBs. Signed-off-by: Xenia Ragiadakou Signed-off-by: Sarah Sharp --- drivers/usb/host/xhci-mem.c | 3 ++- drivers/usb/host/xhci-ring.c | 4 ++-- drivers/usb/host/xhci-trace.h | 5 +++++ 3 files changed, 9 insertions(+), 3 deletions(-) diff --git a/drivers/usb/host/xhci-mem.c b/drivers/usb/host/xhci-mem.c index ef27470b99e3..b150360d1e78 100644 --- a/drivers/usb/host/xhci-mem.c +++ b/drivers/usb/host/xhci-mem.c @@ -348,7 +348,8 @@ int xhci_ring_expansion(struct xhci_hcd *xhci, struct xhci_ring *ring, return -ENOMEM; xhci_link_rings(xhci, ring, first, last, num_segs); - xhci_dbg(xhci, "ring expansion succeed, now has %d segments\n", + xhci_dbg_trace(xhci, trace_xhci_dbg_ring_expansion, + "ring expansion succeed, now has %d segments", ring->num_segs); return 0; diff --git a/drivers/usb/host/xhci-ring.c b/drivers/usb/host/xhci-ring.c index f908e205f7d5..7b35af167e55 100644 --- a/drivers/usb/host/xhci-ring.c +++ b/drivers/usb/host/xhci-ring.c @@ -2904,8 +2904,8 @@ static int prepare_ring(struct xhci_hcd *xhci, struct xhci_ring *ep_ring, return -ENOMEM; } - xhci_dbg(xhci, "ERROR no room on ep ring, " - "try ring expansion\n"); + xhci_dbg_trace(xhci, trace_xhci_dbg_ring_expansion, + "ERROR no room on ep ring, try ring expansion"); num_trbs_needed = num_trbs - ep_ring->num_trbs_free; if (xhci_ring_expansion(xhci, ep_ring, num_trbs_needed, mem_flags)) { diff --git a/drivers/usb/host/xhci-trace.h b/drivers/usb/host/xhci-trace.h index 11025fe6ebba..20364cc8d2fb 100644 --- a/drivers/usb/host/xhci-trace.h +++ b/drivers/usb/host/xhci-trace.h @@ -62,6 +62,11 @@ DEFINE_EVENT(xhci_log_msg, xhci_dbg_init, TP_ARGS(vaf) ); +DEFINE_EVENT(xhci_log_msg, xhci_dbg_ring_expansion, + TP_PROTO(struct va_format *vaf), + TP_ARGS(vaf) +); + DECLARE_EVENT_CLASS(xhci_log_ctx, TP_PROTO(struct xhci_hcd *xhci, struct xhci_container_ctx *ctx, unsigned int ep_num), From c10cf1189d7659ffd7dbe488a4cee7ec0dcdd9c6 Mon Sep 17 00:00:00 2001 From: Xenia Ragiadakou Date: Wed, 14 Aug 2013 05:55:19 +0300 Subject: [PATCH 14/14] xhci: fix dma mask setup in xhci.c The function dma_set_mask() tests internally whether the dma_mask pointer for the device is initialized and fails if the dma_mask pointer is NULL. On pci platforms, the device dma_mask pointer is initialized, when pci devices are enumerated, to point to the pci_dev->dma_mask which is 0xffffffff. However, for non-pci platforms, the dma_mask pointer may not be initialized and in that case dma_set_mask() will fail. This patch initializes the dma_mask and the coherent_dma_mask to 32bits in xhci_plat_probe(), before the call to usb_create_hcd() that sets the "uses_dma" flag for the usb bus and the call to usb_add_hcd() that creates coherent dma pools for the usb hcd. Moreover, a call to dma_set_mask() does not set the device coherent_dma_mask. Since the xhci-hcd driver calls dma_alloc_coherent() and dma_pool_alloc() to allocate consistent DMA memory blocks, the coherent DMA address mask has to be set explicitly. This patch sets the coherent_dma_mask to 64bits in xhci_gen_setup() when the xHC is capable for 64-bit DMA addressing. If dma_set_mask() succeeds, for a given bitmask, it is guaranteed that the given bitmask is also supported for consistent DMA mappings. Other changes introduced in this patch are: - The return value of dma_set_mask() is checked to ensure that the required dma bitmask conforms with the host system's addressing capabilities. - The dma_mask setup code for the non-primary hcd was removed since both primary and non-primary hcd refer to the same generic device whose dma_mask and coherent_dma_mask are already set during the setup of the primary hcd. - The code for reading the HCCPARAMS register to find out the addressing capabilities of xHC was removed since its value is already cached in xhci->hccparams. - hcd->self.controller was replaced with the dev variable since it is already available. Signed-off-by: Xenia Ragiadakou Signed-off-by: Sarah Sharp --- drivers/usb/host/xhci-plat.c | 10 ++++++++++ drivers/usb/host/xhci.c | 19 +++++-------------- 2 files changed, 15 insertions(+), 14 deletions(-) diff --git a/drivers/usb/host/xhci-plat.c b/drivers/usb/host/xhci-plat.c index 3fcdaea21e24..be5e70d2300c 100644 --- a/drivers/usb/host/xhci-plat.c +++ b/drivers/usb/host/xhci-plat.c @@ -15,6 +15,7 @@ #include #include #include +#include #include "xhci.h" @@ -105,6 +106,15 @@ static int xhci_plat_probe(struct platform_device *pdev) if (!res) return -ENODEV; + /* Initialize dma_mask and coherent_dma_mask to 32-bits */ + ret = dma_set_coherent_mask(&pdev->dev, DMA_BIT_MASK(32)); + if (ret) + return ret; + if (!pdev->dev.dma_mask) + pdev->dev.dma_mask = &pdev->dev.coherent_dma_mask; + else + dma_set_mask(&pdev->dev, DMA_BIT_MASK(32)); + hcd = usb_create_hcd(driver, &pdev->dev, dev_name(&pdev->dev)); if (!hcd) return -ENOMEM; diff --git a/drivers/usb/host/xhci.c b/drivers/usb/host/xhci.c index eeb94d109059..e43b3889ab7a 100644 --- a/drivers/usb/host/xhci.c +++ b/drivers/usb/host/xhci.c @@ -4825,7 +4825,6 @@ int xhci_gen_setup(struct usb_hcd *hcd, xhci_get_quirks_t get_quirks) struct xhci_hcd *xhci; struct device *dev = hcd->self.controller; int retval; - u32 temp; /* Accept arbitrarily long scatter-gather lists */ hcd->self.sg_tablesize = ~0; @@ -4853,14 +4852,6 @@ int xhci_gen_setup(struct usb_hcd *hcd, xhci_get_quirks_t get_quirks) /* xHCI private pointer was set in xhci_pci_probe for the second * registered roothub. */ - xhci = hcd_to_xhci(hcd); - temp = xhci_readl(xhci, &xhci->cap_regs->hcc_params); - if (HCC_64BIT_ADDR(temp)) { - xhci_dbg(xhci, "Enabling 64-bit DMA addresses.\n"); - dma_set_mask(hcd->self.controller, DMA_BIT_MASK(64)); - } else { - dma_set_mask(hcd->self.controller, DMA_BIT_MASK(32)); - } return 0; } @@ -4899,12 +4890,12 @@ int xhci_gen_setup(struct usb_hcd *hcd, xhci_get_quirks_t get_quirks) goto error; xhci_dbg(xhci, "Reset complete\n"); - temp = xhci_readl(xhci, &xhci->cap_regs->hcc_params); - if (HCC_64BIT_ADDR(temp)) { + /* Set dma_mask and coherent_dma_mask to 64-bits, + * if xHC supports 64-bit addressing */ + if (HCC_64BIT_ADDR(xhci->hcc_params) && + !dma_set_mask(dev, DMA_BIT_MASK(64))) { xhci_dbg(xhci, "Enabling 64-bit DMA addresses.\n"); - dma_set_mask(hcd->self.controller, DMA_BIT_MASK(64)); - } else { - dma_set_mask(hcd->self.controller, DMA_BIT_MASK(32)); + dma_set_coherent_mask(dev, DMA_BIT_MASK(64)); } xhci_dbg(xhci, "Calling HCD init\n");