Merge "msm: camera: isp: Improve logging by adding context info" into dev/msm-4.14-camx (5d1f55e5) · Commits · e / devices / android_kernel_oneplus_sm8150

drivers/media/platform/msm/camera/cam_isp/cam_isp_context.c

+59 −45

Original line number	Diff line number	Diff line
		@@ -424,10 +424,11 @@ static int __cam_isp_ctx_handle_buf_done_in_activated_state(

		if (!req_isp->bubble_detected) {
		CAM_DBG(CAM_ISP,
		"Sync with success: req %lld res 0x%x fd 0x%x",
		"Sync with success: req %lld res 0x%x fd 0x%x, ctx %u",
		req->request_id,
		req_isp->fence_map_out[j].resource_handle,
		req_isp->fence_map_out[j].sync_id);
		req_isp->fence_map_out[j].sync_id,
		ctx->ctx_id);

		rc = cam_sync_signal(req_isp->fence_map_out[j].sync_id,
		CAM_SYNC_STATE_SIGNALED_SUCCESS);
		@@ -435,11 +436,12 @@ static int __cam_isp_ctx_handle_buf_done_in_activated_state(
		CAM_DBG(CAM_ISP, "Sync failed with rc = %d",
		rc);
		} else if (!req_isp->bubble_report) {
		CAM_DBG(CAM_ISP,
		"Sync with failure: req %lld res 0x%x fd 0x%x",
		CAM_ERR(CAM_ISP,
		"Sync with failure: req %lld res 0x%x fd 0x%x, ctx %u",
		req->request_id,
		req_isp->fence_map_out[j].resource_handle,
		req_isp->fence_map_out[j].sync_id);
		req_isp->fence_map_out[j].sync_id,
		ctx->ctx_id);

		rc = cam_sync_signal(req_isp->fence_map_out[j].sync_id,
		CAM_SYNC_STATE_SIGNALED_ERROR);
		@@ -460,9 +462,9 @@ static int __cam_isp_ctx_handle_buf_done_in_activated_state(
		continue;
		}

		CAM_DBG(CAM_ISP, "req %lld, reset sync id 0x%x",
		CAM_DBG(CAM_ISP, "req %lld, reset sync id 0x%x ctx %u",
		req->request_id,
		req_isp->fence_map_out[j].sync_id);
		req_isp->fence_map_out[j].sync_id, ctx->ctx_id);
		if (!rc) {
		req_isp->num_acked++;
		req_isp->fence_map_out[j].sync_id = -1;
		@@ -472,9 +474,9 @@ static int __cam_isp_ctx_handle_buf_done_in_activated_state(
		if (req_isp->num_acked > req_isp->num_fence_map_out) {
		/* Should not happen */
		CAM_ERR(CAM_ISP,
		"WARNING: req_id %lld num_acked %d > map_out %d",
		"WARNING: req_id %lld num_acked %d > map_out %d, ctx %u",
		req->request_id, req_isp->num_acked,
		req_isp->num_fence_map_out);
		req_isp->num_fence_map_out, ctx->ctx_id);
		WARN_ON(req_isp->num_acked > req_isp->num_fence_map_out);
		}

		@@ -491,15 +493,15 @@ static int __cam_isp_ctx_handle_buf_done_in_activated_state(
		atomic_set(&ctx_isp->process_bubble, 0);

		CAM_DBG(CAM_REQ,
		"Move active request %lld to pending list(cnt = %d) [bubble recovery]",
		req->request_id, ctx_isp->active_req_cnt);
		"Move active request %lld to pending list(cnt = %d) [bubble recovery], ctx %u",
		req->request_id, ctx_isp->active_req_cnt, ctx->ctx_id);
		} else {
		list_del_init(&req->list);
		list_add_tail(&req->list, &ctx->free_req_list);

		CAM_DBG(CAM_REQ,
		"Move active request %lld to free list(cnt = %d) [all fences done]",
		req->request_id, ctx_isp->active_req_cnt);
		"Move active request %lld to free list(cnt = %d) [all fences done], ctx %u",
		req->request_id, ctx_isp->active_req_cnt, ctx->ctx_id);
		}

		end:
		@@ -598,14 +600,15 @@ static int __cam_isp_ctx_reg_upd_in_activated_state(
		if (req_isp->num_fence_map_out != 0) {
		list_add_tail(&req->list, &ctx->active_req_list);
		ctx_isp->active_req_cnt++;
		CAM_DBG(CAM_REQ, "move request %lld to active list(cnt = %d)",
		req->request_id, ctx_isp->active_req_cnt);
		CAM_DBG(CAM_REQ,
		"move request %lld to active list(cnt = %d), ctx %u",
		req->request_id, ctx_isp->active_req_cnt, ctx->ctx_id);
		} else {
		/* no io config, so the request is completed. */
		list_add_tail(&req->list, &ctx->free_req_list);
		CAM_DBG(CAM_ISP,
		"move active request %lld to free list(cnt = %d)",
		req->request_id, ctx_isp->active_req_cnt);
		"move active request %lld to free list(cnt = %d), ctx %u",
		req->request_id, ctx_isp->active_req_cnt, ctx->ctx_id);
		}

		/*
		@@ -644,8 +647,8 @@ static int __cam_isp_ctx_notify_sof_in_activated_state(
		notify.trigger = CAM_TRIGGER_POINT_SOF;

		ctx->ctx_crm_intf->notify_trigger(&notify);
		CAM_DBG(CAM_ISP, "Notify CRM SOF frame %lld",
		ctx_isp->frame_id);
		CAM_DBG(CAM_ISP, "Notify CRM SOF frame %lld ctx %u",
		ctx_isp->frame_id, ctx->ctx_id);
		}

		list_for_each_entry(req, &ctx->active_req_list, list) {
		@@ -662,7 +665,9 @@ static int __cam_isp_ctx_notify_sof_in_activated_state(
		__cam_isp_ctx_send_sof_timestamp(ctx_isp, request_id,
		CAM_REQ_MGR_SOF_EVENT_SUCCESS);
		} else {
		CAM_ERR_RATE_LIMIT(CAM_ISP, "Can not notify SOF to CRM");
		CAM_ERR_RATE_LIMIT(CAM_ISP,
		"Can not notify SOF to CRM for ctx %u",
		ctx->ctx_id);
		rc = -EFAULT;
		}

		@@ -687,10 +692,11 @@ static int __cam_isp_ctx_notify_eof_in_activated_state(
		notify.trigger = CAM_TRIGGER_POINT_EOF;

		ctx->ctx_crm_intf->notify_trigger(&notify);
		CAM_DBG(CAM_ISP, "Notify CRM EOF frame %lld\n",
		ctx_isp->frame_id);
		CAM_DBG(CAM_ISP, "Notify CRM EOF frame %lld ctx %u",
		ctx_isp->frame_id, ctx->ctx_id);
		} else {
		CAM_ERR(CAM_ISP, "Can not notify EOF to CRM");
		CAM_ERR(CAM_ISP, "Can not notify EOF to CRM for ctx %u",
		ctx->ctx_id);
		rc = -EFAULT;
		}

		@@ -725,8 +731,8 @@ static int __cam_isp_ctx_sof_in_activated_state(
		ctx_isp->boot_timestamp = sof_event_data->boot_time;
		__cam_isp_ctx_update_state_monitor_array(ctx_isp,
		CAM_ISP_STATE_CHANGE_TRIGGER_SOF, req->request_id);
		CAM_DBG(CAM_ISP, "frame id: %lld time stamp:0x%llx",
		ctx_isp->frame_id, ctx_isp->sof_timestamp_val);
		CAM_DBG(CAM_ISP, "frame id: %lld time stamp:0x%llx, ctx %u",
		ctx_isp->frame_id, ctx_isp->sof_timestamp_val, ctx->ctx_id);

		return rc;
		}
		@@ -807,8 +813,8 @@ static int __cam_isp_ctx_epoch_in_applied(struct cam_isp_context *ctx_isp,
		notify.error = CRM_KMD_ERR_BUBBLE;
		ctx->ctx_crm_intf->notify_err(&notify);
		atomic_set(&ctx_isp->process_bubble, 1);
		CAM_DBG(CAM_ISP, "Notify CRM about Bubble frame %lld",
		ctx_isp->frame_id);
		CAM_DBG(CAM_ISP, "Notify CRM about Bubble frame %lld, ctx %u",
		ctx_isp->frame_id, ctx->ctx_id);
		} else {
		req_isp->bubble_report = 0;
		}
		@@ -817,8 +823,8 @@ static int __cam_isp_ctx_epoch_in_applied(struct cam_isp_context *ctx_isp,
		* Always move the request to active list. Let buf done
		* function handles the rest.
		*/
		CAM_DBG(CAM_REQ, "move request %lld to active list(cnt = %d)",
		req->request_id, ctx_isp->active_req_cnt);
		CAM_DBG(CAM_REQ, "move request %lld to active list(cnt = %d), ctx %u",
		req->request_id, ctx_isp->active_req_cnt, ctx->ctx_id);
		ctx_isp->active_req_cnt++;
		list_del_init(&req->list);
		list_add_tail(&req->list, &ctx->active_req_list);
		@@ -956,8 +962,8 @@ static int __cam_isp_ctx_epoch_in_bubble_applied(
		notify.error = CRM_KMD_ERR_BUBBLE;
		ctx->ctx_crm_intf->notify_err(&notify);
		CAM_DBG(CAM_REQ,
		"Notify CRM about Bubble req_id %llu frame %lld",
		req->request_id, ctx_isp->frame_id);
		"Notify CRM about Bubble req_id %llu frame %lld, ctx %u",
		req->request_id, ctx_isp->frame_id, ctx->ctx_id);
		} else {
		req_isp->bubble_report = 0;
		}
		@@ -966,7 +972,7 @@ static int __cam_isp_ctx_epoch_in_bubble_applied(
		* Always move the request to active list. Let buf done
		* function handles the rest.
		*/
		CAM_DBG(CAM_ISP, "move request %lld to active list(cnt = %d)",
		CAM_DBG(CAM_ISP, "move request %lld to active list(cnt = %d) ctx %u",
		req->request_id, ctx_isp->active_req_cnt);
		ctx_isp->active_req_cnt++;
		list_del_init(&req->list);
		@@ -1072,9 +1078,11 @@ static int __cam_isp_ctx_handle_error(struct cam_isp_context *ctx_isp,
		for (i = 0; i < req_isp->num_fence_map_out; i++) {
		fence_map_out =
		&req_isp->fence_map_out[i];
		CAM_ERR(CAM_ISP, "req %llu, Sync fd %x",
		CAM_ERR(CAM_ISP,
		"req %llu, Sync fd 0x%x ctx %u",
		req->request_id,
		req_isp->fence_map_out[i].sync_id);
		req_isp->fence_map_out[i].sync_id,
		ctx->ctx_id);
		if (req_isp->fence_map_out[i].sync_id != -1) {
		rc = cam_sync_signal(
		fence_map_out->sync_id,
		@@ -1101,9 +1109,11 @@ static int __cam_isp_ctx_handle_error(struct cam_isp_context *ctx_isp,
		for (i = 0; i < req_isp->num_fence_map_out; i++) {
		fence_map_out =
		&req_isp->fence_map_out[i];
		CAM_ERR(CAM_ISP, "req %llu, Sync fd %x",
		CAM_ERR(CAM_ISP,
		"req %llu, Sync fd 0x%x ctx %u",
		req->request_id,
		req_isp->fence_map_out[i].sync_id);
		req_isp->fence_map_out[i].sync_id,
		ctx->ctx_id);
		if (req_isp->fence_map_out[i].sync_id != -1) {
		rc = cam_sync_signal(
		fence_map_out->sync_id,
		@@ -1190,8 +1200,8 @@ static int __cam_isp_ctx_handle_error(struct cam_isp_context *ctx_isp,
		notify.error = CRM_KMD_ERR_FATAL;
		}

		CAM_WARN(CAM_ISP, "Notify CRM: req %lld, frame %lld\n",
		error_request_id, ctx_isp->frame_id);
		CAM_WARN(CAM_ISP, "Notify CRM: req %lld, frame %lld ctx %u",
		error_request_id, ctx_isp->frame_id, ctx->ctx_id);

		ctx->ctx_crm_intf->notify_err(&notify);

		@@ -1214,12 +1224,15 @@ static int __cam_isp_ctx_handle_error(struct cam_isp_context *ctx_isp,
		V4L_EVENT_CAM_REQ_MGR_ERROR,
		V4L_EVENT_CAM_REQ_MGR_EVENT))
		CAM_ERR(CAM_ISP,
		"Error in notifying the error time for req id:%lld",
		ctx_isp->last_applied_req_id);
		"Error in notifying the error time for req id:%lld ctx %u",
		ctx_isp->last_applied_req_id,
		ctx->ctx_id);
		}
		ctx_isp->substate_activated = CAM_ISP_CTX_ACTIVATED_HW_ERROR;
		} else {
		CAM_ERR_RATE_LIMIT(CAM_ISP, "Can not notify ERRROR to CRM");
		CAM_ERR_RATE_LIMIT(CAM_ISP,
		"Can not notify ERRROR to CRM for ctx %u",
		ctx->ctx_id);
		rc = -EFAULT;
		}

		@@ -1656,15 +1669,16 @@ static int __cam_isp_ctx_apply_req_in_activated_state(
		goto end;
		}

		CAM_DBG(CAM_REQ, "Apply request %lld in substate %d", req->request_id,
		ctx_isp->substate_activated);
		CAM_DBG(CAM_REQ, "Apply request %lld in substate %d ctx %u",
		req->request_id, ctx_isp->substate_activated, ctx->ctx_id);
		req_isp = (struct cam_isp_ctx_req *) req->req_priv;

		if (ctx_isp->active_req_cnt >= 2) {
		CAM_ERR_RATE_LIMIT(CAM_ISP,
		"Reject apply request (id %lld) due to congestion(cnt = %d)",
		"Reject apply request (id %lld) due to congestion(cnt = %d) ctx %u",
		req->request_id,
		ctx_isp->active_req_cnt);
		ctx_isp->active_req_cnt,
		ctx->ctx_id);

		spin_lock_bh(&ctx->lock);
		if (!list_empty(&ctx->active_req_list))