Donate to e Foundation | Murena handsets with /e/OS | Own a part of Murena! Learn more

Commit 27bcbdf4 authored by Abhilash Kumar's avatar Abhilash Kumar
Browse files

msm: camera: isp: Improve logging by adding context info 



Add context id in the logs during various events ISP works upon.
This will ease during debug process by reducing providing enough
info from the logs.

Change-Id: Iebcf02f66597faf64a464dd527dadc7b7201c5b8
Signed-off-by: default avatarAbhilash Kumar <krabhi@codeaurora.org>
parent 0a902be3

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))