Hi Ivo,
with the latest changes, I guess in particular the commit "rt2x00: Fix
in _atomic() usage" changing the flags for rt2500pci results in infinite
calls to the new "rt2x00mc_configure_filter" in rt2x00mac.c. I noticed
this after applying the attached patch that I've been using to debug
some hostapd problems. All it does is add some printk's, I don't think
it can cause the problem, right?
I use compat-wireless, to test stuff on a fedora system, this is the
uname -a:
Linux steady.steadydecline.net 2.6.24.3-50.fc8 #1 SMP Thu Mar 20
13:39:08 EDT 2008 x86_64 x86_64 x86_64 GNU/Linux
this checkout gives the problem (most recent wireless-testing):
mac80211-v2.6.25_rc7_3570_g78f8e64_080329-1.x86_64.rpm
while this one does not:
mac80211-v2.6.25_rc5_2672_g57b58cd_080326-1.x86_64.rpm
with the patch (see attachment) applied, I get this in the logs, upon
running hostapd:
-------------------------------------------------------------
Mar 29 14:25:49 steady kernel: rt2500pci filter_flags: 2
Mar 29 14:25:49 steady kernel:last message repeated 423 times
Mar 29 14:25:49 steady kernel: rt2500pci filte0pci filter_flags: 2
Mar 29 14:25:49 steady kernel: rt2500pci filter_flags: 2
Mar 29 14:25:49 steady kernel:last message repeated 139 times
------------------------------------------------------------
this continues forever, spamming the logs, and eventually making the
system unresponsive, requiring a reboot.
without the patch adding the printk to rt2x00mac_configure_filter, I get
this soft lockup:
------------------------------------------------------------
rt2500pci MAC changed: 00:0c:f6:14:05:19
ADDRCONF(NETDEV_UP): wlan1: link is not ready
BUG: soft lockup - CPU#0 stuck for 11s! [rt2500pci:1541]
CPU 0:
Modules linked in: cpufreq_stats nfsd lockd nfs_acl auth_rpcgss exportfs
autofs4 fuse rfcomm l2cap sunrpc ipt_REJECT xt_multiport iptable_filter
ipt_MASQUERADE ipt_REDIRECT iptable_nat nf_nat nf_conntrack_ipv4 ipt_TOS
iptable_mangle ip_tables nf_conntrack_ipv6 xt_state nf_conntrack
xt_tcpudp ip6t_ipv6header ip6t_REJECT ip6table_filter ip6_tables
x_tables ipv6 cpufreq_ondemand acpi_cpufreq ext2 dm_mirror dm_multipath
dm_mod wm8775 cx25840 msp3400 saa7115 tuner tea5767 tda8290 tuner_simple
snd_hda_intel mt20xx snd_seq_dummy tea5761 snd_seq_oss
snd_seq_midi_event snd_seq arc4 snd_seq_device ecb snd_pcm_oss
snd_mixer_oss blkcipher snd_pcm ivtv i2c_algo_bit cx2341x snd_timer
tveeprom snd_page_alloc rt2500pci(U) rt2x00pci(U) rt2x00lib(U) videodev
rfkill snd_hwdep input_polldev firewire_ohci v4l2_common firewire_core
crc_itu_t v4l1_compat rtl8187(U) mac80211(U) snd ati_remote2 r8169
pcspkr eeprom_93cx6(U) lirc_atiusb cfg80211(U) lirc_dev soundcore
hci_usb button iTCO_wdt i2c_i801 i2c_core bluetooth iTCO_vendor_support
sky2 sr_mod sg floppy cdrom ahci pata_jmicron ata_generic ata_piix
pata_acpi libata sd_mod scsi_mod raid456 async_xor async_memcpy async_tx
xor ext3 jbd mbcache uhci_hcd ohci_hcd ehci_hcd
Pid: 1541, comm: rt2500pci Not tainted 2.6.24.3-50.fc8 #1
RIP: 0010:[<ffffffff8126986b>] [<ffffffff8126986b>]
_spin_unlock_irqrestore+0x8/0x9
RSP: 0018:ffff8101285d7e98 EFLAGS: 00000202
RAX: ffff81012d975fa0 RBX: ffffffff8824002e RCX: 0000000000000000
RDX: 0000000300000000 RSI: 0000000000000202 RDI: ffff81012d975f80
RBP: ffff81012d975f98 R08: ffff81012d975f88 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000000 R12: 0000000300000000
R13: ffffffffffffff10 R14: ffffffff8824002e R15: ffffffffffffffff
FS: 0000000000000000(0000) GS:ffffffff813cb000(0000)
knlGS:0000000000000000
CS: 0010 DS: 0018 ES: 0018 CR0: 000000008005003b
CR2: 0000003ce5e9afa0 CR3: 0000000122418000 CR4: 00000000000006a0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
Call Trace:
[<ffffffff81045ba6>] queue_work+0x37/0x40
[<ffffffff88240065>] :rt2x00lib:rt2x00lib_packetfilter_scheduled
+0x37/0x3c
[<ffffffff81045635>] run_workqueue+0x7f/0x10b
[<ffffffff81045f3d>] worker_thread+0x0/0xe4
[<ffffffff81046017>] worker_thread+0xda/0xe4
[<ffffffff81049221>] autoremove_wake_function+0x0/0x2e
[<ffffffff810490f2>] kthread+0x47/0x75
[<ffffffff8100cca8>] child_rip+0xa/0x12
[<ffffffff81034326>] check_preempt_wakeup+0x0/0xa5
[<ffffffff810490ab>] kthread+0x0/0x75
[<ffffffff8100cc9e>] child_rip+0x0/0x12
------------------------------------------------------------
I guess this softlock might be prevented from winding up in the logs
with the printk I've added, because that spams the log.
any ideas?
best regards,
Bas Hulsken
Hi,
> > The driver most definitely shouldn't do anything, but neither of those
> > flags should be needed. In a BSS, all frames from the stations are
> > addressed to the BSS-MAC, i.e. to the AP, so the regular MAC filter
> > should allow them through without any sort of promisc. And control
> > frames aren't needed, those are just ack/cts/... frames.
>
> Ok, I think I found the problem. The packet filter in all Ralink devices have a
> TODS filter. Currently I had this only enabled when FIF_PROMISC_IN_BSS was set.
> I'll change this to a check that determines if master mode is enabled.
Ah, that would explain it. Bas, I'll scratch this item off my todo list,
please get back to me if that doesn't fix it.
johannes
Hi,
> Thanks for helping debug this. I haven't had a chance to run hostapd
> again, been far too busy. As it stands, I'm not sure when I can possibly
> get to that.
>
> > > rt2500pci filter_flags: 2
> > > rt2500pci MAC changed: 00:0c:f6:14:05:19
> >
> > Packet filter flags of 2 sounds a bit restrictive.
> >
> > Johannes, for Master mode shouldn't the following flags be set as well:
> > FIF_PROMISC_IN_BSS
> > FIF_CONTROL
> >
> > Or should the driver enable those automatically when master mode is enabled?
>
> The driver most definitely shouldn't do anything, but neither of those
> flags should be needed. In a BSS, all frames from the stations are
> addressed to the BSS-MAC, i.e. to the AP, so the regular MAC filter
> should allow them through without any sort of promisc. And control
> frames aren't needed, those are just ack/cts/... frames.
Ok, I think I found the problem. The packet filter in all Ralink devices have a
TODS filter. Currently I had this only enabled when FIF_PROMISC_IN_BSS was set.
I'll change this to a check that determines if master mode is enabled.
Ivo
Hi Ivo,
Thanks for helping debug this. I haven't had a chance to run hostapd
again, been far too busy. As it stands, I'm not sure when I can possibly
get to that.
> > rt2500pci filter_flags: 2
> > rt2500pci MAC changed: 00:0c:f6:14:05:19
>
> Packet filter flags of 2 sounds a bit restrictive.
>
> Johannes, for Master mode shouldn't the following flags be set as well:
> FIF_PROMISC_IN_BSS
> FIF_CONTROL
>
> Or should the driver enable those automatically when master mode is enabled?
The driver most definitely shouldn't do anything, but neither of those
flags should be needed. In a BSS, all frames from the stations are
addressed to the BSS-MAC, i.e. to the AP, so the regular MAC filter
should allow them through without any sort of promisc. And control
frames aren't needed, those are just ack/cts/... frames.
johannes
Hi,
On Sat, 2008-03-29 at 15:53 +0100, Ivo van Doorn wrote:
> Hi,
>
> > with the latest changes, I guess in particular the commit "rt2x00: Fix
> > in _atomic() usage" changing the flags for rt2500pci results in infinite
> > calls to the new "rt2x00mc_configure_filter" in rt2x00mac.c. I noticed
> > this after applying the attached patch that I've been using to debug
> > some hostapd problems. All it does is add some printk's, I don't think
> > it can cause the problem, right?
>
> Oops...
> I found the problem, patch coming will be released in a few minutes. :)
ok, that fixes it. Thanks!
unfortunately, I still can't get hostapd to work :( Do you have some
ideas about this Ivo? I've already discussed this a bit with Johannes,
but he couldn't find any obvious problems. It seems that EAPOL keys sent
from my laptop to hostapd (running on the rt2500pci) don't arrive. Only
when switching wlan1 to promiscuous, they arrive. Unfortunately then
hostapd hangs (perhaps to unrelated things, perhaps due to the fact that
wlan1 is promiscuous, I don't know.).
Here are some logs:
hostapd, without wlan1 set to promiscuous:
--------------------------------------------------------------------
wlan1: STA 00:1b:77:a4:db:26 WPA: sending 1/4 msg of 4-Way Handshake
WPA: Send EAPOL(version=1 secure=0 mic=0 ack=1 install=0 pairwise=8
kde_len=0 keyidx=0 encr=0)
STA 00:1b:77:a4:db:26 sent probe request for our SSID
MGMT (TX callback) ACK
mgmt::proberesp cb
wlan1: STA 00:1b:77:a4:db:26 WPA: EAPOL-Key timeout
WPA: 00:1b:77:a4:db:26 WPA_PTK entering state PTKSTART
wlan1: STA 00:1b:77:a4:db:26 WPA: sending 1/4 msg of 4-Way Handshake
WPA: Send EAPOL(version=1 secure=0 mic=0 ack=1 install=0 pairwise=8
kde_len=0 keyidx=0 encr=0)
wlan1: STA 00:1b:77:a4:db:26 WPA: EAPOL-Key timeout
--------------------------------------------------------------------
this repeats for a while, all the time giving EAPOL-Key timeout
messages. tetherial -i mon.wlan1 on the hostapd machine shows that no
EAPOL key's are received, while tetherial on the laptop shows that they
are being sent.
this is the flag status when running hostapd; as printed with
printk(KERN_INFO "rt2500pci filter_flags: %d\n",
rt2x00dev->packet_filter);
rt2500pci filter_flags: 2
rt2500pci MAC changed: 00:0c:f6:14:05:19
hostapd, with wlan1 set to promiscuous:
--------------------------------------------------------------------
authentication: STA=00:1b:77:a4:db:26 auth_alg=0 auth_transaction=1
status_code=0 wep=0
New STA
wlan1: STA 00:1b:77:a4:db:26 IEEE 802.11: authentication OK (open
system)
wlan1: STA 00:1b:77:a4:db:26 MLME:
MLME-AUTHENTICATE.indication(00:1b:77:a4:db:26, OPEN_SYSTEM)
wlan1: STA 00:1b:77:a4:db:26 MLME:
MLME-DELETEKEYS.request(00:1b:77:a4:db:26)
authentication reply: STA=00:1b:77:a4:db:26 auth_alg=0
auth_transaction=2 resp=0 (IE len=0)
MGMT (TX callback) ACK
mgmt::auth cb
wlan1: STA 00:1b:77:a4:db:26 IEEE 802.11: authenticated
MGMT
mgmt::assoc_req
association request: STA=00:1b:77:a4:db:26 capab_info=0x411
listen_interval=10
WME IE - hexdump(len=7): 00 50 f2 02 00 01 00
Validating WME IE: OUI 00:50:f2 OUI type 2 OUI sub-type 0 version 1
Failed to set CTS protect in kernel driver
Failed to set Short Slot Time option in kernel driver
Could not set preamble for kernel driver
new AID 1
wlan1: STA 00:1b:77:a4:db:26 IEEE 802.11: association OK (aid 1)
MGMT (TX callback) ACK
mgmt::assoc_resp cb
wlan1: STA 00:1b:77:a4:db:26 IEEE 802.11: associated (aid 1, accounting
session 47EE6A5B-00000004)
wlan1: STA 00:1b:77:a4:db:26 MLME:
MLME-ASSOCIATE.indication(00:1b:77:a4:db:26)
wlan1: STA 00:1b:77:a4:db:26 MLME:
MLME-DELETEKEYS.request(00:1b:77:a4:db:26)
wlan1: STA 00:1b:77:a4:db:26 WPA: event 1 notification
wlan1: STA 00:1b:77:a4:db:26 WPA: start authentication
WPA: 00:1b:77:a4:db:26 WPA_PTK entering state INITIALIZE
wlan1: STA 00:1b:77:a4:db:26 IEEE 802.1X: unauthorizing port
WPA: 00:1b:77:a4:db:26 WPA_PTK_GROUP entering state IDLE
WPA: 00:1b:77:a4:db:26 WPA_PTK entering state AUTHENTICATION
WPA: 00:1b:77:a4:db:26 WPA_PTK entering state AUTHENTICATION2
WPA: 00:1b:77:a4:db:26 WPA_PTK entering state INITPSK
WPA: 00:1b:77:a4:db:26 WPA_PTK entering state PTKSTART
wlan1: STA 00:1b:77:a4:db:26 WPA: sending 1/4 msg of 4-Way Handshake
WPA: Send EAPOL(version=1 secure=0 mic=0 ack=1 install=0 pairwise=8
kde_len=0 keyidx=0 encr=0)
IEEE 802.1X: 125 bytes from 00:1b:77:a4:db:26
IEEE 802.1X: version=1 type=3 length=121
wlan1: STA 00:1b:77:a4:db:26 WPA: received EAPOL-Key frame (2/4
Pairwise)
WPA: 00:1b:77:a4:db:26 WPA_PTK entering state PTKCALCNEGOTIATING
WPA: PTK derivation - A1=00:0c:f6:14:05:19 A2=00:1b:77:a4:db:26
WPA: PMK - hexdump(len=32): [REMOVED]
WPA: PTK - hexdump(len=64): [REMOVED]
WPA: 00:1b:77:a4:db:26 WPA_PTK entering state PTKCALCNEGOTIATING2
WPA: 00:1b:77:a4:db:26 WPA_PTK entering state PTKINITNEGOTIATING
--------------------------------------------------------------------
after this, hostapd hangs, and after ctrl-C it outputs this:
--------------------------------------------------------------------
eloop: could not process SIGINT or SIGTERM in two seconds. Looks like
there
is a bug that ends up in a busy loop that prevents clean shutdown.
Killing program forcefully.
--------------------------------------------------------------------
the flag status; as printed with printk(KERN_INFO "rt2500pci
filter_flags: %d\n", rt2x00dev->packet_filter);
when wlan1 is promiscuous:
device mon.wlan1 entered promiscuous mode
rt2500pci filter_flags: 67
device mon.wlan1 left promiscuous mode
rt2500pci filter_flags: 2
so obviously authentication get's a lot further with wlan1 in
promiscuous mode, and EAPOL keys sent from the laptop are being
received. Any clues as to why this happens? Is 2 (00000010B) the correct
flag status? Or 67 (01000011B). Hope you can see what's going wrong
here.. I don't even know if the issue is with rt2x00 or somewhere else,
although Johannes can use hostapd on a broadcom chipset.
thanks a lot for your help,
Bas
>
> Ivo
> --
> 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
Hi,
> with the latest changes, I guess in particular the commit "rt2x00: Fix
> in _atomic() usage" changing the flags for rt2500pci results in infinite
> calls to the new "rt2x00mc_configure_filter" in rt2x00mac.c. I noticed
> this after applying the attached patch that I've been using to debug
> some hostapd problems. All it does is add some printk's, I don't think
> it can cause the problem, right?
Oops...
I found the problem, patch coming will be released in a few minutes. :)
Ivo
Hi,
> --------------------------------------------------------------------
> this repeats for a while, all the time giving EAPOL-Key timeout
> messages. tetherial -i mon.wlan1 on the hostapd machine shows that no
> EAPOL key's are received, while tetherial on the laptop shows that they
> are being sent.
Could you enable debugfs and use the tools here:
http://www-user.rhrk.uni-kl.de/~nissler/rt2x00/index.html
To create a dump of the frames as they are actually send out from the driver
to the hardware including the status report. This will tell if rt2x00 is actually
bringing the frame to the hardware correctly.
> this is the flag status when running hostapd; as printed with
> printk(KERN_INFO "rt2500pci filter_flags: %d\n",
> rt2x00dev->packet_filter);
>
> rt2500pci filter_flags: 2
> rt2500pci MAC changed: 00:0c:f6:14:05:19
Packet filter flags of 2 sounds a bit restrictive.
Johannes, for Master mode shouldn't the following flags be set as well:
FIF_PROMISC_IN_BSS
FIF_CONTROL
Or should the driver enable those automatically when master mode is enabled?
> IEEE 802.1X: 125 bytes from 00:1b:77:a4:db:26
> IEEE 802.1X: version=1 type=3 length=121
> wlan1: STA 00:1b:77:a4:db:26 WPA: received EAPOL-Key frame (2/4
> Pairwise)
> WPA: 00:1b:77:a4:db:26 WPA_PTK entering state PTKCALCNEGOTIATING
> WPA: PTK derivation - A1=00:0c:f6:14:05:19 A2=00:1b:77:a4:db:26
> WPA: PMK - hexdump(len=32): [REMOVED]
> WPA: PTK - hexdump(len=64): [REMOVED]
> WPA: 00:1b:77:a4:db:26 WPA_PTK entering state PTKCALCNEGOTIATING2
> WPA: 00:1b:77:a4:db:26 WPA_PTK entering state PTKINITNEGOTIATING
> --------------------------------------------------------------------
I'm not sure what is happening here...
Ivo