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 <burzalodowa@gmail.com>
Signed-off-by: Sarah Sharp <sarah.a.sharp@linux.intel.com>

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), )

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);
+}

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"

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

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;
 }

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);