From cec32ac0ce901ac768b290d173537d806f10934f Mon Sep 17 00:00:00 2001 From: Vikram Sharma Date: Fri, 29 Sep 2023 18:31:49 +0530 Subject: [PATCH] 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 --- drivers/cam_isp/cam_isp_context.c | 109 ++++++++++++++++++++++-------- drivers/cam_isp/cam_isp_context.h | 19 +++++- 2 files changed, 97 insertions(+), 31 deletions(-) diff --git a/drivers/cam_isp/cam_isp_context.c b/drivers/cam_isp/cam_isp_context.c index eb4b47b99d..315795a397 100644 --- a/drivers/cam_isp/cam_isp_context.c +++ b/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 diff --git a/drivers/cam_isp/cam_isp_context.h b/drivers/cam_isp/cam_isp_context.h index cf44b372fa..ef18c73bce 100644 --- a/drivers/cam_isp/cam_isp_context.h +++ b/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; }; /**