2014-03-21 18:56:52

by Ben Greear

[permalink] [raw]
Subject: [PATCH 1/3] ath10k: Add debugging for tx-credits usage.

From: Ben Greear <[email protected]>

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 send to the firmware.

Signed-off-by: Ben Greear <[email protected]>
---
drivers/net/wireless/ath/ath10k/htc.c | 16 ++++++++++------
drivers/net/wireless/ath/ath10k/htc.h | 2 +-
drivers/net/wireless/ath/ath10k/htt_tx.c | 8 ++++----
drivers/net/wireless/ath/ath10k/wmi.c | 2 +-
4 files changed, 16 insertions(+), 12 deletions(-)

diff --git a/drivers/net/wireless/ath/ath10k/htc.c b/drivers/net/wireless/ath/ath10k/htc.c
index ba3084c..bca5c41 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);
@@ -167,6 +167,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);
}

@@ -244,13 +248,13 @@ 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;
htc->ar->no_tx_credits_at = 0;

+ 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);
@@ -680,7 +684,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;
@@ -826,7 +830,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..b86dc2b 100644
--- a/drivers/net/wireless/ath/ath10k/htc.h
+++ b/drivers/net/wireless/ath/ath10k/htc.h
@@ -356,7 +356,7 @@ 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);
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 8b99e17..a8827e2 100644
--- a/drivers/net/wireless/ath/ath10k/wmi.c
+++ b/drivers/net/wireless/ath/ath10k/wmi.c
@@ -544,7 +544,7 @@ 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);
+ 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



2014-03-24 11:12:09

by Kalle Valo

[permalink] [raw]
Subject: Re: [PATCH 1/3] ath10k: Add debugging for tx-credits usage.

[email protected] writes:

> From: Ben Greear <[email protected]>
>
> 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 send to the firmware.
>
> Signed-off-by: Ben Greear <[email protected]>

This patchset didn't apply, and the sha1 ids were useless so that 3-way
merge didn't work. Can you rebase, please? And better yet if you rebase
in top of my master branch.

> 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);
> @@ -167,6 +167,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);
> }

[...]

> @@ -680,7 +684,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__);

Using line numbers in debug messages is very cumbersome. Some people
cherry pick patches, have their own changes and whatnot which will make
it more difficult to read the debug logs. Isn't there any better way to
do this?

> --- a/drivers/net/wireless/ath/ath10k/wmi.c
> +++ b/drivers/net/wireless/ath/ath10k/wmi.c
> @@ -544,7 +544,7 @@ 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);
> + ret = ath10k_htc_send(&ar->htc, ar->wmi.eid, skb, 0x71100000 | cmd_id);
> trace_ath10k_wmi_cmd(cmd_id, skb->data, skb->len, ret);

What does 0x71100000 stand for?

--
Kalle Valo

2014-03-26 14:40:45

by Ben Greear

[permalink] [raw]
Subject: Re: [PATCH 1/3] ath10k: Add debugging for tx-credits usage.

On 03/26/2014 12:18 AM, Michal Kazior wrote:
> On 25 March 2014 16:14, Ben Greear <[email protected]> wrote:
>> On 03/25/2014 12:27 AM, Michal Kazior wrote:
>>>
>>> On 24 March 2014 17:50, Ben Greear <[email protected]> wrote:
>>>>
>>>> On 03/24/2014 04:21 AM, Michal Kazior wrote:
>>>>>
>>>>> On 24 March 2014 12:12, Kalle Valo <[email protected]> wrote:
>>>>
>>>>
>>>>>>> - status = ath10k_htc_send(htc, ATH10K_HTC_EP_0, skb);
>>>>>>> + status = ath10k_htc_send(htc, ATH10K_HTC_EP_0, skb, __LINE__);
>>>>>>
>>>>>>
>>>>>> Using line numbers in debug messages is very cumbersome. Some people
>>>>>> cherry pick patches, have their own changes and whatnot which will make
>>>>>> it more difficult to read the debug logs. Isn't there any better way to
>>>>>> do this?
>>>>>
>>>>>
>>>>> I would prefer to explicitly wait for tx credit replenishment in
>>>>> ath10k_wmi_cmd_send() after a command is sent instead of all these
>>>>> prints. This way you can get a full call trace if it times out.
>>>>
>>>>
>>>> Would that be a performance problem (by effectively allowing only a
>>>> single
>>>> item to be sent to the firmware at any given time?)
>>>
>>>
>>> The only thing that may suffer here is wmi mgmt tx but I wouldn't
>>> consider that performance critical.
>>
>>
>> In that case, why use credits at all?
>
> Excellent question.
>
> Firmware provides 2 HTC tx credits for WMI. I guess this is on
> purpose. I imagine WMI mgmt tx can hang (i.e. not replenish tx
> credits). In that case the remaining tx credit could be used to try
> recovering, e.g. down/stop vdev (I think it should drop all pending tx
> and thus free the stuck HTC tx credit).
>
> It might be a good idea to keep this recovery strategy in mind when
> implementing the "wait for tx replenishment" wmi tx blocking.

Seems to me we should just fix the firmware to respond quickly..and if we know exactly which
command is not being answered (quickly) in the firmware, it might be easier to debug
it.

That said, while debugging I think I have seen cases where one message would
be consumed for a long time, and then suddenly it frees up again.

So, I'm not sure what to do. Maybe could improve firmware to return an id
so we know exactly which of the messages was processed, and then the driver
could do the work of figuring out what commands are outstanding by just keeping
a copy in RAM....

Thanks,
Ben

>
>
> Michał
>


--
Ben Greear <[email protected]>
Candela Technologies Inc http://www.candelatech.com


2014-03-26 19:41:28

by Janusz Dziedzic

[permalink] [raw]
Subject: Re: [PATCH 1/3] ath10k: Add debugging for tx-credits usage.

On 26 March 2014 15:40, Ben Greear <[email protected]> wrote:
> On 03/26/2014 12:18 AM, Michal Kazior wrote:
>>
>> On 25 March 2014 16:14, Ben Greear <[email protected]> wrote:
>>>
>>> On 03/25/2014 12:27 AM, Michal Kazior wrote:
>>>>
>>>>
>>>> On 24 March 2014 17:50, Ben Greear <[email protected]> wrote:
>>>>>
>>>>>
>>>>> On 03/24/2014 04:21 AM, Michal Kazior wrote:
>>>>>>
>>>>>>
>>>>>> On 24 March 2014 12:12, Kalle Valo <[email protected]> wrote:
>>>>>
>>>>>
>>>>>
>>>>>>>> - status = ath10k_htc_send(htc, ATH10K_HTC_EP_0, skb);
>>>>>>>> + status = ath10k_htc_send(htc, ATH10K_HTC_EP_0, skb, __LINE__);
>>>>>>>
>>>>>>>
>>>>>>>
>>>>>>> Using line numbers in debug messages is very cumbersome. Some people
>>>>>>> cherry pick patches, have their own changes and whatnot which will
>>>>>>> make
>>>>>>> it more difficult to read the debug logs. Isn't there any better way
>>>>>>> to
>>>>>>> do this?
>>>>>>
>>>>>>
>>>>>>
>>>>>> I would prefer to explicitly wait for tx credit replenishment in
>>>>>> ath10k_wmi_cmd_send() after a command is sent instead of all these
>>>>>> prints. This way you can get a full call trace if it times out.
>>>>>
>>>>>
>>>>>
>>>>> Would that be a performance problem (by effectively allowing only a
>>>>> single
>>>>> item to be sent to the firmware at any given time?)
>>>>
>>>>
>>>>
>>>> The only thing that may suffer here is wmi mgmt tx but I wouldn't
>>>> consider that performance critical.
>>>
>>>
>>>
>>> In that case, why use credits at all?
>>
>>
>> Excellent question.
>>
>> Firmware provides 2 HTC tx credits for WMI. I guess this is on
>> purpose. I imagine WMI mgmt tx can hang (i.e. not replenish tx
>> credits). In that case the remaining tx credit could be used to try
>> recovering, e.g. down/stop vdev (I think it should drop all pending tx
>> and thus free the stuck HTC tx credit).
>>
>> It might be a good idea to keep this recovery strategy in mind when
>> implementing the "wait for tx replenishment" wmi tx blocking.
>
>
> Seems to me we should just fix the firmware to respond quickly..and if we
> know exactly which
> command is not being answered (quickly) in the firmware, it might be easier
> to debug
> it.
>
> That said, while debugging I think I have seen cases where one message would
> be consumed for a long time, and then suddenly it frees up again.
>
> So, I'm not sure what to do. Maybe could improve firmware to return an id
> so we know exactly which of the messages was processed, and then the driver
> could do the work of figuring out what commands are outstanding by just
> keeping
> a copy in RAM....
>

I suspect mgmt_tx frames (for AP FW we send them using WMI) without
ACK couse this problem (disassoc + deauth probably). Question if we
saw this problem with 636 firmware? In 636 we send mgmt frames using
HTT, so we don't consume WMI credits.

I will try to reproduce this tommorow.

BR
Janusz

2014-03-24 16:50:38

by Ben Greear

[permalink] [raw]
Subject: Re: [PATCH 1/3] ath10k: Add debugging for tx-credits usage.

On 03/24/2014 04:21 AM, Michal Kazior wrote:
> On 24 March 2014 12:12, Kalle Valo <[email protected]> wrote:

>>> - status = ath10k_htc_send(htc, ATH10K_HTC_EP_0, skb);
>>> + status = ath10k_htc_send(htc, ATH10K_HTC_EP_0, skb, __LINE__);
>>
>> Using line numbers in debug messages is very cumbersome. Some people
>> cherry pick patches, have their own changes and whatnot which will make
>> it more difficult to read the debug logs. Isn't there any better way to
>> do this?
>
> I would prefer to explicitly wait for tx credit replenishment in
> ath10k_wmi_cmd_send() after a command is sent instead of all these
> prints. This way you can get a full call trace if it times out.

Would that be a performance problem (by effectively allowing only a single
item to be sent to the firmware at any given time?)

Thanks,
Ben


--
Ben Greear <[email protected]>
Candela Technologies Inc http://www.candelatech.com


2014-03-25 15:15:18

by Ben Greear

[permalink] [raw]
Subject: Re: [PATCH 1/3] ath10k: Add debugging for tx-credits usage.

On 03/25/2014 12:27 AM, Michal Kazior wrote:
> On 24 March 2014 17:50, Ben Greear <[email protected]> wrote:
>> On 03/24/2014 04:21 AM, Michal Kazior wrote:
>>> On 24 March 2014 12:12, Kalle Valo <[email protected]> wrote:
>>
>>>>> - status = ath10k_htc_send(htc, ATH10K_HTC_EP_0, skb);
>>>>> + status = ath10k_htc_send(htc, ATH10K_HTC_EP_0, skb, __LINE__);
>>>>
>>>> Using line numbers in debug messages is very cumbersome. Some people
>>>> cherry pick patches, have their own changes and whatnot which will make
>>>> it more difficult to read the debug logs. Isn't there any better way to
>>>> do this?
>>>
>>> I would prefer to explicitly wait for tx credit replenishment in
>>> ath10k_wmi_cmd_send() after a command is sent instead of all these
>>> prints. This way you can get a full call trace if it times out.
>>
>> Would that be a performance problem (by effectively allowing only a single
>> item to be sent to the firmware at any given time?)
>
> The only thing that may suffer here is wmi mgmt tx but I wouldn't
> consider that performance critical.

In that case, why use credits at all?

Thanks,
Ben

>
>
> Michał
> --
> To unsubscribe from this list: send the line "unsubscribe linux-wireless" in
> the body of a message to [email protected]
> More majordomo info at http://vger.kernel.org/majordomo-info.html
>


--
Ben Greear <[email protected]>
Candela Technologies Inc http://www.candelatech.com


2014-03-24 11:21:37

by Kalle Valo

[permalink] [raw]
Subject: Re: [PATCH 2/3] ath10k: Better firmware loading error messages.

[email protected] writes:

> From: Ben Greear <[email protected]>
>
> Let user know the name of the board file if it is not
> found, and make it easier to determine if it is api-1
> or api-n firmware logic that is complaining.
>
> Signed-off-by: Ben Greear <[email protected]>
> ---
> drivers/net/wireless/ath/ath10k/core.c | 30 ++++++++++++++++--------------
> 1 file changed, 16 insertions(+), 14 deletions(-)
>
> diff --git a/drivers/net/wireless/ath/ath10k/core.c b/drivers/net/wireless/ath/ath10k/core.c
> index 35f9db4..bf5119f 100644
> --- a/drivers/net/wireless/ath/ath10k/core.c
> +++ b/drivers/net/wireless/ath/ath10k/core.c
> @@ -398,7 +398,7 @@ 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",
> + ath10k_err("api-n: Could not fetch firmware file '%s': %ld\n",
> name, PTR_ERR(ar->firmware));
> return PTR_ERR(ar->firmware);
> }

I see the problem, but I don't think "api-n" is any better. What about
something along these lines (not a complete patch):

diff --git a/drivers/net/wireless/ath/ath10k/core.c b/drivers/net/wireless/ath/ath10k/core.c
index 471c219e5137..1b84c54449cf 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,8 +410,8 @@ 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;
}
@@ -558,19 +558,23 @@ 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;


--
Kalle Valo

2014-03-25 07:27:04

by Michal Kazior

[permalink] [raw]
Subject: Re: [PATCH 1/3] ath10k: Add debugging for tx-credits usage.

On 24 March 2014 17:50, Ben Greear <[email protected]> wrote:
> On 03/24/2014 04:21 AM, Michal Kazior wrote:
>> On 24 March 2014 12:12, Kalle Valo <[email protected]> wrote:
>
>>>> - status = ath10k_htc_send(htc, ATH10K_HTC_EP_0, skb);
>>>> + status = ath10k_htc_send(htc, ATH10K_HTC_EP_0, skb, __LINE__);
>>>
>>> Using line numbers in debug messages is very cumbersome. Some people
>>> cherry pick patches, have their own changes and whatnot which will make
>>> it more difficult to read the debug logs. Isn't there any better way to
>>> do this?
>>
>> I would prefer to explicitly wait for tx credit replenishment in
>> ath10k_wmi_cmd_send() after a command is sent instead of all these
>> prints. This way you can get a full call trace if it times out.
>
> Would that be a performance problem (by effectively allowing only a single
> item to be sent to the firmware at any given time?)

The only thing that may suffer here is wmi mgmt tx but I wouldn't
consider that performance critical.


Michał

2014-03-24 11:25:15

by Kalle Valo

[permalink] [raw]
Subject: Re: [PATCH 3/3] ath10k: add otp and firmware boot error messages.

[email protected] writes:

> From: Ben Greear <[email protected]>
>
> If OTP or firmware fails to load properly, print out some
> extra info in the kernel logs.
>
> Signed-off-by: Ben Greear <[email protected]>

[...]

> @@ -597,12 +598,16 @@ static int ath10k_init_download_firmware(struct ath10k *ar)
> return ret;
>
> ret = ath10k_download_and_run_otp(ar);
> - if (ret)
> + if (ret) {
> + ath10k_err("boot otp execute result %d\n", ret);
> return ret;
> + }

"failed to run otp: %d\n"

> ret = ath10k_download_fw(ar);
> - if (ret)
> + if (ret) {
> + ath10k_err("boot download firmware result %d\n", ret);
> return ret;
> + }

"failed to download firmware: %d\n"

And I think you should add the same for ath10k_download_board_data()
call before these two, it neither prints anything when an error happens.

--
Kalle Valo

2014-03-24 11:21:22

by Michal Kazior

[permalink] [raw]
Subject: Re: [PATCH 1/3] ath10k: Add debugging for tx-credits usage.

On 24 March 2014 12:12, Kalle Valo <[email protected]> wrote:
> [email protected] writes:
>
>> From: Ben Greear <[email protected]>
>>
>> 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 send to the firmware.
>>
>> Signed-off-by: Ben Greear <[email protected]>
>
> This patchset didn't apply, and the sha1 ids were useless so that 3-way
> merge didn't work. Can you rebase, please? And better yet if you rebase
> in top of my master branch.
>
>> 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);
>> @@ -167,6 +167,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);
>> }
>
> [...]
>
>> @@ -680,7 +684,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__);
>
> Using line numbers in debug messages is very cumbersome. Some people
> cherry pick patches, have their own changes and whatnot which will make
> it more difficult to read the debug logs. Isn't there any better way to
> do this?

I would prefer to explicitly wait for tx credit replenishment in
ath10k_wmi_cmd_send() after a command is sent instead of all these
prints. This way you can get a full call trace if it times out.


Michał

2014-03-21 18:56:37

by Ben Greear

[permalink] [raw]
Subject: [PATCH 2/3] ath10k: Better firmware loading error messages.

From: Ben Greear <[email protected]>

Let user know the name of the board file if it is not
found, and make it easier to determine if it is api-1
or api-n firmware logic that is complaining.

Signed-off-by: Ben Greear <[email protected]>
---
drivers/net/wireless/ath/ath10k/core.c | 30 ++++++++++++++++--------------
1 file changed, 16 insertions(+), 14 deletions(-)

diff --git a/drivers/net/wireless/ath/ath10k/core.c b/drivers/net/wireless/ath/ath10k/core.c
index 35f9db4..bf5119f 100644
--- a/drivers/net/wireless/ath/ath10k/core.c
+++ b/drivers/net/wireless/ath/ath10k/core.c
@@ -398,7 +398,7 @@ 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",
+ ath10k_err("api-n: Could not fetch firmware file '%s': %ld\n",
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",
+ ath10k_err("api-n: firmware image too small to contain magic: %zu\n",
len);
ret = -EINVAL;
goto err;
}

if (memcmp(data, ATH10K_FIRMWARE_MAGIC, magic_len) != 0) {
- ath10k_err("Invalid firmware magic\n");
+ ath10k_err("api-n: 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("api-n: Invalid length for FW IE %d (%zu < %zu)\n",
ie_id, len, ie_len);
ret = -EINVAL;
goto err;
@@ -454,7 +454,7 @@ static int ath10k_core_fetch_firmware_api_n(struct ath10k *ar, const char *name)
ar->hw->wiphy->fw_version[ie_len] = '\0';

ath10k_dbg(ATH10K_DBG_BOOT,
- "found fw version %s\n",
+ "api-n: found fw version %s\n",
ar->hw->wiphy->fw_version);
break;
case ATH10K_FW_IE_TIMESTAMP:
@@ -463,12 +463,12 @@ static int ath10k_core_fetch_firmware_api_n(struct ath10k *ar, const char *name)

timestamp = (__le32 *)data;

- ath10k_dbg(ATH10K_DBG_BOOT, "found fw timestamp %d\n",
+ ath10k_dbg(ATH10K_DBG_BOOT, "api-n: found fw timestamp %d\n",
le32_to_cpup(timestamp));
break;
case ATH10K_FW_IE_FEATURES:
ath10k_dbg(ATH10K_DBG_BOOT,
- "found firmware features ie (%zd B)\n",
+ "api-n: found firmware features ie (%zd B)\n",
ie_len);

for (i = 0; i < ATH10K_FW_FEATURE_COUNT; i++) {
@@ -492,7 +492,7 @@ static int ath10k_core_fetch_firmware_api_n(struct ath10k *ar, const char *name)
break;
case ATH10K_FW_IE_FW_IMAGE:
ath10k_dbg(ATH10K_DBG_BOOT,
- "found fw image ie (%zd B)\n",
+ "api-n: found fw image ie (%zd B)\n",
ie_len);

ar->firmware_data = data;
@@ -501,7 +501,7 @@ static int ath10k_core_fetch_firmware_api_n(struct ath10k *ar, const char *name)
break;
case ATH10K_FW_IE_OTP_IMAGE:
ath10k_dbg(ATH10K_DBG_BOOT,
- "found otp image ie (%zd B)\n",
+ "api-n: found otp image ie (%zd B)\n",
ie_len);

ar->otp_data = data;
@@ -514,12 +514,12 @@ static int ath10k_core_fetch_firmware_api_n(struct ath10k *ar, const char *name)
ar->fw_rom_bss_addr = le32_to_cpu(((u32*)(data))[2]);
ar->fw_rom_bss_len = le32_to_cpu(((u32*)(data))[3]);
ath10k_dbg(ATH10K_DBG_BOOT,
- "found FW bss info, RAM: addr 0x%x len 0x%x ROM: addr 0x%x len 0x%x\n",
+ "api-n: found FW bss info, RAM: addr 0x%x len 0x%x ROM: addr 0x%x len 0x%x\n",
ar->fw_ram_bss_addr, ar->fw_ram_bss_len,
ar->fw_rom_bss_addr, ar->fw_rom_bss_len);
break;
default:
- ath10k_warn("Unknown FW IE: %u\n",
+ ath10k_warn("api-n: Unknown FW IE: %u\n",
le32_to_cpu(hdr->id));
break;
}
@@ -532,7 +532,7 @@ 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",
+ ath10k_warn("api-n: No ATH10K_FW_IE_FW_IMAGE found from %s, skipping\n",
name);
ret = -ENOMEDIUM;
goto err;
@@ -540,7 +540,7 @@ static int ath10k_core_fetch_firmware_api_n(struct ath10k *ar, const char *name)

/* now fetch the board file */
if (ar->hw_params.fw.board == NULL) {
- ath10k_err("board data file not defined");
+ ath10k_err("api-n: board data file not defined");
ret = -EINVAL;
goto err;
}
@@ -550,7 +550,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("api-n: could not fetch board data %s/%s (%d)\n",
+ ar->hw_params.fw.dir, ar->hw_params.fw.board,
+ ret);
goto err;
}

--
1.7.11.7


2014-03-24 16:59:20

by Ben Greear

[permalink] [raw]
Subject: Re: [PATCH 1/3] ath10k: Add debugging for tx-credits usage.

On 03/24/2014 04:12 AM, Kalle Valo wrote:
> [email protected] writes:
>
>> From: Ben Greear <[email protected]>
>>
>> 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 send to the firmware.
>>
>> Signed-off-by: Ben Greear <[email protected]>
>
> This patchset didn't apply, and the sha1 ids were useless so that 3-way
> merge didn't work. Can you rebase, please? And better yet if you rebase
> in top of my master branch.

I will do this. I must have some conflicting patch between your top of
tree and this patch in my tree...

>> - status = ath10k_htc_send(htc, ATH10K_HTC_EP_0, skb);
>> + status = ath10k_htc_send(htc, ATH10K_HTC_EP_0, skb, __LINE__);
>
> Using line numbers in debug messages is very cumbersome. Some people
> cherry pick patches, have their own changes and whatnot which will make
> it more difficult to read the debug logs. Isn't there any better way to
> do this?

It is nasty, but I wanted to keep performance overhead light.
I could do an enum instead if you think that would be an improvement.

>> --- a/drivers/net/wireless/ath/ath10k/wmi.c
>> +++ b/drivers/net/wireless/ath/ath10k/wmi.c
>> @@ -544,7 +544,7 @@ 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);
>> + ret = ath10k_htc_send(&ar->htc, ar->wmi.eid, skb, 0x71100000 | cmd_id);
>> trace_ath10k_wmi_cmd(cmd_id, skb->data, skb->len, ret);
>
> What does 0x71100000 stand for?

It's just something that is easily grepped for, and is obviously not
a line number.

Hopefully someone will have a better idea how to do this sort of thing,
as my patch is pretty far down the slope towards total hack :)

Thanks,
Ben


--
Ben Greear <[email protected]>
Candela Technologies Inc http://www.candelatech.com


2014-03-26 07:18:21

by Michal Kazior

[permalink] [raw]
Subject: Re: [PATCH 1/3] ath10k: Add debugging for tx-credits usage.

On 25 March 2014 16:14, Ben Greear <[email protected]> wrote:
> On 03/25/2014 12:27 AM, Michal Kazior wrote:
>>
>> On 24 March 2014 17:50, Ben Greear <[email protected]> wrote:
>>>
>>> On 03/24/2014 04:21 AM, Michal Kazior wrote:
>>>>
>>>> On 24 March 2014 12:12, Kalle Valo <[email protected]> wrote:
>>>
>>>
>>>>>> - status = ath10k_htc_send(htc, ATH10K_HTC_EP_0, skb);
>>>>>> + status = ath10k_htc_send(htc, ATH10K_HTC_EP_0, skb, __LINE__);
>>>>>
>>>>>
>>>>> Using line numbers in debug messages is very cumbersome. Some people
>>>>> cherry pick patches, have their own changes and whatnot which will make
>>>>> it more difficult to read the debug logs. Isn't there any better way to
>>>>> do this?
>>>>
>>>>
>>>> I would prefer to explicitly wait for tx credit replenishment in
>>>> ath10k_wmi_cmd_send() after a command is sent instead of all these
>>>> prints. This way you can get a full call trace if it times out.
>>>
>>>
>>> Would that be a performance problem (by effectively allowing only a
>>> single
>>> item to be sent to the firmware at any given time?)
>>
>>
>> The only thing that may suffer here is wmi mgmt tx but I wouldn't
>> consider that performance critical.
>
>
> In that case, why use credits at all?

Excellent question.

Firmware provides 2 HTC tx credits for WMI. I guess this is on
purpose. I imagine WMI mgmt tx can hang (i.e. not replenish tx
credits). In that case the remaining tx credit could be used to try
recovering, e.g. down/stop vdev (I think it should drop all pending tx
and thus free the stuck HTC tx credit).

It might be a good idea to keep this recovery strategy in mind when
implementing the "wait for tx replenishment" wmi tx blocking.


Michał

2014-03-21 18:56:57

by Ben Greear

[permalink] [raw]
Subject: [PATCH 3/3] ath10k: add otp and firmware boot error messages.

From: Ben Greear <[email protected]>

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

Signed-off-by: Ben Greear <[email protected]>
---
drivers/net/wireless/ath/ath10k/core.c | 11 ++++++++---
1 file changed, 8 insertions(+), 3 deletions(-)

diff --git a/drivers/net/wireless/ath/ath10k/core.c b/drivers/net/wireless/ath/ath10k/core.c
index bf5119f..6b61aa7 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;
}

@@ -597,12 +598,16 @@ static int ath10k_init_download_firmware(struct ath10k *ar)
return ret;

ret = ath10k_download_and_run_otp(ar);
- if (ret)
+ if (ret) {
+ ath10k_err("boot otp execute result %d\n", ret);
return ret;
+ }

ret = ath10k_download_fw(ar);
- if (ret)
+ if (ret) {
+ ath10k_err("boot download firmware result %d\n", ret);
return ret;
+ }

return ret;
}
--
1.7.11.7