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()
-#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);
@@ -909,6 +911,14 @@
+        /* 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", 
+        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 
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:
    NULL 0ns, 512b
    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
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."

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 
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 
03:35:00.781311500 <7>wifi0: dropped unencrypted TX data frame 
03:35:00.781325500 <7>wifi0: dropped unencrypted TX data frame 
03:35:00.781341500 <7>wifi0: dropped unencrypted TX data frame 
03:35:00.781355500 <7>wifi0: dropped unencrypted TX data frame 
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 
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 
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 
03:35:02.497216500 <7>wifi0: dropped unencrypted TX data frame 
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