qcacmn: Check timestamp before calculating time latency

Race condition is observed when runtime suspend is aborted
due to pending tx completions, in this context all tx desc
are checked for corruption or leakage. In parallel tx completion
is received and descriptor timestamp is set to null. As a
result, while checking for leakage in runtime suspend context,
time difference for the tx completion is current jiffies which
is huge, resulting in triggering recovery.
To fix this, tx_desc timestamp is checked before calculating
time latency. Also, printing tx descriptor id for which
completion is not received.

Change-Id: I38b487a47170af374f43c44a96e2a0753f5d57ef
CRs-Fixed: 3117549

dp/wifi3.0/dp_main.c

@@ -12086,31 +12086,44 @@ void dp_flush_ring_hptp(struct dp_soc *soc, hal_ring_handle_t hal_srng)
 
 #ifdef DP_TX_TRACKING
 
-#define DP_TX_COMP_MAX_LATENCY_MS 120000
+#define DP_TX_COMP_MAX_LATENCY_MS 30000
 /**
- * dp_tx_comp_delay() - calculate time latency for tx completion per pkt
+ * dp_tx_comp_delay_check() - calculate time latency for tx completion per pkt
  * @timestamp - tx descriptor timestamp
  *
  * Calculate time latency for tx completion per pkt and trigger self recovery
  * when the delay is more than threshold value.
  *
- * Return: None.
+ * Return: True if delay is more than threshold
  */
-static void dp_tx_comp_delay(uint64_t timestamp)
+static bool dp_tx_comp_delay_check(uint64_t timestamp)
 {
-	uint64_t time_latency;
+	uint64_t time_latency, current_time;
 
-	if (dp_tx_pkt_tracepoints_enabled())
-		time_latency = qdf_ktime_to_ms(qdf_ktime_real_get()) -
-								timestamp;
-	else
-		time_latency = qdf_system_ticks_to_msecs(qdf_system_ticks() -
-								timestamp);
+	if (!timestamp)
+		return false;
 
-	if (time_latency >= DP_TX_COMP_MAX_LATENCY_MS) {
-		dp_err_rl("tx completion not rcvd for %llu ms.", time_latency);
-		qdf_trigger_self_recovery(NULL, QDF_TX_DESC_LEAK);
+	if (dp_tx_pkt_tracepoints_enabled()) {
+		current_time = qdf_ktime_to_ms(qdf_ktime_real_get());
+		time_latency = current_time - timestamp;
+		if (time_latency >= DP_TX_COMP_MAX_LATENCY_MS) {
+			dp_err_rl("enqueued: %llu ms, current : %llu ms",
+				  timestamp, current_time);
+			return true;
+		}
+	} else {
+		current_time = qdf_system_ticks();
+		time_latency = qdf_system_ticks_to_msecs(current_time -
+							 timestamp);
+		if (time_latency >= DP_TX_COMP_MAX_LATENCY_MS) {
+			dp_err_rl("enqueued: %u ms, current : %u ms",
+				  qdf_system_ticks_to_msecs(timestamp),
+				  qdf_system_ticks_to_msecs(current_time));
+			return true;
+		}
 	}
+
+	return false;
 }
 
 /**
@@ -12153,10 +12166,17 @@ static void dp_find_missing_tx_comp(struct dp_soc *soc)
 			if (tx_desc->magic == DP_TX_MAGIC_PATTERN_FREE) {
 				continue;
 			} else if (tx_desc->magic ==
-						DP_TX_MAGIC_PATTERN_INUSE) {
-				dp_tx_comp_delay(tx_desc->timestamp);
+				   DP_TX_MAGIC_PATTERN_INUSE) {
+				if (dp_tx_comp_delay_check(
+							tx_desc->timestamp)) {
+					dp_err_rl("Tx completion not rcvd for id: %u",
+						  tx_desc->id);
+					qdf_trigger_self_recovery(NULL,
+							QDF_TX_DESC_LEAK);
+				}
 			} else {
-				dp_err("tx desc %d corrupted", tx_desc->id);
+				dp_err_rl("tx desc %u corrupted, flags: 0x%x",
+				       tx_desc->id, tx_desc->flags);
 				qdf_trigger_self_recovery(NULL,
 							  QDF_TX_DESC_LEAK);
 			}

dp/wifi3.0/dp_tx_desc.h

@@ -574,6 +574,7 @@ dp_tx_desc_free(struct dp_soc *soc, struct dp_tx_desc_s *tx_desc,
 	tx_desc->nbuf = NULL;
 	tx_desc->flags = 0;
 	dp_tx_desc_set_magic(tx_desc, DP_TX_MAGIC_PATTERN_FREE);
+	tx_desc->timestamp = 0;
 	dp_tx_put_desc_flow_pool(pool, tx_desc);
 	switch (pool->status) {
 	case FLOW_POOL_ACTIVE_PAUSED: