[PATCH] EP info debug

[Michal Pecio]

---
 drivers/usb/host/xhci-ring.c | 62 ++++++++++++++++++++++++++++++++++--
 drivers/usb/host/xhci.c      | 14 ++++++++
 drivers/usb/host/xhci.h      | 28 ++++++++++++++++
 3 files changed, 102 insertions(+), 2 deletions(-)

diff --git a/drivers/usb/host/xhci-ring.c b/drivers/usb/host/xhci-ring.c
index d9ada94ee52c..e4fee00a00b8 100644
--- a/drivers/usb/host/xhci-ring.c
+++ b/drivers/usb/host/xhci-ring.c
@@ -421,6 +421,8 @@ static unsigned int xhci_ring_expansion_needed(struct xhci_hcd *xhci, struct xhc
 /* Ring the host controller doorbell after placing a command on the ring */
 void xhci_ring_cmd_db(struct xhci_hcd *xhci)
 {
+	xhci_ep_info(xhci, 0, -1, "xhci_ring_cmd_db cmd_ring_state %d\n", xhci->cmd_ring_state);
+
 	if (!(xhci->cmd_ring_state & CMD_RING_STATE_RUNNING))
 		return;
 
@@ -565,6 +567,10 @@ void xhci_ring_ep_doorbell(struct xhci_hcd *xhci,
 	    (ep_state & EP_HALTED) || (ep_state & EP_CLEARING_TT))
 		return;
 
+	struct xhci_ep_ctx *ep_ctx = xhci_get_ep_ctx(xhci, xhci->devs[slot_id]->out_ctx, ep_index);
+	if (GET_EP_CTX_STATE(READ_ONCE(ep_ctx)) != EP_STATE_RUNNING)
+		xhci_ep_info(xhci, slot_id, ep_index, "ring_ep_doorbell stream %d\n", stream_id);
+
 	trace_xhci_ring_ep_doorbell(slot_id, DB_VALUE(ep_index, stream_id));
 
 	writel(DB_VALUE(ep_index, stream_id), db_addr);
@@ -779,6 +785,8 @@ static int xhci_move_dequeue_past_td(struct xhci_hcd *xhci,
 
 	if (stream_id)
 		trb_sct = SCT_FOR_TRB(SCT_PRI_TR);
+	xhci_ep_info(xhci, slot_id, ep_index, "queue_set_tr_deq stream %d addr %.8llx\n",
+			stream_id, (u64) addr);
 	ret = queue_command(xhci, cmd,
 		lower_32_bits(addr) | trb_sct | new_cycle,
 		upper_32_bits(addr),
@@ -1239,8 +1247,6 @@ static void xhci_handle_cmd_stop_ep(struct xhci_hcd *xhci, int slot_id,
 			 * If the halt happened before Stop Endpoint failed, its transfer event
 			 * should have already been handled and Reset Endpoint should be pending.
 			 */
-			if (ep->ep_state & EP_HALTED)
-				goto reset_done;
 
 			if (ep->ep_state & EP_HAS_STREAMS) {
 				reset_type = EP_SOFT_RESET;
@@ -1250,6 +1256,12 @@ static void xhci_handle_cmd_stop_ep(struct xhci_hcd *xhci, int slot_id,
 				if (td)
 					td->status = -EPROTO;
 			}
+			xhci_ep_info(xhci, slot_id, ep_index, "handle_cmd_stop_ep stalled TD found %d handled %d\n",
+					!!td, !!(ep->ep_state & EP_HALTED));
+
+			if (ep->ep_state & EP_HALTED)
+				goto reset_done;
+
 			/* reset ep, reset handler cleans up cancelled tds */
 			err = xhci_handle_halted_endpoint(xhci, ep, td, reset_type);
 			xhci_dbg(xhci, "Stop ep completion resetting ep, status %d\n", err);
@@ -1872,6 +1884,10 @@ static void handle_cmd_completion(struct xhci_hcd *xhci,
 	}
 
 	cmd_type = TRB_FIELD_TO_TYPE(le32_to_cpu(cmd_trb->generic.field[3]));
+	int ep_index = TRB_TO_EP_INDEX(le32_to_cpu(cmd_trb->generic.field[3]));
+	xhci_ep_info(xhci, slot_id, ep_index, "handle_cmd_completion cmd_type %d comp_code %d\n",
+			cmd_type, cmd_comp_code);
+
 	switch (cmd_type) {
 	case TRB_ENABLE_SLOT:
 		xhci_handle_cmd_enable_slot(slot_id, cmd, cmd_comp_code);
@@ -2664,6 +2680,10 @@ static int handle_tx_event(struct xhci_hcd *xhci,
 	trb_comp_code = GET_COMP_CODE(le32_to_cpu(event->transfer_len));
 	ep_trb_dma = le64_to_cpu(event->buffer);
 
+	if (trb_comp_code != COMP_SUCCESS && trb_comp_code != COMP_SHORT_PACKET)
+		xhci_ep_info(xhci, slot_id, ep_index, "handle_tx_event comp_code %d trb_dma %.8llx\n",
+				trb_comp_code, (u64) ep_trb_dma);
+
 	ep = xhci_get_virt_ep(xhci, slot_id, ep_index);
 	if (!ep) {
 		xhci_err(xhci, "ERROR Invalid Transfer event\n");
@@ -2686,6 +2706,18 @@ static int handle_tx_event(struct xhci_hcd *xhci,
 	/* find the transfer trb this events points to */
 	ep_trb = xhci_dma_to_trb(ep_ring->deq_seg, ep_trb_dma, NULL);
 
+	if (trb_comp_code != COMP_SUCCESS && trb_comp_code != COMP_SHORT_PACKET) {
+		u32 remaining, ep_trb_len;
+
+		remaining = EVENT_TRB_LEN(le32_to_cpu(event->transfer_len));
+		ep_trb_len = ep_trb ?
+				TRB_LEN(le32_to_cpu(ep_trb->generic.field[2])) :
+				~0;
+
+		xhci_ep_info(xhci, slot_id, ep_index, "handle_tx_event stream_id %d trb_len %u missing %d\n",
+				ep_ring->stream_id, ep_trb_len, remaining);
+	}
+
 	/* Look for common error cases */
 	switch (trb_comp_code) {
 	/* Skip codes that require special handling depending on
@@ -4411,6 +4443,18 @@ static int queue_command(struct xhci_hcd *xhci, struct xhci_command *cmd,
 int xhci_queue_slot_control(struct xhci_hcd *xhci, struct xhci_command *cmd,
 		u32 trb_type, u32 slot_id)
 {
+	char *type = "wtf";
+
+	switch (trb_type) {
+	case TRB_ENABLE_SLOT:
+		type = "enable";
+		break;
+	case TRB_DISABLE_SLOT:
+		type = "disable";
+		break;
+	}
+	xhci_ep_info(xhci, slot_id, -1, "queue_%s_slot\n", type);
+
 	return queue_command(xhci, cmd, 0, 0, 0,
 			TRB_TYPE(trb_type) | SLOT_ID_FOR_TRB(slot_id), false);
 }
@@ -4419,6 +4463,9 @@ int xhci_queue_slot_control(struct xhci_hcd *xhci, struct xhci_command *cmd,
 int xhci_queue_address_device(struct xhci_hcd *xhci, struct xhci_command *cmd,
 		dma_addr_t in_ctx_ptr, u32 slot_id, enum xhci_setup_dev setup)
 {
+	xhci_ep_info(xhci, slot_id, -1, "queue_address_device bsr %d\n",
+			setup == SETUP_CONTEXT_ONLY);
+
 	return queue_command(xhci, cmd, lower_32_bits(in_ctx_ptr),
 			upper_32_bits(in_ctx_ptr), 0,
 			TRB_TYPE(TRB_ADDR_DEV) | SLOT_ID_FOR_TRB(slot_id)
@@ -4435,6 +4482,8 @@ int xhci_queue_vendor_command(struct xhci_hcd *xhci, struct xhci_command *cmd,
 int xhci_queue_reset_device(struct xhci_hcd *xhci, struct xhci_command *cmd,
 		u32 slot_id)
 {
+	xhci_ep_info(xhci, slot_id, -1, "queue_reset_device\n");
+
 	return queue_command(xhci, cmd, 0, 0, 0,
 			TRB_TYPE(TRB_RESET_DEV) | SLOT_ID_FOR_TRB(slot_id),
 			false);
@@ -4445,6 +4494,8 @@ int xhci_queue_configure_endpoint(struct xhci_hcd *xhci,
 		struct xhci_command *cmd, dma_addr_t in_ctx_ptr,
 		u32 slot_id, bool command_must_succeed)
 {
+	xhci_ep_info(xhci, slot_id, -1, "queue_configure_endpoint in_ctx %.8llx\n", (u64) in_ctx_ptr);
+
 	return queue_command(xhci, cmd, lower_32_bits(in_ctx_ptr),
 			upper_32_bits(in_ctx_ptr), 0,
 			TRB_TYPE(TRB_CONFIG_EP) | SLOT_ID_FOR_TRB(slot_id),
@@ -4466,6 +4517,8 @@ int xhci_queue_get_port_bw(struct xhci_hcd *xhci,
 int xhci_queue_evaluate_context(struct xhci_hcd *xhci, struct xhci_command *cmd,
 		dma_addr_t in_ctx_ptr, u32 slot_id, bool command_must_succeed)
 {
+	xhci_ep_info(xhci, slot_id, -1, "queue_evaluate_context in_ctx %.8llx\n", (u64) in_ctx_ptr);
+
 	return queue_command(xhci, cmd, lower_32_bits(in_ctx_ptr),
 			upper_32_bits(in_ctx_ptr), 0,
 			TRB_TYPE(TRB_EVAL_CONTEXT) | SLOT_ID_FOR_TRB(slot_id),
@@ -4484,6 +4537,8 @@ int xhci_queue_stop_endpoint(struct xhci_hcd *xhci, struct xhci_command *cmd,
 	u32 type = TRB_TYPE(TRB_STOP_RING);
 	u32 trb_suspend = SUSPEND_PORT_FOR_TRB(suspend);
 
+	xhci_ep_info(xhci, slot_id, ep_index, "queue_stop_endpoint suspend %d\n", suspend);
+
 	return queue_command(xhci, cmd, 0, 0, 0,
 			trb_slot_id | trb_ep_index | type | trb_suspend, false);
 }
@@ -4496,6 +4551,9 @@ int xhci_queue_reset_ep(struct xhci_hcd *xhci, struct xhci_command *cmd,
 	u32 trb_ep_index = EP_INDEX_FOR_TRB(ep_index);
 	u32 type = TRB_TYPE(TRB_RESET_EP);
 
+	xhci_ep_info(xhci, slot_id, ep_index, "queue_reset_endpoint tsp %d\n",
+			reset_type == EP_SOFT_RESET);
+
 	if (reset_type == EP_SOFT_RESET)
 		type |= TRB_TSP;
 
diff --git a/drivers/usb/host/xhci.c b/drivers/usb/host/xhci.c
index 849a568d0e63..0b96fd8bff12 100644
--- a/drivers/usb/host/xhci.c
+++ b/drivers/usb/host/xhci.c
@@ -1853,6 +1853,9 @@ static int xhci_urb_dequeue(struct usb_hcd *hcd, struct urb *urb, int status)
 
 	for (; i < urb_priv->num_tds; i++) {
 		td = &urb_priv->td[i];
+		xhci_ep_info(xhci, urb->dev->slot_id, ep_index, "xhci_urb_dequeue cancel TD at %.8llx stream %d\n",
+				(u64) xhci_trb_virt_to_dma(urb_priv->td[i].start_seg, urb_priv->td[i].start_trb),
+				urb->stream_id);
 		/* TD can already be on cancelled list if ep halted on it */
 		if (list_empty(&td->cancelled_td_list)) {
 			td->cancel_status = TD_DIRTY;
@@ -1969,6 +1972,7 @@ int xhci_drop_endpoint(struct usb_hcd *hcd, struct usb_device *udev,
 	u32 drop_flag;
 	u32 new_add_flags, new_drop_flags;
 	int ret;
+	int td_num = -1;
 
 	ret = xhci_check_args(hcd, udev, ep, 1, true, __func__);
 	if (ret <= 0)
@@ -1995,7 +1999,13 @@ int xhci_drop_endpoint(struct usb_hcd *hcd, struct usb_device *udev,
 	}
 
 	ep_index = xhci_get_endpoint_index(&ep->desc);
+	struct xhci_virt_ep *vep = &xhci->devs[udev->slot_id]->eps[ep_index];
+	if (vep && vep->ring)
+		td_num = list_count_nodes(&vep->ring->td_list);
 	ep_ctx = xhci_get_ep_ctx(xhci, out_ctx, ep_index);
+	xhci_ep_info(xhci, udev->slot_id, ep_index, "xhci_drop_endpoint ctx_state %d td_num %d\n",
+			GET_EP_CTX_STATE(ep_ctx), td_num);
+
 	/* If the HC already knows the endpoint is disabled,
 	 * or the HCD has noted it is disabled, ignore this request
 	 */
@@ -2087,6 +2097,8 @@ int xhci_add_endpoint(struct usb_hcd *hcd, struct usb_device *udev,
 	}
 
 	ep_index = xhci_get_endpoint_index(&ep->desc);
+	xhci_ep_info(xhci, udev->slot_id, ep_index, "xhci_add_endpoint\n");
+
 	/* If this endpoint is already in use, and the upper layers are trying
 	 * to add it again without dropping it, reject the addition.
 	 */
@@ -3388,6 +3400,8 @@ static void xhci_endpoint_reset(struct usb_hcd *hcd,
 	xhci = hcd_to_xhci(hcd);
 	ep_index = xhci_get_endpoint_index(&host_ep->desc);
 
+	xhci_ep_info(xhci, udev->slot_id, ep_index, "xhci_endpoint_reset\n");
+
 	/*
 	 * Usb core assumes a max packet value for ep0 on FS devices until the
 	 * real value is read from the descriptor. Core resets Ep0 if values
diff --git a/drivers/usb/host/xhci.h b/drivers/usb/host/xhci.h
index 32617dc155ac..c46bd4697c7a 100644
--- a/drivers/usb/host/xhci.h
+++ b/drivers/usb/host/xhci.h
@@ -1747,6 +1747,34 @@ static inline bool xhci_has_one_roothub(struct xhci_hcd *xhci)
 #define xhci_info(xhci, fmt, args...) \
 	dev_info(xhci_to_hcd(xhci)->self.controller , fmt , ## args)
 
+#define xhci_ep_info(xhci, slot_id, ep_index, fmt, args...)				\
+	do {										\
+		int ep_state = 0xfff;							\
+		int ctx_state = 0xf;							\
+		u64 ep_deq = 0xffffffff;						\
+		u64 ctx_deq = 0xffffffff;						\
+		u64 ep_enq = 0xffffffff;						\
+		if (slot_id > 0 && slot_id < MAX_HC_SLOTS &&				\
+				ep_index >= 0 && ep_index < 32 &&			\
+				xhci->devs[slot_id]) {					\
+			struct xhci_virt_device *vdev = xhci->devs[slot_id];		\
+			struct xhci_virt_ep *ep = vdev->eps + ep_index;			\
+			struct xhci_ep_ctx *ep_ctx =					\
+				xhci_get_ep_ctx(xhci, vdev->out_ctx, ep_index);		\
+			if (ep->ring) {							\
+				ep_deq = xhci_trb_virt_to_dma(ep->ring->deq_seg,	\
+								ep->ring->dequeue);	\
+				ep_enq = xhci_trb_virt_to_dma(ep->ring->enq_seg,	\
+								ep->ring->enqueue);	\
+			}								\
+			ep_state = ep->ep_state;					\
+			ctx_state = GET_EP_CTX_STATE(READ_ONCE(ep_ctx));		\
+			ctx_deq = le64_to_cpu(READ_ONCE(ep_ctx->deq));			\
+		}									\
+		xhci_info(xhci, "%d/%d (%.3x/%x) [%.8llx/%.8llx/%.8llx] " fmt,		\
+				slot_id, ep_index, ep_state, ctx_state,			\
+				ep_deq, ctx_deq, ep_enq, ## args);			\
+	} while (0);
 /*
  * Registers should always be accessed with double word or quad word accesses.
  *
-- 
2.48.1


--MP_/a30Xhx_PbaPSoGRaznypMiF--