lists.openwall.net   lists  /  announce  owl-users  owl-dev  john-users  john-dev  passwdqc-users  yescrypt  popa3d-users  /  oss-security  kernel-hardening  musl  sabotage  tlsify  passwords  /  crypt-dev  xvendor  /  Bugtraq  Full-Disclosure  linux-kernel  linux-netdev  linux-ext4  linux-hardening  linux-cve-announce  PHC 
Open Source and information security mailing list archives
 
Hash Suite: Windows password security audit tool. GUI, reports in PDF.
[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Message-Id: <1487126112-6069-3-git-send-email-baolu.lu@linux.intel.com>
Date:   Wed, 15 Feb 2017 10:35:08 +0800
From:   Lu Baolu <baolu.lu@...ux.intel.com>
To:     Mathias Nyman <mathias.nyman@...ux.intel.com>
Cc:     linux-usb@...r.kernel.org, linux-kernel@...r.kernel.org,
        Lu Baolu <baolu.lu@...ux.intel.com>
Subject: [PATCH 2/6] usb: xhci: enhance xhci_log_ctx trace events

XHCI driver has defined xhci_log_ctx trace events to trace
the change of an xhci input or output context. This patch
extends the trace class of xhci_log_ctx to print out the
contents of a context block in a human readable way.

This patch also adds some other xhci_log_ctx based events
where the xhci input or output context changes.

Signed-off-by: Lu Baolu <baolu.lu@...ux.intel.com>
---
 drivers/usb/host/xhci-trace.h | 63 ++++++++++++++++++++++++++++++-------------
 drivers/usb/host/xhci.c       | 23 +++++++++++-----
 drivers/usb/host/xhci.h       | 60 +++++++++++++++++++++++++++++++++++++++++
 3 files changed, 121 insertions(+), 25 deletions(-)

diff --git a/drivers/usb/host/xhci-trace.h b/drivers/usb/host/xhci-trace.h
index c31eeaf..8fe01b1 100644
--- a/drivers/usb/host/xhci-trace.h
+++ b/drivers/usb/host/xhci-trace.h
@@ -75,44 +75,71 @@ DEFINE_EVENT(xhci_log_msg, xhci_dbg_ring_expansion,
 );
 
 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_PROTO(struct xhci_hcd *xhci, struct xhci_container_ctx *ctx),
+	TP_ARGS(xhci, ctx),
 	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))
+			((ctx->type == XHCI_CTX_TYPE_INPUT) + xhci_get_ep_num(xhci, ctx) + 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;
+		__entry->ctx_ep_num = xhci_get_ep_num(xhci, ctx);
 		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));
+			((ctx->type == XHCI_CTX_TYPE_INPUT) + xhci_get_ep_num(xhci, ctx) + 1));
 	),
-	TP_printk("ctx_64=%d, ctx_type=%u, ctx_dma=@...x, ctx_va=@%p",
-			__entry->ctx_64, __entry->ctx_type,
-			(unsigned long long) __entry->ctx_dma, __entry->ctx_va
+	TP_printk("ctx @%p: ctx_64=%d, ctx_type=%u, ctx_dma=@...x: %s",
+		__entry->ctx_va, __entry->ctx_64, __entry->ctx_type,
+		(unsigned long long)__entry->ctx_dma,
+		xhci_decode_ctx((u8 *)__get_dynamic_array(ctx_data),
+				__entry->ctx_type,
+				__entry->ctx_ep_num,
+				__entry->ctx_64 ? 64 : 32)
 	)
 );
 
-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)
+DEFINE_EVENT(xhci_log_ctx, ctx_xhci_setup_device,
+	TP_PROTO(struct xhci_hcd *xhci, struct xhci_container_ctx *ctx),
+	TP_ARGS(xhci, ctx)
+);
+
+DEFINE_EVENT(xhci_log_ctx, ctx_xhci_check_maxpacket,
+	TP_PROTO(struct xhci_hcd *xhci, struct xhci_container_ctx *ctx),
+	TP_ARGS(xhci, ctx)
+);
+
+DEFINE_EVENT(xhci_log_ctx, ctx_xhci_check_bandwidth,
+	TP_PROTO(struct xhci_hcd *xhci, struct xhci_container_ctx *ctx),
+	TP_ARGS(xhci, ctx)
+);
+
+DEFINE_EVENT(xhci_log_ctx, ctx_xhci_alloc_streams,
+	TP_PROTO(struct xhci_hcd *xhci, struct xhci_container_ctx *ctx),
+	TP_ARGS(xhci, ctx)
+);
+
+DEFINE_EVENT(xhci_log_ctx, ctx_xhci_free_streams,
+	TP_PROTO(struct xhci_hcd *xhci, struct xhci_container_ctx *ctx),
+	TP_ARGS(xhci, ctx)
+);
+
+DEFINE_EVENT(xhci_log_ctx, ctx_xhci_update_hub_device,
+	TP_PROTO(struct xhci_hcd *xhci, struct xhci_container_ctx *ctx),
+	TP_ARGS(xhci, ctx)
+);
+
+DEFINE_EVENT(xhci_log_ctx, ctx_xhci_change_max_exit_latency,
+	TP_PROTO(struct xhci_hcd *xhci, struct xhci_container_ctx *ctx),
+	TP_ARGS(xhci, ctx)
 );
 
 DECLARE_EVENT_CLASS(xhci_log_trb,
diff --git a/drivers/usb/host/xhci.c b/drivers/usb/host/xhci.c
index dff912e..304f38d 100644
--- a/drivers/usb/host/xhci.c
+++ b/drivers/usb/host/xhci.c
@@ -1311,8 +1311,10 @@ static int xhci_check_maxpacket(struct xhci_hcd *xhci, unsigned int slot_id,
 		xhci_dbg(xhci, "Slot %d output context\n", slot_id);
 		xhci_dbg_ctx(xhci, out_ctx, ep_index);
 
+		trace_ctx_xhci_check_maxpacket(xhci, command->in_ctx);
 		ret = xhci_configure_endpoint(xhci, urb->dev, command,
 				true, false);
+		trace_ctx_xhci_check_maxpacket(xhci, out_ctx);
 
 		/* Clean up the input context for later use by bandwidth
 		 * functions.
@@ -2745,8 +2747,10 @@ int xhci_check_bandwidth(struct usb_hcd *hcd, struct usb_device *udev)
 	xhci_dbg_ctx(xhci, virt_dev->in_ctx,
 		     LAST_CTX_TO_EP_NUM(le32_to_cpu(slot_ctx->dev_info)));
 
+	trace_ctx_xhci_check_bandwidth(xhci, command->in_ctx);
 	ret = xhci_configure_endpoint(xhci, udev, command,
 			false, false);
+	trace_ctx_xhci_check_bandwidth(xhci, virt_dev->out_ctx);
 	if (ret)
 		/* Callee should call reset_bandwidth() */
 		goto command_cleanup;
@@ -3207,8 +3211,10 @@ int xhci_alloc_streams(struct usb_hcd *hcd, struct usb_device *udev,
 			changed_ep_bitmask, changed_ep_bitmask);
 
 	/* Issue and wait for the configure endpoint command */
+	trace_ctx_xhci_alloc_streams(xhci, config_cmd->in_ctx);
 	ret = xhci_configure_endpoint(xhci, udev, config_cmd,
 			false, false);
+	trace_ctx_xhci_alloc_streams(xhci, vdev->out_ctx);
 
 	/* xHC rejected the configure endpoint command for some reason, so we
 	 * leave the old ring intact and free our internal streams data
@@ -3314,8 +3320,10 @@ int xhci_free_streams(struct usb_hcd *hcd, struct usb_device *udev,
 	/* Issue and wait for the configure endpoint command,
 	 * which must succeed.
 	 */
+	trace_ctx_xhci_free_streams(xhci, command->in_ctx);
 	ret = xhci_configure_endpoint(xhci, udev, command,
 			false, true);
+	trace_ctx_xhci_free_streams(xhci, vdev->out_ctx);
 
 	/* xHC rejected the configure endpoint command for some reason, so we
 	 * leave the streams rings intact.
@@ -3819,8 +3827,7 @@ static int xhci_setup_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,
-				le32_to_cpu(slot_ctx->dev_info) >> 27);
+	trace_ctx_xhci_setup_device(xhci, virt_dev->in_ctx);
 
 	spin_lock_irqsave(&xhci->lock, flags);
 	trace_xhci_setup_device(virt_dev);
@@ -3874,7 +3881,7 @@ static int xhci_setup_device(struct usb_hcd *hcd, struct usb_device *udev,
 			 act, command->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);
+		trace_ctx_xhci_setup_device(xhci, virt_dev->out_ctx);
 		ret = -EINVAL;
 		break;
 	}
@@ -3894,8 +3901,7 @@ static int xhci_setup_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,
-				le32_to_cpu(slot_ctx->dev_info) >> 27);
+	trace_ctx_xhci_setup_device(xhci, virt_dev->in_ctx);
 	xhci_dbg(xhci, "Slot ID %d Output Context:\n", udev->slot_id);
 	xhci_dbg_ctx(xhci, virt_dev->out_ctx, 2);
 	/*
@@ -3903,8 +3909,7 @@ static int xhci_setup_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,
-				le32_to_cpu(slot_ctx->dev_info) >> 27);
+	trace_ctx_xhci_setup_device(xhci, virt_dev->out_ctx);
 	/* Zero the input context control for later use */
 	ctrl_ctx->add_flags = 0;
 	ctrl_ctx->drop_flags = 0;
@@ -4007,8 +4012,10 @@ static int __maybe_unused xhci_change_max_exit_latency(struct xhci_hcd *xhci,
 	xhci_dbg_ctx(xhci, command->in_ctx, 0);
 
 	/* Issue and wait for the evaluate context command. */
+	trace_ctx_xhci_change_max_exit_latency(xhci, command->in_ctx);
 	ret = xhci_configure_endpoint(xhci, udev, command,
 			true, true);
+	trace_ctx_xhci_change_max_exit_latency(xhci, virt_dev->out_ctx);
 	xhci_dbg(xhci, "Slot %u Output Context:\n", udev->slot_id);
 	xhci_dbg_ctx(xhci, virt_dev->out_ctx, 0);
 
@@ -4784,12 +4791,14 @@ int xhci_update_hub_device(struct usb_hcd *hcd, struct usb_device *hdev,
 	/* Issue and wait for the configure endpoint or
 	 * evaluate context command.
 	 */
+	trace_ctx_xhci_update_hub_device(xhci, config_cmd->in_ctx);
 	if (xhci->hci_version > 0x95)
 		ret = xhci_configure_endpoint(xhci, hdev, config_cmd,
 				false, false);
 	else
 		ret = xhci_configure_endpoint(xhci, hdev, config_cmd,
 				true, false);
+	trace_ctx_xhci_update_hub_device(xhci, vdev->out_ctx);
 
 	xhci_dbg(xhci, "Slot %u Output Context:\n", hdev->slot_id);
 	xhci_dbg_ctx(xhci, vdev->out_ctx, 0);
diff --git a/drivers/usb/host/xhci.h b/drivers/usb/host/xhci.h
index da3eb69..d6c4038 100644
--- a/drivers/usb/host/xhci.h
+++ b/drivers/usb/host/xhci.h
@@ -2359,5 +2359,65 @@ static inline const char *xhci_decode_trb(u32 field0, u32 field1, u32 field2,
 	return str;
 }
 
+static inline unsigned int
+xhci_get_ep_num(struct xhci_hcd *xhci, struct xhci_container_ctx *ctx)
+{
+	struct xhci_slot_ctx *slot_ctx;
+
+	slot_ctx = xhci_get_slot_ctx(xhci, ctx);
+	return (le32_to_cpu(slot_ctx->dev_info) >> 27);
+}
+
+static inline const char *
+xhci_decode_ctx(u8 *ctx, unsigned int type, unsigned int ep_num,
+		unsigned int ctx_size)
+{
+	char *next;
+	int i, temp, size;
+	unsigned int index;
+	static char str[1600];
+	struct xhci_ep_ctx *ep_ctx;
+	struct xhci_slot_ctx *slot_ctx;
+	struct xhci_input_control_ctx *ctrl_ctx;
+
+	next = str;
+	size = sizeof(str);
+
+	if (type == XHCI_CTX_TYPE_INPUT) {
+		ctrl_ctx = (struct xhci_input_control_ctx *)ctx;
+		temp = scnprintf(next, size,
+				 "Input control:%#08x %#08x\n",
+				 le32_to_cpu(ctrl_ctx->drop_flags),
+				 le32_to_cpu(ctrl_ctx->add_flags));
+		next += temp;
+		size -= temp;
+	}
+
+	index = (type == XHCI_CTX_TYPE_INPUT);
+	slot_ctx = (struct xhci_slot_ctx *)(ctx + index * ctx_size);
+	temp = scnprintf(next, size,
+			 "Slot Context:%#08x %#08x %#08x %#08x\n",
+			 le32_to_cpu(slot_ctx->dev_info),
+			 le32_to_cpu(slot_ctx->dev_info2),
+			 le32_to_cpu(slot_ctx->tt_info),
+			 le32_to_cpu(slot_ctx->dev_state));
+	next += temp;
+	size -= temp;
+
+	for (i = 0; i < ep_num && size > 0; i++) {
+		index = i + 1 + (type == XHCI_CTX_TYPE_INPUT);
+		ep_ctx = (struct xhci_ep_ctx *)(ctx + index * ctx_size);
+		temp = scnprintf(next, size,
+				 "Endpoint Context [index %02d]: %#08x %#08x %#08llx %#08x\n",
+				 i + 1, le32_to_cpu(ep_ctx->ep_info),
+				 le32_to_cpu(ep_ctx->ep_info2),
+				 le64_to_cpu(ep_ctx->deq),
+				 le32_to_cpu(ep_ctx->tx_info));
+		next += temp;
+		size -= temp;
+	}
+
+	return str;
+}
 
 #endif /* __LINUX_XHCI_HCD_H */
-- 
2.1.4

Powered by blists - more mailing lists

Powered by Openwall GNU/*/Linux Powered by OpenVZ