[PATCH] mwifiex: add support for SDIO card reset

[PATCH] mwifiex: add support for SDIO card reset

[Bing Zhao]

From: Amitkumar Karwar <akarwar@marvell.com>

When command timeout happens due to a bug in firmware/hardware,
the timeout handler just prints some debug information. User is
unable to reload the driver in this case.

Inspired by 9a821f5 "libertas: add sd8686 reset_card support",
this patch adds card reset support for SDIO interface when
command timeout happens. If the SDIO host contoller supports
MMC_POWER_OFF|UP|ON operations, the chip will be reset and the
firmware will be re-downloaded.

Signed-off-by: Amitkumar Karwar <akarwar@marvell.com>
Signed-off-by: Bing Zhao <bzhao@marvell.com>
---
 drivers/net/wireless/mwifiex/cmdevt.c |    3 +++
 drivers/net/wireless/mwifiex/main.h   |    1 +
 drivers/net/wireless/mwifiex/sdio.c   |   33 +++++++++++++++++++++++++++++++++
 drivers/net/wireless/mwifiex/sdio.h   |    1 +
 4 files changed, 38 insertions(+), 0 deletions(-)

diff --git a/drivers/net/wireless/mwifiex/cmdevt.c b/drivers/net/wireless/mwifiex/cmdevt.c
index da6c491..c9528b3 100644
--- a/drivers/net/wireless/mwifiex/cmdevt.c
+++ b/drivers/net/wireless/mwifiex/cmdevt.c
@@ -944,6 +944,9 @@ mwifiex_cmd_timeout_func(unsigned long function_context)
 	}
 	if (adapter->hw_status == MWIFIEX_HW_STATUS_INITIALIZING)
 		mwifiex_init_fw_complete(adapter);
+
+	if (adapter->if_ops.card_reset)
+		adapter->if_ops.card_reset(adapter);
 }
 
 /*
diff --git a/drivers/net/wireless/mwifiex/main.h b/drivers/net/wireless/mwifiex/main.h
index 81f8772..68f3646 100644
--- a/drivers/net/wireless/mwifiex/main.h
+++ b/drivers/net/wireless/mwifiex/main.h
@@ -600,6 +600,7 @@ struct mwifiex_if_ops {
 	int (*event_complete) (struct mwifiex_adapter *, struct sk_buff *);
 	int (*data_complete) (struct mwifiex_adapter *, struct sk_buff *);
 	int (*dnld_fw) (struct mwifiex_adapter *, struct mwifiex_fw_image *);
+	void (*card_reset) (struct mwifiex_adapter *);
 };
 
 struct mwifiex_adapter {
diff --git a/drivers/net/wireless/mwifiex/sdio.c b/drivers/net/wireless/mwifiex/sdio.c
index 8b81d8a..b3680f7 100644
--- a/drivers/net/wireless/mwifiex/sdio.c
+++ b/drivers/net/wireless/mwifiex/sdio.c
@@ -1748,6 +1748,37 @@ mwifiex_update_mp_end_port(struct mwifiex_adapter *adapter, u16 port)
 		port, card->mp_data_port_mask);
 }
 
+static struct mmc_host *reset_host;
+static void sdio_card_reset_worker(struct work_struct *work)
+{
+	/* The actual reset operation must be run outside of driver thread.
+	 * This is because mmc_remove_host() will cause the device to be
+	 * instantly destroyed, and the driver then needs to end its thread,
+	 * leading to a deadlock.
+	 *
+	 * We run it in a totally independent workqueue.
+	 */
+
+	pr_err("Resetting card...\n");
+	mmc_remove_host(reset_host);
+	/* 20ms delay is based on experiment with sdhci controller */
+	mdelay(20);
+	mmc_add_host(reset_host);
+}
+static DECLARE_WORK(card_reset_work, sdio_card_reset_worker);
+
+/* This function resets the card */
+static void mwifiex_sdio_card_reset(struct mwifiex_adapter *adapter)
+{
+	struct sdio_mmc_card *card = adapter->card;
+
+	if (work_pending(&card_reset_work))
+		return;
+
+	reset_host = card->func->card->host;
+	schedule_work(&card_reset_work);
+}
+
 static struct mwifiex_if_ops sdio_ops = {
 	.init_if = mwifiex_init_sdio,
 	.cleanup_if = mwifiex_cleanup_sdio,
@@ -1766,6 +1797,7 @@ static struct mwifiex_if_ops sdio_ops = {
 	.cleanup_mpa_buf = mwifiex_cleanup_mpa_buf,
 	.cmdrsp_complete = mwifiex_sdio_cmdrsp_complete,
 	.event_complete = mwifiex_sdio_event_complete,
+	.card_reset = mwifiex_sdio_card_reset,
 };
 
 /*
@@ -1803,6 +1835,7 @@ mwifiex_sdio_cleanup_module(void)
 	/* Set the flag as user is removing this module. */
 	user_rmmod = 1;
 
+	cancel_work_sync(&card_reset_work);
 	sdio_unregister_driver(&mwifiex_sdio);
 }
 
diff --git a/drivers/net/wireless/mwifiex/sdio.h b/drivers/net/wireless/mwifiex/sdio.h
index 2103373..8cc5468 100644
--- a/drivers/net/wireless/mwifiex/sdio.h
+++ b/drivers/net/wireless/mwifiex/sdio.h
@@ -25,6 +25,7 @@
 #include <linux/mmc/sdio_ids.h>
 #include <linux/mmc/sdio_func.h>
 #include <linux/mmc/card.h>
+#include <linux/mmc/host.h>
 
 #include "main.h"
 
-- 
1.7.0.2

Re: [PATCH] mwifiex: add support for SDIO card reset

[Tim Shepard]

Bing,

I am trying to figure out if this patch would help in the situation I
told you about in September.

I was doing suspend/resume testing using

  rtcwake -s 6 -mmem

in a loop to test the ability of the mwifiex driver to suspend/resume.

I was seeing sporadic failures (wedgeups), and the majority of those
failures I saw printed the printouts in mwifiex_cmd_timeout_func with
cmd = 0xe5 which is CMD_802_11_HS_CFG_ENH.  When this happens, two
minutes later I get notified that the rtcwake thread is blocked, like
this:

      INFO: task rtcwake:3495 blocked for more than 120 seconds.



I believe the hang happens when mwifiex_sdio_suspend() is called in
the rtcwake thread it winds winds up blocked waiting on a wait queue
in mwifiex_enable_hs() because when the timeout happens it never gets
woken up.

Reading your patch today, I don't see how your patch will add a new
way to get that hung thread unblocked.  

(I'm also not sure doing the reset of the card will work properly while
 the system is in the middle of trying to suspend, but that's a
 different question.)

If I'm missing a clue about this, please let me know.


			-Tim Shepard
			 shep@laptop.org

RE: [PATCH] mwifiex: add support for SDIO card reset

[Bing Zhao]

[-- Attachment #1: Type: text/plain, Size: 2197 bytes --]

Hi Tim,

> Bing,
> 
> I am trying to figure out if this patch would help in the situation I
> told you about in September.
> 
> I was doing suspend/resume testing using
> 
>   rtcwake -s 6 -mmem
> 
> in a loop to test the ability of the mwifiex driver to suspend/resume.
> 
> I was seeing sporadic failures (wedgeups), and the majority of those
> failures I saw printed the printouts in mwifiex_cmd_timeout_func with
> cmd = 0xe5 which is CMD_802_11_HS_CFG_ENH.  When this happens, two
> minutes later I get notified that the rtcwake thread is blocked, like
> this:
> 
>       INFO: task rtcwake:3495 blocked for more than 120 seconds.
> 
> 
> 
> I believe the hang happens when mwifiex_sdio_suspend() is called in
> the rtcwake thread it winds winds up blocked waiting on a wait queue
> in mwifiex_enable_hs() because when the timeout happens it never gets
> woken up.

You can try it with an asynchronous call.

diff --git a/drivers/net/wireless/mwifiex/sta_ioctl.c b/drivers/net/wireless/mwi
index c8b50c7..704d344 100644
--- a/drivers/net/wireless/mwifiex/sta_ioctl.c
+++ b/drivers/net/wireless/mwifiex/sta_ioctl.c
@@ -472,7 +472,7 @@ int mwifiex_enable_hs(struct mwifiex_adapter *adapter)

        if (mwifiex_set_hs_params(mwifiex_get_priv(adapter,
                                                   MWIFIEX_BSS_ROLE_STA),
-                                 HostCmd_ACT_GEN_SET, MWIFIEX_SYNC_CMD,
+                                 HostCmd_ACT_GEN_SET, MWIFIEX_ASYNC_CMD,
                                  &hscfg)) {
                dev_err(adapter->dev, "IOCTL request HS enable failed\n");
                return false;

If this doesn't help, please apply the debug patch attached. Hopefully we can get some useful information.

Thanks,
Bing

> 
> Reading your patch today, I don't see how your patch will add a new
> way to get that hung thread unblocked.
> 
> (I'm also not sure doing the reset of the card will work properly while
>  the system is in the middle of trying to suspend, but that's a
>  different question.)
> 
> If I'm missing a clue about this, please let me know.
> 
> 
> 			-Tim Shepard
> 			 shep@laptop.org

[-- Attachment #2: mwifiex_v3.7rc3_debug_suspend_resume.diff --]
[-- Type: application/octet-stream, Size: 6818 bytes --]

diff --git a/drivers/net/wireless/mwifiex/cmdevt.c b/drivers/net/wireless/mwifiex/cmdevt.c
index c9528b3..de23947 100644
--- a/drivers/net/wireless/mwifiex/cmdevt.c
+++ b/drivers/net/wireless/mwifiex/cmdevt.c
@@ -186,7 +186,7 @@ static int mwifiex_dnld_cmd_to_fw(struct mwifiex_private *priv,
 		skb_put(cmd_node->cmd_skb, cmd_size - cmd_node->cmd_skb->len);
 
 	do_gettimeofday(&tstamp);
-	dev_dbg(adapter->dev, "cmd: DNLD_CMD: (%lu.%lu): %#x, act %#x, len %d,"
+	dev_info(adapter->dev, "cmd: DNLD_CMD: (%lu.%lu): %#x, act %#x, len %d,"
 		" seqno %#x\n",
 		tstamp.tv_sec, tstamp.tv_usec, cmd_code,
 		le16_to_cpu(*(__le16 *) ((u8 *) host_cmd + S_DS_GEN)), cmd_size,
@@ -449,6 +449,8 @@ int mwifiex_process_event(struct mwifiex_adapter *adapter)
 		rx_info->bss_type = priv->bss_type;
 	}
 
+	dev_info(adapter->dev, "event: %lu.%lu: cause: %#x\n",
+		tstamp.tv_sec, tstamp.tv_usec, eventcause);
 	if (eventcause != EVENT_PS_SLEEP && eventcause != EVENT_PS_AWAKE) {
 		do_gettimeofday(&tstamp);
 		dev_dbg(adapter->dev, "event: %lu.%lu: cause: %#x\n",
@@ -817,7 +819,7 @@ int mwifiex_process_cmdresp(struct mwifiex_adapter *adapter)
 								orig_cmdresp_no;
 
 	do_gettimeofday(&tstamp);
-	dev_dbg(adapter->dev, "cmd: CMD_RESP: (%lu.%lu): 0x%x, result %d,"
+	dev_info(adapter->dev, "cmd: CMD_RESP: (%lu.%lu): 0x%x, result %d,"
 		" len %d, seqno 0x%x\n",
 	       tstamp.tv_sec, tstamp.tv_usec, orig_cmdresp_no, cmdresp_result,
 	       le16_to_cpu(resp->size), le16_to_cpu(resp->seq_num));
@@ -1096,15 +1098,15 @@ mwifiex_hs_activated_event(struct mwifiex_private *priv, u8 activated)
 			priv->adapter->hs_activated = true;
 			mwifiex_update_rxreor_flags(priv->adapter,
 						    RXREOR_FORCE_NO_DROP);
-			dev_dbg(priv->adapter->dev, "event: hs_activated\n");
+			dev_info(priv->adapter->dev, "event: hs_activated\n");
 			priv->adapter->hs_activate_wait_q_woken = true;
 			wake_up_interruptible(
 				&priv->adapter->hs_activate_wait_q);
 		} else {
-			dev_dbg(priv->adapter->dev, "event: HS not configured\n");
+			dev_info(priv->adapter->dev, "event: HS not configured\n");
 		}
 	} else {
-		dev_dbg(priv->adapter->dev, "event: hs_deactivated\n");
+		dev_info(priv->adapter->dev, "event: hs_deactivated\n");
 		priv->adapter->hs_activated = false;
 	}
 }
diff --git a/drivers/net/wireless/mwifiex/sdio.c b/drivers/net/wireless/mwifiex/sdio.c
index 90a87b5..02e2137 100644
--- a/drivers/net/wireless/mwifiex/sdio.c
+++ b/drivers/net/wireless/mwifiex/sdio.c
@@ -165,9 +165,11 @@ static int mwifiex_sdio_suspend(struct device *dev)
 	int i;
 	int ret = 0;
 
+	pr_info("%s entry dev=%p\n", __func__, dev);
+
 	if (func) {
 		pm_flag = sdio_get_host_pm_caps(func);
-		pr_debug("cmd: %s: suspend: PM flag = 0x%x\n",
+		pr_info("cmd: %s: suspend: PM flag = 0x%x\n",
 			 sdio_func_id(func), pm_flag);
 		if (!(pm_flag & MMC_PM_KEEP_POWER)) {
 			pr_err("%s: cannot remain alive while host is"
@@ -190,7 +192,7 @@ static int mwifiex_sdio_suspend(struct device *dev)
 	/* Enable the Host Sleep */
 	hs_actived = mwifiex_enable_hs(adapter);
 	if (hs_actived) {
-		pr_debug("cmd: suspend with MMC_PM_KEEP_POWER\n");
+		pr_info("cmd: suspend with MMC_PM_KEEP_POWER\n");
 		ret = sdio_set_host_pm_flags(func, MMC_PM_KEEP_POWER);
 	}
 
@@ -221,6 +223,8 @@ static int mwifiex_sdio_resume(struct device *dev)
 	mmc_pm_flag_t pm_flag = 0;
 	int i;
 
+	pr_info("%s entry dev=%p\n", __func__, dev);
+
 	if (func) {
 		pm_flag = sdio_get_host_pm_caps(func);
 		card = sdio_get_drvdata(func);
@@ -242,6 +246,12 @@ static int mwifiex_sdio_resume(struct device *dev)
 
 	adapter->is_suspended = false;
 
+	if (!adapter->hs_activated) {
+		dev_warn(adapter->dev,
+			 "host sleep deactivated before suspend\n");
+		//adapter->if_ops.wakeup(adapter);
+	}
+
 	for (i = 0; i < adapter->priv_num; i++)
 		if (adapter->priv[i]->media_connected)
 			netif_carrier_on(adapter->priv[i]->netdev);
@@ -914,6 +924,7 @@ mwifiex_sdio_interrupt(struct sdio_func *func)
 	struct mwifiex_adapter *adapter;
 	struct sdio_mmc_card *card;
 
+	printk("*");
 	card = sdio_get_drvdata(func);
 	if (!card || !card->adapter) {
 		pr_debug("int: func=%p card=%p adapter=%p\n",
diff --git a/drivers/net/wireless/mwifiex/sta_cmdresp.c b/drivers/net/wireless/mwifiex/sta_cmdresp.c
index 65c12eb..bb1df82 100644
--- a/drivers/net/wireless/mwifiex/sta_cmdresp.c
+++ b/drivers/net/wireless/mwifiex/sta_cmdresp.c
@@ -51,6 +51,9 @@ mwifiex_process_cmdresp_error(struct mwifiex_private *priv,
 	dev_err(adapter->dev, "CMD_RESP: cmd %#x error, result=%#x\n",
 		resp->command, resp->result);
 
+	print_hex_dump(KERN_DEBUG, "CMDRESP:", DUMP_PREFIX_OFFSET, 16, 1, resp, le16_to_cpu(resp->size), false);
+	printk(KERN_DEBUG "\n");
+
 	if (adapter->curr_cmd->wait_q_enabled)
 		adapter->cmd_wait_q.status = -1;
 
diff --git a/drivers/net/wireless/mwifiex/sta_ioctl.c b/drivers/net/wireless/mwifiex/sta_ioctl.c
index c8b50c7..1f471df 100644
--- a/drivers/net/wireless/mwifiex/sta_ioctl.c
+++ b/drivers/net/wireless/mwifiex/sta_ioctl.c
@@ -360,7 +360,7 @@ static int mwifiex_set_hs_params(struct mwifiex_private *priv, u16 action,
 	switch (action) {
 	case HostCmd_ACT_GEN_SET:
 		if (adapter->pps_uapsd_mode) {
-			dev_dbg(adapter->dev, "info: Host Sleep IOCTL"
+			dev_info(adapter->dev, "info: Host Sleep IOCTL"
 				" is blocked in UAPSD/PPS mode\n");
 			status = -1;
 			break;
@@ -388,6 +388,9 @@ static int mwifiex_set_hs_params(struct mwifiex_private *priv, u16 action,
 				status = -1;
 				break;
 			}
+			dev_info(adapter->dev, "%s: %#x %#x %#x\n", __func__,
+				adapter->hs_cfg.conditions,
+				adapter->hs_cfg.gpio, adapter->hs_cfg.gap);
 			if (cmd_type == MWIFIEX_SYNC_CMD)
 				status = mwifiex_send_cmd_sync(priv,
 						HostCmd_CMD_802_11_HS_CFG_ENH,
@@ -398,6 +401,7 @@ static int mwifiex_set_hs_params(struct mwifiex_private *priv, u16 action,
 						HostCmd_CMD_802_11_HS_CFG_ENH,
 						HostCmd_ACT_GEN_SET, 0,
 						&adapter->hs_cfg);
+			dev_info(adapter->dev, "%s: HS_CFG_ENH sent\n", __func__);
 			if (hs_cfg->conditions == HOST_SLEEP_CFG_CANCEL)
 				/* Restore previous condition */
 				adapter->hs_cfg.conditions =
@@ -452,6 +456,7 @@ int mwifiex_enable_hs(struct mwifiex_adapter *adapter)
 	struct mwifiex_private *priv;
 	int i;
 
+	dev_info(adapter->dev, "%s: hs_activated=%d\n", __func__, adapter->hs_activated);
 	if (disconnect_on_suspend) {
 		for (i = 0; i < adapter->priv_num; i++) {
 			priv = adapter->priv[i];
@@ -478,8 +483,10 @@ int mwifiex_enable_hs(struct mwifiex_adapter *adapter)
 		return false;
 	}
 
+	dev_info(adapter->dev, "%s: waiting for event, hs_activated=%d\n", __func__, adapter->hs_activated);
 	wait_event_interruptible(adapter->hs_activate_wait_q,
 				 adapter->hs_activate_wait_q_woken);
+	dev_info(adapter->dev, "%s: return hs_activated=%d\n", __func__, adapter->hs_activated);
 
 	return true;
 }

RE: [PATCH] mwifiex: add support for SDIO card reset

[Bing Zhao]

Hi Tim,

> Bing,
> 
> I am trying to figure out if this patch would help in the situation I
> told you about in September.
> 
> I was doing suspend/resume testing using
> 
>   rtcwake -s 6 -mmem

Since the command times out in 10 seconds, please change the sleep time to 11 or longer for your tests. For example,

rtcwake -s 12 -mmem

> 
> in a loop to test the ability of the mwifiex driver to suspend/resume.
> 
> I was seeing sporadic failures (wedgeups), and the majority of those
> failures I saw printed the printouts in mwifiex_cmd_timeout_func with
> cmd = 0xe5 which is CMD_802_11_HS_CFG_ENH.  When this happens, two
> minutes later I get notified that the rtcwake thread is blocked, like
> this:
> 
>       INFO: task rtcwake:3495 blocked for more than 120 seconds.

In this case, we should wake up the command wait queue and cancel the pending iotcl when timeout happens.

diff --git a/drivers/net/wireless/mwifiex/cmdevt.c b/drivers/net/wireless/mwifiex/cmdevt.c
index c9528b3..0847cf0 100644
--- a/drivers/net/wireless/mwifiex/cmdevt.c
+++ b/drivers/net/wireless/mwifiex/cmdevt.c
@@ -890,9 +890,6 @@ mwifiex_cmd_timeout_func(unsigned long function_context)
 		return;
 	}
 	cmd_node = adapter->curr_cmd;
-	if (cmd_node->wait_q_enabled)
-		adapter->cmd_wait_q.status = -ETIMEDOUT;
-
 	if (cmd_node) {
 		adapter->dbg.timeout_cmd_id =
 			adapter->dbg.last_cmd_id[adapter->dbg.last_cmd_index];
@@ -941,6 +938,12 @@ mwifiex_cmd_timeout_func(unsigned long function_context)
 
 		dev_err(adapter->dev, "ps_mode=%d ps_state=%d\n",
 			adapter->ps_mode, adapter->ps_state);
+
+		if (cmd_node->wait_q_enabled) {
+			adapter->cmd_wait_q.status = -ETIMEDOUT;
+			wake_up_interruptible(&adapter->cmd_wait_q.wait);
+			mwifiex_cancel_pending_ioctl(adapter);
+		}
 	}
 	if (adapter->hw_status == MWIFIEX_HW_STATUS_INITIALIZING)
 		mwifiex_init_fw_complete(adapter);

> 
> 
> 
> I believe the hang happens when mwifiex_sdio_suspend() is called in
> the rtcwake thread it winds winds up blocked waiting on a wait queue
> in mwifiex_enable_hs() because when the timeout happens it never gets
> woken up.
> 
> Reading your patch today, I don't see how your patch will add a new
> way to get that hung thread unblocked.

Above change should get the hung thread unblocked.

> 
> (I'm also not sure doing the reset of the card will work properly while
>  the system is in the middle of trying to suspend, but that's a
>  different question.)

When suspend command (0xe5) fails we should return failure to MMC core. Once the card is reset the next suspend attempt will likely succeed.

diff --git a/drivers/net/wireless/mwifiex/sdio.c b/drivers/net/wireless/mwifiex/sdio.c
index 90a87b5..9779fae 100644
--- a/drivers/net/wireless/mwifiex/sdio.c
+++ b/drivers/net/wireless/mwifiex/sdio.c
@@ -189,11 +189,14 @@ static int mwifiex_sdio_suspend(struct device *dev)
 
 	/* Enable the Host Sleep */
 	hs_actived = mwifiex_enable_hs(adapter);
-	if (hs_actived) {
-		pr_debug("cmd: suspend with MMC_PM_KEEP_POWER\n");
-		ret = sdio_set_host_pm_flags(func, MMC_PM_KEEP_POWER);
+	if (!hs_actived) {
+		dev_err(adapter->dev, "cmd: failed to suspend\n");
+		return -EFAULT;
 	}
 
+	dev_dbg(adapter->dev, "cmd: suspend with MMC_PM_KEEP_POWER\n");
+	ret = sdio_set_host_pm_flags(func, MMC_PM_KEEP_POWER);
+
 	/* Indicate device suspended */
 	adapter->is_suspended = true;

Please give it a try with this card reset patch and above two changes applied.

Thanks,
Bing

Re: [PATCH] mwifiex: add support for SDIO card reset

[Tim Shepard]

Bing,

Thanks, that looks like it might fix the total wedgeup problem I was
seeing on some suspends.

I will try to test this in the next few days.

However, I am limited in my ability to test this.  At best, I could
produce only a few such failures per day of testing, and that was with
the SDIO dev kit, not with our protype cards.  It seems to test this
directly and repeatedly I would have to have a modified version of the
firmware that would deliberately cause on command what is normally
only a sporadic failure.

I will also try to understand how this patch behaves in the context of
the rest of the driver.

			-Tim Shepard
			 shep@laptop.org

Re: [PATCH] mwifiex: add support for SDIO card reset

[Tim Shepard]

Bing,

I have now managed to test your patches from 6-November-2012, but I
still get system wedgeups eventually whenever a command timeout happens.

To make the timeouts happen regularly enough to test this, I went
back to a 3.5.2 kernel.org kernel (so I no longer have your
adjustment to HOST_SLEEP_CFG_GAP_DEF).  I applied your patch to the
functions mwifiex_cmd_timeout_func and mwifiex_sdio_suspend from your
e-mail and ran my suspend/resume in a loop test.  Diff against
kernel.org v3.5.2 linux included below (contains just your two
patches from 6-November-2012 e-mail).

The difference now is that the first such timeout on an attempted
suspend (while waiting for a response to the host sleep command) the
system fails to suspend but continues running.  The second time it
attempts to suspend, then it wedges the system.

I have complete serial console log from initial boot to wedge up of
four such cases, and have put them up at 

     http://dev.laptop.org/~shep/bzhao_20121106_tests/


It looks like the card is not getting reset as you had intended.  (I
need to investigate the control of having the card powered down on
suspend for other reasons anyway, so I might be able to figure this
out also.)



I did notice that the mwifiex_cmd_timeout_func incidents are
preceded by one of these (before the previous suspend attempt):

     mwifiex_sdio mmc1:0001:1: card_to_host_mpa failed: int status=0x1

but I also see that error message earlier in some of the logs in which
case things are still working after such an error.

Sometimes the above error is paired up with a "read iomem failed"
message like this:

 [ 4131.795129] mwifiex_sdio mmc1:0001:1: mwifiex_sdio_card_to_host: read iomem failed: -1
 [ 4131.823222] mwifiex_sdio mmc1:0001:1: card_to_host_mpa failed: int status=0x1

Maybe it would help to understand why these are happening and if they
are closer to the root cause of the timeouts in the first place.
(But remember, HOST_SLEEP_CFG_GAP_DEF is back to zero in these tests,
so that I could get enough events to test mwifiex_cmd_timeout_func.)

			-Tim Shepard
			 shep@laptop.org

 ___ _ ___ _   _ _ ___   ___     _ _ _ _   _   _ ___ _   _   _ ___ _ ___ _ ___

diff --git a/drivers/net/wireless/mwifiex/cmdevt.c b/drivers/net/wireless/mwifiex/cmdevt.c
index 51e023e..f4e0919 100644
--- a/drivers/net/wireless/mwifiex/cmdevt.c
+++ b/drivers/net/wireless/mwifiex/cmdevt.c
@@ -873,9 +873,6 @@ mwifiex_cmd_timeout_func(unsigned long function_context)
 		return;
 	}
 	cmd_node = adapter->curr_cmd;
-	if (cmd_node->wait_q_enabled)
-		adapter->cmd_wait_q.status = -ETIMEDOUT;
-
 	if (cmd_node) {
 		adapter->dbg.timeout_cmd_id =
 			adapter->dbg.last_cmd_id[adapter->dbg.last_cmd_index];
@@ -921,6 +918,12 @@ mwifiex_cmd_timeout_func(unsigned long function_context)
 
 		dev_err(adapter->dev, "ps_mode=%d ps_state=%d\n",
 			adapter->ps_mode, adapter->ps_state);
+
+		if (cmd_node->wait_q_enabled) {
+			adapter->cmd_wait_q.status = -ETIMEDOUT;
+			wake_up_interruptible(&adapter->cmd_wait_q.wait);
+			mwifiex_cancel_pending_ioctl(adapter);
+		}
 	}
 	if (adapter->hw_status == MWIFIEX_HW_STATUS_INITIALIZING)
 		mwifiex_init_fw_complete(adapter);
diff --git a/drivers/net/wireless/mwifiex/sdio.c b/drivers/net/wireless/mwifiex/sdio.c
index fc8a9bf..8597a77 100644
--- a/drivers/net/wireless/mwifiex/sdio.c
+++ b/drivers/net/wireless/mwifiex/sdio.c
@@ -189,11 +189,14 @@ static int mwifiex_sdio_suspend(struct device *dev)
 
 	/* Enable the Host Sleep */
 	hs_actived = mwifiex_enable_hs(adapter);
-	if (hs_actived) {
-		pr_debug("cmd: suspend with MMC_PM_KEEP_POWER\n");
-		ret = sdio_set_host_pm_flags(func, MMC_PM_KEEP_POWER);
+	if (!hs_actived) {
+		dev_err(adapter->dev, "cmd: failed to suspend\n");
+		return -EFAULT;
 	}
 
+	dev_dbg(adapter->dev, "cmd: suspend with MMC_PM_KEEP_POWER\n");
+	ret = sdio_set_host_pm_flags(func, MMC_PM_KEEP_POWER);
+
 	/* Indicate device suspended */
 	adapter->is_suspended = true;
 

RE: [PATCH] mwifiex: add support for SDIO card reset

[Bing Zhao]

Hi Tim,

> Bing,
> 
> I have now managed to test your patches from 6-November-2012, but I
> still get system wedgeups eventually whenever a command timeout happens.
> 
> To make the timeouts happen regularly enough to test this, I went
> back to a 3.5.2 kernel.org kernel (so I no longer have your
> adjustment to HOST_SLEEP_CFG_GAP_DEF).  I applied your patch to the
> functions mwifiex_cmd_timeout_func and mwifiex_sdio_suspend from your
> e-mail and ran my suspend/resume in a loop test.  Diff against
> kernel.org v3.5.2 linux included below (contains just your two
> patches from 6-November-2012 e-mail).
> 
> The difference now is that the first such timeout on an attempted
> suspend (while waiting for a response to the host sleep command) the
> system fails to suspend but continues running.  The second time it
> attempts to suspend, then it wedges the system.
> 
> I have complete serial console log from initial boot to wedge up of
> four such cases, and have put them up at
> 
>      http://dev.laptop.org/~shep/bzhao_20121106_tests/
> 
> 
> It looks like the card is not getting reset as you had intended.  (I
> need to investigate the control of having the card powered down on
> suspend for other reasons anyway, so I might be able to figure this
> out also.)
> 
> 
> 
> I did notice that the mwifiex_cmd_timeout_func incidents are
> preceded by one of these (before the previous suspend attempt):
> 
>      mwifiex_sdio mmc1:0001:1: card_to_host_mpa failed: int status=0x1
> 
> but I also see that error message earlier in some of the logs in which
> case things are still working after such an error.
> 
> Sometimes the above error is paired up with a "read iomem failed"
> message like this:
> 
>  [ 4131.795129] mwifiex_sdio mmc1:0001:1: mwifiex_sdio_card_to_host: read iomem failed: -1
>  [ 4131.823222] mwifiex_sdio mmc1:0001:1: card_to_host_mpa failed: int status=0x1

There is always an MMC error right before "read iomem failed" message:

[ 5778.800096] mmc1: Timeout waiting for hardware interrupt.
[ 5778.815234] mwifiex_sdio mmc1:0001:1: mwifiex_sdio_card_to_host: read iomem failed: -1
[ 5778.843418] mwifiex_sdio mmc1:0001:1: card_to_host_mpa failed: int status=0x1

This indicates that we do not receive the CMD53 CMD_DONE interrupt.

> 
> Maybe it would help to understand why these are happening and if they
> are closer to the root cause of the timeouts in the first place.

You can apply the "mwifiex_v3.7rc3_debug_suspend_resume.diff" patch (I sent last Friday) to collect some more debug info.

> (But remember, HOST_SLEEP_CFG_GAP_DEF is back to zero in these tests,
> so that I could get enough events to test mwifiex_cmd_timeout_func.)
> 
> 			-Tim Shepard
> 			 shep@laptop.org
> 
>  ___ _ ___ _   _ _ ___   ___     _ _ _ _   _   _ ___ _   _   _ ___ _ ___ _ ___
> 
> diff --git a/drivers/net/wireless/mwifiex/cmdevt.c b/drivers/net/wireless/mwifiex/cmdevt.c
> index 51e023e..f4e0919 100644
> --- a/drivers/net/wireless/mwifiex/cmdevt.c
> +++ b/drivers/net/wireless/mwifiex/cmdevt.c
> @@ -873,9 +873,6 @@ mwifiex_cmd_timeout_func(unsigned long function_context)
>  		return;
>  	}
>  	cmd_node = adapter->curr_cmd;
> -	if (cmd_node->wait_q_enabled)
> -		adapter->cmd_wait_q.status = -ETIMEDOUT;
> -
>  	if (cmd_node) {
>  		adapter->dbg.timeout_cmd_id =
>  			adapter->dbg.last_cmd_id[adapter->dbg.last_cmd_index];
> @@ -921,6 +918,12 @@ mwifiex_cmd_timeout_func(unsigned long function_context)
> 
>  		dev_err(adapter->dev, "ps_mode=%d ps_state=%d\n",
>  			adapter->ps_mode, adapter->ps_state);
> +
> +		if (cmd_node->wait_q_enabled) {
> +			adapter->cmd_wait_q.status = -ETIMEDOUT;
> +			wake_up_interruptible(&adapter->cmd_wait_q.wait);
> +			mwifiex_cancel_pending_ioctl(adapter);

FYI, I've submitted a newer version which clears the "cmd_sent" flag, it doesn't seem to solve the system wedgeups issue you are facing though.

Thanks,
Bing

Re: [PATCH] mwifiex: add support for SDIO card reset

[Andrei Emeltchenko]

Hi all,

On Fri, Nov 2, 2012 at 3:44 AM, Bing Zhao <bzhao@marvell.com> wrote:
> From: Amitkumar Karwar <akarwar@marvell.com>
>
> When command timeout happens due to a bug in firmware/hardware,
> the timeout handler just prints some debug information. User is
> unable to reload the driver in this case.
>
> Inspired by 9a821f5 "libertas: add sd8686 reset_card support",
> this patch adds card reset support for SDIO interface when
> command timeout happens. If the SDIO host contoller supports
> MMC_POWER_OFF|UP|ON operations, the chip will be reset and the
> firmware will be re-downloaded.

After this patch my board started to reset itself frequently. Before I have seen
warnings but it was working (somehow).

See logs below:

[ 7402.431601] ieee80211 phy12: uap0: changing to 2 not supported
[ 7402.432234] Bluetooth: Skip incorrect packet: hdrlen 3077 buffer 64
[ 7412.436879] Bluetooth: hci1 command tx timeout
[ 7412.468830] Bluetooth: hci0 command tx timeout
[ 7412.468842] mwifiex_sdio mmc0:0001:1: mwifiex_cmd_timeout_func:
Timeout cmd id (1353927138.543839) = 0x10c, act = 0x1
[ 7412.468852] mwifiex_sdio mmc0:0001:1: num_data_h2c_failure = 0
[ 7412.468857] mwifiex_sdio mmc0:0001:1: num_cmd_h2c_failure = 0
[ 7412.468863] mwifiex_sdio mmc0:0001:1: num_cmd_timeout = 1
[ 7412.468868] mwifiex_sdio mmc0:0001:1: num_tx_timeout = 0
[ 7412.468873] mwifiex_sdio mmc0:0001:1: last_cmd_index = 0
[ 7412.468879] mwifiex_sdio mmc0:0001:1: last_cmd_id: 0c 01 28 00 28
00 e4 00 0c 01
[ 7412.468885] mwifiex_sdio mmc0:0001:1: last_cmd_act: 01 00 13 01 13
01 ff 00 01 00
[ 7412.468890] mwifiex_sdio mmc0:0001:1: last_cmd_resp_index = 4
[ 7412.468896] mwifiex_sdio mmc0:0001:1: last_cmd_resp_id: 0c 81 28 80
28 80 e4 80 0c 81
[ 7412.468901] mwifiex_sdio mmc0:0001:1: last_event_index = 0
[ 7412.468907] mwifiex_sdio mmc0:0001:1: last_event: 00 00 00 00 00 00
00 00 00 00
[ 7412.468913] mwifiex_sdio mmc0:0001:1: data_sent=0 cmd_sent=1
[ 7412.468921] mwifiex_sdio mmc0:0001:1: ps_mode=1 ps_state=0
[ 7412.469014] mwifiex_sdio: Resetting card...
[ 7412.469452] mwifiex_sdio mmc0:0001:1: rx_pending=0, tx_pending=0,
cmd_pending=-1
[ 7412.589781] mmc0:0001:1: pending IRQ with no handler
[ 7477.264586] kmemleak: 2 new suspected memory leaks (see
/sys/kernel/debug/kmemleak)
[ 7558.642494] INFO: task kworker/3:0:32056 blocked for more than 120 seconds.
[ 7558.642505] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[ 7558.642511] kworker/3:0     D 00000000     0 32056      2 0x00000000
[ 7558.642523]  e68f9cf0 00000086 f0e19694 00000000 00000004 f53ceae0
e0de9b71 000006bd
[ 7558.642544]  c19cb680 c19cb680 00008194 c1ed9f28 f55c9680 f0e191d0
c10a7f4d e68f9d1c
[ 7558.642563]  c10a7f4d f0e191d0 0ca6209c 00000004 0066850d 00008194
00598194 c1ecff58
[ 7558.642584] Call Trace:
[ 7558.642603]  [<c10a7f4d>] ? __lock_acquire+0x3ad/0x1770
[ 7558.642612]  [<c10a7f4d>] ? __lock_acquire+0x3ad/0x1770
[ 7558.642628]  [<c15fc2c3>] schedule+0x23/0x60
[ 7558.642639]  [<c15fa005>] schedule_timeout+0x135/0x1f0
[ 7558.642651]  [<c10a6c65>] ? mark_held_locks+0x85/0xe0
[ 7558.642660]  [<c15fd6d7>] ? _raw_spin_unlock_irq+0x27/0x40
[ 7558.642671]  [<c15fc172>] wait_for_common+0xd2/0x120
[ 7558.642682]  [<c107f330>] ? try_to_wake_up+0x290/0x290
[ 7558.642692]  [<c15fc297>] wait_for_completion+0x17/0x20
[ 7558.642703]  [<c106d587>] kthread_stop+0x47/0xf0
[ 7558.642717]  [<f8502ad6>] btmrvl_remove_card+0x36/0x80 [btmrvl]
[ 7558.642727]  [<f852f6d2>] btmrvl_sdio_remove+0x42/0x80 [btmrvl_sdio]
[ 7558.642737]  [<c14e1fc2>] sdio_bus_remove+0x32/0x100
[ 7558.642747]  [<c13cd841>] ? __pm_runtime_idle+0x61/0xa0
[ 7558.642760]  [<c13c2cb4>] __device_release_driver+0x64/0xc0
[ 7558.642769]  [<c13c2f96>] device_release_driver+0x26/0x40
[ 7558.642779]  [<c13c27f6>] bus_remove_device+0xb6/0x110
[ 7558.642789]  [<c13bfb2a>] ? device_remove_attrs+0x2a/0x60
[ 7558.642797]  [<c13c01b5>] device_del+0xe5/0x150
[ 7558.642806]  [<c14e21dc>] sdio_remove_func+0x1c/0x30
[ 7558.642814]  [<c14e0fbc>] mmc_sdio_remove+0x3c/0x80
[ 7558.642824]  [<c14da1f1>] mmc_stop_host+0x71/0x110
[ 7558.642835]  [<c14daa6d>] mmc_remove_host+0x1d/0x40
[ 7558.642845]  [<f8861877>] sdio_card_reset_worker+0x27/0x50 [mwifiex_sdio]
[ 7558.642856]  [<c106670b>] process_one_work+0x18b/0x4c0
[ 7558.642865]  [<c1066694>] ? process_one_work+0x114/0x4c0
[ 7558.642875]  [<f8861850>] ? mwifiex_register_dev+0x120/0x120 [mwifiex_sdio]
[ 7558.642886]  [<c1067e49>] worker_thread+0x119/0x3a0
[ 7558.642896]  [<c1067d30>] ? __next_gcwq_cpu+0x60/0x60
[ 7558.642904]  [<c106d52f>] kthread+0x9f/0xb0
[ 7558.642915]  [<c1604e37>] ret_from_kernel_thread+0x1b/0x28
[ 7558.642924]  [<c106d490>] ? kthread_create_on_node+0xe0/0xe0
[ 7558.642931] 3 locks held by kworker/3:0/32056:
[ 7558.642935]  #0:  (events){.+.+.+}, at: [<c1066694>]
process_one_work+0x114/0x4c0
[ 7558.642953]  #1:  (card_reset_work){+.+.+.}, at: [<c1066694>]
process_one_work+0x114/0x4c0
[ 7558.642970]  #2:  (&__lockdep_no_validate__){......}, at:
[<c13c2f8f>] device_release_driver+0x1f/0x40
[ 7678.604370] INFO: task kworker/3:0:32056 blocked for more than 120 seconds.
[ 7678.604381] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[ 7678.604387] kworker/3:0     D 00000000     0 32056      2 0x00000000
[ 7678.604400]  e68f9cf0 00000086 f0e19694 00000000 00000004 f53ceae0
e0de9b71 000006bd
[ 7678.604421]  c19cb680 c19cb680 00008194 c1ed9f28 f55c9680 f0e191d0
c10a7f4d e68f9d1c
[ 7678.604440]  c10a7f4d f0e191d0 0ca6209c 00000004 0066850d 00008194
00598194 c1ecff58
[ 7678.604461] Call Trace:
[ 7678.604479]  [<c10a7f4d>] ? __lock_acquire+0x3ad/0x1770
[ 7678.604487]  [<c10a7f4d>] ? __lock_acquire+0x3ad/0x1770
[ 7678.604503]  [<c15fc2c3>] schedule+0x23/0x60
[ 7678.604513]  [<c15fa005>] schedule_timeout+0x135/0x1f0
[ 7678.604526]  [<c10a6c65>] ? mark_held_locks+0x85/0xe0
[ 7678.604535]  [<c15fd6d7>] ? _raw_spin_unlock_irq+0x27/0x40
[ 7678.604546]  [<c15fc172>] wait_for_common+0xd2/0x120
[ 7678.604557]  [<c107f330>] ? try_to_wake_up+0x290/0x290
[ 7678.604568]  [<c15fc297>] wait_for_completion+0x17/0x20
[ 7678.604578]  [<c106d587>] kthread_stop+0x47/0xf0
[ 7678.604592]  [<f8502ad6>] btmrvl_remove_card+0x36/0x80 [btmrvl]
[ 7678.604602]  [<f852f6d2>] btmrvl_sdio_remove+0x42/0x80 [btmrvl_sdio]
[ 7678.604612]  [<c14e1fc2>] sdio_bus_remove+0x32/0x100
[ 7678.604622]  [<c13cd841>] ? __pm_runtime_idle+0x61/0xa0
[ 7678.604634]  [<c13c2cb4>] __device_release_driver+0x64/0xc0
[ 7678.604644]  [<c13c2f96>] device_release_driver+0x26/0x40
[ 7678.604653]  [<c13c27f6>] bus_remove_device+0xb6/0x110
[ 7678.604663]  [<c13bfb2a>] ? device_remove_attrs+0x2a/0x60
[ 7678.604671]  [<c13c01b5>] device_del+0xe5/0x150
[ 7678.604680]  [<c14e21dc>] sdio_remove_func+0x1c/0x30
[ 7678.604688]  [<c14e0fbc>] mmc_sdio_remove+0x3c/0x80
[ 7678.604698]  [<c14da1f1>] mmc_stop_host+0x71/0x110
[ 7678.604709]  [<c14daa6d>] mmc_remove_host+0x1d/0x40
[ 7678.604718]  [<f8861877>] sdio_card_reset_worker+0x27/0x50 [mwifiex_sdio]
[ 7678.604731]  [<c106670b>] process_one_work+0x18b/0x4c0
[ 7678.604741]  [<c1066694>] ? process_one_work+0x114/0x4c0
[ 7678.604750]  [<f8861850>] ? mwifiex_register_dev+0x120/0x120 [mwifiex_sdio]
[ 7678.604761]  [<c1067e49>] worker_thread+0x119/0x3a0
[ 7678.604771]  [<c1067d30>] ? __next_gcwq_cpu+0x60/0x60
[ 7678.604779]  [<c106d52f>] kthread+0x9f/0xb0
[ 7678.604790]  [<c1604e37>] ret_from_kernel_thread+0x1b/0x28
[ 7678.604799]  [<c106d490>] ? kthread_create_on_node+0xe0/0xe0

< skipped>

Regards,
Andrei

RE: [PATCH] mwifiex: add support for SDIO card reset

[Bing Zhao]

Hi Andrei,

> Hi all,
> 
> On Fri, Nov 2, 2012 at 3:44 AM, Bing Zhao <bzhao@marvell.com> wrote:
> > From: Amitkumar Karwar <akarwar@marvell.com>
> >
> > When command timeout happens due to a bug in firmware/hardware,
> > the timeout handler just prints some debug information. User is
> > unable to reload the driver in this case.
> >
> > Inspired by 9a821f5 "libertas: add sd8686 reset_card support",
> > this patch adds card reset support for SDIO interface when
> > command timeout happens. If the SDIO host contoller supports
> > MMC_POWER_OFF|UP|ON operations, the chip will be reset and the
> > firmware will be re-downloaded.
> 
> After this patch my board started to reset itself frequently. Before I have seen
> warnings but it was working (somehow).

Are the command timeout warnings the same with and without this patch applied?
Could you please revert this patch and generate a log with the warnings shown but still working?

> 
> See logs below:
> 
> [ 7402.431601] ieee80211 phy12: uap0: changing to 2 not supported
> [ 7402.432234] Bluetooth: Skip incorrect packet: hdrlen 3077 buffer 64
> [ 7412.436879] Bluetooth: hci1 command tx timeout
> [ 7412.468830] Bluetooth: hci0 command tx timeout

Here the Bluetooth driver btmrvl timed out before WLAN driver got the timeout.
Since the patch takes effect only after mwifiex times out, I assume that btmrvl timeout also happens without this patch.

I only tested the patch with the timeout triggered by mwifiex driver. I will try to reproduce the btmrvl driver timeout on my setup. If you have a way to recreate btmrvl timeout quickly please let me know.

Thanks,
Bing

> [ 7412.468842] mwifiex_sdio mmc0:0001:1: mwifiex_cmd_timeout_func:
> Timeout cmd id (1353927138.543839) = 0x10c, act = 0x1
> [ 7412.468852] mwifiex_sdio mmc0:0001:1: num_data_h2c_failure = 0
> [ 7412.468857] mwifiex_sdio mmc0:0001:1: num_cmd_h2c_failure = 0
> [ 7412.468863] mwifiex_sdio mmc0:0001:1: num_cmd_timeout = 1
> [ 7412.468868] mwifiex_sdio mmc0:0001:1: num_tx_timeout = 0
> [ 7412.468873] mwifiex_sdio mmc0:0001:1: last_cmd_index = 0
> [ 7412.468879] mwifiex_sdio mmc0:0001:1: last_cmd_id: 0c 01 28 00 28
> 00 e4 00 0c 01
> [ 7412.468885] mwifiex_sdio mmc0:0001:1: last_cmd_act: 01 00 13 01 13
> 01 ff 00 01 00
> [ 7412.468890] mwifiex_sdio mmc0:0001:1: last_cmd_resp_index = 4
> [ 7412.468896] mwifiex_sdio mmc0:0001:1: last_cmd_resp_id: 0c 81 28 80
> 28 80 e4 80 0c 81
> [ 7412.468901] mwifiex_sdio mmc0:0001:1: last_event_index = 0
> [ 7412.468907] mwifiex_sdio mmc0:0001:1: last_event: 00 00 00 00 00 00
> 00 00 00 00
> [ 7412.468913] mwifiex_sdio mmc0:0001:1: data_sent=0 cmd_sent=1
> [ 7412.468921] mwifiex_sdio mmc0:0001:1: ps_mode=1 ps_state=0
> [ 7412.469014] mwifiex_sdio: Resetting card...
> [ 7412.469452] mwifiex_sdio mmc0:0001:1: rx_pending=0, tx_pending=0,
> cmd_pending=-1
> [ 7412.589781] mmc0:0001:1: pending IRQ with no handler
> [ 7477.264586] kmemleak: 2 new suspected memory leaks (see
> /sys/kernel/debug/kmemleak)
> [ 7558.642494] INFO: task kworker/3:0:32056 blocked for more than 120 seconds.
> [ 7558.642505] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
> disables this message.
> [ 7558.642511] kworker/3:0     D 00000000     0 32056      2 0x00000000
> [ 7558.642523]  e68f9cf0 00000086 f0e19694 00000000 00000004 f53ceae0
> e0de9b71 000006bd
> [ 7558.642544]  c19cb680 c19cb680 00008194 c1ed9f28 f55c9680 f0e191d0
> c10a7f4d e68f9d1c
> [ 7558.642563]  c10a7f4d f0e191d0 0ca6209c 00000004 0066850d 00008194
> 00598194 c1ecff58
> [ 7558.642584] Call Trace:
> [ 7558.642603]  [<c10a7f4d>] ? __lock_acquire+0x3ad/0x1770
> [ 7558.642612]  [<c10a7f4d>] ? __lock_acquire+0x3ad/0x1770
> [ 7558.642628]  [<c15fc2c3>] schedule+0x23/0x60
> [ 7558.642639]  [<c15fa005>] schedule_timeout+0x135/0x1f0
> [ 7558.642651]  [<c10a6c65>] ? mark_held_locks+0x85/0xe0
> [ 7558.642660]  [<c15fd6d7>] ? _raw_spin_unlock_irq+0x27/0x40
> [ 7558.642671]  [<c15fc172>] wait_for_common+0xd2/0x120
> [ 7558.642682]  [<c107f330>] ? try_to_wake_up+0x290/0x290
> [ 7558.642692]  [<c15fc297>] wait_for_completion+0x17/0x20
> [ 7558.642703]  [<c106d587>] kthread_stop+0x47/0xf0
> [ 7558.642717]  [<f8502ad6>] btmrvl_remove_card+0x36/0x80 [btmrvl]
> [ 7558.642727]  [<f852f6d2>] btmrvl_sdio_remove+0x42/0x80 [btmrvl_sdio]
> [ 7558.642737]  [<c14e1fc2>] sdio_bus_remove+0x32/0x100
> [ 7558.642747]  [<c13cd841>] ? __pm_runtime_idle+0x61/0xa0
> [ 7558.642760]  [<c13c2cb4>] __device_release_driver+0x64/0xc0
> [ 7558.642769]  [<c13c2f96>] device_release_driver+0x26/0x40
> [ 7558.642779]  [<c13c27f6>] bus_remove_device+0xb6/0x110
> [ 7558.642789]  [<c13bfb2a>] ? device_remove_attrs+0x2a/0x60
> [ 7558.642797]  [<c13c01b5>] device_del+0xe5/0x150
> [ 7558.642806]  [<c14e21dc>] sdio_remove_func+0x1c/0x30
> [ 7558.642814]  [<c14e0fbc>] mmc_sdio_remove+0x3c/0x80
> [ 7558.642824]  [<c14da1f1>] mmc_stop_host+0x71/0x110
> [ 7558.642835]  [<c14daa6d>] mmc_remove_host+0x1d/0x40
> [ 7558.642845]  [<f8861877>] sdio_card_reset_worker+0x27/0x50 [mwifiex_sdio]
> [ 7558.642856]  [<c106670b>] process_one_work+0x18b/0x4c0
> [ 7558.642865]  [<c1066694>] ? process_one_work+0x114/0x4c0
> [ 7558.642875]  [<f8861850>] ? mwifiex_register_dev+0x120/0x120 [mwifiex_sdio]
> [ 7558.642886]  [<c1067e49>] worker_thread+0x119/0x3a0
> [ 7558.642896]  [<c1067d30>] ? __next_gcwq_cpu+0x60/0x60
> [ 7558.642904]  [<c106d52f>] kthread+0x9f/0xb0
> [ 7558.642915]  [<c1604e37>] ret_from_kernel_thread+0x1b/0x28
> [ 7558.642924]  [<c106d490>] ? kthread_create_on_node+0xe0/0xe0
> [ 7558.642931] 3 locks held by kworker/3:0/32056:
> [ 7558.642935]  #0:  (events){.+.+.+}, at: [<c1066694>]
> process_one_work+0x114/0x4c0
> [ 7558.642953]  #1:  (card_reset_work){+.+.+.}, at: [<c1066694>]
> process_one_work+0x114/0x4c0
> [ 7558.642970]  #2:  (&__lockdep_no_validate__){......}, at:
> [<c13c2f8f>] device_release_driver+0x1f/0x40
> [ 7678.604370] INFO: task kworker/3:0:32056 blocked for more than 120 seconds.
> [ 7678.604381] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
> disables this message.
> [ 7678.604387] kworker/3:0     D 00000000     0 32056      2 0x00000000
> [ 7678.604400]  e68f9cf0 00000086 f0e19694 00000000 00000004 f53ceae0
> e0de9b71 000006bd
> [ 7678.604421]  c19cb680 c19cb680 00008194 c1ed9f28 f55c9680 f0e191d0
> c10a7f4d e68f9d1c
> [ 7678.604440]  c10a7f4d f0e191d0 0ca6209c 00000004 0066850d 00008194
> 00598194 c1ecff58
> [ 7678.604461] Call Trace:
> [ 7678.604479]  [<c10a7f4d>] ? __lock_acquire+0x3ad/0x1770
> [ 7678.604487]  [<c10a7f4d>] ? __lock_acquire+0x3ad/0x1770
> [ 7678.604503]  [<c15fc2c3>] schedule+0x23/0x60
> [ 7678.604513]  [<c15fa005>] schedule_timeout+0x135/0x1f0
> [ 7678.604526]  [<c10a6c65>] ? mark_held_locks+0x85/0xe0
> [ 7678.604535]  [<c15fd6d7>] ? _raw_spin_unlock_irq+0x27/0x40
> [ 7678.604546]  [<c15fc172>] wait_for_common+0xd2/0x120
> [ 7678.604557]  [<c107f330>] ? try_to_wake_up+0x290/0x290
> [ 7678.604568]  [<c15fc297>] wait_for_completion+0x17/0x20
> [ 7678.604578]  [<c106d587>] kthread_stop+0x47/0xf0
> [ 7678.604592]  [<f8502ad6>] btmrvl_remove_card+0x36/0x80 [btmrvl]
> [ 7678.604602]  [<f852f6d2>] btmrvl_sdio_remove+0x42/0x80 [btmrvl_sdio]
> [ 7678.604612]  [<c14e1fc2>] sdio_bus_remove+0x32/0x100
> [ 7678.604622]  [<c13cd841>] ? __pm_runtime_idle+0x61/0xa0
> [ 7678.604634]  [<c13c2cb4>] __device_release_driver+0x64/0xc0
> [ 7678.604644]  [<c13c2f96>] device_release_driver+0x26/0x40
> [ 7678.604653]  [<c13c27f6>] bus_remove_device+0xb6/0x110
> [ 7678.604663]  [<c13bfb2a>] ? device_remove_attrs+0x2a/0x60
> [ 7678.604671]  [<c13c01b5>] device_del+0xe5/0x150
> [ 7678.604680]  [<c14e21dc>] sdio_remove_func+0x1c/0x30
> [ 7678.604688]  [<c14e0fbc>] mmc_sdio_remove+0x3c/0x80
> [ 7678.604698]  [<c14da1f1>] mmc_stop_host+0x71/0x110
> [ 7678.604709]  [<c14daa6d>] mmc_remove_host+0x1d/0x40
> [ 7678.604718]  [<f8861877>] sdio_card_reset_worker+0x27/0x50 [mwifiex_sdio]
> [ 7678.604731]  [<c106670b>] process_one_work+0x18b/0x4c0
> [ 7678.604741]  [<c1066694>] ? process_one_work+0x114/0x4c0
> [ 7678.604750]  [<f8861850>] ? mwifiex_register_dev+0x120/0x120 [mwifiex_sdio]
> [ 7678.604761]  [<c1067e49>] worker_thread+0x119/0x3a0
> [ 7678.604771]  [<c1067d30>] ? __next_gcwq_cpu+0x60/0x60
> [ 7678.604779]  [<c106d52f>] kthread+0x9f/0xb0
> [ 7678.604790]  [<c1604e37>] ret_from_kernel_thread+0x1b/0x28
> [ 7678.604799]  [<c106d490>] ? kthread_create_on_node+0xe0/0xe0
> 
> < skipped>
> 
> Regards,
> Andrei

Re: [PATCH] mwifiex: add support for SDIO card reset

[Andrei Emeltchenko]

Hi Bing,

On Tue, Nov 27, 2012 at 3:09 AM, Bing Zhao <bzhao@marvell.com> wrote:
>> On Fri, Nov 2, 2012 at 3:44 AM, Bing Zhao <bzhao@marvell.com> wrote:
>> > From: Amitkumar Karwar <akarwar@marvell.com>
>> >
>> > When command timeout happens due to a bug in firmware/hardware,
>> > the timeout handler just prints some debug information. User is
>> > unable to reload the driver in this case.
>> >
>> > Inspired by 9a821f5 "libertas: add sd8686 reset_card support",
>> > this patch adds card reset support for SDIO interface when
>> > command timeout happens. If the SDIO host contoller supports
>> > MMC_POWER_OFF|UP|ON operations, the chip will be reset and the
>> > firmware will be re-downloaded.
>>
>> After this patch my board started to reset itself frequently. Before I have seen
>> warnings but it was working (somehow).
>
> Are the command timeout warnings the same with and without this patch applied?
> Could you please revert this patch and generate a log with the warnings shown but still working?

I actually reverted the patch and I see warnings but the board seems
to be working
(at least Bluetooth + WIFI AMP). I see following messages:

<lots of wifi regulatory spam here >
.....
[ 5554.082703] mwifiex_sdio mmc0:0001:1: ignoring F/W country code US
[ 5554.096694] mwifiex_sdio mmc0:0001:1: driver_version = mwifiex 1.0
(14.66.9.p96)
[ 5554.353287] ieee80211 phy1: uap0: changing to 2 not supported
[ 5554.354125] ieee80211 phy1: uap0: changing to 2 not supported
[ 5554.355429] ieee80211 phy1: uap0: changing to 2 not supported
[ 5554.355492] ieee80211 phy1: uap0: changing to 2 not supported
[ 5554.356275] ieee80211 phy1: uap0: changing to 2 not supported
[ 5556.932508] cfg80211: Found new beacon on frequency: 2472 MHz (Ch 13) on phy1
[ 5559.907548] cfg80211: Found new beacon on frequency: 5180 MHz (Ch 36) on phy1
[ 5560.403407] cfg80211: Found new beacon on frequency: 5220 MHz (Ch 44) on phy1
[ 5567.407174] Bluetooth: BNEP (Ethernet Emulation) ver 1.3
[ 5567.407178] Bluetooth: BNEP filters: protocol multicast
[ 5567.407209] Bluetooth: BNEP socket layer initialized
[ 5697.022102] mwifiex_sdio mmc0:0001:1: mwifiex_cmd_timeout_func:
Timeout cmd id (1354009998.573301) = 0x6, act = 0x3
[ 5697.022116] mwifiex_sdio mmc0:0001:1: num_data_h2c_failure = 0
[ 5697.022122] mwifiex_sdio mmc0:0001:1: num_cmd_h2c_failure = 0
[ 5697.022127] mwifiex_sdio mmc0:0001:1: num_cmd_timeout = 1
[ 5697.022132] mwifiex_sdio mmc0:0001:1: num_tx_timeout = 0
[ 5697.022137] mwifiex_sdio mmc0:0001:1: last_cmd_index = 3
[ 5697.022144] mwifiex_sdio mmc0:0001:1: last_cmd_id: 06 00 06 00 06
00 06 00 06 00
[ 5697.022149] mwifiex_sdio mmc0:0001:1: last_cmd_act: 03 00 03 00 03
00 03 00 03 00
[ 5697.022154] mwifiex_sdio mmc0:0001:1: last_cmd_resp_index = 2
[ 5697.022159] mwifiex_sdio mmc0:0001:1: last_cmd_resp_id: 06 80 06 80
06 80 06 80 06 80
[ 5697.022164] mwifiex_sdio mmc0:0001:1: last_event_index = 2
[ 5697.022169] mwifiex_sdio mmc0:0001:1: last_event: 0a 00 0b 00 0a 00
0a 00 0b 00
[ 5697.022175] mwifiex_sdio mmc0:0001:1: data_sent=0 cmd_sent=1
[ 5697.022180] mwifiex_sdio mmc0:0001:1: ps_mode=1 ps_state=0
....
[ 6381.253112] mwifiex_sdio mmc0:0001:1: mwifiex_cmd_timeout_func:
Timeout cmd id (1354010683.21145) = 0x6, act = 0x3
[ 6381.253125] mwifiex_sdio mmc0:0001:1: num_data_h2c_failure = 0
[ 6381.253131] mwifiex_sdio mmc0:0001:1: num_cmd_h2c_failure = 0
[ 6381.253136] mwifiex_sdio mmc0:0001:1: num_cmd_timeout = 2
[ 6381.253141] mwifiex_sdio mmc0:0001:1: num_tx_timeout = 0
[ 6381.253146] mwifiex_sdio mmc0:0001:1: last_cmd_index = 4
[ 6381.253152] mwifiex_sdio mmc0:0001:1: last_cmd_id: 06 00 06 00 06
00 06 00 06 00
[ 6381.253157] mwifiex_sdio mmc0:0001:1: last_cmd_act: 03 00 03 00 03
00 03 00 03 00
[ 6381.253162] mwifiex_sdio mmc0:0001:1: last_cmd_resp_index = 3
[ 6381.253167] mwifiex_sdio mmc0:0001:1: last_cmd_resp_id: 06 80 06 80
06 80 06 80 06 80
[ 6381.253173] mwifiex_sdio mmc0:0001:1: last_event_index = 3
[ 6381.253178] mwifiex_sdio mmc0:0001:1: last_event: 0a 00 0b 00 0a 00
0b 00 0b 00
[ 6381.253183] mwifiex_sdio mmc0:0001:1: data_sent=0 cmd_sent=0
[ 6381.253189] mwifiex_sdio mmc0:0001:1: ps_mode=1 ps_state=1
[ 6408.880560] mwifiex_sdio mmc0:0001:1: CMD_RESP: cmd 0x6 error, result=0x4
...

>> [ 7402.431601] ieee80211 phy12: uap0: changing to 2 not supported
>> [ 7402.432234] Bluetooth: Skip incorrect packet: hdrlen 3077 buffer 64
>> [ 7412.436879] Bluetooth: hci1 command tx timeout
>> [ 7412.468830] Bluetooth: hci0 command tx timeout
>
> Here the Bluetooth driver btmrvl timed out before WLAN driver got the timeout.
> Since the patch takes effect only after mwifiex times out, I assume that btmrvl timeout also happens without this patch.
>
> I only tested the patch with the timeout triggered by mwifiex driver. I will try to reproduce the btmrvl driver timeout on my setup. If you have a way to recreate btmrvl timeout quickly please let me know.

Just insert the board and wait some time or make "hcitool scan".

Regards,
Andrei