[PATCH 1/4 v2] ath10k: add debugging for tx-credits usage

[PATCH 1/4 v2] ath10k: add debugging for tx-credits usage

[greearb]

From: Ben Greear <greearb@candelatech.com>

This helps track tx credits accounting and usage.  If
firmware hangs or otherwise fails to return credits, one
can more easily see the last few command types that
was sent to the firmware.

Signed-off-by: Ben Greear <greearb@candelatech.com>
---

v2:  Improve comments.  Issue of using __LINE__ is not resolved.

 drivers/net/wireless/ath/ath10k/htc.c    | 16 ++++++++++------
 drivers/net/wireless/ath/ath10k/htc.h    |  6 +++++-
 drivers/net/wireless/ath/ath10k/htt_tx.c |  8 ++++----
 drivers/net/wireless/ath/ath10k/wmi.c    |  5 ++++-
 4 files changed, 23 insertions(+), 12 deletions(-)

diff --git a/drivers/net/wireless/ath/ath10k/htc.c b/drivers/net/wireless/ath/ath10k/htc.c
index 7f1bccd..2f8bc33 100644
--- a/drivers/net/wireless/ath/ath10k/htc.c
+++ b/drivers/net/wireless/ath/ath10k/htc.c
@@ -121,7 +121,7 @@ static void ath10k_htc_prepare_tx_skb(struct ath10k_htc_ep *ep,
 
 int ath10k_htc_send(struct ath10k_htc *htc,
 		    enum ath10k_htc_ep_id eid,
-		    struct sk_buff *skb)
+		    struct sk_buff *skb, int dbg)
 {
 	struct ath10k_htc_ep *ep = &htc->endpoint[eid];
 	struct ath10k_skb_cb *skb_cb = ATH10K_SKB_CB(skb);
@@ -157,6 +157,10 @@ int ath10k_htc_send(struct ath10k_htc *htc,
 			goto err_pull;
 		}
 		ep->tx_credits -= credits;
+		ath10k_dbg(ATH10K_DBG_HTC,
+			   "ep %d used %d credits, remaining %d dbg %d (0x%x)\n",
+			   eid, credits, ep->tx_credits, dbg, dbg);
+
 		spin_unlock_bh(&htc->tx_lock);
 	}
 
@@ -234,12 +238,12 @@ ath10k_htc_process_credit_report(struct ath10k_htc *htc,
 		if (report->eid >= ATH10K_HTC_EP_COUNT)
 			break;
 
-		ath10k_dbg(ATH10K_DBG_HTC, "ep %d got %d credits\n",
-			   report->eid, report->credits);
-
 		ep = &htc->endpoint[report->eid];
 		ep->tx_credits += report->credits;
 
+		ath10k_dbg(ATH10K_DBG_HTC, "ep %d got %d credits tot %d\n",
+			   report->eid, report->credits, ep->tx_credits);
+
 		if (ep->ep_ops.ep_tx_credits) {
 			spin_unlock_bh(&htc->tx_lock);
 			ep->ep_ops.ep_tx_credits(htc->ar);
@@ -669,7 +673,7 @@ int ath10k_htc_connect_service(struct ath10k_htc *htc,
 
 	reinit_completion(&htc->ctl_resp);
 
-	status = ath10k_htc_send(htc, ATH10K_HTC_EP_0, skb);
+	status = ath10k_htc_send(htc, ATH10K_HTC_EP_0, skb, __LINE__);
 	if (status) {
 		kfree_skb(skb);
 		return status;
@@ -815,7 +819,7 @@ int ath10k_htc_start(struct ath10k_htc *htc)
 
 	ath10k_dbg(ATH10K_DBG_HTC, "HTC is using TX credit flow control\n");
 
-	status = ath10k_htc_send(htc, ATH10K_HTC_EP_0, skb);
+	status = ath10k_htc_send(htc, ATH10K_HTC_EP_0, skb, __LINE__);
 	if (status) {
 		kfree_skb(skb);
 		return status;
diff --git a/drivers/net/wireless/ath/ath10k/htc.h b/drivers/net/wireless/ath/ath10k/htc.h
index 4716d33..b74b07f 100644
--- a/drivers/net/wireless/ath/ath10k/htc.h
+++ b/drivers/net/wireless/ath/ath10k/htc.h
@@ -355,8 +355,12 @@ int ath10k_htc_start(struct ath10k_htc *htc);
 int ath10k_htc_connect_service(struct ath10k_htc *htc,
 			       struct ath10k_htc_svc_conn_req  *conn_req,
 			       struct ath10k_htc_svc_conn_resp *conn_resp);
+/* dbg is used for logging, trying to track roughly what kind of command
+ * we are sending and/or where it came from.  May help debug firmware
+ * issues where we do not get tx-credits returned properly.
+ */
 int ath10k_htc_send(struct ath10k_htc *htc, enum ath10k_htc_ep_id eid,
-		    struct sk_buff *packet);
+		    struct sk_buff *packet, int dbg);
 void ath10k_htc_stop(struct ath10k_htc *htc);
 struct sk_buff *ath10k_htc_alloc_skb(int size);
 
diff --git a/drivers/net/wireless/ath/ath10k/htt_tx.c b/drivers/net/wireless/ath/ath10k/htt_tx.c
index 7a3e2e4..22a4542 100644
--- a/drivers/net/wireless/ath/ath10k/htt_tx.c
+++ b/drivers/net/wireless/ath/ath10k/htt_tx.c
@@ -173,7 +173,7 @@ int ath10k_htt_h2t_ver_req_msg(struct ath10k_htt *htt)
 	cmd = (struct htt_cmd *)skb->data;
 	cmd->hdr.msg_type = HTT_H2T_MSG_TYPE_VERSION_REQ;
 
-	ret = ath10k_htc_send(&htt->ar->htc, htt->eid, skb);
+	ret = ath10k_htc_send(&htt->ar->htc, htt->eid, skb, __LINE__);
 	if (ret) {
 		dev_kfree_skb_any(skb);
 		return ret;
@@ -212,7 +212,7 @@ int ath10k_htt_h2t_stats_req(struct ath10k_htt *htt, u8 mask, u64 cookie)
 	req->cookie_lsb = cpu_to_le32(cookie & 0xffffffff);
 	req->cookie_msb = cpu_to_le32((cookie & 0xffffffff00000000ULL) >> 32);
 
-	ret = ath10k_htc_send(&htt->ar->htc, htt->eid, skb);
+	ret = ath10k_htc_send(&htt->ar->htc, htt->eid, skb, __LINE__);
 	if (ret) {
 		ath10k_warn("failed to send htt type stats request: %d", ret);
 		dev_kfree_skb_any(skb);
@@ -298,7 +298,7 @@ int ath10k_htt_send_rx_ring_cfg_ll(struct ath10k_htt *htt)
 
 #undef desc_offset
 
-	ret = ath10k_htc_send(&htt->ar->htc, htt->eid, skb);
+	ret = ath10k_htc_send(&htt->ar->htc, htt->eid, skb, __LINE__);
 	if (ret) {
 		dev_kfree_skb_any(skb);
 		return ret;
@@ -360,7 +360,7 @@ int ath10k_htt_mgmt_tx(struct ath10k_htt *htt, struct sk_buff *msdu)
 
 	skb_cb->htt.txbuf = NULL;
 
-	res = ath10k_htc_send(&htt->ar->htc, htt->eid, txdesc);
+	res = ath10k_htc_send(&htt->ar->htc, htt->eid, txdesc, __LINE__);
 	if (res)
 		goto err_unmap_msdu;
 
diff --git a/drivers/net/wireless/ath/ath10k/wmi.c b/drivers/net/wireless/ath/ath10k/wmi.c
index d4b48ef..433ec5a 100644
--- a/drivers/net/wireless/ath/ath10k/wmi.c
+++ b/drivers/net/wireless/ath/ath10k/wmi.c
@@ -544,7 +544,10 @@ static int ath10k_wmi_cmd_send_nowait(struct ath10k *ar, struct sk_buff *skb,
 	cmd_hdr->cmd_id = __cpu_to_le32(cmd);
 
 	memset(skb_cb, 0, sizeof(*skb_cb));
-	ret = ath10k_htc_send(&ar->htc, ar->wmi.eid, skb);
+	/* 0x71100000 is hack so that we know the debug value is a cmd-id
+	 * instead of a line number.
+	 */
+	ret = ath10k_htc_send(&ar->htc, ar->wmi.eid, skb, 0x71100000 | cmd_id);
 	trace_ath10k_wmi_cmd(cmd_id, skb->data, skb->len, ret);
 
 	if (ret)
-- 
1.7.11.7

[PATCH 2/4 v2] ath10k: better firmware loading error messages

[greearb]

From: Ben Greear <greearb@candelatech.com>

Let user know the name of the board file if it is not
found, and make it easier to determine the firmware
api being used.

Signed-off-by: Ben Greear <greearb@candelatech.com>
---

v2:  Incorporate Kalle's suggestions and sample code.

 drivers/net/wireless/ath/ath10k/core.c | 36 +++++++++++++++++++---------------
 1 file changed, 20 insertions(+), 16 deletions(-)

diff --git a/drivers/net/wireless/ath/ath10k/core.c b/drivers/net/wireless/ath/ath10k/core.c
index 471c219..79c7d48 100644
--- a/drivers/net/wireless/ath/ath10k/core.c
+++ b/drivers/net/wireless/ath/ath10k/core.c
@@ -398,8 +398,8 @@ static int ath10k_core_fetch_firmware_api_n(struct ath10k *ar, const char *name)
 	/* first fetch the firmware file (firmware-*.bin) */
 	ar->firmware = ath10k_fetch_fw_file(ar, ar->hw_params.fw.dir, name);
 	if (IS_ERR(ar->firmware)) {
-		ath10k_err("Could not fetch firmware file '%s': %ld\n",
-			   name, PTR_ERR(ar->firmware));
+		ath10k_err("could not fetch firmware file '%s/%s': %ld\n",
+			   ar->hw_params.fw.dir, name, PTR_ERR(ar->firmware));
 		return PTR_ERR(ar->firmware);
 	}
 
@@ -410,14 +410,14 @@ static int ath10k_core_fetch_firmware_api_n(struct ath10k *ar, const char *name)
 	magic_len = strlen(ATH10K_FIRMWARE_MAGIC) + 1;
 
 	if (len < magic_len) {
-		ath10k_err("firmware image too small to contain magic: %zu\n",
-			   len);
+		ath10k_err("firmware file '%s/%s' too small to contain magic: %zu\n",
+			   ar->hw_params.fw.dir, name, len);
 		ret = -EINVAL;
 		goto err;
 	}
 
 	if (memcmp(data, ATH10K_FIRMWARE_MAGIC, magic_len) != 0) {
-		ath10k_err("Invalid firmware magic\n");
+		ath10k_err("invalid firmware magic\n");
 		ret = -EINVAL;
 		goto err;
 	}
@@ -439,7 +439,7 @@ static int ath10k_core_fetch_firmware_api_n(struct ath10k *ar, const char *name)
 		data += sizeof(*hdr);
 
 		if (len < ie_len) {
-			ath10k_err("Invalid length for FW IE %d (%zu < %zu)\n",
+			ath10k_err("invalid length for FW IE %d (%zu < %zu)\n",
 				   ie_id, len, ie_len);
 			ret = -EINVAL;
 			goto err;
@@ -522,8 +522,8 @@ static int ath10k_core_fetch_firmware_api_n(struct ath10k *ar, const char *name)
 	}
 
 	if (!ar->firmware_data || !ar->firmware_len) {
-		ath10k_warn("No ATH10K_FW_IE_FW_IMAGE found from %s, skipping\n",
-			    name);
+		ath10k_warn("No ATH10K_FW_IE_FW_IMAGE found from '%s/%s', skipping\n",
+			    ar->hw_params.fw.dir, name);
 		ret = -ENOMEDIUM;
 		goto err;
 	}
@@ -540,7 +540,9 @@ static int ath10k_core_fetch_firmware_api_n(struct ath10k *ar, const char *name)
 					 ar->hw_params.fw.board);
 	if (IS_ERR(ar->board)) {
 		ret = PTR_ERR(ar->board);
-		ath10k_err("could not fetch board data (%d)\n", ret);
+		ath10k_err("could not fetch board data '%s/%s' (%d)\n",
+			   ar->hw_params.fw.dir, ar->hw_params.fw.board,
+			   ret);
 		goto err;
 	}
 
@@ -558,19 +560,21 @@ static int ath10k_core_fetch_firmware_files(struct ath10k *ar)
 {
 	int ret;
 
+	ar->fw_api = 2;
+	ath10k_dbg(ATH10K_DBG_BOOT, "trying fw api %d\n", ar->fw_api);
+
 	ret = ath10k_core_fetch_firmware_api_n(ar, ATH10K_FW_API2_FILE);
-	if (ret == 0) {
-		ar->fw_api = 2;
-		goto out;
-	}
+	if (ret == 0)
+		goto success;
+
+	ar->fw_api = 1;
+	ath10k_dbg(ATH10K_DBG_BOOT, "trying fw api %d\n", ar->fw_api);
 
 	ret = ath10k_core_fetch_firmware_api_1(ar);
 	if (ret)
 		return ret;
 
-	ar->fw_api = 1;
-
-out:
+success:
 	ath10k_dbg(ATH10K_DBG_BOOT, "using fw api %d\n", ar->fw_api);
 
 	return 0;
-- 
1.7.11.7

[PATCH 3/4 v2] ath10k: add otp and firmware boot error messages

[greearb]

From: Ben Greear <greearb@candelatech.com>

If OTP or firmware fails to load properly, print out some
extra info in the kernel logs.

Signed-off-by: Ben Greear <greearb@candelatech.com>
---
 drivers/net/wireless/ath/ath10k/core.c | 15 +++++++++++----
 1 file changed, 11 insertions(+), 4 deletions(-)

diff --git a/drivers/net/wireless/ath/ath10k/core.c b/drivers/net/wireless/ath/ath10k/core.c
index 79c7d48..da59c8a 100644
--- a/drivers/net/wireless/ath/ath10k/core.c
+++ b/drivers/net/wireless/ath/ath10k/core.c
@@ -255,7 +255,8 @@ static int ath10k_download_and_run_otp(struct ath10k *ar)
 	/* OTP is optional */
 
 	if (!ar->otp_data || !ar->otp_len) {
-		ath10k_warn("Not running otp, calibration will be incorrect!\n");
+		ath10k_warn("Not running otp, calibration will be incorrect (otp-data %p otp_len %zd)!\n",
+			    ar->otp_data, ar->otp_len);
 		return 0;
 	}
 
@@ -585,16 +586,22 @@ static int ath10k_init_download_firmware(struct ath10k *ar)
 	int ret;
 
 	ret = ath10k_download_board_data(ar);
-	if (ret)
+	if (ret) {
+		ath10k_err("failed to download board data: %d\n", ret);
 		return ret;
+	}
 
 	ret = ath10k_download_and_run_otp(ar);
-	if (ret)
+	if (ret) {
+		ath10k_err("failed to run otp: %d\n", ret);
 		return ret;
+	}
 
 	ret = ath10k_download_fw(ar);
-	if (ret)
+	if (ret) {
+		ath10k_err("failed to download firmware: %d\n", ret);
 		return ret;
+	}
 
 	return ret;
 }
-- 
1.7.11.7

[PATCH 4/4 v2] ath10k: invalid msdu-id logging

[greearb]

From: Ben Greear <greearb@candelatech.com>

Make this message more obvious that it is a serious
problem (will cause tx flush issues, at least).

Signed-off-by: Ben Greear <greearb@candelatech.com>
---

v2:  Add this to series, but ordering is not overly important.

 drivers/net/wireless/ath/ath10k/txrx.c | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/drivers/net/wireless/ath/ath10k/txrx.c b/drivers/net/wireless/ath/ath10k/txrx.c
index 0541dd9..9be5974 100644
--- a/drivers/net/wireless/ath/ath10k/txrx.c
+++ b/drivers/net/wireless/ath/ath10k/txrx.c
@@ -58,7 +58,7 @@ void ath10k_txrx_tx_unref(struct ath10k_htt *htt,
 		   tx_done->msdu_id, !!tx_done->discard, !!tx_done->no_ack);
 
 	if (tx_done->msdu_id >= htt->max_num_pending_tx) {
-		ath10k_warn("warning: msdu_id %d too big, ignoring\n",
+		ath10k_warn("error: msdu_id %d too big, ignoring\n",
 			    tx_done->msdu_id);
 		return;
 	}
-- 
1.7.11.7

Re: [PATCH 1/4 v2] ath10k: add debugging for tx-credits usage

[Kalle Valo]

greearb@candelatech.com writes:

> From: Ben Greear <greearb@candelatech.com>
>
> This helps track tx credits accounting and usage.  If
> firmware hangs or otherwise fails to return credits, one
> can more easily see the last few command types that
> was sent to the firmware.
>
> Signed-off-by: Ben Greear <greearb@candelatech.com>
> ---
>
> v2:  Improve comments.  Issue of using __LINE__ is not resolved.

I'm going to drop this patch 1 for now, I'm not really fond of the idea
using line numbers in debug messages. Hopefully we find an alternative
solution, like what Michal proposed.

-- 
Kalle Valo

Re: [PATCH 4/4 v2] ath10k: invalid msdu-id logging

[Kalle Valo]

greearb@candelatech.com writes:

> From: Ben Greear <greearb@candelatech.com>
>
> Make this message more obvious that it is a serious
> problem (will cause tx flush issues, at least).
>
> Signed-off-by: Ben Greear <greearb@candelatech.com>
> ---
>
> v2:  Add this to series, but ordering is not overly important.
>

[...]

> --- a/drivers/net/wireless/ath/ath10k/txrx.c
> +++ b/drivers/net/wireless/ath/ath10k/txrx.c
> @@ -58,7 +58,7 @@ void ath10k_txrx_tx_unref(struct ath10k_htt *htt,
>  		   tx_done->msdu_id, !!tx_done->discard, !!tx_done->no_ack);
>  
>  	if (tx_done->msdu_id >= htt->max_num_pending_tx) {
> -		ath10k_warn("warning: msdu_id %d too big, ignoring\n",
> +		ath10k_warn("error: msdu_id %d too big, ignoring\n",
>  			    tx_done->msdu_id);
>  		return;
>  	}

To me any warning is a serious matter, I'm not sure how changing this to
message to use "error:" makes any difference?

-- 
Kalle Valo

Re: [PATCH 4/4 v2] ath10k: invalid msdu-id logging

[Ben Greear]

On 03/25/2014 05:02 AM, Kalle Valo wrote:
> greearb@candelatech.com writes:
> 
>> From: Ben Greear <greearb@candelatech.com>
>>
>> Make this message more obvious that it is a serious
>> problem (will cause tx flush issues, at least).
>>
>> Signed-off-by: Ben Greear <greearb@candelatech.com>
>> ---
>>
>> v2:  Add this to series, but ordering is not overly important.
>>
> 
> [...]
> 
>> --- a/drivers/net/wireless/ath/ath10k/txrx.c
>> +++ b/drivers/net/wireless/ath/ath10k/txrx.c
>> @@ -58,7 +58,7 @@ void ath10k_txrx_tx_unref(struct ath10k_htt *htt,
>>  		   tx_done->msdu_id, !!tx_done->discard, !!tx_done->no_ack);
>>  
>>  	if (tx_done->msdu_id >= htt->max_num_pending_tx) {
>> -		ath10k_warn("warning: msdu_id %d too big, ignoring\n",
>> +		ath10k_warn("error: msdu_id %d too big, ignoring\n",
>>  			    tx_done->msdu_id);
>>  		return;
>>  	}
> 
> To me any warning is a serious matter, I'm not sure how changing this to
> message to use "error:" makes any difference?

To me, warning is bad, but probably not critical.  Error would be a failure that
is not (easily) recovered from.  In the case above, the result of this problem
would be effectively a reference counting leak that hangs the driver for 5 seconds
(under rtnl lock, I believe) each time the driver tries to flush.  This will never
recover until firmware is restarted.

So, I think it is more of an error than warning, but it is not a big deal
either way, so feel free to just drop the patch.

Thanks,
Ben


-- 
Ben Greear <greearb@candelatech.com>
Candela Technologies Inc  http://www.candelatech.com

Re: [PATCH 2/4 v2] ath10k: better firmware loading error messages

[Kalle Valo]

greearb@candelatech.com writes:

> From: Ben Greear <greearb@candelatech.com>
>
> Let user know the name of the board file if it is not
> found, and make it easier to determine the firmware
> api being used.
>
> Signed-off-by: Ben Greear <greearb@candelatech.com>

Thanks, patches 2 and 3 applied. Patches 1 and 4 dropped.

-- 
Kalle Valo