qcacmn: Profile scan APIs to debug scheduler watch dog bite

Profile the scan APIs to debug the scheduler watch dog bite
due to callback scm_scan_event_handler exceeded its allotted
time of 10s

CRs-Fixed: 2713584
Change-Id: I494ce9df4cd6c7458c367527c8e5d47a9262739a

umac/scan/core/src/wlan_scan_main.h

@@ -93,6 +93,12 @@
 /* MAX RNR entries per channel*/
 #define WLAN_MAX_RNR_COUNT 15
 
+/*
+ * Maximum numbers of callback functions that may be invoked
+ * for a particular scan event.
+ */
+#define MAX_SCAN_EVENT_LISTENERS (MAX_SCAN_EVENT_HANDLERS_PER_PDEV + 1)
+
 /**
  * struct probe_time_dwell_time - probe time, dwell time map
  * @dwell_time: dwell time
@@ -525,8 +531,124 @@ struct wlan_scan_obj {
 #ifdef FEATURE_6G_SCAN_CHAN_SORT_ALGO
 	struct channel_list_db rnr_channel_db;
 #endif
+#ifdef ENABLE_SCAN_PROFILE
+	uint64_t scan_listener_cb_exe_dur[MAX_SCAN_EVENT_LISTENERS];
+	uint64_t scm_scan_event_duration;
+	uint64_t scm_scan_to_post_scan_duration;
+#endif
 };
 
+#ifdef ENABLE_SCAN_PROFILE
+static inline
+void scm_duration_init(struct wlan_scan_obj *scan)
+{
+	if (!scan)
+		return;
+
+	scan->scm_scan_event_duration = 0;
+	scan->scm_scan_to_post_scan_duration = 0;
+}
+
+static inline
+void scm_event_duration_start(struct wlan_scan_obj *scan)
+{
+	if (!scan)
+		return;
+
+	scan->scm_scan_event_duration =
+		qdf_ktime_to_ms(qdf_ktime_get());
+}
+
+static inline
+void scm_event_duration_end(struct wlan_scan_obj *scan)
+{
+	if (!scan)
+		return;
+
+	scan->scm_scan_event_duration =
+		(qdf_ktime_to_ms(qdf_ktime_get()) -
+		 scan->scm_scan_event_duration);
+}
+
+static inline
+void scm_to_post_scan_duration_set(struct wlan_scan_obj *scan)
+{
+	if (!scan)
+		return;
+
+	scan->scm_scan_to_post_scan_duration =
+		(qdf_ktime_to_ms(qdf_ktime_get()) -
+		 scan->scm_scan_event_duration);
+}
+
+static inline
+void scm_listener_cb_exe_dur_start(struct wlan_scan_obj *scan, uint8_t index)
+{
+	if (!scan || (index >= MAX_SCAN_EVENT_LISTENERS))
+		return;
+
+	scan->scan_listener_cb_exe_dur[index] =
+		qdf_ktime_to_ms(qdf_ktime_get());
+}
+
+static inline
+void scm_listener_cb_exe_dur_end(struct wlan_scan_obj *scan, uint8_t index)
+{
+	if (!scan || (index >= MAX_SCAN_EVENT_LISTENERS))
+		return;
+
+	scan->scan_listener_cb_exe_dur[index] =
+		(qdf_ktime_to_ms(qdf_ktime_get()) -
+		 scan->scan_listener_cb_exe_dur[index]);
+}
+
+static inline
+void scm_listener_duration_init(struct wlan_scan_obj *scan)
+{
+	if (!scan)
+		return;
+
+	qdf_mem_set(&scan->scan_listener_cb_exe_dur,
+		    sizeof(uint64_t) * MAX_SCAN_EVENT_LISTENERS,
+		    0);
+}
+#else
+static inline
+void scm_duration_init(struct wlan_scan_obj *scan)
+{
+}
+
+static inline
+void scm_event_duration_start(struct wlan_scan_obj *scan)
+{
+}
+
+static inline
+void scm_event_duration_end(struct wlan_scan_obj *scan)
+{
+}
+
+static inline
+void scm_to_post_scan_duration_set(struct wlan_scan_obj *scan)
+{
+}
+
+static inline
+void scm_listener_cb_exe_dur_start(struct wlan_scan_obj *scan, uint8_t index)
+{
+}
+
+static inline
+void scm_listener_cb_exe_dur_end(struct wlan_scan_obj *scan, uint8_t index)
+{
+}
+
+static inline
+void scm_listener_duration_init(struct wlan_scan_obj *scan)
+{
+}
+#endif
+
 /**
  * wlan_psoc_get_scan_obj() - private API to get scan object from psoc
  * @psoc: psoc object

umac/scan/core/src/wlan_scan_manager.c

@@ -190,9 +190,14 @@ static void scm_scan_post_event(struct wlan_objmgr_vdev *vdev,
 			event->requester);
 	qdf_spin_unlock_bh(&scan->lock);
 
+	scm_listener_duration_init(scan);
+
 	/* notify all interested handlers */
-	for (i = 0; i < listeners->count; i++)
+	for (i = 0; i < listeners->count; i++) {
+		scm_listener_cb_exe_dur_start(scan, i);
 		listeners->cb[i].func(vdev, event, listeners->cb[i].arg);
+		scm_listener_cb_exe_dur_end(scan, i);
+	}
 	qdf_mem_free(listeners);
 }
 
@@ -1704,6 +1709,12 @@ scm_scan_event_handler(struct scheduler_msg *msg)
 	vdev = event_info->vdev;
 	event = &(event_info->event);
 
+	scan = wlan_vdev_get_scan_obj(vdev);
+
+	scm_duration_init(scan);
+
+	scm_event_duration_start(scan);
+
 	scm_debug("vdevid:%d, type:%d, reason:%d, freq:%d, reqstr:%d, scanid:%d",
 		  event->vdev_id, event->type, event->reason, event->chan_freq,
 		  event->requester, event->scan_id);
@@ -1757,7 +1768,6 @@ scm_scan_event_handler(struct scheduler_msg *msg)
 		goto exit;
 	}
 
-	scan = wlan_vdev_get_scan_obj(vdev);
 	if (scan)
 		scm_scan_update_scan_event(scan, event, scan_start_req);
 
@@ -1774,12 +1784,16 @@ scm_scan_event_handler(struct scheduler_msg *msg)
 		break;
 	}
 
+	scm_to_post_scan_duration_set(scan);
 	/* Notify all interested parties */
 	scm_scan_post_event(vdev, event);
 
 exit:
 	/* free event info memory */
 	qdf_mem_free(event_info);
+
+	scm_event_duration_end(scan);
+
 	wlan_objmgr_vdev_release_ref(vdev, WLAN_SCAN_ID);
 
 	return QDF_STATUS_SUCCESS;

umac/scan/core/src/wlan_scan_manager.h

@@ -1,5 +1,5 @@
 /*
- * Copyright (c) 2017-2018 The Linux Foundation. All rights reserved.
+ * Copyright (c) 2017-2018, 2020 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
@@ -28,12 +28,6 @@
 
 #include "wlan_scan_main.h"
 
-/*
- * Maximum numbers of callback functions that may be invoked
- * for a particular scan event.
- */
-#define MAX_SCAN_EVENT_LISTENERS (MAX_SCAN_EVENT_HANDLERS_PER_PDEV + 1)
-
 /**
  * struct scan_event_listners - listeners interested in a particular scan event
  * @count: number of listners