BUG: getting erranesous command timeouts

[Holger Schurig]

Okay, in current wireless-testing (v2.6.26-rc3-8056-gc2c4044) I
have a bug which I haven't yet nailed down. When I insert my
card, the following happens:


Here I sent a command to the card:

May 23 13:54:08: libertas thread: 4: currenttxskb 00000000, dnld_sent 0
May 23 13:54:08: libertas enter: lbs_execute_next_command()
May 23 13:54:08: libertas host: EXEC_NEXT_CMD: sending command 0x0003
May 23 13:54:08: libertas enter: lbs_submit_command()
May 23 13:54:08: libertas cmd: DNLD_CMD: command 0x0003, seq 1, size 46
May 23 13:54:08: libertas DNLD_CMD: 03 00 2e 00 01 00 00 00 00 00 00 00 00 00 00 00
May 23 13:54:08: libertas DNLD_CMD: ff ff ff ff ff ff 00 00 00 00 00 00 00 00 00 00
May 23 13:54:08: libertas DNLD_CMD: 00 00 00 00 00 00 00 00 00 00 00 00 00 00
May 23 13:54:08: libertas_cs enter: if_cs_host_to_card(type 1, bytes 46)
May 23 13:54:08: libertas_cs enter: if_cs_send_cmd()
May 23 13:54:08: libertas_cs leave: if_cs_send_cmd(), ret 0
May 23 13:54:08: libertas_cs leave: if_cs_host_to_card(), ret 0

Here I sent a command to the card. Now I get an Interrupt:

May 23 13:54:08: libertas_cs enter (INT): if_cs_interrupt()
May 23 13:54:08: libertas_cs cs (INT): cause 0x0008
May 23 13:54:08: libertas_cs cs (INT): cmd upload over

and pull the response out of the CF card:

May 23 13:54:08: libertas_cs enter (INT): if_cs_receive_cmdres()
May 23 13:54:08: libertas_cs leave (INT): if_cs_receive_cmdres(), ret 0, len 46

I notify the upper libertas layout about this end leave the ISR:

May 23 13:54:08: libertas enter (INT): lbs_notify_command_response()
May 23 13:54:08: libertas leave (INT): lbs_notify_command_response()
May 23 13:54:08: libertas_cs leave (INT): if_cs_interrupt()

Now I have send a command, got a response, but the thread is going to
sleep. That shouldn't happen, or should it?

May 23 13:54:08: libertas leave: lbs_submit_command()
May 23 13:54:08: libertas leave: lbs_execute_next_command()
May 23 13:54:08: libertas thread: 1: currenttxskb 00000000, dnld_sent 0
May 23 13:54:08: libertas thread: sleeping, connect_status 1, psmode 0, psstate 0

And because the thread sleeps, we're now getting a command timeout:

May 23 13:54:11: libertas enter (INT): command_timer_fn()
May 23 13:54:11: libertas: command 0x0003 timed out
May 23 13:54:11: libertas leave (INT): command_timer_fn()

This wakes the thread again:

May 23 13:54:11: libertas thread: 2: currenttxskb 00000000, dnld_send 0
May 23 13:54:11: libertas thread: 3: currenttxskb 00000000, dnld_sent 0
May 23 13:54:11: libertas thread: 4: currenttxskb 00000000, dnld_sent 0

And now the thread precesses the command response, 3 seconds too late:

May 23 13:54:11: libertas enter: lbs_process_command_response()
May 23 13:54:11: libertas cmd: CMD_RESP: response 0x8003, seq 1, size 46
May 23 13:54:11: libertas CMD_RESP: 03 80 2e 00 01 00 00 00 02 00 13 02 08 00 40 00
May 23 13:54:11: libertas CMD_RESP: 00 0e 8e 16 68 a3 40 30 01 00 10 00 05 00 00 00
May 23 13:54:11: libertas CMD_RESP: 00 00 00 00 00 00 00 00 00 00 03 03 00 00
May 23 13:54:11: libertas leave: lbs_process_command_response(), ret 0


Right now I assume that the "wake_up_interruptible(&priv->waitq)"
in lbs_notify_command_response() doesn't work, because the thread
doesn't sleep at this time, however, I'm unsure what the proper fix
would be .... and why I wasn't bitten by this previously.