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

Commit 98d9f67e authored by Karthik Anantha Ram's avatar Karthik Anantha Ram Committed by Gerrit - the friendly Code Review server
Browse files

msm: camera: Improve logging capability in kmd drivers



Adds new log tags to segregate logs across kernel drivers.
The change adds tags to track a request(CAM_REQ),
performance logs(CAM_PERF), memory manager(CAM_MEM) &
irq controller(CAM_IRQ_CTRL) events.

Change-Id: Id6c8dc9403d711e02c171a393ddcdce11c506bba
Signed-off-by: default avatarKarthik Anantha Ram <kartanan@codeaurora.org>
parent b66f27dc
Loading
Loading
Loading
Loading
+11 −2
Original line number Diff line number Diff line
@@ -91,10 +91,19 @@ int cam_context_buf_done_from_hw(struct cam_context *ctx,
	 */
	list_del_init(&req->list);
	spin_unlock(&ctx->lock);
	if (!bubble_state)
	if (!bubble_state) {
		result = CAM_SYNC_STATE_SIGNALED_SUCCESS;
	else
	} else {
		CAM_DBG(CAM_REQ,
			"[%s][ctx_id %d] : req[%llu] is done with error",
			ctx->dev_name, ctx->ctx_id, req->request_id);

		for (j = 0; j < req->num_out_map_entries; j++)
			CAM_DBG(CAM_REQ, "fence %d signaled with error",
				req->out_map_entries[j].sync_id);

		result = CAM_SYNC_STATE_SIGNALED_ERROR;
	}

	for (j = 0; j < req->num_out_map_entries; j++) {
		cam_sync_signal(req->out_map_entries[j].sync_id, result);
+2 −2
Original line number Diff line number Diff line
@@ -738,7 +738,7 @@ static int cam_cpas_hw_update_axi_vote(struct cam_hw_info *cpas_hw,
		goto unlock_client;
	}

	CAM_DBG(CAM_CPAS,
	CAM_DBG(CAM_PERF,
		"Client=[%d][%s][%d] Requested compressed[%llu], uncompressed[%llu]",
		client_indx, cpas_client->data.identifier,
		cpas_client->data.cell_index, axi_vote.compressed_bw,
@@ -900,7 +900,7 @@ static int cam_cpas_hw_update_ahb_vote(struct cam_hw_info *cpas_hw,
		goto unlock_client;
	}

	CAM_DBG(CAM_CPAS,
	CAM_DBG(CAM_PERF,
		"client=[%d][%s][%d] : type[%d], level[%d], freq[%ld], applied[%d]",
		client_indx, cpas_client->data.identifier,
		cpas_client->data.cell_index, ahb_vote.type,
+53 −10
Original line number Diff line number Diff line
@@ -995,6 +995,8 @@ static int cam_icp_update_clk_rate(struct cam_icp_hw_mgr *hw_mgr,
		id = CAM_ICP_IPE_CMD_UPDATE_CLK;
	}

	CAM_DBG(CAM_PERF, "clk_rate %u for dev_type %d", curr_clk_rate,
		ctx_data->icp_dev_acquire_info->dev_type);
	clk_upd_cmd.curr_clk_rate = curr_clk_rate;
	clk_upd_cmd.ipe_bps_pc_enable = icp_hw_mgr.ipe_bps_pc_flag;

@@ -1058,6 +1060,10 @@ static int cam_icp_update_cpas_vote(struct cam_icp_hw_mgr *hw_mgr,
	 * anyway.
	 */

	CAM_DBG(CAM_ICP, "compress_bw %llu uncompress_bw %llu dev_type %d",
		clk_info->compressed_bw, clk_info->uncompressed_bw,
		ctx_data->icp_dev_acquire_info->dev_type);

	return 0;
}

@@ -1452,8 +1458,10 @@ static int cam_icp_mgr_handle_frame_process(uint32_t *msg_ptr, int flag)
		CAM_ERR(CAM_ICP, "Invalid Context");
		return -EINVAL;
	}
	CAM_DBG(CAM_ICP, "ctx : %pK, request_id :%lld",
		(void *)ctx_data->context_priv, request_id);
	CAM_DBG(CAM_REQ,
		"ctx_id : %u, request_id :%lld dev_type: %d",
		ctx_data->ctx_id, request_id,
		ctx_data->icp_dev_acquire_info->dev_type);

	mutex_lock(&ctx_data->ctx_mutex);
	cam_icp_ctx_timer_reset(ctx_data);
@@ -2326,6 +2334,7 @@ static int cam_icp_mgr_hw_close_u(void *hw_priv, void *hw_close_args)
	struct cam_icp_hw_mgr *hw_mgr = hw_priv;
	int rc = 0;

	CAM_DBG(CAM_ICP, "UMD calls close");
	if (!hw_mgr) {
		CAM_ERR(CAM_ICP, "Null hw mgr");
		return 0;
@@ -2342,6 +2351,7 @@ static int cam_icp_mgr_hw_close_k(void *hw_priv, void *hw_close_args)
{
	struct cam_icp_hw_mgr *hw_mgr = hw_priv;

	CAM_DBG(CAM_ICP, "KMD calls close");
	if (!hw_mgr) {
		CAM_ERR(CAM_ICP, "Null hw mgr");
		return 0;
@@ -2371,6 +2381,7 @@ static int cam_icp_mgr_icp_power_collapse(struct cam_icp_hw_mgr *hw_mgr)
			a5_dev->soc_info.reg_map[A5_SIERRA_BASE].mem_base);
		rc = cam_icp_mgr_hw_close_k(hw_mgr, NULL);
	} else {
		CAM_DBG(CAM_PERF, "Sending PC prep ICP PC enabled");
		rc = cam_icp_mgr_send_pc_prep(hw_mgr);
		cam_hfi_disable_cpu(
			a5_dev->soc_info.reg_map[A5_SIERRA_BASE].mem_base);
@@ -3181,8 +3192,10 @@ static int cam_icp_mgr_config_hw(void *hw_mgr_priv, void *config_hw_args)
	rc = cam_icp_mgr_enqueue_config(hw_mgr, config_args);
	if (rc)
		goto config_err;
	CAM_DBG(CAM_ICP, "req_id = %lld %u",
		req_id, ctx_data->ctx_id);
	CAM_DBG(CAM_REQ,
		"req_id = %lld on ctx_id %u for dev %d queued to FW",
		req_id, ctx_data->ctx_id,
		ctx_data->icp_dev_acquire_info->dev_type);
	mutex_unlock(&ctx_data->ctx_mutex);
	mutex_unlock(&hw_mgr->hw_mgr_mutex);

@@ -3368,8 +3381,11 @@ static int cam_icp_mgr_process_io_cfg(struct cam_icp_hw_mgr *hw_mgr,
				io_cfg_ptr[i].fence;
			prepare_args->num_out_map_entries++;
		}
		CAM_DBG(CAM_ICP, "dir[%d]: %u, fence: %u",
			i, io_cfg_ptr[i].direction, io_cfg_ptr[i].fence);
		CAM_DBG(CAM_REQ,
			"ctx_id: %u req_id: %llu dir[%d]: %u, fence: %u resource_type = %u",
			ctx_data->ctx_id, packet->header.request_id, i,
			io_cfg_ptr[i].direction, io_cfg_ptr[i].fence,
			io_cfg_ptr[i].resource_type);
	}

	if (prepare_args->num_in_map_entries > 1) {
@@ -3385,7 +3401,9 @@ static int cam_icp_mgr_process_io_cfg(struct cam_icp_hw_mgr *hw_mgr,
			merged_sync_in_obj;
		prepare_args->in_map_entries[0].sync_id = merged_sync_in_obj;
		prepare_args->num_in_map_entries = 1;
		CAM_DBG(CAM_ICP, "Merged Sync obj = %d", merged_sync_in_obj);
		CAM_DBG(CAM_REQ, "ctx_id: %u req_id: %llu Merged Sync obj: %d",
			ctx_data->ctx_id, packet->header.request_id,
			merged_sync_in_obj);
	} else if (prepare_args->num_in_map_entries == 1) {
		prepare_args->in_map_entries[0].sync_id = sync_in_obj[0];
		prepare_args->num_in_map_entries = 1;
@@ -3606,7 +3624,8 @@ static int cam_icp_mgr_prepare_hw_update(void *hw_mgr_priv,
		return rc;
	}

	CAM_DBG(CAM_ICP, "E: req id = %lld", packet->header.request_id);
	CAM_DBG(CAM_REQ, "req id = %lld for ctx = %u",
		packet->header.request_id, ctx_data->ctx_id);
	/* Update Buffer Address from handles and patch information */
	rc = cam_packet_util_process_patches(packet, hw_mgr->iommu_hdl,
		hw_mgr->iommu_sec_hdl);
@@ -3822,6 +3841,11 @@ static int cam_icp_mgr_hw_flush(void *hw_priv, void *hw_flush_args)
		return -EINVAL;
	}

	CAM_DBG(CAM_REQ, "ctx_id %d req %lld Flush type %d",
		ctx_data->ctx_id,
		*(int64_t *)flush_args->flush_req_pending[0],
		flush_args->flush_type);

	switch (flush_args->flush_type) {
	case CAM_FLUSH_TYPE_ALL:
		mutex_lock(&hw_mgr->hw_mgr_mutex);
@@ -3916,7 +3940,8 @@ static int cam_icp_mgr_release_hw(void *hw_mgr_priv, void *release_hw_args)
	if ((!hw_mgr->bps_ctxt_cnt || !hw_mgr->ipe_ctxt_cnt))
		cam_icp_device_timer_stop(hw_mgr);

	CAM_DBG(CAM_ICP, "Exit");
	CAM_DBG(CAM_ICP, "Release done for ctx_id %d dev %d", ctx_id,
		ctx_data->icp_dev_acquire_info->dev_type);
	return rc;
}

@@ -4093,6 +4118,21 @@ static int cam_icp_get_acquire_info(struct cam_icp_hw_mgr *hw_mgr,
	return 0;
}

static const char *cam_icp_dev_type_to_name(
	uint32_t dev_type)
{
	switch (dev_type) {
	case CAM_ICP_RES_TYPE_BPS:
		return "BPS";
	case CAM_ICP_RES_TYPE_IPE_RT:
		return "IPE_RT";
	case CAM_ICP_RES_TYPE_IPE:
		return "IPE";
	default:
		return "Invalid dev type";
	}
}

static int cam_icp_mgr_acquire_hw(void *hw_mgr_priv, void *acquire_hw_args)
{
	int rc = 0, bitmap_size = 0;
@@ -4224,7 +4264,10 @@ static int cam_icp_mgr_acquire_hw(void *hw_mgr_priv, void *acquire_hw_args)
	cam_icp_ctx_timer_start(ctx_data);
	hw_mgr->ctxt_cnt++;
	mutex_unlock(&hw_mgr->hw_mgr_mutex);
	CAM_DBG(CAM_ICP, "Acquire Done");
	CAM_DBG(CAM_ICP, "Acquire Done for ctx_id %u dev name %s dev type %d",
		ctx_data->ctx_id, cam_icp_dev_type_to_name(
		icp_dev_acquire_info->dev_type),
		icp_dev_acquire_info->dev_type);

	return 0;

+24 −14
Original line number Diff line number Diff line
@@ -436,8 +436,8 @@ static int __cam_isp_ctx_handle_buf_done_in_activated_state(
		list_del_init(&req->list);
		list_add_tail(&req->list, &ctx->free_req_list);
		ctx_isp->active_req_cnt--;
		CAM_DBG(CAM_ISP,
			"Move active request %lld to free list(cnt = %d)",
		CAM_DBG(CAM_REQ,
			"Move active request %lld to free list(cnt = %d) [all fences done]",
			 req->request_id, ctx_isp->active_req_cnt);
	}

@@ -537,7 +537,7 @@ 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_ISP, "move request %lld to active list(cnt = %d)",
		CAM_DBG(CAM_REQ, "move request %lld to active list(cnt = %d)",
			 req->request_id, ctx_isp->active_req_cnt);
	} else {
		/* no io config, so the request is completed. */
@@ -698,7 +698,7 @@ static int __cam_isp_ctx_reg_upd_in_sof(struct cam_isp_context *ctx_isp,
			/* need to handle the buf done */
			list_add_tail(&req->list, &ctx->active_req_list);
			ctx_isp->active_req_cnt++;
			CAM_DBG(CAM_ISP,
			CAM_DBG(CAM_REQ,
				"move request %lld to active list(cnt = %d)",
				 req->request_id,
				ctx_isp->active_req_cnt);
@@ -762,7 +762,7 @@ static int __cam_isp_ctx_epoch_in_applied(struct cam_isp_context *ctx_isp,
		list_del_init(&req->list);
		list_add_tail(&req->list, &ctx->active_req_list);
		ctx_isp->active_req_cnt++;
		CAM_DBG(CAM_ISP, "move request %lld to active list(cnt = %d)",
		CAM_DBG(CAM_REQ, "move request %lld to active list(cnt = %d)",
			 req->request_id, ctx_isp->active_req_cnt);
		req_isp->bubble_report = 0;
	}
@@ -896,8 +896,9 @@ static int __cam_isp_ctx_epoch_in_bubble_applied(
		notify.req_id = req->request_id;
		notify.error = CRM_KMD_ERR_BUBBLE;
		ctx->ctx_crm_intf->notify_err(&notify);
		CAM_DBG(CAM_ISP, "Notify CRM about Bubble frame %lld",
			ctx_isp->frame_id);
		CAM_DBG(CAM_REQ,
			"Notify CRM about Bubble req_id %llu frame %lld",
			req->request_id, ctx_isp->frame_id);
	} else {
		/*
		 * If we can not report bubble, then treat it as if no bubble
@@ -1193,7 +1194,8 @@ static int __cam_isp_ctx_apply_req_in_activated_state(
		goto end;
	}

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

	if (ctx_isp->active_req_cnt >=  2) {
@@ -1314,6 +1316,8 @@ static int __cam_isp_ctx_flush_req(struct cam_context *ctx,
			return 0;
	}

	CAM_DBG(CAM_REQ, "Flush [%u] in progress for req_id %llu",
		flush_req->type, flush_req->req_id);
	list_for_each_entry_safe(req, req_temp, req_list, list) {
		if (flush_req->type == CAM_REQ_MGR_FLUSH_TYPE_CANCEL_REQ) {
			if (req->request_id != flush_req->req_id) {
@@ -1941,7 +1945,8 @@ static int __cam_isp_ctx_release_dev_in_top_state(struct cam_context *ctx,
	ctx->state = CAM_CTX_AVAILABLE;

	trace_cam_context_state("ISP", ctx);
	CAM_DBG(CAM_ISP, "next state %d", ctx->state);
	CAM_DBG(CAM_ISP, "Release device success[%u] next state %d",
		ctx->ctx_id, ctx->state);
	return rc;
}

@@ -2067,8 +2072,9 @@ static int __cam_isp_ctx_config_dev_in_top_state(
	if (rc)
		goto free_req;

	CAM_DBG(CAM_ISP, "Preprocessing Config %lld successful",
		req->request_id);
	CAM_DBG(CAM_REQ,
		"Preprocessing Config req_id %lld successful on ctx %u",
		req->request_id, ctx->ctx_id);

	return rc;

@@ -2199,7 +2205,10 @@ static int __cam_isp_ctx_acquire_dev_in_available(struct cam_context *ctx,
	ctx->state = CAM_CTX_ACQUIRED;

	trace_cam_context_state("ISP", ctx);
	CAM_DBG(CAM_ISP, "Acquire success.");
	CAM_DBG(CAM_ISP,
		"Acquire success on session_hdl 0x%x num_rsrces %d RDI only %d ctx %u",
		cmd->session_handle, cmd->num_resources,
		(hw_cmd_args.u.is_rdi_only_context ? 1 : 0), ctx->ctx_id);
	kfree(isp_res);
	return rc;

@@ -2341,7 +2350,7 @@ static int __cam_isp_ctx_start_dev_in_ready(struct cam_context *ctx,
		trace_cam_context_state("ISP", ctx);
		goto end;
	}
	CAM_DBG(CAM_ISP, "start device success");
	CAM_DBG(CAM_ISP, "start device success ctx %u", ctx->ctx_id);

	if (req_isp->num_fence_map_out) {
		list_del_init(&req->list);
@@ -2424,7 +2433,8 @@ static int __cam_isp_ctx_stop_dev_in_activated_unlock(
	ctx_isp->active_req_cnt = 0;
	ctx_isp->reported_req_id = 0;

	CAM_DBG(CAM_ISP, "next state %d", ctx->state);
	CAM_DBG(CAM_ISP, "Stop device success next state %d on ctx %u",
		ctx->state, ctx->ctx_id);
	return rc;
}

+7 −5
Original line number Diff line number Diff line
@@ -1591,7 +1591,7 @@ static int cam_isp_blob_bw_update(
	bool                                   camif_l_bw_updated = false;
	bool                                   camif_r_bw_updated = false;

	CAM_DBG(CAM_ISP,
	CAM_DBG(CAM_PERF,
		"usage=%u left cam_bw_bps=%llu ext_bw_bps=%llu\n"
		"right cam_bw_bps=%llu ext_bw_bps=%llu",
		bw_config->usage_type,
@@ -2035,7 +2035,8 @@ static int cam_ife_mgr_stop_hw(void *hw_mgr_priv, void *stop_hw_args)
	for (i = 0; i < CAM_IFE_HW_OUT_RES_MAX; i++)
		cam_ife_hw_mgr_deinit_hw_res(&ctx->res_list_ife_out[i]);

	CAM_DBG(CAM_ISP, "Exit...ctx id:%d rc :%d", ctx->ctx_index, rc);
	CAM_DBG(CAM_ISP,
		"Stop success for ctx id:%d rc :%d", ctx->ctx_index, rc);

	mutex_lock(&g_ife_hw_mgr.ctx_mutex);
	if (!atomic_dec_return(&g_ife_hw_mgr.active_ctx_cnt)) {
@@ -2313,7 +2314,7 @@ static int cam_ife_mgr_start_hw(void *hw_mgr_priv, void *start_hw_args)
	}

	/* Start IFE root node: do nothing */
	CAM_DBG(CAM_ISP, "Exit...(success)");
	CAM_DBG(CAM_ISP, "Start success for ctx id:%d", ctx->ctx_index);
	return 0;
err:
	stop_hw_method.hw_stop_cmd = CAM_ISP_HW_STOP_IMMEDIATELY;
@@ -2625,7 +2626,7 @@ static int cam_isp_blob_clock_update(

	ctx = prepare->ctxt_to_hw_map;

	CAM_DBG(CAM_ISP,
	CAM_DBG(CAM_PERF,
		"usage=%u left_clk= %lu right_clk=%lu",
		clock_config->usage_type,
		clock_config->left_pix_hz,
@@ -2818,7 +2819,8 @@ static int cam_ife_mgr_prepare_hw_update(void *hw_mgr_priv,
		return -EINVAL;
	}

	CAM_DBG(CAM_ISP, "enter");
	CAM_DBG(CAM_REQ, "Enter for req_id %lld",
		prepare->packet->header.request_id);

	prepare_hw_data = (struct cam_isp_prepare_hw_update_data  *)
		prepare->priv;
Loading