[RFC v2 1/4] xhci: add trace for debug messages related to quirks

[Xenia Ragiadakou]

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 <***@gmail.com>
---

Differences from version 1:

Remove trailing newline from statements traced with xhci_log_msg
trace events.

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 | 61 +++++++++++++++++++++++++++----------------
5 files changed, 65 insertions(+), 33 deletions(-)

diff --git a/drivers/usb/host/xhci-hub.c b/drivers/usb/host/xhci-hub.c
index 1d35459..3a44399 100644
--- a/drivers/usb/host/xhci-hub.c
+++ b/drivers/usb/host/xhci-hub.c
@@ -24,6 +24,7 @@
#include <asm/unaligned.h>

#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 | \
@@ -528,8 +529,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 cc24e39..419572d 100644
--- a/drivers/usb/host/xhci-pci.c
+++ b/drivers/usb/host/xhci-pci.c
@@ -25,6 +25,7 @@
#include <linux/module.h>

#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;
}
@@ -111,7 +114,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 e67011e..451fece 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 6286243..f0447c6 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 b4d8c02..e639c8b 100644
--- a/drivers/usb/host/xhci.c
+++ b/drivers/usb/host/xhci.c
@@ -458,7 +458,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 +510,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 +670,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 +869,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 +935,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 +1899,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 +1926,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 +1946,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 +2108,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 +2230,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 +2838,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 +3319,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 +3583,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;
}

[Xenia Ragiadakou]

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 <***@gmail.com>
---
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 451fece..08849ac 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 f0447c6..757b26f 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 e639c8b..957d563 100644
--- a/drivers/usb/host/xhci.c
+++ b/drivers/usb/host/xhci.c
@@ -2816,7 +2816,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.
@@ -2829,7 +2830,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 {
@@ -2872,16 +2874,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);
/*

[Xenia Ragiadakou]

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 <***@gmail.com>
---

Differences from version 2:

Remove trailing newline from statements traced with xhci_log_msg
trace events.

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 b881bc1..b1bb59b 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",
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..e67011e 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,
@@ -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 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 f8c1c45..b4d8c02 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);
@@ -3863,7 +3870,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.");
xhci_dbg(xhci, "Slot %u Input Context:\n", udev->slot_id);
xhci_dbg_ctx(xhci, command->in_ctx, 0);

[Xenia Ragiadakou]

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 <***@gmail.com>
---
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 757b26f..4d4687e 100644
--- a/drivers/usb/host/xhci-trace.h
+++ b/drivers/usb/host/xhci-trace.h
@@ -18,6 +18,7 @@
#define __XHCI_TRACE_H

#include <linux/tracepoint.h>
+#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=@%08llx, ctx_va=@%p",
+ __entry->ctx_64, __entry->ctx_type, __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 957d563..bef1e77 100644
--- a/drivers/usb/host/xhci.c
+++ b/drivers/usb/host/xhci.c
@@ -3736,6 +3736,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;
@@ -3792,6 +3794,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;
}
@@ -3810,6 +3813,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);
/*
@@ -3817,6 +3822,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)

[Xenia Ragiadakou]

This patch creates a new event class, called xhci_log_cmd,
for tracing the commands issued to xHC that generate a
completion event in the event ring by placing into the
ring buffer the completion event's status and flags as
well as the command TRB's data, dma and virtual address.

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, this patch defines the xhci_cmd_completion trace event,
part of the class xhci_log_cmd, and adds a tracepoint in
handle_cmd_completion().

Signed-off-by: Xenia Ragiadakou <***@gmail.com>
---
drivers/usb/host/xhci-ring.c | 2 ++
drivers/usb/host/xhci-trace.h | 28 ++++++++++++++++++++++++++++
2 files changed, 30 insertions(+)

diff --git a/drivers/usb/host/xhci-ring.c b/drivers/usb/host/xhci-ring.c
index 08849ac..1f71b56 100644
--- a/drivers/usb/host/xhci-ring.c
+++ b/drivers/usb/host/xhci-ring.c
@@ -1380,6 +1380,8 @@ static void handle_cmd_completion(struct xhci_hcd *xhci,
return;
}

+ trace_xhci_cmd_completion(&xhci->cmd_ring->dequeue->generic, 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 4d4687e..c7eb065 100644
--- a/drivers/usb/host/xhci-trace.h
+++ b/drivers/usb/host/xhci-trace.h
@@ -93,6 +93,34 @@ DEFINE_EVENT(xhci_log_ctx, xhci_address_ctx,
TP_ARGS(xhci, ctx, ep_num)
);

+DECLARE_EVENT_CLASS(xhci_log_cmd,
+ TP_PROTO(void *cmd_trb_va, struct xhci_event_cmd *compl_event),
+ TP_ARGS(cmd_trb_va, compl_event),
+ TP_STRUCT__entry(
+ __field(void *, va)
+ __field(u64, dma)
+ __field(u32, status)
+ __field(u32, flags)
+ __dynamic_array(__le32, cmd_trb, 4)
+ ),
+ TP_fast_assign(
+ __entry->va = cmd_trb_va;
+ __entry->dma = le64_to_cpu(compl_event->cmd_trb);
+ __entry->status = le32_to_cpu(compl_event->status);
+ __entry->flags = le32_to_cpu(compl_event->flags);
+ memcpy(__get_dynamic_array(cmd_trb), cmd_trb_va,
+ sizeof(struct xhci_generic_trb));
+ ),
+ TP_printk("\ncmd_dma=@%08llx, cmd_va=@%p, status=%08x, flags=%08x",
+ __entry->dma, __entry->va, __entry->status, __entry->flags
+ )
+);
+
+DEFINE_EVENT(xhci_log_cmd, xhci_cmd_completion,
+ TP_PROTO(void *cmd_trb_va, struct xhci_event_cmd *compl_event),
+ TP_ARGS(cmd_trb_va, compl_event)
+);
+
#endif /* __XHCI_TRACE_H */

/* this part must be outside header guard */

[Xenia Ragiadakou]

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 <***@gmail.com>
---

Differences from version 4:

Put back the unsigned long long typecasting for le64_to_cpu() since
in some platforms u64 is defined as unsigned long and the typecasting
is necessary because the printing format is %llx.

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 bea7112..ca0a119 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 5d5e58f..73503a8 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 0000000..7cf30c8
--- /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 : ***@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 0000000..432aa67
--- /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 : ***@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 <linux/tracepoint.h>
+
+#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 <trace/define_trace.h>
diff --git a/drivers/usb/host/xhci.c b/drivers/usb/host/xhci.c
index 189ca85..daff592 100644
--- a/drivers/usb/host/xhci.c
+++ b/drivers/usb/host/xhci.c
@@ -29,6 +29,7 @@
#include <linux/dmi.h>

#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 4d43531..d204591 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);

[Xenia Ragiadakou]

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 <***@gmail.com>
---

Differences from version 2:

Add tracepoints for the debug statements in compliance_mode_recovery()
function that I had missed.

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 1d35459..3a44399 100644
--- a/drivers/usb/host/xhci-hub.c
+++ b/drivers/usb/host/xhci-hub.c
@@ -24,6 +24,7 @@
#include <asm/unaligned.h>

#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 | \
@@ -528,8 +529,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 cc24e39..419572d 100644
--- a/drivers/usb/host/xhci-pci.c
+++ b/drivers/usb/host/xhci-pci.c
@@ -25,6 +25,7 @@
#include <linux/module.h>

#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;
}
@@ -111,7 +114,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 e67011e..451fece 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 6286243..f0447c6 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 9aefe9b..417ec77 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;
}

[Xenia Ragiadakou]

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 <***@gmail.com>
---
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 451fece..08849ac 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 f0447c6..757b26f 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 417ec77..91e3943 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);
/*

[Xenia Ragiadakou]

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 <***@gmail.com>
---

Differences from version 2:

Fix the TP_printk() by typecasting __entry->ctx_dma to unsigned long long
so that it will be printed appropriately with the printing format %llx.

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 757b26f..c653ddf 100644
--- a/drivers/usb/host/xhci-trace.h
+++ b/drivers/usb/host/xhci-trace.h
@@ -18,6 +18,7 @@
#define __XHCI_TRACE_H

#include <linux/tracepoint.h>
+#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 91e3943..542ad21 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)

[Xenia Ragiadakou]

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 <***@gmail.com>
---

Differences from version 2:

- Rename xhci_log_cmd class to xhci_log_event and make its implementation
more generic in order to enable tracing not only command completion events
but also transfer events using trace events of the same class avoiding.
That will help reducing code duplication.

- Fix the TP_printk() by typecasting __entry->trb_dma to unsigned long long
so that it will be printed appropriately with the printing format %llx.

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 08849ac..0bb275e 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 c653ddf..d6c2229 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 */