Donate to e Foundation | Murena handsets with /e/OS | Own a part of Murena! Learn more

Commit 6b09eba2 authored by Jack Pham's avatar Jack Pham Committed by Matt Wagantall
Browse files

usb: dwc3: gadget: Keep track of IRQ timing statistics 



It may be useful to debug how much time is spent in the
DWC3 hard IRQ context. Add low-overhead statistics counters
which keep a histogram of the last 10 interrupts' time of
occurence, time spent, and number of events read (which will
get processed in the bottom half handler).

Change-Id: I466144d8141f4236b9fb834dded93225b56d0422
[jackp@codeaurora.org: Also added BH stats from "usb: dwc3: Offload
 IRQ handling to softirq context"]
Signed-off-by: default avatarJack Pham <jackp@codeaurora.org>
parent d8301c21

drivers/usb/dwc3/core.h

+14 −0
Original line number Diff line number Diff line
@@ -723,6 +723,8 @@ struct dwc3_scratchpad_array { 
#define DWC3_CORE_PM_RESUME_EVENT			6

#define DWC3_CONTROLLER_POST_INITIALIZATION_EVENT	7

#define DWC3_CONTROLLER_CONNDONE_EVENT			8



#define MAX_INTR_STATS					10

/**

 * struct dwc3 - representation of our controller

 * @ctrl_req: usb control request which is used for ep0
@@ -788,6 +790,9 @@ struct dwc3_scratchpad_array { 
 * @hird_thresh: value to configure in DCTL[HIRD_Thresh]

 * @in_lpm: if 1, indicates that the controller is in low power mode (no clocks)

 * @tx_fifo_size: Available RAM size for TX fifo allocation

 * @bh_completion_time: time taken for taklet completion

 * @bh_handled_evt_cnt: no. of events handled by tasklet per interrupt

 * @bh_dbg_index: index for capturing bh_completion_time and bh_handled_evt_cnt

 */

struct dwc3 {

	struct usb_ctrlrequest	*ctrl_req;
@@ -916,6 +921,15 @@ struct dwc3 { 
	atomic_t		in_lpm;

	int			tx_fifo_size;

	bool			tx_fifo_reduced;



	/* IRQ timing statistics */

	unsigned                bh_completion_time[MAX_INTR_STATS];

	unsigned                bh_handled_evt_cnt[MAX_INTR_STATS];

	unsigned                bh_dbg_index;

	ktime_t			irq_start_time[MAX_INTR_STATS];

	unsigned                irq_completion_time[MAX_INTR_STATS];

	unsigned                irq_event_count[MAX_INTR_STATS];

	unsigned                irq_dbg_index;

};



/* -------------------------------------------------------------------------- */

drivers/usb/dwc3/debugfs.c

+18 −0
Original line number Diff line number Diff line
@@ -1154,6 +1154,24 @@ static int dwc3_gadget_int_events_show(struct seq_file *s, void *unused) 
		dbg_gadget_events->cmdcmplt);

	seq_printf(s, "unknown_event:%u\n", dbg_gadget_events->unknown_event);



	seq_printf(s, "\n\t== Last %d interrupts stats ==\t\n", MAX_INTR_STATS);

	seq_puts(s, "@ time (us):\t");

	for (i = 0; i < MAX_INTR_STATS; i++)

		seq_printf(s, "%lld\t", ktime_to_us(dwc->irq_start_time[i]));

	seq_puts(s, "\nhard irq time (us):\t");

	for (i = 0; i < MAX_INTR_STATS; i++)

		seq_printf(s, "%d\t", dwc->irq_completion_time[i]);

	seq_puts(s, "\nevents count:\t\t");

	for (i = 0; i < MAX_INTR_STATS; i++)

		seq_printf(s, "%d\t", dwc->irq_event_count[i]);

	seq_puts(s, "\nbh handled count:\t");

	for (i = 0; i < MAX_INTR_STATS; i++)

		seq_printf(s, "%d\t", dwc->bh_handled_evt_cnt[i]);

	seq_puts(s, "\nirq thread time (us):\t");

	for (i = 0; i < MAX_INTR_STATS; i++)

		seq_printf(s, "%d\t", dwc->bh_completion_time[i]);

	seq_putc(s, '\n');



	spin_unlock_irqrestore(&dwc->lock, flags);

	return 0;

}

drivers/usb/dwc3/gadget.c

+22 −0
Original line number Diff line number Diff line
@@ -3287,6 +3287,8 @@ static irqreturn_t dwc3_process_event_buf(struct dwc3 *dwc, u32 buf) 
		dwc3_writel(dwc->regs, DWC3_GEVNTCOUNT(buf), 4);

	}



	dwc->bh_handled_evt_cnt[dwc->bh_dbg_index] += (evt->count / 4);



	evt->count = 0;

	evt->flags &= ~DWC3_EVENT_PENDING;

	ret = IRQ_HANDLED;
@@ -3305,14 +3307,23 @@ static irqreturn_t dwc3_thread_interrupt(int irq, void *_dwc) 
	unsigned long flags;

	irqreturn_t ret = IRQ_NONE;

	int i;

	unsigned temp_time;

	ktime_t start_time;



	start_time = ktime_get();



	spin_lock_irqsave(&dwc->lock, flags);

	dwc->bh_handled_evt_cnt[dwc->bh_dbg_index] = 0;



	for (i = 0; i < dwc->num_event_buffers; i++)

		ret |= dwc3_process_event_buf(dwc, i);



	spin_unlock_irqrestore(&dwc->lock, flags);



	temp_time = ktime_to_us(ktime_sub(ktime_get(), start_time));

	dwc->bh_completion_time[dwc->bh_dbg_index] = temp_time;

	dwc->bh_dbg_index = (dwc->bh_dbg_index + 1) % 10;



	pm_runtime_put(dwc->dev);

	return ret;

}
@@ -3346,7 +3357,10 @@ static irqreturn_t dwc3_interrupt(int irq, void *_dwc) 
	struct dwc3			*dwc = _dwc;

	int				i;

	irqreturn_t			ret = IRQ_NONE;

	unsigned			temp_cnt = 0;

	ktime_t				start_time;



	start_time = ktime_get();

	spin_lock(&dwc->lock);



	for (i = 0; i < dwc->num_event_buffers; i++) {
@@ -3355,10 +3369,18 @@ static irqreturn_t dwc3_interrupt(int irq, void *_dwc) 
		status = dwc3_check_event_buf(dwc, i);

		if (status == IRQ_WAKE_THREAD)

			ret = status;



		temp_cnt += dwc->ev_buffs[i]->count;

	}



	spin_unlock(&dwc->lock);



	dwc->irq_start_time[dwc->irq_dbg_index] = start_time;

	dwc->irq_completion_time[dwc->irq_dbg_index] =

		ktime_us_delta(ktime_get(), start_time);

	dwc->irq_event_count[dwc->irq_dbg_index] = temp_cnt / 4;

	dwc->irq_dbg_index = (dwc->irq_dbg_index + 1) % MAX_INTR_STATS;



	if (ret == IRQ_WAKE_THREAD)

		pm_runtime_get(dwc->dev);