qcacmn: Log runtime PM resume source

It is very critical to know the source of who requests runtime
PM resume to debug all kinds of runtime PM related issues. Hence
log them accordingly.

Change-Id: I9551830b1cb567fd29e9d9bbec18705f9cc5e9ec
CRs-fixed: 2496481

hif/src/pcie/if_pci.c

@@ -3870,10 +3870,19 @@ void hif_pci_irq_disable(struct hif_softc *scn, int ce_id)
 int hif_pm_runtime_request_resume(struct hif_opaque_softc *hif_ctx)
 {
 	struct hif_pci_softc *sc = HIF_GET_PCI_SOFTC(hif_ctx);
+	int pm_state;
 
 	if (!sc)
 		return -EINVAL;
 
+	pm_state = qdf_atomic_read(&sc->pm_state);
+	if (pm_state == HIF_PM_RUNTIME_STATE_SUSPENDED)
+		HIF_INFO("Runtime PM resume is requested by %ps",
+			 (void *)_RET_IP_);
+
+	sc->pm_stats.request_resume++;
+	sc->pm_stats.last_resume_caller = (void *)_RET_IP_;
+
 	return hif_pm_request_resume(sc->dev);
 }
 
@@ -3952,11 +3961,19 @@ int hif_pm_runtime_get(struct hif_opaque_softc *hif_ctx)
 		return ret;
 	}
 
+	if (pm_state == HIF_PM_RUNTIME_STATE_SUSPENDED) {
+		HIF_INFO("Runtime PM resume is requested by %ps",
+			 (void *)_RET_IP_);
+		ret = -EAGAIN;
+	} else {
+		ret = -EBUSY;
+	}
+
 	sc->pm_stats.request_resume++;
 	sc->pm_stats.last_resume_caller = (void *)_RET_IP_;
-	ret = hif_pm_request_resume(sc->dev);
+	hif_pm_request_resume(sc->dev);
 
-	return -EAGAIN;
+	return ret;
 }
 
 /**

htc/htc_api.h

@@ -124,6 +124,10 @@ typedef HTC_PACKET *(*HTC_EP_RECV_ALLOC)(void *,
 					 HTC_ENDPOINT_ID Endpoint,
 					 int Length);
 
+/* Optional per service connection callback to log packet information.
+ */
+typedef void (*HTC_EP_LOG_PKT)(void *, HTC_PACKET *);
+
 enum htc_send_full_action {
 	/* packet that overflowed should be kept in the queue */
 	HTC_SEND_FULL_KEEP = 0,
@@ -183,6 +187,8 @@ struct htc_ep_callbacks {
 	 * are empty
 	 */
 	int RecvRefillWaterMark;
+	/* OPTIONAL callback to log packet information */
+	HTC_EP_LOG_PKT ep_log_pkt;
 };
 
 /* service connection information */

htc/htc_send.c

@@ -137,6 +137,34 @@ static void send_packet_completion(HTC_TARGET *target, HTC_PACKET *pPacket)
 
 }
 
+#ifdef FEATURE_RUNTIME_PM
+/**
+ * log_packet_info() - Log HTC packet information
+ *
+ * @target: handle of HTC context
+ * @pPacket: handle of HTC packet
+ *
+ * Return: None
+ */
+static void log_packet_info(HTC_TARGET *target, HTC_PACKET *pPacket)
+{
+	HTC_ENDPOINT *pEndpoint = &target->endpoint[pPacket->Endpoint];
+	HTC_EP_LOG_PKT ep_log_pkt;
+	qdf_nbuf_t netbuf = GET_HTC_PACKET_NET_BUF_CONTEXT(pPacket);
+
+	ep_log_pkt = pEndpoint->EpCallBacks.ep_log_pkt;
+	if (ep_log_pkt) {
+		qdf_nbuf_pull_head(netbuf, sizeof(HTC_FRAME_HDR));
+		ep_log_pkt(pEndpoint->EpCallBacks.pContext, pPacket);
+		qdf_nbuf_push_head(netbuf, sizeof(HTC_FRAME_HDR));
+	}
+}
+#else
+static void log_packet_info(HTC_TARGET *target, HTC_PACKET *pPacket)
+{
+}
+#endif
+
 void htc_send_complete_check_cleanup(void *context)
 {
 	HTC_ENDPOINT *pEndpoint = (HTC_ENDPOINT *) context;
@@ -782,6 +810,7 @@ static void get_htc_send_packets_credit_based(HTC_TARGET *target,
 	HTC_PACKET_QUEUE *tx_queue;
 	HTC_PACKET_QUEUE pm_queue;
 	bool do_pm_get = false;
+	int ret;
 
 	/*** NOTE : the TX lock is held when this function is called ***/
 	AR_DEBUG_PRINTF(ATH_DEBUG_SEND,
@@ -798,10 +827,19 @@ static void get_htc_send_packets_credit_based(HTC_TARGET *target,
 
 	/* loop until we can grab as many packets out of the queue as we can */
 	while (true) {
-		if (do_pm_get && hif_pm_runtime_get(target->hif_dev)) {
-			/* bus suspended, runtime resume issued */
-			QDF_ASSERT(HTC_PACKET_QUEUE_DEPTH(pQueue) == 0);
-			break;
+		if (do_pm_get) {
+			ret = hif_pm_runtime_get(target->hif_dev);
+			if (ret) {
+				/* bus suspended, runtime resume issued */
+				QDF_ASSERT(HTC_PACKET_QUEUE_DEPTH(pQueue) == 0);
+				if (ret == -EAGAIN) {
+					pPacket = htc_get_pkt_at_head(tx_queue);
+					if (!pPacket)
+						break;
+					log_packet_info(target, pPacket);
+				}
+				break;
+			}
 		}
 
 		sendFlags = 0;
@@ -912,6 +950,7 @@ static void get_htc_send_packets(HTC_TARGET *target,
 	HTC_PACKET_QUEUE *tx_queue;
 	HTC_PACKET_QUEUE pm_queue;
 	bool do_pm_get = false;
+	int ret;
 
 	/*** NOTE : the TX lock is held when this function is called ***/
 	AR_DEBUG_PRINTF(ATH_DEBUG_SEND,
@@ -930,10 +969,19 @@ static void get_htc_send_packets(HTC_TARGET *target,
 	while (Resources > 0) {
 		int num_frags;
 
-		if (do_pm_get && hif_pm_runtime_get(target->hif_dev)) {
-			/* bus suspended, runtime resume issued */
-			QDF_ASSERT(HTC_PACKET_QUEUE_DEPTH(pQueue) == 0);
-			break;
+		if (do_pm_get) {
+			ret = hif_pm_runtime_get(target->hif_dev);
+			if (ret) {
+				/* bus suspended, runtime resume issued */
+				QDF_ASSERT(HTC_PACKET_QUEUE_DEPTH(pQueue) == 0);
+				if (ret == -EAGAIN) {
+					pPacket = htc_get_pkt_at_head(tx_queue);
+					if (!pPacket)
+						break;
+					log_packet_info(target, pPacket);
+				}
+				break;
+			}
 		}
 
 		pPacket = htc_packet_dequeue(tx_queue);

wmi/src/wmi_unified.c

@@ -2764,6 +2764,33 @@ static void wmi_htc_tx_complete(void *ctx, HTC_PACKET *htc_pkt)
 	qdf_atomic_dec(&wmi_handle->pending_cmds);
 }
 
+#ifdef FEATURE_RUNTIME_PM
+/**
+ * wmi_htc_log_pkt() - Print information of WMI command from HTC packet
+ *
+ * @ctx: handle of WMI context
+ * @htc_pkt: handle of HTC packet
+ *
+ * @Return: none
+ */
+static void wmi_htc_log_pkt(void *ctx, HTC_PACKET *htc_pkt)
+{
+	wmi_buf_t wmi_cmd_buf = GET_HTC_PACKET_NET_BUF_CONTEXT(htc_pkt);
+	uint32_t cmd_id;
+
+	ASSERT(wmi_cmd_buf);
+	cmd_id = WMI_GET_FIELD(qdf_nbuf_data(wmi_cmd_buf), WMI_CMD_HDR,
+			       COMMANDID);
+
+	WMI_LOGI("WMI command from HTC packet: %s, ID: %d\n",
+		 wmi_id_to_name(cmd_id), cmd_id);
+}
+#else
+static void wmi_htc_log_pkt(void *ctx, HTC_PACKET *htc_pkt)
+{
+}
+#endif
+
 /**
  * wmi_connect_pdev_htc_service() -  WMI API to get connect to HTC service
  *
@@ -2794,6 +2821,7 @@ static QDF_STATUS wmi_connect_pdev_htc_service(struct wmi_soc *soc,
 	connect.EpCallbacks.EpSendFull = NULL /* ar6000_tx_queue_full */;
 	connect.EpCallbacks.EpTxComplete =
 		wmi_htc_tx_complete /* ar6000_tx_queue_full */;
+	connect.EpCallbacks.ep_log_pkt = wmi_htc_log_pkt;
 
 	/* connect to control service */
 	connect.service_id = soc->svc_ids[pdev_idx];