From 37084ff13d80d9e91089e5c3f8e6d338540cea0d Mon Sep 17 00:00:00 2001 From: Mayank Rana Date: Tue, 16 Jun 2020 10:57:06 -0700 Subject: [PATCH] dwc3: gadget: Separate out top and bottom half based logging Currently USB top and bottom half are using same index to update number of events posted/handled, and updating relevant time. As top half is not guaranteed to be prevented when bottom half is running those index based logging doesn't allow to relate information. Also start logging bh_start_time and increase existing buffer size from 10 to 25 to get more data of USB interrupt processing. Also get count how many cancelled requqest being given back from bottom half context, and log any update/start cmd failure. Change-Id: Iefc883cb5a2259f256f30c9727db8a68ddd41af7 Signed-off-by: Mayank Rana --- drivers/usb/dwc3/core.h | 4 +++- drivers/usb/dwc3/gadget.c | 15 ++++++++++++--- 2 files changed, 15 insertions(+), 4 deletions(-) diff --git a/drivers/usb/dwc3/core.h b/drivers/usb/dwc3/core.h index 3e669b606561..a386dd71dd50 100644 --- a/drivers/usb/dwc3/core.h +++ b/drivers/usb/dwc3/core.h @@ -986,7 +986,7 @@ struct dwc3_scratchpad_array { __le64 dma_adr[DWC3_MAX_HIBER_SCRATCHBUFS]; }; -#define MAX_INTR_STATS 10 +#define MAX_INTR_STATS 25 /** * struct dwc3 - representation of our controller @@ -1355,8 +1355,10 @@ struct dwc3 { /* IRQ timing statistics */ int irq; unsigned long irq_cnt; + ktime_t bh_start_time[MAX_INTR_STATS]; unsigned int bh_completion_time[MAX_INTR_STATS]; unsigned int bh_handled_evt_cnt[MAX_INTR_STATS]; + unsigned int bh_dbg_index; ktime_t irq_start_time[MAX_INTR_STATS]; ktime_t t_pwr_evt_irq; unsigned int irq_completion_time[MAX_INTR_STATS]; diff --git a/drivers/usb/dwc3/gadget.c b/drivers/usb/dwc3/gadget.c index aa4517e9c1fe..04b100951247 100644 --- a/drivers/usb/dwc3/gadget.c +++ b/drivers/usb/dwc3/gadget.c @@ -1387,6 +1387,7 @@ static int __dwc3_gadget_kick_transfer(struct dwc3_ep *dep) if (ret == -EAGAIN) return ret; + dbg_log_string("dep:%s cmd failed ret:%d", dep->name, ret); dwc3_stop_active_transfer(dep, true, true); list_for_each_entry_safe(req, tmp, &dep->started_list, list) @@ -1662,11 +1663,18 @@ static void dwc3_gadget_ep_cleanup_cancelled_requests(struct dwc3_ep *dep) { struct dwc3_request *req; struct dwc3_request *tmp; + struct dwc3 *dwc = dep->dwc; + int request_count = 0; list_for_each_entry_safe(req, tmp, &dep->cancelled_list, list) { dwc3_gadget_ep_skip_trbs(dep, req); dwc3_gadget_giveback(dep, req, -ECONNRESET); + request_count++; } + + if (request_count) + dbg_log_string("dep:%s request_count:%d", dep->name, + request_count); } static int dwc3_gadget_ep_dequeue(struct usb_ep *ep, @@ -3708,7 +3716,7 @@ static irqreturn_t dwc3_process_event_buf(struct dwc3_event_buffer *evt) left -= 4; } - dwc->bh_handled_evt_cnt[dwc->irq_dbg_index] += (evt->count / 4); + dwc->bh_handled_evt_cnt[dwc->bh_dbg_index] += (evt->count / 4); evt->count = 0; evt->flags &= ~DWC3_EVENT_PENDING; ret = IRQ_HANDLED; @@ -3750,9 +3758,10 @@ static irqreturn_t dwc3_thread_interrupt(int irq, void *_evt) ret = dwc3_process_event_buf(evt); spin_unlock_irqrestore(&dwc->lock, flags); - dwc->bh_completion_time[dwc->irq_dbg_index] = + dwc->bh_start_time[dwc->bh_dbg_index] = start_time; + dwc->bh_completion_time[dwc->bh_dbg_index] = ktime_to_us(ktime_sub(ktime_get(), start_time)); - dwc->irq_dbg_index = (dwc->irq_dbg_index + 1) % MAX_INTR_STATS; + dwc->bh_dbg_index = (dwc->bh_dbg_index + 1) % MAX_INTR_STATS; return ret; }