msm: camera: isp: Update event record for shutter notification

This change adds shutter notification event in event record too
which can be dumped at the time of recovery.

CRs-Fixed: 3616617
Change-Id: I4eb57da6faf7ed3dc0a0a4a407fb669078db2a25
Signed-off-by: Vikram Sharma <[email protected]>

drivers/cam_isp/cam_isp_context.c

@@ -71,6 +71,8 @@ static const char *__cam_isp_evt_val_to_type(
 		return "RUP";
 	case CAM_ISP_CTX_EVENT_BUFDONE:
 		return "BUFDONE";
+	case CAM_ISP_CTX_EVENT_SHUTTER:
+		return "SHUTTER_NOTIFICATION";
 	default:
 		return "CAM_ISP_EVENT_INVALID";
 	}
@@ -79,7 +81,8 @@ static const char *__cam_isp_evt_val_to_type(
 static void __cam_isp_ctx_update_event_record(
 	struct cam_isp_context *ctx_isp,
 	enum cam_isp_ctx_event  event,
-	struct cam_ctx_request *req)
+	struct cam_ctx_request *req,
+	void *event_data)
 {
 	int                      iterator = 0;
 	ktime_t                  cur_time;
@@ -93,6 +96,7 @@ static void __cam_isp_ctx_update_event_record(
 	case CAM_ISP_CTX_EVENT_EPOCH:
 	case CAM_ISP_CTX_EVENT_RUP:
 	case CAM_ISP_CTX_EVENT_BUFDONE:
+	case CAM_ISP_CTX_EVENT_SHUTTER:
 		break;
 	case CAM_ISP_CTX_EVENT_SUBMIT:
 	case CAM_ISP_CTX_EVENT_APPLY:
@@ -117,6 +121,25 @@ static void __cam_isp_ctx_update_event_record(
 		ctx_isp->dbg_monitors.event_record[event][iterator].req_id = 0;
 	}
 	ctx_isp->dbg_monitors.event_record[event][iterator].timestamp  = cur_time;
+
+	if (event_data == NULL)
+		return;
+	/* Update event specific data */
+	ctx_isp->dbg_monitors.event_record[event][iterator].event_type = event;
+	if (event == CAM_ISP_CTX_EVENT_SHUTTER) {
+		ctx_isp->dbg_monitors.event_record[event][iterator].req_id =
+			((struct shutter_event *)event_data)->req_id;
+		ctx_isp->dbg_monitors.event_record[event][iterator].event.shutter_event.req_id =
+			((struct shutter_event *)event_data)->req_id;
+		ctx_isp->dbg_monitors.event_record[event][iterator].event.shutter_event.status =
+			((struct shutter_event *)event_data)->status;
+		ctx_isp->dbg_monitors.event_record[event][iterator].event.shutter_event.frame_id =
+			((struct shutter_event *)event_data)->frame_id;
+		ctx_isp->dbg_monitors.event_record[event][iterator].event.shutter_event.boot_ts =
+			((struct shutter_event *)event_data)->boot_ts;
+		ctx_isp->dbg_monitors.event_record[event][iterator].event.shutter_event.sof_ts =
+			((struct shutter_event *)event_data)->sof_ts;
+	}
 }
 
 static int __cam_isp_ctx_handle_sof_freeze_evt(
@@ -190,12 +213,29 @@ static int __cam_isp_ctx_print_event_record(struct cam_isp_context *ctx_isp)
 		len = 0;
 		memset(buf, 0, CAM_ISP_CONTEXT_DBG_BUF_LEN);
 		for (j = 0; j < num_entries; j++) {
-
 			record = &ctx_isp->dbg_monitors.event_record[i][index];
 			ts = ktime_to_timespec64(record->timestamp);
-			len += scnprintf(buf + len, CAM_ISP_CONTEXT_DBG_BUF_LEN - len,
-				"%llu[%lld:%06lld] ", record->req_id, ts.tv_sec,
-				ts.tv_nsec / NSEC_PER_USEC);
+			if (len >= CAM_ISP_CONTEXT_DBG_BUF_LEN) {
+				CAM_WARN(CAM_ISP, "Overshooting buffer length %llu", len);
+				break;
+			}
+			if (record->event_type != CAM_ISP_CTX_EVENT_SHUTTER)
+				len += scnprintf(buf + len, CAM_ISP_CONTEXT_DBG_BUF_LEN - len,
+					"%llu[%lld:%06lld] ", record->req_id, ts.tv_sec,
+					ts.tv_nsec / NSEC_PER_USEC);
+			else
+				/*
+				 * Output format
+				 * req Id[timestamp] status frmId softs bootts
+				 */
+				len += scnprintf(buf + len, (CAM_ISP_CONTEXT_DBG_BUF_LEN) - len,
+					"%llu[%lld:%06lld] [%d %lld %llu %llu] | ",
+					record->req_id, ts.tv_sec,
+					ts.tv_nsec / NSEC_PER_USEC,
+					record->event.shutter_event.status,
+					record->event.shutter_event.frame_id,
+					record->event.shutter_event.sof_ts,
+					record->event.shutter_event.boot_ts);
 			index = (index + 1) %
 				CAM_ISP_CTX_EVENT_RECORD_MAX_ENTRIES;
 		}
@@ -1055,7 +1095,7 @@ static int __cam_isp_ctx_enqueue_request_in_order(
 	}
 	ctx_isp = (struct cam_isp_context *) ctx->ctx_priv;
 	__cam_isp_ctx_update_event_record(ctx_isp,
-		CAM_ISP_CTX_EVENT_SUBMIT, req);
+		CAM_ISP_CTX_EVENT_SUBMIT, req, NULL);
 	if (lock)
 		spin_unlock_bh(&ctx->lock);
 	return 0;
@@ -1450,7 +1490,7 @@ static int __cam_isp_ctx_recover_sof_timestamp(struct cam_context *ctx, uint64_t
 
 static void __cam_isp_ctx_send_sof_boot_timestamp(
 	struct cam_isp_context *ctx_isp, uint64_t request_id,
-	uint32_t sof_event_status)
+	uint32_t sof_event_status, struct shutter_event *shutter_event)
 {
 	struct cam_req_mgr_message   req_msg;
 
@@ -1466,6 +1506,10 @@ static void __cam_isp_ctx_send_sof_boot_timestamp(
 		"request id:%lld frame number:%lld boot time stamp:0x%llx status:%u",
 		 request_id, ctx_isp->frame_id,
 		 ctx_isp->boot_timestamp, sof_event_status);
+	shutter_event->frame_id = ctx_isp->frame_id;
+	shutter_event->req_id   = request_id;
+	shutter_event->boot_ts  = ctx_isp->boot_timestamp;
+	shutter_event->sof_ts   = ctx_isp->sof_timestamp_val;
 
 	if (cam_req_mgr_notify_message(&req_msg,
 		V4L_EVENT_CAM_REQ_MGR_SOF_BOOT_TS,
@@ -1473,10 +1517,14 @@ static void __cam_isp_ctx_send_sof_boot_timestamp(
 		CAM_ERR(CAM_ISP,
 			"Error in notifying the boot time for req id:%lld",
 			request_id);
+
+	__cam_isp_ctx_update_event_record(ctx_isp,
+		CAM_ISP_CTX_EVENT_SHUTTER, NULL, shutter_event);
 }
 
 static void __cam_isp_ctx_send_unified_timestamp(
-	struct cam_isp_context *ctx_isp, uint64_t request_id)
+	struct cam_isp_context *ctx_isp, uint64_t request_id,
+	struct shutter_event *shutter_event)
 {
 	struct cam_req_mgr_message   req_msg;
 
@@ -1494,12 +1542,18 @@ static void __cam_isp_ctx_send_unified_timestamp(
 		boot time stamp:0x%llx", ctx_isp->base->link_hdl, request_id,
 		ctx_isp->frame_id, ctx_isp->sof_timestamp_val,ctx_isp->base->ctx_id,
 		ctx_isp->boot_timestamp);
+	shutter_event->frame_id = ctx_isp->frame_id;
+	shutter_event->req_id   = request_id;
+	shutter_event->boot_ts  = ctx_isp->boot_timestamp;
+	shutter_event->sof_ts   = ctx_isp->sof_timestamp_val;
 
 	if (cam_req_mgr_notify_message(&req_msg,
 		V4L_EVENT_CAM_REQ_MGR_SOF_UNIFIED_TS, V4L_EVENT_CAM_REQ_MGR_EVENT))
 		CAM_ERR(CAM_ISP,
 			"Error in notifying the sof and boot time for req id:%lld",
 			request_id);
+	__cam_isp_ctx_update_event_record(ctx_isp,
+		CAM_ISP_CTX_EVENT_SHUTTER, NULL, shutter_event);
 }
 
 static void __cam_isp_ctx_send_sof_timestamp_frame_header(
@@ -1544,6 +1598,7 @@ static void __cam_isp_ctx_send_sof_timestamp(
 {
 	struct cam_req_mgr_message   req_msg;
 	struct cam_context           *ctx = ctx_isp->base;
+	struct shutter_event         shutter_event = {0};
 
 	if (ctx_isp->reported_frame_id == ctx_isp->frame_id) {
 		if (__cam_isp_ctx_recover_sof_timestamp(ctx_isp->base, request_id))
@@ -1559,10 +1614,11 @@ static void __cam_isp_ctx_send_sof_timestamp(
 	}
 
 	ctx_isp->reported_frame_id = ctx_isp->frame_id;
+	shutter_event.status = sof_event_status;
 
 	if ((ctx_isp->v4l2_event_sub_ids & (1 << V4L_EVENT_CAM_REQ_MGR_SOF_UNIFIED_TS))
 		&& !ctx_isp->use_frame_header_ts) {
-		__cam_isp_ctx_send_unified_timestamp(ctx_isp,request_id);
+		__cam_isp_ctx_send_unified_timestamp(ctx_isp, request_id, &shutter_event);
 		return;
 	}
 
@@ -1579,7 +1635,7 @@ static void __cam_isp_ctx_send_sof_timestamp(
 
 	CAM_DBG(CAM_ISP,
 		"request id:%lld frame number:%lld SOF time stamp:0x%llx status:%u ctx_idx: %u, link: 0x%x",
-		 request_id, ctx_isp->frame_id,
+		request_id, ctx_isp->frame_id,
 		ctx_isp->sof_timestamp_val, sof_event_status, ctx->ctx_id, ctx->link_hdl);
 
 	if (cam_req_mgr_notify_message(&req_msg,
@@ -1590,7 +1646,7 @@ static void __cam_isp_ctx_send_sof_timestamp(
 
 end:
 	__cam_isp_ctx_send_sof_boot_timestamp(ctx_isp,
-		request_id, sof_event_status);
+		request_id, sof_event_status, &shutter_event);
 }
 
 static void __cam_isp_ctx_handle_buf_done_fail_log(
@@ -1812,7 +1868,7 @@ static int __cam_isp_ctx_handle_buf_done_for_req_list(
 		CAM_ISP_STATE_CHANGE_TRIGGER_DONE, buf_done_req_id);
 
 	__cam_isp_ctx_update_event_record(ctx_isp,
-		CAM_ISP_CTX_EVENT_BUFDONE, req);
+		CAM_ISP_CTX_EVENT_BUFDONE, req, NULL);
 	return rc;
 }
 
@@ -2954,7 +3010,7 @@ static int __cam_isp_ctx_reg_upd_in_applied_state(
 			"move request %lld to active list(cnt = %d), ctx %u, link: 0x%x",
 			req->request_id, ctx_isp->active_req_cnt, ctx->ctx_id, ctx->link_hdl);
 		__cam_isp_ctx_update_event_record(ctx_isp,
-			CAM_ISP_CTX_EVENT_RUP, req);
+			CAM_ISP_CTX_EVENT_RUP, req, NULL);
 	} else {
 		cam_smmu_buffer_tracker_putref(&req->buf_tracker);
 		/* no io config, so the request is completed. */
@@ -3096,7 +3152,7 @@ notify_only:
 				(req->request_id > ctx_isp->reported_req_id)) {
 				request_id = req->request_id;
 				__cam_isp_ctx_update_event_record(ctx_isp,
-					CAM_ISP_CTX_EVENT_EPOCH, req);
+					CAM_ISP_CTX_EVENT_EPOCH, req, NULL);
 				break;
 			}
 		}
@@ -3266,7 +3322,7 @@ static int __cam_isp_ctx_epoch_in_applied(struct cam_isp_context *ctx_isp,
 		__cam_isp_ctx_send_sof_timestamp(ctx_isp, request_id,
 			CAM_REQ_MGR_SOF_EVENT_SUCCESS);
 		__cam_isp_ctx_update_event_record(ctx_isp,
-			CAM_ISP_CTX_EVENT_EPOCH, NULL);
+			CAM_ISP_CTX_EVENT_EPOCH, NULL, NULL);
 		goto end;
 	}
 
@@ -3340,7 +3396,7 @@ static int __cam_isp_ctx_epoch_in_applied(struct cam_isp_context *ctx_isp,
 	 * other invalid req.
 	 */
 	__cam_isp_ctx_update_event_record(ctx_isp,
-		CAM_ISP_CTX_EVENT_EPOCH, req);
+		CAM_ISP_CTX_EVENT_EPOCH, req, NULL);
 
 	/*
 	 * Get the req again from active_req_list in case
@@ -3514,8 +3570,7 @@ static int __cam_isp_ctx_epoch_in_bubble_applied(
 		__cam_isp_ctx_send_sof_timestamp(ctx_isp, request_id,
 			CAM_REQ_MGR_SOF_EVENT_SUCCESS);
 		__cam_isp_ctx_update_event_record(ctx_isp,
-			CAM_ISP_CTX_EVENT_EPOCH, NULL);
-
+			CAM_ISP_CTX_EVENT_EPOCH, NULL, NULL);
 		ctx_isp->substate_activated = CAM_ISP_CTX_ACTIVATED_BUBBLE;
 		goto end;
 	}
@@ -3577,21 +3632,20 @@ static int __cam_isp_ctx_epoch_in_bubble_applied(
 			request_id = req->request_id;
 			ctx_isp->reported_req_id = request_id;
 			__cam_isp_ctx_send_sof_timestamp(ctx_isp, request_id,
-			CAM_REQ_MGR_SOF_EVENT_ERROR);
-
+				CAM_REQ_MGR_SOF_EVENT_ERROR);
 			__cam_isp_ctx_update_event_record(ctx_isp,
-				CAM_ISP_CTX_EVENT_EPOCH, req);
+				CAM_ISP_CTX_EVENT_EPOCH, req, NULL);
 		} else {
 			__cam_isp_ctx_send_sof_timestamp(ctx_isp, request_id,
 				CAM_REQ_MGR_SOF_EVENT_SUCCESS);
 			__cam_isp_ctx_update_event_record(ctx_isp,
-				CAM_ISP_CTX_EVENT_EPOCH, NULL);
+				CAM_ISP_CTX_EVENT_EPOCH, NULL, NULL);
 		}
 	} else {
 		__cam_isp_ctx_send_sof_timestamp(ctx_isp, request_id,
 			CAM_REQ_MGR_SOF_EVENT_SUCCESS);
 		__cam_isp_ctx_update_event_record(ctx_isp,
-			CAM_ISP_CTX_EVENT_EPOCH, NULL);
+			CAM_ISP_CTX_EVENT_EPOCH, NULL, NULL);
 	}
 	ctx_isp->substate_activated = CAM_ISP_CTX_ACTIVATED_BUBBLE;
 	CAM_DBG(CAM_ISP, "next Substate[%s], ctx_idx: %u, link: 0x%x",
@@ -4997,7 +5051,7 @@ static int __cam_isp_ctx_apply_req_in_activated_state(
 			CAM_ISP_STATE_CHANGE_TRIGGER_APPLIED,
 			req->request_id);
 		__cam_isp_ctx_update_event_record(ctx_isp,
-			CAM_ISP_CTX_EVENT_APPLY, req);
+			CAM_ISP_CTX_EVENT_APPLY, req, NULL);
 	} else if (rc == -EALREADY) {
 		spin_lock_bh(&ctx->lock);
 		req_isp->bubble_detected = true;
@@ -6025,7 +6079,6 @@ static int __cam_isp_ctx_rdi_only_sof_in_bubble_applied(
 		/* Send SOF event as empty frame*/
 		__cam_isp_ctx_send_sof_timestamp(ctx_isp, request_id,
 			CAM_REQ_MGR_SOF_EVENT_SUCCESS);
-
 		goto end;
 	}
 
@@ -6061,7 +6114,7 @@ static int __cam_isp_ctx_rdi_only_sof_in_bubble_applied(
 			request_id = req->request_id;
 			ctx_isp->reported_req_id = request_id;
 			__cam_isp_ctx_send_sof_timestamp(ctx_isp, request_id,
-			CAM_REQ_MGR_SOF_EVENT_ERROR);
+				CAM_REQ_MGR_SOF_EVENT_ERROR);
 		} else
 			__cam_isp_ctx_send_sof_timestamp(ctx_isp, request_id,
 				CAM_REQ_MGR_SOF_EVENT_SUCCESS);
@@ -6299,14 +6352,14 @@ static int __cam_isp_ctx_rdi_only_reg_upd_in_bubble_applied_state(
 		__cam_isp_ctx_substate_val_to_type(
 		ctx_isp->substate_activated), ctx->ctx_id, ctx->link_hdl);
 	__cam_isp_ctx_update_event_record(ctx_isp,
-		CAM_ISP_CTX_EVENT_RUP, req);
+		CAM_ISP_CTX_EVENT_RUP, req, NULL);
 	return 0;
 error:
 	/* Send SOF event as idle frame*/
 	__cam_isp_ctx_send_sof_timestamp(ctx_isp, request_id,
 		CAM_REQ_MGR_SOF_EVENT_SUCCESS);
 	__cam_isp_ctx_update_event_record(ctx_isp,
-		CAM_ISP_CTX_EVENT_RUP, NULL);
+		CAM_ISP_CTX_EVENT_RUP, NULL, NULL);
 
 	/*
 	 * There is no request in the pending list, move the sub state machine

drivers/cam_isp/cam_isp_context.h

@@ -60,7 +60,7 @@
 #define CAM_ISP_CONTEXT_AEB_ERROR_CNT_MAX 6
 
 /* Debug Buffer length*/
-#define CAM_ISP_CONTEXT_DBG_BUF_LEN 300
+#define CAM_ISP_CONTEXT_DBG_BUF_LEN 1000
 
 /* AFD pipeline delay for FCG configuration */
 #define CAM_ISP_AFD_PIPELINE_DELAY 3
@@ -103,6 +103,7 @@ enum cam_isp_ctx_event {
 	CAM_ISP_CTX_EVENT_EPOCH,
 	CAM_ISP_CTX_EVENT_RUP,
 	CAM_ISP_CTX_EVENT_BUFDONE,
+	CAM_ISP_CTX_EVENT_SHUTTER,
 	CAM_ISP_CTX_EVENT_MAX
 };
 
@@ -237,6 +238,14 @@ struct cam_isp_context_req_id_info {
 	int64_t                          last_bufdone_req_id;
 };
 
+struct shutter_event {
+	uint64_t frame_id;
+	uint64_t req_id;
+	uint32_t status;
+	ktime_t  boot_ts;
+	ktime_t  sof_ts;
+};
+
 /**
  *
  *
@@ -248,8 +257,12 @@ struct cam_isp_context_req_id_info {
  *
  */
 struct cam_isp_context_event_record {
-	uint64_t                         req_id;
-	ktime_t                          timestamp;
+	uint64_t req_id;
+	ktime_t  timestamp;
+	int event_type;
+	union event {
+		struct shutter_event shutter_event;
+	} event;
 };
 
 /**