Lots of trans->state != IWL_TRANS_FW_ALIVE warnings

Lots of trans->state != IWL_TRANS_FW_ALIVE warnings

[Stanislaw Gruszka]

On Fedora (3.5 and 3.6 kernels) we are currently overwhelmed by
tons of iwlwifi warnings at iwlagn_mac_flush() and iwl_dvm_send_cmd()
reports.

iwlagn_mac_flush warning is triggered at:

static inline int iwl_trans_wait_tx_queue_empty(struct iwl_trans *trans)
{
        WARN_ONCE(trans->state != IWL_TRANS_FW_ALIVE,
                  "%s bad state = %d", __func__, trans->state);

        return trans->ops->wait_tx_queue_empty(trans);
}

We have 2 instances of this issue:

- started at ieee80211_scan()
https://bugzilla.redhat.com/show_bug.cgi?id=866013
- started at ieee80211_sta_monitor_work()
https://bugzilla.redhat.com/show_bug.cgi?id=861753

iwl_dvm_send_cmd is triggered at:

static inline int iwl_trans_send_cmd(struct iwl_trans *trans,
                                struct iwl_host_cmd *cmd)
{
        WARN_ONCE(trans->state != IWL_TRANS_FW_ALIVE,
                  "%s bad state = %d", __func__, trans->state);

        return trans->ops->send_cmd(trans, cmd);
}

And have 3 instances:

- started at ieee80211_set_disassoc()
https://bugzilla.redhat.com/show_bug.cgi?id=861599
- started at ieee80211_restart_work()
https://bugzilla.redhat.com/show_bug.cgi?id=865072
- started at ieee80211_auth()
https://bugzilla.redhat.com/show_bug.cgi?id=866015

Can those be fixed in some reasonable time ?

I'm not sure if they are related with some user visible problem like
disconnects.

I'll probably revert f0d120af8f55649571c681f49c920b0822050fa5
on Fedora, just to stop getting those warnings ...

Stanislaw

RE: Lots of trans->state != IWL_TRANS_FW_ALIVE warnings

[Grumbach, Emmanuel]

> 
> On Fedora (3.5 and 3.6 kernels) we are currently overwhelmed by tons of
> iwlwifi warnings at iwlagn_mac_flush() and iwl_dvm_send_cmd() reports.
> 
> iwlagn_mac_flush warning is triggered at:
> 
> static inline int iwl_trans_wait_tx_queue_empty(struct iwl_trans *trans) {
>         WARN_ONCE(trans->state != IWL_TRANS_FW_ALIVE,
>                   "%s bad state = %d", __func__, trans->state);
> 
>         return trans->ops->wait_tx_queue_empty(trans);
> }
> 
> We have 2 instances of this issue:
> 
> - started at ieee80211_scan()
> https://bugzilla.redhat.com/show_bug.cgi?id=866013
> - started at ieee80211_sta_monitor_work()
> https://bugzilla.redhat.com/show_bug.cgi?id=861753
> 
> iwl_dvm_send_cmd is triggered at:
> 
> static inline int iwl_trans_send_cmd(struct iwl_trans *trans,
>                                 struct iwl_host_cmd *cmd) {
>         WARN_ONCE(trans->state != IWL_TRANS_FW_ALIVE,
>                   "%s bad state = %d", __func__, trans->state);
> 
>         return trans->ops->send_cmd(trans, cmd); }
> 
> And have 3 instances:
> 
> - started at ieee80211_set_disassoc()
> https://bugzilla.redhat.com/show_bug.cgi?id=861599
> - started at ieee80211_restart_work()
> https://bugzilla.redhat.com/show_bug.cgi?id=865072
> - started at ieee80211_auth()
> https://bugzilla.redhat.com/show_bug.cgi?id=866015
> 

I glanced at the bugs and I can only see the trace dump. I am pretty sure there is an issue before the dump - fw assert of something like that. Can it be possible to get the full log?

> Can those be fixed in some reasonable time ?
> 
> I'm not sure if they are related with some user visible problem like
> disconnects.

Well... if the fw isn't ALIVE then something bad happens, bad enough to get disconnected, yes.
> 
> I'll probably revert f0d120af8f55649571c681f49c920b0822050fa5
> on Fedora, just to stop getting those warnings ...
> 

You will stop get the warnings, but that of course won't solve anything else.
---------------------------------------------------------------------
Intel Israel (74) Limited

This e-mail and any attachments may contain confidential material for
the sole use of the intended recipient(s). Any review or distribution
by others is strictly prohibited. If you are not the intended
recipient, please contact the sender and delete all copies.

RE: Lots of trans->state != IWL_TRANS_FW_ALIVE warnings

[Grumbach, Emmanuel]

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

> 
> >
> > On Fedora (3.5 and 3.6 kernels) we are currently overwhelmed by tons
> > of iwlwifi warnings at iwlagn_mac_flush() and iwl_dvm_send_cmd()
> reports.
> >
> > iwlagn_mac_flush warning is triggered at:
> >
> > static inline int iwl_trans_wait_tx_queue_empty(struct iwl_trans *trans) {
> >         WARN_ONCE(trans->state != IWL_TRANS_FW_ALIVE,
> >                   "%s bad state = %d", __func__, trans->state);
> >
> >         return trans->ops->wait_tx_queue_empty(trans);
> > }
> >
> > We have 2 instances of this issue:
> >
> > - started at ieee80211_scan()
> > https://bugzilla.redhat.com/show_bug.cgi?id=866013
> > - started at ieee80211_sta_monitor_work()
> > https://bugzilla.redhat.com/show_bug.cgi?id=861753
> >
> > iwl_dvm_send_cmd is triggered at:
> >
> > static inline int iwl_trans_send_cmd(struct iwl_trans *trans,
> >                                 struct iwl_host_cmd *cmd) {
> >         WARN_ONCE(trans->state != IWL_TRANS_FW_ALIVE,
> >                   "%s bad state = %d", __func__, trans->state);
> >
> >         return trans->ops->send_cmd(trans, cmd); }
> >
> > And have 3 instances:
> >
> > - started at ieee80211_set_disassoc()
> > https://bugzilla.redhat.com/show_bug.cgi?id=861599
> > - started at ieee80211_restart_work()
> > https://bugzilla.redhat.com/show_bug.cgi?id=865072
> > - started at ieee80211_auth()
> > https://bugzilla.redhat.com/show_bug.cgi?id=866015
> >
> 
> I glanced at the bugs and I can only see the trace dump. I am pretty sure
> there is an issue before the dump - fw assert of something like that. Can it be
> possible to get the full log?
> 

Can you ask people to try the attached patch?
This will let us know where the fw is brought down.

> > Can those be fixed in some reasonable time ?
> >
> > I'm not sure if they are related with some user visible problem like
> > disconnects.
> 
> Well... if the fw isn't ALIVE then something bad happens, bad enough to get
> disconnected, yes.
> >
> > I'll probably revert f0d120af8f55649571c681f49c920b0822050fa5
> > on Fedora, just to stop getting those warnings ...
> >
> 
> You will stop get the warnings, but that of course won't solve anything else.

---------------------------------------------------------------------
Intel Israel (74) Limited

This e-mail and any attachments may contain confidential material for
the sole use of the intended recipient(s). Any review or distribution
by others is strictly prohibited. If you are not the intended
recipient, please contact the sender and delete all copies.

[-- Attachment #2: 0001-iwlwifi-print-state-changes-in-transport-layer.patch --]
[-- Type: application/octet-stream, Size: 2388 bytes --]

From e7db3736c850e5aff9a1a0cfc0d4c11d2ce93914 Mon Sep 17 00:00:00 2001
From: Emmanuel Grumbach <emmanuel.grumbach@intel.com>
Date: Mon, 15 Oct 2012 20:04:55 +0200
Subject: [PATCH] iwlwifi:  print state changes in transport layer

This will help to debug...

Signed-off-by: Emmanuel Grumbach <emmanuel.grumbach@intel.com>
---
 drivers/net/wireless/iwlwifi/iwl-debug.h |    2 ++
 drivers/net/wireless/iwlwifi/iwl-trans.h |    6 ++++++
 2 files changed, 8 insertions(+), 0 deletions(-)

diff --git a/drivers/net/wireless/iwlwifi/iwl-debug.h b/drivers/net/wireless/iwlwifi/iwl-debug.h
index 7ae181a..727b520 100644
--- a/drivers/net/wireless/iwlwifi/iwl-debug.h
+++ b/drivers/net/wireless/iwlwifi/iwl-debug.h
@@ -126,6 +126,7 @@ do {                                            			\
 /* 0x0000F000 - 0x00001000 */
 #define IWL_DL_ASSOC		0x00001000
 #define IWL_DL_DROP		0x00002000
+#define IWL_DL_TRANS		0x00004000
 #define IWL_DL_COEX		0x00008000
 /* 0x000F0000 - 0x00010000 */
 #define IWL_DL_FW		0x00010000
@@ -183,5 +184,6 @@ do {                                            			\
 #define IWL_DEBUG_RADIO(p, f, a...)	IWL_DEBUG(p, IWL_DL_RADIO, f, ## a)
 #define IWL_DEBUG_POWER(p, f, a...)	IWL_DEBUG(p, IWL_DL_POWER, f, ## a)
 #define IWL_DEBUG_11H(p, f, a...)	IWL_DEBUG(p, IWL_DL_11H, f, ## a)
+#define IWL_DEBUG_TRANS(p, f, a...)	IWL_DEBUG(p, IWL_DL_TRANS, f, ## a)
 
 #endif
diff --git a/drivers/net/wireless/iwlwifi/iwl-trans.h b/drivers/net/wireless/iwlwifi/iwl-trans.h
index 695b8d5..d6d6e12 100644
--- a/drivers/net/wireless/iwlwifi/iwl-trans.h
+++ b/drivers/net/wireless/iwlwifi/iwl-trans.h
@@ -508,6 +508,8 @@ static inline void iwl_trans_stop_hw(struct iwl_trans *trans,
 
 	trans->ops->stop_hw(trans, op_mode_leaving);
 
+	IWL_DEBUG_TRANS(trans, "trans->state: %d -> %d\n",
+			trans->state, IWL_TRANS_NO_FW);
 	trans->state = IWL_TRANS_NO_FW;
 }
 
@@ -515,6 +517,8 @@ static inline void iwl_trans_fw_alive(struct iwl_trans *trans)
 {
 	might_sleep();
 
+	IWL_DEBUG_TRANS(trans, "trans->state: %d -> %d\n",
+			trans->state, IWL_TRANS_FW_ALIVE);
 	trans->state = IWL_TRANS_FW_ALIVE;
 
 	trans->ops->fw_alive(trans);
@@ -536,6 +540,8 @@ static inline void iwl_trans_stop_device(struct iwl_trans *trans)
 
 	trans->ops->stop_device(trans);
 
+	IWL_DEBUG_TRANS(trans, "trans->state: %d -> %d\n",
+			trans->state, IWL_TRANS_NO_FW);
 	trans->state = IWL_TRANS_NO_FW;
 }
 
-- 
1.7.1

Re: Lots of trans->state != IWL_TRANS_FW_ALIVE warnings

[Stanislaw Gruszka]

On Mon, Oct 15, 2012 at 03:14:51PM +0000, Grumbach, Emmanuel wrote:
> > I glanced at the bugs and I can only see the trace dump. I am pretty sure
> > there is an issue before the dump - fw assert of something like that. Can it be
> > possible to get the full log?
> > 
> 
> Can you ask people to try the attached patch?
> This will let us know where the fw is brought down.

Yes, I'll build kernel with that patch and request for test and dmesg.

Stanislaw

Re: Lots of trans->state != IWL_TRANS_FW_ALIVE warnings

[Stanislaw Gruszka]

On Mon, Oct 15, 2012 at 05:23:36PM +0200, Stanislaw Gruszka wrote:
> On Mon, Oct 15, 2012 at 03:14:51PM +0000, Grumbach, Emmanuel wrote:
> > > I glanced at the bugs and I can only see the trace dump. I am pretty sure
> > > there is an issue before the dump - fw assert of something like that. Can it be
> > > possible to get the full log?
> > > 
> > 
> > Can you ask people to try the attached patch?
> > This will let us know where the fw is brought down.
> 
> Yes, I'll build kernel with that patch and request for test and dmesg.

debug=0x400 is enough or do you want also some other flags?

Stanislaw

RE: Lots of trans->state != IWL_TRANS_FW_ALIVE warnings

[Grumbach, Emmanuel]

> 
> On Mon, Oct 15, 2012 at 05:23:36PM +0200, Stanislaw Gruszka wrote:
> > On Mon, Oct 15, 2012 at 03:14:51PM +0000, Grumbach, Emmanuel wrote:
> > > > I glanced at the bugs and I can only see the trace dump. I am
> > > > pretty sure there is an issue before the dump - fw assert of
> > > > something like that. Can it be possible to get the full log?
> > > >
> > >
> > > Can you ask people to try the attached patch?
> > > This will let us know where the fw is brought down.
> >
> > Yes, I'll build kernel with that patch and request for test and dmesg.
> 
> debug=0x400 is enough or do you want also some other flags?
> 
0x400 should be enough, but 0x403 would be better :-)
---------------------------------------------------------------------
Intel Israel (74) Limited

This e-mail and any attachments may contain confidential material for
the sole use of the intended recipient(s). Any review or distribution
by others is strictly prohibited. If you are not the intended
recipient, please contact the sender and delete all copies.

Re: Lots of trans->state != IWL_TRANS_FW_ALIVE warnings

[Stanislaw Gruszka]

On Mon, Oct 15, 2012 at 06:53:05PM +0000, Grumbach, Emmanuel wrote:
> > 
> > On Mon, Oct 15, 2012 at 05:23:36PM +0200, Stanislaw Gruszka wrote:
> > > On Mon, Oct 15, 2012 at 03:14:51PM +0000, Grumbach, Emmanuel wrote:
> > > > > I glanced at the bugs and I can only see the trace dump. I am
> > > > > pretty sure there is an issue before the dump - fw assert of
> > > > > something like that. Can it be possible to get the full log?
> > > > >
> > > >
> > > > Can you ask people to try the attached patch?
> > > > This will let us know where the fw is brought down.
> > >
> > > Yes, I'll build kernel with that patch and request for test and dmesg.
> > 
> > debug=0x400 is enough or do you want also some other flags?
> > 
> 0x400 should be enough, but 0x403 would be better :-)


There is some feedback from user with micocode errors here
https://bugzilla.redhat.com/show_bug.cgi?id=866013

Emmanuel, perhaps you could CC to those bug report I provided links
earlier, so I'll not need to mail you, when someone will add additional
info to those reports ?

Thanks
Stanislaw 

RE: Lots of trans->state != IWL_TRANS_FW_ALIVE warnings

[Grumbach, Emmanuel]

> > > > > > I glanced at the bugs and I can only see the trace dump. I am
> > > > > > pretty sure there is an issue before the dump - fw assert of
> > > > > > something like that. Can it be possible to get the full log?
> > > > > >
> > > > >
> > > > > Can you ask people to try the attached patch?
> > > > > This will let us know where the fw is brought down.
> > > >
> > > > Yes, I'll build kernel with that patch and request for test and dmesg.
> > >
> > > debug=0x400 is enough or do you want also some other flags?
> > >
> > 0x400 should be enough, but 0x403 would be better :-)
> 
> 
> There is some feedback from user with micocode errors here
> https://bugzilla.redhat.com/show_bug.cgi?id=866013
> 

Ok, this is what I suspected. SYSASSERT before the WARNING....
So we have 2 issues here - the SYSASSERT  and the reset.
BTW - do we have any insight on the NIC used - although I am pretty sure it doesn't matter much.

> Emmanuel, perhaps you could CC to those bug report I provided links earlier,
> so I'll not need to mail you, when someone will add additional info to those
> reports ?
> 

I will check :-)


> Thanks
> Stanislaw
---------------------------------------------------------------------
Intel Israel (74) Limited

This e-mail and any attachments may contain confidential material for
the sole use of the intended recipient(s). Any review or distribution
by others is strictly prohibited. If you are not the intended
recipient, please contact the sender and delete all copies.