msm: camera: core: Add delay detection support

This changes is to detect workqueue and tasklet
scheduling and execution delay.

CRs-Fixed: 2977775
Change-Id: Ia4b4845a067c22bd1f24bd63a971d103fcfc049c
Signed-off-by: Ayush Kumar <[email protected]>

drivers/cam_cdm/cam_cdm_hw_core.c

@@ -1306,8 +1306,10 @@ static void cam_hw_cdm_work(struct work_struct *work)
 		return;
 	}
 
-	cam_req_mgr_thread_switch_delay_detect(cdm_hw->soc_info.dev_name,
-		payload->workq_scheduled_ts);
+	cam_common_util_thread_switch_delay_detect(
+		"CDM workq schedule",
+		payload->workq_scheduled_ts,
+		CAM_WORKQ_SCHEDULE_TIME_THRESHOLD);
 
 	CAM_DBG(CAM_CDM, "IRQ status=0x%x", payload->irq_status);
 	if (payload->irq_status &

drivers/cam_cdm/cam_cdm_virtual_core.c

@@ -20,6 +20,7 @@
 #include "cam_cdm_soc.h"
 #include "cam_io_util.h"
 #include "cam_req_mgr_workq.h"
+#include "cam_common_util.h"
 
 #define CAM_CDM_VIRTUAL_NAME "qcom,cam_virtual_cdm"
 
@@ -34,8 +35,10 @@ static void cam_virtual_cdm_work(struct work_struct *work)
 		cdm_hw = payload->hw;
 		core = (struct cam_cdm *)cdm_hw->core_info;
 
-		cam_req_mgr_thread_switch_delay_detect(core->name,
-			payload->workq_scheduled_ts);
+		cam_common_util_thread_switch_delay_detect(
+			"Virtual CDM workq schedule",
+			payload->workq_scheduled_ts,
+			CAM_WORKQ_SCHEDULE_TIME_THRESHOLD);
 
 		if (payload->irq_status & 0x2) {
 			struct cam_cdm_bl_cb_request_entry *node;

drivers/cam_cpas/cpas_top/cam_cpastop_hw.c

@@ -33,6 +33,7 @@
 #include "cpastop_v165_100.h"
 #include "cpastop_v780_100.h"
 #include "cam_req_mgr_workq.h"
+#include "cam_common_util.h"
 
 struct cam_camnoc_info *camnoc_info;
 struct cam_cpas_camnoc_qchannel *qchannel_info;
@@ -602,8 +603,10 @@ static void cam_cpastop_work(struct work_struct *work)
 		return;
 	}
 
-	cam_req_mgr_thread_switch_delay_detect(CAM_CPAS_WORKQUEUE_NAME,
-			payload->workq_scheduled_ts);
+	cam_common_util_thread_switch_delay_detect(
+		"CPAS workq schedule",
+		payload->workq_scheduled_ts,
+		CAM_WORKQ_SCHEDULE_TIME_THRESHOLD);
 
 	cpas_hw = payload->hw;
 	cpas_core = (struct cam_cpas *) cpas_hw->core_info;

drivers/cam_isp/isp_hw_mgr/hw_utils/cam_tasklet_util.c

@@ -11,8 +11,16 @@
 #include "cam_tasklet_util.h"
 #include "cam_irq_controller.h"
 #include "cam_debug_util.h"
+#include "cam_common_util.h"
 
-#define CAM_TASKLETQ_SIZE              256
+
+/* Threshold for scheduling delay in ms */
+#define CAM_TASKLET_SCHED_TIME_THRESHOLD        5
+
+/* Threshold for execution delay in ms */
+#define CAM_TASKLET_EXE_TIME_THRESHOLD          10
+
+#define CAM_TASKLETQ_SIZE                          256
 
 static void cam_tasklet_action(unsigned long data);
 
@@ -27,6 +35,7 @@ static void cam_tasklet_action(unsigned long data);
  * @handler_priv:           Private data passed at event subscribe
  * @bottom_half_handler:    Function pointer for event handler in bottom
  *                          half context
+ * @tasklet_enqueue_ts:     enqueue time of tasklet
  *
  */
 struct cam_tasklet_queue_cmd {
@@ -34,6 +43,7 @@ struct cam_tasklet_queue_cmd {
 	void                              *payload;
 	void                              *handler_priv;
 	CAM_IRQ_HANDLER_BOTTOM_HALF        bottom_half_handler;
+	ktime_t                            tasklet_enqueue_ts;
 };
 
 /**
@@ -209,6 +219,7 @@ void cam_tasklet_enqueue_cmd(
 	tasklet_cmd->bottom_half_handler = bottom_half_handler;
 	tasklet_cmd->payload = evt_payload_priv;
 	tasklet_cmd->handler_priv = handler_priv;
+	tasklet_cmd->tasklet_enqueue_ts = ktime_get();
 	spin_lock_irqsave(&tasklet->tasklet_lock, flags);
 	list_add_tail(&tasklet_cmd->list,
 		&tasklet->used_cmd_list);
@@ -322,12 +333,24 @@ static void cam_tasklet_action(unsigned long data)
 {
 	struct cam_tasklet_info          *tasklet_info = NULL;
 	struct cam_tasklet_queue_cmd     *tasklet_cmd = NULL;
+	ktime_t                           tasklet_exec_start_time;
 
 	tasklet_info = (struct cam_tasklet_info *)data;
 
 	while (!cam_tasklet_dequeue_cmd(tasklet_info, &tasklet_cmd)) {
+		cam_common_util_thread_switch_delay_detect(
+			"Tasklet schedule",
+			tasklet_cmd->tasklet_enqueue_ts,
+			CAM_TASKLET_SCHED_TIME_THRESHOLD);
+		tasklet_exec_start_time = ktime_get();
+
 		tasklet_cmd->bottom_half_handler(tasklet_cmd->handler_priv,
 			tasklet_cmd->payload);
+
+		cam_common_util_thread_switch_delay_detect(
+			"Tasklet execution",
+			tasklet_exec_start_time,
+			CAM_TASKLET_EXE_TIME_THRESHOLD);
 		cam_tasklet_put_cmd(tasklet_info, (void **)(&tasklet_cmd));
 	}
 }

drivers/cam_req_mgr/cam_req_mgr_workq.c

@@ -5,6 +5,7 @@
 
 #include "cam_req_mgr_workq.h"
 #include "cam_debug_util.h"
+#include "cam_common_util.h"
 
 #define WORKQ_ACQUIRE_LOCK(workq, flags) {\
 	if ((workq)->in_irq) \
@@ -106,6 +107,7 @@ void cam_req_mgr_process_workq(struct work_struct *w)
 	struct crm_workq_task         *task;
 	int32_t                        i = CRM_TASK_PRIORITY_0;
 	unsigned long                  flags = 0;
+	ktime_t                        sched_start_time;
 
 	if (!w) {
 		CAM_ERR(CAM_CRM, "NULL task pointer can not schedule");
@@ -114,7 +116,11 @@ void cam_req_mgr_process_workq(struct work_struct *w)
 	workq = (struct cam_req_mgr_core_workq *)
 		container_of(w, struct cam_req_mgr_core_workq, work);
 
-	cam_req_mgr_thread_switch_delay_detect(workq->workq_name, workq->workq_scheduled_ts);
+	cam_common_util_thread_switch_delay_detect(
+		"CRM workq schedule",
+		workq->workq_scheduled_ts,
+		CAM_WORKQ_SCHEDULE_TIME_THRESHOLD);
+	sched_start_time = ktime_get();
 	while (i < CRM_TASK_PRIORITY_MAX) {
 		WORKQ_ACQUIRE_LOCK(workq, flags);
 		while (!list_empty(&workq->task.process_head[i])) {
@@ -132,6 +138,10 @@ void cam_req_mgr_process_workq(struct work_struct *w)
 		WORKQ_RELEASE_LOCK(workq, flags);
 		i++;
 	}
+	cam_common_util_thread_switch_delay_detect(
+		"CRM workq execution",
+		sched_start_time,
+		CAM_WORKQ_EXE_TIME_THRESHOLD);
 }
 
 int cam_req_mgr_workq_enqueue_task(struct crm_workq_task *task,
@@ -282,26 +292,3 @@ void cam_req_mgr_workq_destroy(struct cam_req_mgr_core_workq **crm_workq)
 		*crm_workq = NULL;
 	}
 }
-
-void cam_req_mgr_thread_switch_delay_detect(const char *name, ktime_t workq_scheduled)
-{
-	uint64_t                         diff;
-	ktime_t                          cur_time;
-	struct timespec64                cur_ts;
-	struct timespec64                workq_scheduled_ts;
-
-	cur_time = ktime_get();
-	diff = ktime_ms_delta(cur_time, workq_scheduled);
-	workq_scheduled_ts  = ktime_to_timespec64(workq_scheduled);
-	cur_ts = ktime_to_timespec64(cur_time);
-
-	if (diff > CAM_WORKQ_RESPONSE_TIME_THRESHOLD) {
-		CAM_WARN_RATE_LIMIT(CAM_CRM,
-			"Workq %s delay detected %ld:%06ld %ld:%06ld %ld:",
-			name,
-			workq_scheduled_ts.tv_sec,
-			workq_scheduled_ts.tv_nsec/NSEC_PER_USEC,
-			cur_ts.tv_sec, cur_ts.tv_nsec/NSEC_PER_USEC,
-			diff);
-	}
-}

drivers/cam_req_mgr/cam_req_mgr_workq.h

@@ -16,6 +16,12 @@
 
 #include "cam_req_mgr_core.h"
 
+/* Threshold for scheduling delay in ms */
+#define CAM_WORKQ_SCHEDULE_TIME_THRESHOLD   5
+
+/* Threshold for execution delay in ms */
+#define CAM_WORKQ_EXE_TIME_THRESHOLD        10
+
 /* Flag to create a high priority workq */
 #define CAM_WORKQ_FLAG_HIGH_PRIORITY             (1 << 0)
 
@@ -26,13 +32,6 @@
  */
 #define CAM_WORKQ_FLAG_SERIAL                    (1 << 1)
 
-/*
- * Response time threshold in ms beyond which it is considered
- * as workq scheduling/processing delay.
- */
-#define CAM_WORKQ_RESPONSE_TIME_THRESHOLD   5
-
-
 /* Task priorities, lower the number higher the priority*/
 enum crm_task_priority {
 	CRM_TASK_PRIORITY_0,
@@ -78,6 +77,7 @@ struct crm_workq_task {
  * @in_irq      : set true if workque can be used in irq context
  * @flush       : used to track if flush has been called on workqueue
  * @work_q_name : name of the workq
+ * @workq_scheduled_ts: enqueue time of workq
  * task -
  * @lock        : Current task's lock handle
  * @pending_cnt : # of tasks left in queue
@@ -154,15 +154,6 @@ void cam_req_mgr_workq_destroy(struct cam_req_mgr_core_workq **workq);
 int cam_req_mgr_workq_enqueue_task(struct crm_workq_task *task,
 	void *priv, int32_t prio);
 
-/**
- * cam_req_mgr_thread_switch_delay_detect()
- * @brief: Detects if workq delay has occurred or not
- * @name : Name of the workq
- * @timestamp: workq scheduled timestamp
- */
-void cam_req_mgr_thread_switch_delay_detect(const char *name,
-	ktime_t timestamp);
-
 /**
  * cam_req_mgr_workq_get_task()
  * @brief: Returns empty task pointer for use

drivers/cam_sensor_module/cam_cci/cam_cci_core.c

@@ -7,6 +7,7 @@
 #include "cam_cci_core.h"
 #include "cam_cci_dev.h"
 #include "cam_req_mgr_workq.h"
+#include "cam_common_util.h"
 
 static int32_t cam_cci_convert_type_to_num_bytes(
 	enum camera_sensor_i2c_type type)
@@ -1516,8 +1517,10 @@ static void cam_cci_write_async_helper(struct work_struct *work)
 	enum cci_i2c_master_t master;
 	struct cam_cci_master_info *cci_master_info;
 
-	cam_req_mgr_thread_switch_delay_detect(CAM_CCI_WORKQUEUE_NAME,
-		write_async->workq_scheduled_ts);
+	cam_common_util_thread_switch_delay_detect(
+		"CCI workq schedule",
+		write_async->workq_scheduled_ts,
+		CAM_WORKQ_SCHEDULE_TIME_THRESHOLD);
 	cci_dev = write_async->cci_dev;
 	i2c_msg = &write_async->c_ctrl.cfg.cci_i2c_write_cfg;
 	master = write_async->c_ctrl.cci_info->cci_i2c_master;

drivers/cam_sync/cam_sync_util.c

@@ -1,10 +1,11 @@
 // SPDX-License-Identifier: GPL-2.0-only
 /*
- * Copyright (c) 2017-2018, 2020 The Linux Foundation. All rights reserved.
+ * Copyright (c) 2017-2018, 2020-2021 The Linux Foundation. All rights reserved.
  */
 
 #include "cam_sync_util.h"
 #include "cam_req_mgr_workq.h"
+#include "cam_common_util.h"
 
 int cam_sync_util_find_and_set_empty_row(struct sync_device *sync_dev,
 	long *idx)
@@ -295,8 +296,10 @@ void cam_sync_util_cb_dispatch(struct work_struct *cb_dispatch_work)
 		cb_dispatch_work);
 	sync_callback sync_data = cb_info->callback_func;
 
-	cam_req_mgr_thread_switch_delay_detect(CAM_SYNC_WORKQUEUE_NAME,
-			cb_info->workq_scheduled_ts);
+	cam_common_util_thread_switch_delay_detect(
+		"CAM-SYNC workq schedule",
+		cb_info->workq_scheduled_ts,
+		CAM_WORKQ_SCHEDULE_TIME_THRESHOLD);
 	sync_data(cb_info->sync_obj, cb_info->status, cb_info->cb_data);
 
 	kfree(cb_info);

drivers/cam_utils/cam_common_util.c

@@ -122,3 +122,26 @@ int cam_common_modify_timer(struct timer_list *timer, int32_t timeout_val)
 
 	return 0;
 }
+
+void cam_common_util_thread_switch_delay_detect(
+	const char *token, ktime_t scheduled_time, uint32_t threshold)
+{
+	uint64_t                         diff;
+	ktime_t                          cur_time;
+	struct timespec64                cur_ts;
+	struct timespec64                scheduled_ts;
+
+	cur_time = ktime_get();
+	diff = ktime_ms_delta(cur_time, scheduled_time);
+
+	if (diff > threshold) {
+		scheduled_ts  = ktime_to_timespec64(scheduled_time);
+		cur_ts = ktime_to_timespec64(cur_time);
+		CAM_WARN_RATE_LIMIT_CUSTOM(CAM_UTIL, 1, 1,
+			"%s delay detected %ld:%06ld cur %ld:%06ld diff %ld: threshold %d",
+			token, scheduled_ts.tv_sec,
+			scheduled_ts.tv_nsec/NSEC_PER_USEC,
+			cur_ts.tv_sec, cur_ts.tv_nsec/NSEC_PER_USEC,
+			diff, threshold);
+	}
+}

drivers/cam_utils/cam_common_util.h

@@ -125,4 +125,17 @@ int cam_common_read_poll_timeout(
  */
 int cam_common_modify_timer(struct timer_list *timer, int32_t timeout_val);
 
+/**
+ * cam_common_util_thread_switch_delay_detect()
+ *
+ * @brief                  Detect if there is any scheduling delay
+ *
+ * @token:                 String identifier to print workq name or tasklet
+ * @scheduled_time:        Time when workq or tasklet was scheduled
+ * @threshold:             Threshold time
+ *
+ */
+void cam_common_util_thread_switch_delay_detect(const char *token,
+	ktime_t scheduled_time, uint32_t threshold);
+
 #endif /* _CAM_COMMON_UTIL_H_ */