prism2_tx_timeout() card reset doesn't trigger wpa_supplicant reassociate
Duncan Grove
duncan.grove
Tue Apr 5 23:53:10 PDT 2005
Bug description:
If a card using hostap-driver-0.3.7 is reset in prism2_tx_timeout()
wpa_supplicant reassociation does not occur. Manual invocation of
"wpa_cli reassoc" is required to renegotiate access to the network.
Workaround/solution (although probably not the best fix! Jouni?):
--- hostap.c (revision 648)
+++ hostap.c (working copy)
@@ -53,7 +53,7 @@
#define hostap_crypto_deinit()
#endif /* HOSTAP_CRYPT_MODULE */
-#define TX_TIMEOUT (2 * HZ)
+#define TX_TIMEOUT (1 * HZ)
#define PRISM2_MAX_FRAME_SIZE 2304
#define PRISM2_MIN_MTU 256
@@ -899,6 +899,8 @@
local_info_t *local = iface->local;
struct hfa384x_regs regs;
+ union iwreq_data wrqu;
+
printk(KERN_WARNING "%s Tx timed out! Resetting card\n", dev->name);
netif_stop_queue(local->dev);
@@ -909,6 +911,14 @@
regs.swsupport0);
local->func->schedule_reset(local);
+
+ /* Send disconnect event to trigger reassociation
+ * if wpa_supplicant is used. */
+ memset(&wrqu, 0, sizeof(wrqu));
+ wrqu.ap_addr.sa_family = ARPHRD_ETHER;
+
+ printk(KERN_WARNING "%s Sending discon to trigger reassoc\n",
dev->name);
+ wireless_send_event(local->dev, SIOCGIWAP, &wrqu, NULL);
}
#endif /* HAVE_TX_TIMEOUT */
Further details:
Although the solution above recovers from a tx timeout, I would like to
solve the original
cause of the timeout because a substantial dropout in network
connectivity (~5 seconds
or so) is incurred. Although I think the bug is quite platform specific
I would appreciate
any thoughts anyone might have...
The platform is an Ipaq h5550 running (essentially) familiar hh37 with a
dual PCMCIA
sleeve. I am using a D-Link DCF660W (secondary F/W rev 1.7.4) in a CF-PCMCIA
sleeve with hostap-0.3.7 and wpa_supplicant 0.3.8. I am connecting to a
Cisco Aironet
1200 running IOS 12.3(2)JA using WPA-PSK. The tx timeout is *much* more
likely to
occur under heavy load (eg scp) than light (eg ssh) traffic.
At this stage I suspect a bug in either the PXA PCMCIA driver or in the
dual sleeve
driver -- particularly an interrupt related problem.
~ # dump_cis
Socket 0:
dev_info
NULL 0ns, 512b
attr_dev_info
SRAM 500ns, 1kb
vers_1 5.0, "D-Link", "DCF-660W", ""
manfid 0xd601, 0x0005
funcid network_adapter
lan_technology wireless
lan_speed 34 mb/sec
lan_speed 35 mb/sec
lan_media 2.4_GHz
lan_node_id 00 00 00 00 00 00
lan_connector Closed connector standard
config base 0x03e0 mask 0x0001 last_index 0x01
cftable_entry 0x01 [default]
Vcc Vnom 3300mV Vmin 3V Vmax 3600mV Iavg 300mA
Ipeak 350mA Idown 100mA
io 0x0000-0x003f [lines=6] [16bit]
irq mask 0xffff [level] [pulse]
Tracing through the kernel shows that immediately prior to the tx
timeout the card asserts that it is NOT READY (from the Ipaq sleeve's
expansion pack status register - for more information refer to
http://www.handhelds.org/platforms/hp/ipaq-h5xxx/04-expansion-if.pdf).
This can also be seen via "cat /proc/bus/pccard/00/status" where the ready
flags disappear. The card never seems to go READY again, hence triggering
the tx timeout.
Does anyone know what might cause the card to assert NOT READY and
never respond? Is it likely to be a flow control problem? Or an interrupt
problem? Or a power problem? Or something else?
I have increased some PCMCIA timing parameters in linux/drivers/pcmcia/pxa
and this seems to have lessened the problem, but it still occurs:
--- pxa.h (revision 648)
+++ pxa.h (working copy)
@@ -178,12 +178,12 @@
* was used to determine correct PXA_PCMCIA_IO_ACCES time
*/
-#define PXA_PCMCIA_IO_ACCESS (165)
+#define PXA_PCMCIA_IO_ACCESS (250) /* was 165 */
/* Default PC Card Common Memory timings*/
-#define PXA_PCMCIA_5V_MEM_ACCESS (250)
-#define PXA_PCMCIA_3V_MEM_ACCESS (250)
+#define PXA_PCMCIA_5V_MEM_ACCESS (250) /* was 250 */
+#define PXA_PCMCIA_3V_MEM_ACCESS (250) /* was 250 */
/* Atrribute Memory timing - must be constant via PC Card standart*/
@@ -193,7 +193,7 @@
/* The socket driver actually works nicely in interrupt-driven form,
* so the (relatively infrequent) polling is "just to be sure."
*/
-#define PXA_PCMCIA_POLL_PERIOD (2*HZ)
+#define PXA_PCMCIA_POLL_PERIOD (1*HZ)
As another data point, I have a single PCMCIA slot expansion sleeve,
and under load this asserts NOT READY as well, but recovers to
READY very quickly and the tx timeout doesn't occur.
FYI results of patch:
03:34:57.588428500 <7>pxa_pcmcia_poll_event(): polling for events
03:34:57.588483500 <7>pxa_pcmcia_task_handler(): entering PCMCIA
monitoring thread
03:34:57.588502500 <7>pxa_pcmcia_task_handler(): interrogating low-level
PCMCIA service
03:34:57.588519500 <7>events: <NONE>
03:34:57.588529500 <7>events: <NONE>
03:34:58.590207500 <7>pxa_pcmcia_poll_event(): polling for events
03:34:58.590261500 <7>pxa_pcmcia_task_handler(): entering PCMCIA
monitoring thread
03:34:58.590280500 <7>pxa_pcmcia_task_handler(): interrogating low-level
PCMCIA service
03:34:58.590297500 <7>events: <NONE>
03:34:58.590307500 <7>events: <NONE>
03:34:59.586953500 <7>pxa_pcmcia_poll_event(): polling for events
03:34:59.587008500 <7>pxa_pcmcia_task_handler(): entering PCMCIA
monitoring thread
03:34:59.587026500 <7>pxa_pcmcia_task_handler(): interrogating low-level
PCMCIA service
03:34:59.587043500 <7>pxa_pcmcia_events(): card ready value 0
03:34:59.587057500 <7>pxa_pcmcia_events(): card became UNready,
signalling event
03:34:59.587071500 <7>events: <NONE>
03:34:59.587079500 <7>events: <NONE>
03:35:00.760301500 <6>NETDEV WATCHDOG: wifi0: transmit timed out
03:35:00.760356500 <4>wifi0 Tx timed out! Resetting card
03:35:00.760366500 <7>wifi0: CMD=0011 EVSTAT=8091 OFFSET0=0000
OFFSET1=0000 SWSUPPORT0=8a32
03:35:00.760383500 <4>wifi0 Sending discon to trigger reassoc
03:35:00.760397500 <7>wifi0: scheduled card reset
03:35:00.760408500 <4>hostap_cs: wifi0: resetting card
03:35:00.760421500 <7>pxa_pcmcia_set_mem_map() for sock 0
03:35:00.760432500 <7> map 0 speed 300
03:35:00.760441500 <4> sys_start 0x28000000
03:35:00.760451500 <4> sys_stop 0x28000fff
03:35:00.760460500 <4> card_start 0x0
03:35:00.760469500 <4> flags: ACTIVE ATTRIB
03:35:00.760478500 <7>prism2_pccard_cor_sreset: original COR 41
03:35:00.760490500 <7>pxa_pcmcia_set_mem_map() for sock 0
03:35:00.760501500 <7> map 0 speed 300
03:35:00.760510500 <4> sys_start 0x28000000
03:35:00.760519500 <4> sys_stop 0x28000fff
03:35:00.760529500 <4> card_start 0x0
03:35:00.760537500 <4> flags: ACTIVE ATTRIB
03:35:00.760547500 <7>pxa_pcmcia_set_mem_map() for sock 0
03:35:00.760558500 <7> map 0 speed 300
03:35:00.760566500 <4> sys_start 0x28000000
03:35:00.760576500 <4> sys_stop 0x28000fff
03:35:00.760585500 <4> card_start 0x0
03:35:00.760594500 <4> flags: ACTIVE ATTRIB
03:35:00.760603500 <7>wifi0: removed pending cmd_queue entry (type=1,
cmd=0x0011, param0=0xf)
03:35:00.760620500 <7>wifi0: removed pending cmd_queue entry (type=1,
cmd=0x010b, param0=0x0)
03:35:00.760636500 <7>pxa_pcmcia_poll_event(): polling for events
03:35:00.760649500 <7>prism2_hw_init: initialized in 200 ms
03:35:00.781222500 <7>pxa_pcmcia_task_handler(): entering PCMCIA
monitoring thread
03:35:00.781282500 <4>NET: 6 messages suppressed.
03:35:00.781295500 <7>wifi0: dropped unencrypted TX data frame
(drop_unencrypted=1)
03:35:00.781311500 <7>wifi0: dropped unencrypted TX data frame
(drop_unencrypted=1)
03:35:00.781325500 <7>wifi0: dropped unencrypted TX data frame
(drop_unencrypted=1)
03:35:00.781341500 <7>wifi0: dropped unencrypted TX data frame
(drop_unencrypted=1)
03:35:00.781355500 <7>wifi0: dropped unencrypted TX data frame
(drop_unencrypted=1)
03:35:00.781370500 <7>pxa_pcmcia_task_handler(): interrogating low-level
PCMCIA service
03:35:00.781385500 <7>pxa_pcmcia_events(): card ready value 1
03:35:00.781398500 <7>pxa_pcmcia_events(): card became ready, signalling
event
03:35:00.781412500 <7>events: <NONE>
03:35:00.781420500 <7>events: <NONE>
03:35:01.267101500 <7>wifi0: dropped unencrypted TX data frame
(drop_unencrypted=1)
03:35:01.586750500 <7>pxa_pcmcia_poll_event(): polling for events
03:35:01.587792500 <7>pxa_pcmcia_task_handler(): entering PCMCIA
monitoring thread
03:35:01.587852500 <7>pxa_pcmcia_task_handler(): interrogating low-level
PCMCIA service
03:35:01.587870500 <7>events: <NONE>
03:35:01.587881500 <7>events: <NONE>
03:35:01.703240500 <7>wifi0: LinkStatus=2 (Disconnected)
03:35:01.716314500 <7>wifi0: LinkStatus: BSSID=44:44:44:44:44:44
03:35:01.729204500 <7>wifi0: LinkStatus=2 (Disconnected)
03:35:01.742932500 <7>wifi0: LinkStatus: BSSID=44:44:44:44:44:44
03:35:01.755073500 <7>wifi0: LinkStatus=2 (Disconnected)
03:35:01.768539500 <7>wifi0: LinkStatus: BSSID=44:44:44:44:44:44
03:35:01.770272500 <7>wlan0: Trying to join BSSID 00:13:1a:30:55:30
03:35:01.798678500 <7>wifi0: LinkStatus=1 (Connected)
03:35:01.802286500 <7>wifi0: LinkStatus: BSSID=00:13:1a:30:55:30
03:35:01.828133500 <7>wifi0: dropped unencrypted TX data frame
(drop_unencrypted=1)
03:35:02.497216500 <7>wifi0: dropped unencrypted TX data frame
(drop_unencrypted=1)
03:35:02.586747500 <7>pxa_pcmcia_poll_event(): polling for events
03:35:02.587787500 <7>pxa_pcmcia_task_handler(): entering PCMCIA
monitoring thread
03:35:02.587847500 <7>pxa_pcmcia_task_handler(): interrogating low-level
PCMCIA service
03:35:02.587865500 <7>events: <NONE>
03:35:02.587876500 <7>events: <NONE>
03:35:02.951944500 <7>TKIP: replay detected: STA=00:13:1a:30:55:30
previous TSC 0000000000111
03:35:02.952009500 <7>wifi0: decryption failed (SA=00:13:1a:30:55:30) res=-4
03:35:03.586772500 <7>pxa_pcmcia_poll_event(): polling for events
03:35:03.587817500 <7>pxa_pcmcia_task_handler(): entering PCMCIA
monitoring thread
03:35:03.587877500 <7>pxa_pcmcia_task_handler(): interrogating low-level
PCMCIA service
03:35:03.587895500 <7>events: <NONE>
03:35:03.587906500 <7>events: <NONE>
03:35:04.586766500 <7>pxa_pcmcia_poll_event(): polling for events
03:35:04.587816500 <7>pxa_pcmcia_task_handler(): entering PCMCIA
monitoring thread
03:35:04.587876500 <7>pxa_pcmcia_task_handler(): interrogating low-level
PCMCIA service
03:35:04.587894500 <7>events: <NONE>
03:35:04.587905500 <7>events: <NONE>
03:35:05.586879500 <7>pxa_pcmcia_poll_event(): polling for events
03:35:05.586933500 <7>pxa_pcmcia_task_handler(): entering PCMCIA
monitoring thread
03:35:05.586951500 <7>pxa_pcmcia_task_handler(): interrogating low-level
PCMCIA service
03:35:05.586969500 <7>events: <NONE>
03:35:05.586979500 <7>events: <NONE>
More information about the Hostap
mailing list