git HEAD WARNING: at net/wireless/util.c:83

Live forum: http://rt2x00.serialmonkey.com/viewtopic.php?t=4595

Hazzl

02-02-2008 09:26:43

Hi there

with current git HEAD (50a83859) I get the following warning during the boot process

[code2e62yf6h]
[ 49.471140] WARNING: at net/wireless/util.c:83 set_mandatory_flags_band()
[ 49.471199] Pid: 852, comm: modprobe Not tainted 2.6.24-g50a83859 #7
[ 49.471257] [<c02fc01d>] ieee80211_set_bitrate_flags+0x141/0x15c
[ 49.471347] [<c02fbb5b>] wiphy_register+0xd5/0x12d
[ 49.471431] [<e0076422>] rt2500pci_probe_hw+0x6e/0x36d [rt2500pci]
[ 49.471522] [<c02fed80>] ieee80211_register_hw+0x31/0x20b
[ 49.471606] [<e0069bcb>] rt2x00lib_probe_dev+0x313/0x325 [rt2x00lib]
[ 49.471698] [<e00573ef>] rt2x00pci_probe+0x16f/0x1aa [rt2x00pci]
[ 49.471787] [<c01d6f31>] pci_device_probe+0x36/0x55
[ 49.471869] [<c022fc60>] driver_probe_device+0xc4/0x146
[ 49.471955] [<c022fdc7>] __driver_attach+0x50/0x83
[ 49.472037] [<c022f2aa>] bus_for_each_dev+0x35/0x57
[ 49.472120] [<c022fae1>] driver_attach+0x16/0x18
[ 49.472201] [<c022fd77>] __driver_attach+0x0/0x83
[ 49.472282] [<c022f54d>] bus_add_driver+0x6d/0x17d
[ 49.472363] [<c01d7052>] __pci_register_driver+0x41/0x6d
[ 49.472445] [<c0130fc3>] sys_init_module+0x1245/0x12fb
[ 49.472530] [<c0145ae4>] vma_link+0x89/0x92
[ 49.472616] [<e0057686>] rt2x00pci_write_tx_data+0x0/0x115 [rt2x00pci]
[ 49.472706] [<c0103be2>] sysenter_past_esp+0x5f/0x85
[ 49.472791] =======================
[ 49.476592] phy0: Selected rate control algorithm 'pid'
[/code2e62yf6h]

and the machine hangs sometimes thereafter, probably when NetworkManager tries to access the WLAN. I'm also attaching a full dmsg dump

Anything else I could try to get more useful debugging info?

mrjoel

02-02-2008 15:49:27

I get the exact same error (same stacktrace, same per-function offset, obviously different overall offsets) from git HEAD with rt2500usb. The error occurs anytime I load the module, whether during boot or afterwards. I also get the following error when attempting to remove the rt2500usb module

[code2srwokvg]
usbcore: deregistering interface driver rt2500usb
BUG: unable to handle kernel paging request at virtual address 1761604d
printing eip: f085eb3a *pde = 00000000
Oops: 0000 [#1]
Modules linked in: arc4 ecb blkcipher rt2500usb rt2x00usb rt2x00lib mac80211 cfg80211 mga drm ac battery ipv6 ext2 loop sd_mod snd_via82xx gameport snd_ac97_codec ac97_bus snd_pcm_oss snd_mixer_oss snd_pcm snd_page_alloc snd_mpu401_uart snd_seq_dummy usb_storage rtc snd_seq_oss pcspkr serio_raw snd_seq_midi snd_seq_midi_event snd_seq psmouse snd_timer snd_rawmidi snd_seq_device snd soundcore button via_agp agpgart evdev ext3 jbd mbcache dm_mirror dm_snapshot dm_mod raid1 md_mod ide_cd cdrom ata_generic libata scsi_mod ide_disk usbhid hid generic floppy ehci_hcd ohci_hcd e100 mii pdc202xx_new uhci_hcd via82cxxx usbcore ide_core thermal processor fan

Pid: 4885, comm: rmmod Not tainted (2.6.24 #1)
EIP: 0060:[<f085eb3a>] EFLAGS: 00010202 CPU: 0
EIP is at usb_kill_urb+0xf/0xbb [usbcore]
EAX: 17616025 EBX: 17616025 ECX: fffffffe EDX: 0000008c
ESI: da13542c EDI: d7de7040 EBP: ee99c400 ESP: d18fbe3c
DS: 007b ES: 007b FS: 0000 GS: 0033 SS: 0068
Process rmmod (pid: 4885, ti=d18fa000 task=d7f691c0 task.ti=d18fa000)
Stack: 40400000 d7de7040 ee99c400 00000000 00000005 00000008 d7de7040 f0e7273c
00000000 00000000 00000000 00000000 000001f4 d18fbec6 00000005 d7de7040
f0ebaa57 00000466 d18fbec6 00000002 000001f4 00000282 00000282 d7de7140
Call Trace:
[<f0e7273c>] rt2x00usb_disable_radio+0x7c/0xa9 [rt2x00usb]
[<f0ebaa57>] rt2500usb_set_device_state+0xf5e/0x11cb [rt2500usb]
[<c0120dad>] __cancel_work_timer+0x22/0xb2
[<f085ebe0>] usb_kill_urb+0xb5/0xbb [usbcore]
[<c01234be>] autoremove_wake_function+0x0/0x33
[<f0e5e20e>] rt2x00lib_disable_radio+0x60/0x62 [rt2x00lib]
[<f0e5e21d>] rt2x00lib_remove_dev+0xd/0x2a [rt2x00lib]
[<f0e7277e>] rt2x00usb_disconnect+0x15/0x3e [rt2x00usb]
[<f08616e8>] usb_unbind_interface+0x44/0x94 [usbcore]
[<c02153ba>] __device_release_driver+0x6b/0x88
[<c021577f>] driver_detach+0x5a/0x97
[<c0214fe1>] bus_remove_driver+0x63/0x81
[<f0861148>] usb_deregister+0x77/0x82 [usbcore]
[<c012f887>] sys_delete_module+0x14f/0x18c
[<c01103b9>] do_page_fault+0x18c/0x51b
[<c014ae83>] do_munmap+0x19b/0x1b4
[<c0103b5e>] sysenter_past_esp+0x5f/0x85
=======================
Code: 74 17 83 78 28 00 b2 ed 74 0f 83 78 2c 00 b2 d5 74 07 b2 98 e9 23 ff ff ff 89 d0 c3 57 53 89 c3 83 ec 14 85 c0 0f 84 a6 00 00 00 <83> 78 28 00 0f 84 9c 00 00 00 83 78 2c 00 0f 84 92 00 00 00 b8
EIP: [<f085eb3a>] usb_kill_urb+0xf/0xbb [usbcore] SS:ESP 0068:d18fbe3c
---[ end trace c1ba24cc25984087 ]---
[/code2srwokvg]

AdamBaker

02-02-2008 15:52:09

I can confirm I'm seeing the same thing with RT61 and RT73 but not b43. Trace is from RT61 but it looks pretty similar for RT73 other than pci changing to usb.

[code1a6rly1u]
[ 39.110707] phy1 -> rt61pci_validate_eeprom: EEPROM recovery - NIC: 0xff80
[ 39.110709] phy1 -> rt61pci_validate_eeprom: EEPROM recovery - Led: 0xe0ff
[ 39.110714] phy1 -> rt2x00_set_chip: Info - Chipset detected - rt: 0302, rf: 0003, rev: 0002661b.
[ 39.110755] WARNING: at net/wireless/util.c:83 set_mandatory_flags_band()
[ 39.110787] Pid: 2095, comm: modprobe Not tainted 2.6.24 #3
[ 39.110830] [<ee94fbe2>] ieee80211_set_bitrate_flags+0x1e2/0x1f0 [cfg80211]
[ 39.110905] [<ee94f533>] wiphy_register+0xa3/0x170 [cfg80211]
[ 39.110977] [<ee97d427>] ieee80211_register_hw+0x27/0x2a0 [mac80211]
[ 39.111052] [<ee9eeb3d>] rt2x00lib_probe_dev+0x2dd/0x390 [rt2x00lib]
[ 39.111111] [<c011c9a5>] __ioremap+0xe5/0x110
[ 39.111188] [<eea2243f>] rt2x00pci_probe+0x11f/0x1f0 [rt2x00pci]
[ 39.111258] [<c02580f6>] pci_device_probe+0x56/0x80
[ 39.111318] [<c02b10be>] driver_probe_device+0x8e/0x190
[ 39.111385] [<c02b132e>] __driver_attach+0x9e/0xa0
[ 39.111444] [<c02b049b>] bus_for_each_dev+0x3b/0x60
[ 39.111508] [<c02b0f36>] driver_attach+0x16/0x20
[ 39.111562] [<c02b1290>] __driver_attach+0x0/0xa0
[ 39.111615] [<c02b086a>] bus_add_driver+0x8a/0x1e0
[ 39.111681] [<c02582a3>] __pci_register_driver+0x53/0xa0
[ 39.111739] [<c014be51>] sys_init_module+0x151/0x1990
[ 39.111834] [<eea26000>] ac97_surround_jack_mode_get+0x0/0x10 [snd_ac97_codec]
[ 39.111916] [<eea22810>] rt2x00pci_write_tx_data+0x0/0x130 [rt2x00pci]
[ 39.111984] [<c01089fd>] sys_mmap2+0xcd/0xd0
[ 39.112049] [<c0104266>] sysenter_past_esp+0x5f/0x89
[ 39.112127] =======================
[/code1a6rly1u]

IvD

02-02-2008 16:07:17

Could you check the value of "want" is when the warning occurs, and what bitrates were registered?

Hazzl

02-02-2008 17:32:59

I'd be glad to check if you could tell me where to look for a "want" parameter. I'm not familiar with that.

BTW I seem to be unable to enable debugging
[code1fptyerr]
[ 383.448397] rt2500pci: Unknown parameter `debug'
[/code1fptyerr]

even though I enabled debug output in my kernel configuration (

IvD

02-02-2008 18:08:04

There is no debug parameter for the rt2500 module, if you enabled debug output in the kernel config, then all messages will be printed..

The "want" parameter is inside net/wireless/util.c

Hazzl

02-02-2008 20:57:13

I inserted a printk immediately before the WARN_ON on line 83 which gives me want=7

AdamBaker

02-02-2008 21:17:49

I'm about to add more debug to check but the lines
[code2hwzrco8]
for (i = 0; i < spec->num_rates; i++)
rt2x00lib_rate(&rates[0], i, rt2x00_get_rate(i));
[/code2hwzrco8]
in rt2x00lib_probe_hw_modes look suspicious to me, shouldn't that be rates?

IvD

02-02-2008 22:43:26

Ehh, yes that would make sense woulnd't it. ;)

Fixed in rt2x00.git, thanks. )

AdamBaker

02-02-2008 23:45:14

Unfortunately that doesn't seem to get us far - Arrived at non-free entry in the non-full queue on the second attempt to do a scan (and the 1st attempt failed) so it looks like the ring handling changes aren't quite right yet.

Unplugging the RT61 and plugging it back in got me a kernel panic somewhere in b43 which I guess points to a missing lock in mac80211. b43 doesn't seem very reliable the rest of the time, I'm seeing lots of retries from the AP. If those errors are in the stack we can expect to see poor performance from rt2x00 even when it does work.

Those will have to wait till tomorrow (at least) and missing broadcasts in moitor mode will have to wait till the card is vaguely working.

IvD

03-02-2008 13:54:36

I've committed a fix for the queue error. There was an obvious bug in the length calculation.

AdamBaker

03-02-2008 23:15:02

It now panic's in rt2x00pci_write_tx_data. I haven't managed to capture a full trace but it is at offset 0x44 in the function which is offset 0x774 in the file. I'm struggling slightly to make sense of how the optimiser has re-organized the code, I think the call to _ffs relates to the rt2x00_get_field32(word, TXD_ENTRY_OWNER_NIC) that occurs later.

[code6ld27q6g]
if (rt2x00queue_full(queue))
760: 0f b7 43 16 movzwl 0x16(%ebx),%eax
764: 66 3b 43 14 cmp 0x14(%ebx),%ax
768: 74 72 je 7dc <rt2x00pci_write_tx_data+0xac>
* @word: Word index from where the descriptor should be read.
* @value: Address where the descriptor value should be written into.
*/
static inline void rt2x00_desc_read(__le32 *desc, const u8 word, u32 *value)
{
*value = le32_to_cpu(desc[word]);
76a: 8b 06 mov (%esi),%eax
*
* Undefined if no bit exists, so code should check against 0 first.
*/
static inline unsigned long __ffs(unsigned long word)
{
__asm__("bsfl %1,%0"
76c: b9 01 00 00 00 mov $0x1,%ecx
771: 0f bc c9 bsf %ecx,%ecx
774: 8b 10 mov (%eax),%edx
return -EINVAL;

rt2x00_desc_read(priv_tx->desc, 0, &word);

[/code6ld27q6g]