msm: eva: Add CVP_CMD debug logging

Add cmd logging functionality as an
alternative to pkt logging. This has
advantages related to log dropping
and log mangling.

Change-Id: I0ff6801445821e1224f83fa7e2eb8bf8a849962b

msm/eva/cvp_hfi.c

@@ -405,6 +405,7 @@ static int __write_queue(struct cvp_iface_q_info *qinfo, u8 *packet,
 		bool *rx_req_is_set)
 {
 	struct cvp_hfi_queue_header *queue;
+	struct cvp_hfi_cmd_session_hdr *cmd_pkt;
 	u32 packet_size_in_words, new_write_idx;
 	u32 empty_space, read_idx, write_idx;
 	u32 *write_ptr;
@@ -423,6 +424,14 @@ static int __write_queue(struct cvp_iface_q_info *qinfo, u8 *packet,
 		return -ENOENT;
 	}
 
+	cmd_pkt = (struct cvp_hfi_cmd_session_hdr *)packet;
+	dprintk(CVP_CMD, "%s: "
+		"pkt_type %08x sess_id %08x trans_id %u ktid %llu\n",
+		__func__, cmd_pkt->packet_type,
+		cmd_pkt->session_id,
+		cmd_pkt->client_data.transaction_id,
+		cmd_pkt->client_data.kdata & (FENCE_BIT - 1));
+
 	if (msm_cvp_debug & CVP_PKT) {
 		dprintk(CVP_PKT, "%s: %pK\n", __func__, qinfo);
 		__dump_packet(packet, CVP_PKT);
@@ -495,6 +504,7 @@ static int __read_queue(struct cvp_iface_q_info *qinfo, u8 *packet,
 		u32 *pb_tx_req_is_set)
 {
 	struct cvp_hfi_queue_header *queue;
+	struct cvp_hfi_msg_session_hdr *msg_pkt;
 	u32 packet_size_in_words, new_read_idx;
 	u32 *read_ptr;
 	u32 receive_request = 0;
@@ -613,6 +623,16 @@ static int __read_queue(struct cvp_iface_q_info *qinfo, u8 *packet,
 
 	spin_unlock(&qinfo->hfi_lock);
 
+	if (!(queue->qhdr_type & HFI_Q_ID_CTRL_TO_HOST_DEBUG_Q)) {
+		msg_pkt = (struct cvp_hfi_msg_session_hdr *)packet;
+		dprintk(CVP_CMD, "%s:  "
+			"pkt_type %08x sess_id %08x trans_id %u ktid %llu\n",
+			__func__, msg_pkt->packet_type,
+			msg_pkt->session_id,
+			msg_pkt->client_data.transaction_id,
+			msg_pkt->client_data.kdata & (FENCE_BIT - 1));
+	}
+
 	if ((msm_cvp_debug & CVP_PKT) &&
 		!(queue->qhdr_type & HFI_Q_ID_CTRL_TO_HOST_DEBUG_Q)) {
 		dprintk(CVP_PKT, "%s: %pK\n", __func__, qinfo);

msm/eva/msm_cvp.c

@@ -187,6 +187,13 @@ static int msm_cvp_session_process_hfi(
 	if (!s)
 		return -ECONNRESET;
 
+	pkt_hdr = (struct cvp_hfi_cmd_session_hdr *)in_pkt;
+	dprintk(CVP_CMD, "%s: "
+		"pkt_type %08x sess_id %08x trans_id %u ktid %llu\n",
+		__func__, pkt_hdr->packet_type,
+		pkt_hdr->session_id,
+		pkt_hdr->client_data.transaction_id,
+		pkt_hdr->client_data.kdata & (FENCE_BIT - 1));
 
 	pkt_idx = get_pkt_index((struct cvp_hal_session_cmd_pkt *)in_pkt);
 	if (pkt_idx < 0) {
@@ -242,7 +249,6 @@ static int msm_cvp_session_process_hfi(
 
 	rc = cvp_enqueue_pkt(inst, in_pkt, offset, buf_num);
 	if (rc) {
-		pkt_hdr = (struct cvp_hfi_cmd_session_hdr *)in_pkt;
 		dprintk(CVP_ERR, "Failed to enqueue pkt, inst %pK "
 			"pkt_type %08x ktid %llu transaction_id %u\n",
 			inst, pkt_hdr->packet_type,
@@ -728,6 +734,12 @@ static int cvp_enqueue_pkt(struct msm_cvp_inst* inst,
 	cmd_hdr = (struct cvp_hfi_cmd_session_hdr *)in_pkt;
 	/* The kdata will be overriden by transaction ID if the cmd has buf */
 	cmd_hdr->client_data.kdata = 0;
+	dprintk(CVP_CMD, "%s: "
+		"pkt_type %08x sess_id %08x trans_id %u ktid %llu\n",
+		__func__, cmd_hdr->packet_type,
+		cmd_hdr->session_id,
+		cmd_hdr->client_data.transaction_id,
+		cmd_hdr->client_data.kdata & (FENCE_BIT - 1));
 
 	if (map_type == MAP_PERSIST)
 		rc = msm_cvp_map_user_persist(inst, in_pkt, in_offset, in_buf_num);

msm/eva/msm_cvp_buf.c

@@ -1474,8 +1474,14 @@ void msm_cvp_unmap_frame(struct msm_cvp_inst *inst, u64 ktid)
 	}
 	mutex_unlock(&inst->frames.lock);
 
-	if (found)
+	if (found) {
+		dprintk(CVP_CMD, "%s: "
+			"pkt_type %08x sess_id %08x trans_id <> ktid %llu\n",
+			__func__, frame->pkt_type,
+			hash32_ptr(inst->session),
+			frame->ktid);
 		msm_cvp_unmap_frame_buf(inst, frame);
+	}
 	else
 		dprintk(CVP_WARN, "%s frame %llu not found!\n", __func__, ktid);
 }
@@ -1542,12 +1548,18 @@ int msm_cvp_map_frame(struct msm_cvp_inst *inst,
 	if (!offset || !buf_num)
 		return 0;
 
-
 	cmd_hdr = (struct cvp_hfi_cmd_session_hdr *)in_pkt;
 	ktid = atomic64_inc_return(&inst->core->kernel_trans_id);
 	ktid &= (FENCE_BIT - 1);
 	cmd_hdr->client_data.kdata = ktid;
 
+	dprintk(CVP_CMD, "%s:   "
+		"pkt_type %08x sess_id %08x trans_id %u ktid %llu\n",
+		__func__, cmd_hdr->packet_type,
+		cmd_hdr->session_id,
+		cmd_hdr->client_data.transaction_id,
+		cmd_hdr->client_data.kdata & (FENCE_BIT - 1));
+
 	frame = cvp_kmem_cache_zalloc(&cvp_driver->frame_cache, GFP_KERNEL);
 	if (!frame)
 		return -ENOMEM;

msm/eva/msm_cvp_debug.h

@@ -26,6 +26,7 @@ enum cvp_msg_prio {
 	CVP_ERR  = 0x000001,
 	CVP_WARN = 0x000002,
 	CVP_INFO = 0x000004,
+	CVP_CMD  = 0x000008,
 	CVP_PROF = 0x000010,
 	CVP_PKT  = 0x000020,
 	CVP_MEM  = 0x000040,
@@ -38,7 +39,7 @@ enum cvp_msg_prio {
 	CVP_SESS = 0x002000,
 	CVP_HFI  = 0x004000,
 	CVP_VM   = 0x008000,
-	CVP_DBG  = CVP_MEM | CVP_SYNX | CVP_CORE | CVP_REG |
+	CVP_DBG  = CVP_MEM | CVP_SYNX | CVP_CORE | CVP_REG | CVP_CMD |
 		CVP_PWR | CVP_DSP | CVP_SESS | CVP_HFI | CVP_PKT | CVP_VM,
 };
 
@@ -104,6 +105,8 @@ static inline char *get_debug_level_str(int level)
 		return "warn";
 	case CVP_INFO:
 		return "info";
+	case CVP_CMD:
+		return "cmd";
 	case CVP_DBG:
 		return "dbg";
 	case CVP_PROF: