[ath9k-devel] Warning in ath_rc_get_highest_rix()

[ath9k-devel] Warning in ath_rc_get_highest_rix()

[Pavel Roskin]

Hello!

I hit this bug on a freshly installed Fedora 16 and judging by the
duplicate bugs it looks like many Fedora users are hitting it too:
https://bugzilla.redhat.com/show_bug.cgi?id=771113

The standard Fedora kernel uses Linux 3.1.6 with
compat-wireless-3.2-rc6-3, but I was able to reproduce the same warning
with the bleeding edge compat-wireless for December 31, 2011.

The warning only happens with one wireless router.  I'm not sure I can
reproduce it on purpose, but my abrt was showing about one hundred of
instances of that warning in a few hours.

Other bug reporters report that the warning appears after their laptop
was woken up from sleep.  That my explain why I have never seen that
warning with self-compiled kernels from wireless-testing.git, as I
normally don't enable many power management features.

I'm going to "see" that router once in a while, so if anyone has an
idea what patch to try, I can do it.

The code that triggers the warning is in ath_rc_get_highest_rix()
(drivers/net/wireless/ath/ath9k/rc.c), and it reads:

/* This should not happen */
WARN_ON(1);

-- 
Regards,
Pavel Roskin

[ath9k-devel] Warning in ath_rc_get_highest_rix()

[Adrian Chadd]

Hi!

Can someone please add some debugging printfs to those users, to see
exactly what the code in that function is doing?

It shouldn't be bigger than ath_rc_priv->rate_table_size - 1, as it's
enforced by the code above it.

Is somehow the rate control code idea of what the available rate
entries are completely wrong/blank? I remember seeing this in FreeBSD
in various erroneous conditions..

So what's the value of 'rate' there?


Adrian

[ath9k-devel] Warning in ath_rc_get_highest_rix()

[Pavel Roskin]

On Wed, 4 Jan 2012 17:46:45 -0500
Pavel Roskin <proski@gnu.org> wrote:

> I hit this bug on a freshly installed Fedora 16 and judging by the
> duplicate bugs it looks like many Fedora users are hitting it too:
> https://bugzilla.redhat.com/show_bug.cgi?id=771113

Some detailed information has been posted in the bug.

That's the variables printed before WARN_ON():

legacy = 0
minindex = 0
maxindex = 9
ath_rc_priv->probe_time = 34481809
now_msec = 54187647
best_thruput = -939514064
this_thruput = 264
rate = 11
next_rate = 0
best_rate = 11
rate_table->info[rate].rate_flags = 0x0
ath_rc_priv->ht_cap = 0x0
ath_rc_priv->rate_table_size = 12
ath_rc_priv->hw_maxretry_pktcnt = 0
ath_rc_priv->rate_max_phy = 11

There are 3 conditions when the rate is returned.  If neither
condition is true, WARN_ON() is hit and the lowest rate is returned.

The first two conditions require that ath_rc_priv->ht_cap is not 0, so
they don't apply.

The last condition requires that rate_table->info[rate].rate_flags is
not 0, so it doesn't apply either.

I think rate_table->info[rate].rate_flags should not be 0.  rate is 11,
which is reasonable.

Rate flags 0 corresponds to RC_INVALID.  I'm not sure how we can get it
with the rate 11.

Also, best_thruput should not be negative.  Its value in hex is
0xc8002730.  That looks like an address to me.  Or maybe there
was an overflow in this_thruput calculation.  But even the worst case
scenario would be 450000 * 100 = 45000000, well below largest integer.
Or maybe ath_rc_priv->per[tx_rate] was negative?

I'll appreciate is somebody could take a closer look and maybe suggest
a patch that would clarify the problem.  I cannot reproduce the problem
anymore, so we have to rely on the bug reporters who can.

-- 
Regards,
Pavel Roskin