qcacmn: HIF schedule latency measurement

Add support to measure interrupt latencies, store them
in different "bins" and display the constructed histogram
through user command.

Change-Id: I268be6b39745d550ac7db5d321c2d1fdb2d17d41
CRs-Fixed: 2365812

dp/inc/cdp_txrx_cmn_struct.h

@@ -199,6 +199,7 @@ enum htt_cmn_dbg_stats_type {
  * @TXRX_REO_QUEUE_STATS: Print Per peer REO Queue Stats
  * @TXRX_SOC_CFG_PARAMS: Print soc cfg params info
  * @TXRX_PDEV_CFG_PARAMS: Print pdev cfg params info
+ * @TXRX_NAPI_STATS: Print NAPI scheduling statistics
  */
 enum cdp_host_txrx_stats {
 	TXRX_HOST_STATS_INVALID  = -1,
@@ -213,6 +214,7 @@ enum cdp_host_txrx_stats {
 	TXRX_REO_QUEUE_STATS = 8,
 	TXRX_SOC_CFG_PARAMS   = 9,
 	TXRX_PDEV_CFG_PARAMS  = 10,
+	TXRX_NAPI_STATS       = 11,
 	TXRX_HOST_STATS_MAX,
 };
 

dp/wifi3.0/dp_main.c

@@ -1447,7 +1447,6 @@ static uint32_t dp_service_srngs(void *dp_ctx, uint32_t dp_budget)
 		for (mac_id = 0; mac_id < NUM_RXDMA_RINGS_PER_PDEV; mac_id++) {
 			int mac_for_pdev = dp_get_mac_id_for_pdev(mac_id,
 								pdev->pdev_id);
-
 			if (int_ctx->rx_mon_ring_mask & (1 << mac_for_pdev)) {
 				work_done = dp_mon_process(soc, mac_for_pdev,
 						remaining_quota);
@@ -6981,6 +6980,15 @@ dp_print_ring_stat_from_hal(struct dp_soc *soc,  struct dp_srng *srng,
 
 }
 
+/*
+ * dp_print_napi_stats(): NAPI stats
+ * @soc - soc handle
+ */
+static void dp_print_napi_stats(struct dp_soc *soc)
+{
+	hif_print_napi_stats(soc->hif_handle);
+}
+
 /**
  * dp_print_mon_ring_stats_from_hal() - Print stat for monitor rings based
  *					on target
@@ -7079,7 +7087,6 @@ dp_print_ring_stats(struct dp_pdev *pdev)
 		dp_print_ring_stat_from_hal(pdev->soc,
 					    &pdev->rxdma_err_dst_ring[i],
 					    RXDMA_DST);
-
 }
 
 /**
@@ -7099,6 +7106,9 @@ dp_txrx_host_stats_clr(struct dp_vdev *vdev)
 	DP_STATS_CLR(vdev->pdev);
 	DP_STATS_CLR(vdev->pdev->soc);
 	DP_STATS_CLR(vdev);
+
+	hif_clear_napi_stats(vdev->pdev->soc->hif_handle);
+
 	TAILQ_FOREACH(peer, &vdev->peer_list, peer_list_elem) {
 		if (!peer)
 			return;
@@ -7856,6 +7866,9 @@ dp_print_host_stats(struct cdp_vdev *vdev_handle,
 	case TXRX_PDEV_CFG_PARAMS:
 		dp_print_pdev_cfg_params(pdev);
 		break;
+	case TXRX_NAPI_STATS:
+		dp_print_napi_stats(pdev->soc);
+		break;
 	default:
 		dp_info("Wrong Input For TxRx Host Stats");
 		dp_txrx_stats_help();
@@ -8762,15 +8775,6 @@ QDF_STATUS dp_txrx_stats_request(struct cdp_vdev *vdev,
 	return QDF_STATUS_SUCCESS;
 }
 
-/*
- * dp_print_napi_stats(): NAPI stats
- * @soc - soc handle
- */
-static void dp_print_napi_stats(struct dp_soc *soc)
-{
-	hif_print_napi_stats(soc->hif_handle);
-}
-
 /*
  * dp_print_per_ring_stats(): Packet count per ring
  * @soc - soc handle

hif/inc/hif.h

@@ -929,6 +929,15 @@ void hif_update_pipe_callback(struct hif_opaque_softc *osc,
 				struct hif_msg_callbacks *callbacks);
 
 void hif_print_napi_stats(struct hif_opaque_softc *hif_ctx);
+
+/* hif_clear_napi_stats() - function clears the stats of the
+ * latency when called.
+ * @hif_ctx - the HIF context to assign the callback to
+ *
+ * Return: None
+ */
+void hif_clear_napi_stats(struct hif_opaque_softc *hif_ctx);
+
 #ifdef __cplusplus
 }
 #endif

hif/src/dispatcher/pci_api.h

@@ -1,5 +1,5 @@
 /*
- * Copyright (c) 2016-2018 The Linux Foundation. All rights reserved.
+ * Copyright (c) 2016-2019 The Linux Foundation. All rights reserved.
  *
  * Permission to use, copy, modify, and/or distribute this software for
  * any purpose with or without fee is hereby granted, provided that the
@@ -52,4 +52,5 @@ void hif_pci_display_stats(struct hif_softc *hif_ctx);
 void hif_pci_clear_stats(struct hif_softc *hif_ctx);
 int hif_pci_legacy_map_ce_to_irq(struct hif_softc *scn, int ce_id);
 bool hif_pci_needs_bmi(struct hif_softc *scn);
+const char *hif_pci_get_irq_name(int irq_no);
 #endif /* _PCI_API_H_ */

hif/src/hif_exec.c

@@ -33,6 +33,99 @@
 
 static struct hif_exec_context *hif_exec_tasklet_create(void);
 
+/**
+ * hif_clear_napi_stats() - reset NAPI stats
+ * @hif_ctx: hif context
+ *
+ * return: void
+ */
+void hif_clear_napi_stats(struct hif_opaque_softc *hif_ctx)
+{
+	struct HIF_CE_state *hif_state = HIF_GET_CE_STATE(hif_ctx);
+	struct hif_exec_context *hif_ext_group;
+	size_t i;
+
+	for (i = 0; i < hif_state->hif_num_extgroup; i++) {
+		hif_ext_group = hif_state->hif_ext_group[i];
+
+		if (!hif_ext_group)
+			return;
+
+		qdf_mem_set(hif_ext_group->sched_latency_stats,
+			    sizeof(hif_ext_group->sched_latency_stats),
+			    0x0);
+	}
+}
+
+qdf_export_symbol(hif_clear_napi_stats);
+
+/**
+ * hif_print_napi_latency_stats() - print NAPI scheduling latency stats
+ * @hif_state: hif context
+ *
+ * return: void
+ */
+#ifdef HIF_LATENCY_PROFILE_ENABLE
+static void hif_print_napi_latency_stats(struct HIF_CE_state *hif_state)
+{
+	struct hif_exec_context *hif_ext_group;
+	int i, j;
+	int64_t cur_tstamp;
+
+	const char time_str[HIF_SCHED_LATENCY_BUCKETS][15] =  {
+		"0-2   ms",
+		"3-10  ms",
+		"11-20 ms",
+		"21-50 ms",
+		"51-100 ms",
+		"101-250 ms",
+		"251-500 ms",
+		"> 500 ms"
+	};
+
+	cur_tstamp = qdf_ktime_to_ms(qdf_ktime_get());
+
+	QDF_TRACE(QDF_MODULE_ID_HIF, QDF_TRACE_LEVEL_FATAL,
+		  "Current timestamp: %lld", cur_tstamp);
+
+	for (i = 0; i < hif_state->hif_num_extgroup; i++) {
+		if (hif_state->hif_ext_group[i]) {
+			hif_ext_group = hif_state->hif_ext_group[i];
+
+			QDF_TRACE(QDF_MODULE_ID_HIF, QDF_TRACE_LEVEL_FATAL,
+				  "Interrupts in the HIF Group");
+
+			for (j = 0; j < hif_ext_group->numirq; j++) {
+				QDF_TRACE(QDF_MODULE_ID_HIF,
+					  QDF_TRACE_LEVEL_FATAL,
+					  "  %s",
+					  hif_ext_group->irq_name
+					  (hif_ext_group->irq[j]));
+			}
+
+			QDF_TRACE(QDF_MODULE_ID_HIF, QDF_TRACE_LEVEL_FATAL,
+				  "Last serviced timestamp: %lld",
+				  hif_ext_group->tstamp);
+
+			QDF_TRACE(QDF_MODULE_ID_HIF, QDF_TRACE_LEVEL_FATAL,
+				  "Latency Bucket     | Time elapsed");
+
+			for (j = 0; j < HIF_SCHED_LATENCY_BUCKETS; j++) {
+				QDF_TRACE(QDF_MODULE_ID_HIF,
+					  QDF_TRACE_LEVEL_FATAL,
+					  "%s     |    %lld", time_str[j],
+					  hif_ext_group->
+					  sched_latency_stats[j]);
+			}
+		}
+	}
+}
+#else
+static void hif_print_napi_latency_stats(struct HIF_CE_state *hif_state)
+{
+}
+#endif
+
 /**
  * hif_print_napi_stats() - print NAPI stats
  * @hif_ctx: hif context
@@ -67,6 +160,8 @@ void hif_print_napi_stats(struct hif_opaque_softc *hif_ctx)
 			}
 		}
 	}
+
+	hif_print_napi_latency_stats(hif_state);
 }
 qdf_export_symbol(hif_print_napi_stats);
 
@@ -102,10 +197,72 @@ static void hif_exec_tasklet_fn(unsigned long data)
 }
 
 /**
- * hif_exec_poll() - grp tasklet
- * data: context
+ * hif_latency_profile_measure() - calculate latency and update histogram
+ * hif_ext_group: hif exec context
  *
- * return: void
+ * return: None
+ */
+#ifdef HIF_LATENCY_PROFILE_ENABLE
+static void hif_latency_profile_measure(struct hif_exec_context *hif_ext_group)
+{
+	int64_t cur_tstamp;
+	int64_t time_elapsed;
+
+	cur_tstamp = qdf_ktime_to_ms(qdf_ktime_get());
+
+	if (cur_tstamp > hif_ext_group->tstamp)
+		time_elapsed = (cur_tstamp - hif_ext_group->tstamp);
+	else
+		time_elapsed = ~0x0 - (hif_ext_group->tstamp - cur_tstamp);
+
+	hif_ext_group->tstamp = cur_tstamp;
+
+	if (time_elapsed <= HIF_SCHED_LATENCY_BUCKET_0_2)
+		hif_ext_group->sched_latency_stats[0]++;
+	else if (time_elapsed <= HIF_SCHED_LATENCY_BUCKET_3_10)
+		hif_ext_group->sched_latency_stats[1]++;
+	else if (time_elapsed <= HIF_SCHED_LATENCY_BUCKET_11_20)
+		hif_ext_group->sched_latency_stats[2]++;
+	else if (time_elapsed <= HIF_SCHED_LATENCY_BUCKET_21_50)
+		hif_ext_group->sched_latency_stats[3]++;
+	else if (time_elapsed <= HIF_SCHED_LATENCY_BUCKET_51_100)
+		hif_ext_group->sched_latency_stats[4]++;
+	else if (time_elapsed <= HIF_SCHED_LATENCY_BUCKET_101_250)
+		hif_ext_group->sched_latency_stats[5]++;
+	else if (time_elapsed <= HIF_SCHED_LATENCY_BUCKET_251_500)
+		hif_ext_group->sched_latency_stats[6]++;
+	else
+		hif_ext_group->sched_latency_stats[7]++;
+}
+#else
+static void hif_latency_profile_measure(struct hif_exec_context *hif_ext_group)
+{
+}
+#endif
+
+/**
+ * hif_latency_profile_start() - Update the start timestamp for HIF ext group
+ * hif_ext_group: hif exec context
+ *
+ * return: None
+ */
+#ifdef HIF_LATENCY_PROFILE_ENABLE
+static void hif_latency_profile_start(struct hif_exec_context *hif_ext_group)
+{
+	hif_ext_group->tstamp = qdf_ktime_to_ms(qdf_ktime_get());
+}
+#else
+static void hif_latency_profile_start(struct hif_exec_context *hif_ext_group)
+{
+}
+#endif
+
+/**
+ * hif_exec_poll() - napi pool
+ * napi: napi struct
+ * budget: budget for napi
+ *
+ * return: mapping of internal budget to napi
  */
 static int hif_exec_poll(struct napi_struct *napi, int budget)
 {
@@ -120,8 +277,11 @@ static int hif_exec_poll(struct napi_struct *napi, int budget)
 
 	if (budget)
 		normalized_budget = NAPI_BUDGET_TO_INTERNAL_BUDGET(budget, shift);
+
+	hif_latency_profile_measure(hif_ext_group);
+
 	work_done = hif_ext_group->handler(hif_ext_group->context,
-							normalized_budget);
+					   normalized_budget);
 
 	if (work_done < normalized_budget) {
 		napi_complete(napi);
@@ -357,6 +517,8 @@ irqreturn_t hif_ext_group_interrupt_handler(int irq, void *context)
 	struct hif_softc *scn = HIF_GET_SOFTC(hif_ext_group->hif);
 
 	if (hif_ext_group->irq_requested) {
+		hif_latency_profile_start(hif_ext_group);
+
 		hif_ext_group->irq_disable(hif_ext_group);
 		/*
 		 * if private ioctl has issued fake suspend command to put

hif/src/hif_exec.h

@@ -1,5 +1,5 @@
 /*
- * Copyright (c) 2017-2018 The Linux Foundation. All rights reserved.
+ * Copyright (c) 2017-2019 The Linux Foundation. All rights reserved.
  *
  * Permission to use, copy, modify, and/or distribute this software for
  * any purpose with or without fee is hereby granted, provided that the
@@ -21,6 +21,23 @@
 
 #include <hif.h>
 #include <linux/cpumask.h>
+/*Number of buckets for latency*/
+#define HIF_SCHED_LATENCY_BUCKETS 8
+
+/*Buckets for latency between 0 to 2 ms*/
+#define HIF_SCHED_LATENCY_BUCKET_0_2 2
+/*Buckets for latency between 3 to 10 ms*/
+#define HIF_SCHED_LATENCY_BUCKET_3_10 10
+/*Buckets for latency between 11 to 20 ms*/
+#define HIF_SCHED_LATENCY_BUCKET_11_20 20
+/*Buckets for latency between 21 to 50 ms*/
+#define HIF_SCHED_LATENCY_BUCKET_21_50 50
+/*Buckets for latency between 50 to 100 ms*/
+#define HIF_SCHED_LATENCY_BUCKET_51_100 100
+/*Buckets for latency between 100 to 250 ms*/
+#define HIF_SCHED_LATENCY_BUCKET_101_250 250
+/*Buckets for latency between 250 to 500 ms*/
+#define HIF_SCHED_LATENCY_BUCKET_251_500 500
 
 struct hif_exec_context;
 
@@ -46,8 +63,11 @@ struct hif_execution_ops {
  *	determine if this context should reschedule or wait for an interrupt.
  *	This function may be used as a hook for post processing.
  *
+ * @sched_latency_stats: schdule latency stats for different latency buckets
+ * @tstamp: timestamp when napi poll happens
  * @irq_disable: called before scheduling the context.
  * @irq_enable: called when the context leaves polling mode
+ * @irq_name: pointer to function to return irq name/string mapped to irq number
  */
 struct hif_exec_context {
 	struct hif_execution_ops *sched_ops;
@@ -65,6 +85,9 @@ struct hif_exec_context {
 	bool (*work_complete)(struct hif_exec_context *, int work_done);
 	void (*irq_enable)(struct hif_exec_context *);
 	void (*irq_disable)(struct hif_exec_context *);
+	const char* (*irq_name)(int irq_no);
+	uint64_t sched_latency_stats[HIF_SCHED_LATENCY_BUCKETS];
+	uint64_t tstamp;
 
 	uint8_t cpu;
 	struct qca_napi_stat stats[NR_CPUS];

hif/src/pcie/if_pci.c

@@ -3424,6 +3424,19 @@ static void hif_exec_grp_irq_enable(struct hif_exec_context *hif_ext_group)
 		enable_irq(hif_ext_group->os_irq[i]);
 }
 
+/**
+ * hif_pci_get_irq_name() - get irqname
+ * This function gives irqnumber to irqname
+ * mapping.
+ *
+ * @irq_no: irq number
+ *
+ * Return: irq name
+ */
+const char *hif_pci_get_irq_name(int irq_no)
+{
+	return "pci-dummy";
+}
 
 int hif_pci_configure_grp_irq(struct hif_softc *scn,
 			      struct hif_exec_context *hif_ext_group)
@@ -3434,6 +3447,7 @@ int hif_pci_configure_grp_irq(struct hif_softc *scn,
 
 	hif_ext_group->irq_enable = &hif_exec_grp_irq_enable;
 	hif_ext_group->irq_disable = &hif_exec_grp_irq_disable;
+	hif_ext_group->irq_name = &hif_pci_get_irq_name;
 	hif_ext_group->work_complete = &hif_dummy_grp_done;
 
 	for (j = 0; j < hif_ext_group->numirq; j++) {

hif/src/snoc/if_ahb.c

@@ -1,5 +1,5 @@
 /*
- * Copyright (c) 2013-2018 The Linux Foundation. All rights reserved.
+ * Copyright (c) 2013-2019 The Linux Foundation. All rights reserved.
  *
  * Permission to use, copy, modify, and/or distribute this software for
  * any purpose with or without fee is hereby granted, provided that the
@@ -101,6 +101,19 @@ const char *ic_irqname[HIF_IC_MAX_IRQ] = {
 "tcl2host-status-ring",
 };
 
+/** hif_ahb_get_irq_name() - get irqname
+ * This function gives irqnumber to irqname
+ * mapping.
+ *
+ * @irq_no: irq number
+ *
+ * Return: irq name
+ */
+const char *hif_ahb_get_irq_name(int irq_no)
+{
+	return ic_irqname[irq_no];
+}
+
 /**
  * hif_disable_isr() - disable isr
  *
@@ -289,6 +302,7 @@ int hif_ahb_configure_grp_irq(struct hif_softc *scn,
 	/* configure external interrupts */
 	hif_ext_group->irq_enable = &hif_ahb_exec_grp_irq_enable;
 	hif_ext_group->irq_disable = &hif_ahb_exec_grp_irq_disable;
+	hif_ext_group->irq_name = &hif_ahb_get_irq_name;
 	hif_ext_group->work_complete = &hif_dummy_grp_done;
 
 	qdf_spin_lock_irqsave(&hif_ext_group->irq_lock);