8686 sdio - don't get first interrupt

Charlie Hamilton charleeh at earthlink.net
Tue Apr 5 20:07:20 EDT 2011


Hi,

I've got a Marvell 8686 with an SDIO interface using a Conexant mmc/sdio
driver. I can successfully load the firmware. When I send the first
command to the host, I don't get an interrupt. It times out and resends
the command, and I immediately get an interrupt. I then read out the
reply to the first command, and the sequence numbers don't match.

>From this point on, every command times out and resendsreads out a reply
to with a non-matching sequence number, because there is always a second
reply because they all timeout.

It might be livable, but the scan command causes the marvell part to
stop responding entirely, and I suspect it has something to do with the
fact that we end up issuing every command twice.

Has anyone seen this type of behavior before? I suspect it's a problem
in how the SDIO driver is initialized, but am hoping someone's been down
this road before.

What follows is the libertas debug output from the point where the
firmware is loaded until a few packets have been processed.

Thanks,
Charlie

=====


<7>[   78.120000] libertas enter: lbs_add_card()
<7>[   78.120000] libertas enter: lbs_init_adapter()
<7>[   78.120000] libertas enter: lbs_allocate_cmd_buffer()
<7>[   78.120000] libertas enter: __lbs_cleanup_and_insert_cmd()
<7>[   78.120000] libertas leave: __lbs_cleanup_and_insert_cmd()
<7>[   78.120000] libertas enter: __lbs_cleanup_and_insert_cmd()
<7>[   78.120000] libertas leave: __lbs_cleanup_and_insert_cmd()
<7>[   78.120000] libertas enter: __lbs_cleanup_and_insert_cmd()
<7>[   78.120000] libertas leave: __lbs_cleanup_and_insert_cmd()
<7>[   78.120000] libertas enter: __lbs_cleanup_and_insert_cmd()
<7>[   78.120000] libertas leave: __lbs_cleanup_and_insert_cmd()
<7>[   78.120000] libertas enter: __lbs_cleanup_and_insert_cmd()
<7>[   78.120000] libertas leave: __lbs_cleanup_and_insert_cmd()
<7>[   78.120000] libertas enter: __lbs_cleanup_and_insert_cmd()
<7>[   78.120000] libertas leave: __lbs_cleanup_and_insert_cmd()
<7>[   78.120000] libertas enter: __lbs_cleanup_and_insert_cmd()
<7>[   78.120000] libertas leave: __lbs_cleanup_and_insert_cmd()
<7>[   78.120000] libertas enter: __lbs_cleanup_and_insert_cmd()
<7>[   78.120000] libertas leave: __lbs_cleanup_and_insert_cmd()
<7>[   78.120000] libertas enter: __lbs_cleanup_and_insert_cmd()
<7>[   78.120000] libertas leave: __lbs_cleanup_and_insert_cmd()
<7>[   78.120000] libertas enter: __lbs_cleanup_and_insert_cmd()
<7>[   78.120000] libertas leave: __lbs_cleanup_and_insert_cmd()
<7>[   78.120000] libertas leave: lbs_allocate_cmd_buffer(), ret 0
<7>[   78.120000] libertas leave: lbs_init_adapter(), ret 0
<7>[   78.120000] libertas thread: Starting main thread...
<7>[   78.120000] libertas leave: lbs_add_card(), priv c08b4300
<7>[   78.120000] libertas enter: lbs_start_card()
<7>[   78.120000] libertas enter: lbs_setup_firmware()
<7>[   78.120000] libertas enter: lbs_update_hw_spec()
<7>[   78.120000] libertas enter: __lbs_cmd()
<7>[   78.120000] libertas enter: __lbs_cmd_async()
<7>[   78.120000] libertas enter: lbs_get_cmd_ctrl_node()
<7>[   78.120000] libertas leave: lbs_get_cmd_ctrl_node()
<7>[   78.120000] libertas host: PREP_CMD: command 0x0003
<7>[   78.120000] libertas enter: lbs_queue_cmd()
<7>[   78.120000] libertas host: QUEUE_CMD: inserted command 0x0003 into
cmdpendingq
<7>[   78.120000] libertas leave: lbs_queue_cmd()
<7>[   78.120000] libertas leave: __lbs_cmd_async(), ret c2ff5a00
<7>[   78.120000] libertas enter: lbs_thread()
<7>[   78.120000] libertas thread: 1: currenttxskb (null), dnld_sent 0
<7>[   78.120000] libertas thread: 2: currenttxskb (null), dnld_send 0
<7>[   78.120000] libertas thread: 3: currenttxskb (null), dnld_sent 0
<7>[   78.120000] libertas thread: 4: currenttxskb (null), dnld_sent 0
<7>[   78.120000] libertas enter: lbs_execute_next_command()
<7>[   78.120000] libertas host: EXEC_NEXT_CMD: sending command 0x0003
<7>[   78.120000] libertas enter: lbs_submit_command()
<7>[   78.120000] libertas cmd: DNLD_CMD: command 0x0003, seq 1, size 46
<4>[   78.120000] libertas DNLD_CMD: 03 00 2e 00 01 00 00 00 00 00 00 00
00 00 00 00 
<4>[   78.120000] libertas DNLD_CMD: ff ff ff ff ff ff 00 00 00 00 00 00
00 00 00 00 
<4>[   78.130000] libertas DNLD_CMD: 00 00 00 00 00 00 00 00 00 00 00 00
00 00 
<7>[   78.140000] libertas enter: if_sdio_host_to_card(type 1, bytes 46)
<7>[   78.140000] libertas leave: if_sdio_host_to_card(), ret 0
<7>[   78.140000] libertas leave: lbs_submit_command()
<7>[   78.140000] libertas leave: lbs_execute_next_command()
<7>[   78.140000] libertas thread: 1: currenttxskb (null), dnld_sent 2
<7>[   78.140000] libertas thread: sleeping, connect_status 1, psmode 0,
psstate 0
<7>[   78.140000] libertas enter: if_sdio_host_to_card_worker()
<7>[   78.150000] libertas leave: if_sdio_host_to_card_worker()
<7>[   81.140000] libertas enter (INT): command_timer_fn()
<6>[   81.140000] libertas: command 0x0003 timed out
<7>[   81.140000] libertas leave (INT): command_timer_fn()
<7>[   81.140000] libertas thread: 2: currenttxskb (null), dnld_send 2
<7>[   81.140000] libertas thread: 3: currenttxskb (null), dnld_sent 2
<7>[   81.140000] libertas thread: 4: currenttxskb (null), dnld_sent 2
<6>[   81.140000] libertas: requeueing command 0x0003 due to timeout
(#1)
<7>[   81.140000] libertas enter: lbs_execute_next_command()
<7>[   81.140000] libertas host: EXEC_NEXT_CMD: sending command 0x0003
<7>[   81.140000] libertas enter: lbs_submit_command()
<7>[   81.140000] libertas cmd: DNLD_CMD: command 0x0003, seq 1, size 46
<4>[   81.140000] libertas DNLD_CMD: 03 00 2e 00 01 00 00 00 00 00 00 00
00 00 00 00 
<4>[   81.150000] libertas DNLD_CMD: ff ff ff ff ff ff 00 00 00 00 00 00
00 00 00 00 
<4>[   81.160000] libertas DNLD_CMD: 00 00 00 00 00 00 00 00 00 00 00 00
00 00 
<7>[   81.160000] libertas enter: if_sdio_host_to_card(type 1, bytes 46)
<7>[   81.160000] libertas leave: if_sdio_host_to_card(), ret 0
<7>[   81.160000] libertas leave: lbs_submit_command()
<7>[   81.160000] libertas leave: lbs_execute_next_command()
<7>[   81.160000] libertas thread: 1: currenttxskb (null), dnld_sent 2
<7>[   81.160000] libertas thread: sleeping, connect_status 1, psmode 0,
psstate 0
<7>[   81.160000] libertas enter: if_sdio_host_to_card_worker()
<7>[   81.160000] libertas leave: if_sdio_host_to_card_worker()
<7>[   81.160000] libertas enter: if_sdio_interrupt()
<7>[   81.160000] libertas sdio: interrupt: 0x3
<7>[   81.160000] libertas enter: lbs_host_to_card_done()
<7>[   81.160000] libertas leave: lbs_host_to_card_done()
<7>[   81.160000] libertas enter: if_sdio_card_to_host()
<7>[   81.160000] libertas sdio: packet of type 1 and size 50 bytes
<7>[   81.160000] libertas enter: if_sdio_handle_cmd()
<7>[   81.160000] libertas enter: lbs_notify_command_response()
<7>[   81.160000] libertas leave: lbs_notify_command_response()
<7>[   81.160000] libertas leave: if_sdio_handle_cmd(), ret 0
<7>[   81.160000] libertas leave: if_sdio_card_to_host(), ret 0
<7>[   81.160000] libertas leave: if_sdio_interrupt(), ret 0
<7>[   81.160000] libertas thread: 2: currenttxskb (null), dnld_send 0
<7>[   81.160000] libertas thread: 3: currenttxskb (null), dnld_sent 0
<7>[   81.160000] libertas thread: 4: currenttxskb (null), dnld_sent 0
<7>[   81.160000] libertas enter: lbs_process_command_response()
<7>[   81.160000] libertas cmd: CMD_RESP: response 0x8003, seq 1, size
46
<4>[   81.160000] libertas CMD_RESP: 03 80 2e 00 01 00 00 00 02 00 12 00
08 00 40 00 
<4>[   81.160000] libertas CMD_RESP: 00 1b fb 1a 1c 76 10 00 01 00 03 46
09 18 00 00 
<4>[   81.160000] libertas CMD_RESP: 00 00 00 00 00 00 00 00 00 00 03 03
00 00 
<6>[   81.160000] libertas: Received result 0 to command 3 after 1
retries
<7>[   81.170000] libertas leave: lbs_process_command_response(), ret 0
<7>[   81.170000] libertas enter: lbs_execute_next_command()
<7>[   81.170000] libertas leave: lbs_execute_next_command()
<7>[   81.170000] libertas thread: 1: currenttxskb (null), dnld_sent 0
<7>[   81.170000] libertas thread: sleeping, connect_status 1, psmode 0,
psstate 0
<7>[   81.170000] libertas enter: __lbs_cleanup_and_insert_cmd()
<7>[   81.170000] libertas leave: __lbs_cleanup_and_insert_cmd()
<7>[   81.170000] libertas leave: __lbs_cmd(), ret 0
<6>[   81.170000] libertas: 00:1b:fb:1a:1c:76, fw 9.70.3p24, cap
0x00000303
<7>[   81.170000] libertas cmd: GET_HW_SPEC: hardware interface 0x2,
hardware spec 0x0012
<7>[   81.170000] libertas enter: lbs_set_regiontable()
<7>[   81.170000] libertas enter: lbs_get_region_cfp_table()
<7>[   81.170000] libertas main: region_cfp_table[i].region=16
<7>[   81.170000] libertas leave: lbs_get_region_cfp_table()
<7>[   81.170000] libertas leave: lbs_set_regiontable(), ret 0
<7>[   81.170000] libertas 11d: BG-band nrcfp 14
<7>[   81.170000] libertas leave: lbs_update_hw_spec()
<7>[   81.170000] libertas enter: lbs_get_tx_power()
<7>[   81.170000] libertas enter: __lbs_cmd()
<7>[   81.170000] libertas enter: __lbs_cmd_async()
<7>[   81.170000] libertas enter: lbs_get_cmd_ctrl_node()
<7>[   81.170000] libertas leave: lbs_get_cmd_ctrl_node()
<7>[   81.170000] libertas host: PREP_CMD: command 0x001e
<7>[   81.170000] libertas enter: lbs_queue_cmd()
<7>[   81.170000] libertas host: QUEUE_CMD: inserted command 0x001e into
cmdpendingq
<7>[   81.170000] libertas leave: lbs_queue_cmd()
<7>[   81.170000] libertas leave: __lbs_cmd_async(), ret c2ff5a24
<7>[   81.170000] libertas thread: 2: currenttxskb (null), dnld_send 0
<7>[   81.170000] libertas thread: 3: currenttxskb (null), dnld_sent 0
<7>[   81.170000] libertas thread: 4: currenttxskb (null), dnld_sent 0
<7>[   81.170000] libertas enter: lbs_execute_next_command()
<7>[   81.170000] libertas host: EXEC_NEXT_CMD: sending command 0x001e
<7>[   81.170000] libertas enter: lbs_submit_command()
<7>[   81.170000] libertas cmd: DNLD_CMD: command 0x001e, seq 2, size 14
<4>[   81.170000] libertas DNLD_CMD: 1e 00 0e 00 02 00 00 00 00 00 00 00
00 00 
<7>[   81.180000] libertas enter: if_sdio_host_to_card(type 1, bytes 14)
<7>[   81.180000] libertas leave: if_sdio_host_to_card(), ret 0
<7>[   81.180000] libertas leave: lbs_submit_command()
<7>[   81.180000] libertas leave: lbs_execute_next_command()
<7>[   81.180000] libertas thread: 1: currenttxskb (null), dnld_sent 2
<7>[   81.180000] libertas thread: sleeping, connect_status 1, psmode 0,
psstate 0
<7>[   81.180000] libertas enter: if_sdio_host_to_card_worker()
<7>[   81.180000] libertas leave: if_sdio_host_to_card_worker()
<7>[   81.180000] libertas enter: if_sdio_interrupt()
<7>[   81.180000] libertas sdio: interrupt: 0x3
<7>[   81.180000] libertas enter: lbs_host_to_card_done()
<7>[   81.180000] libertas leave: lbs_host_to_card_done()
<7>[   81.180000] libertas enter: if_sdio_card_to_host()
<7>[   81.180000] libertas sdio: packet of type 1 and size 50 bytes
<7>[   81.180000] libertas enter: if_sdio_handle_cmd()
<7>[   81.180000] libertas enter: lbs_notify_command_response()
<7>[   81.180000] libertas leave: lbs_notify_command_response()
<7>[   81.180000] libertas leave: if_sdio_handle_cmd(), ret 0
<7>[   81.180000] libertas leave: if_sdio_card_to_host(), ret 0
<7>[   81.180000] libertas leave: if_sdio_interrupt(), ret 0
<7>[   81.180000] libertas thread: 2: currenttxskb (null), dnld_send 0
<7>[   81.180000] libertas thread: 3: currenttxskb (null), dnld_sent 0
<7>[   81.180000] libertas thread: 4: currenttxskb (null), dnld_sent 0
<7>[   81.180000] libertas enter: lbs_process_command_response()
<7>[   81.180000] libertas cmd: CMD_RESP: response 0x8003, seq 1, size
46
<4>[   81.180000] libertas CMD_RESP: 03 80 2e 00 01 00 00 00 02 00 12 00
08 00 40 00 
<4>[   81.180000] libertas CMD_RESP: 00 1b fb 1a 1c 76 10 00 01 00 03 46
09 18 00 00 
<4>[   81.180000] libertas CMD_RESP: 00 00 00 00 00 00 00 00 00 00 03 03
00 00 
<6>[   81.180000] libertas: Received CMD_RESP with invalid sequence 1
(expected 2)
<7>[   81.190000] libertas leave: lbs_process_command_response(), ret -1
<7>[   81.190000] libertas thread: 1: currenttxskb (null), dnld_sent 0
<7>[   81.190000] libertas thread: sleeping, connect_status 1, psmode 0,
psstate 0
<7>[   84.180000] libertas enter (INT): command_timer_fn()
<6>[   84.180000] libertas: command 0x001e timed out
<7>[   84.180000] libertas leave (INT): command_timer_fn()
<7>[   84.180000] libertas thread: 2: currenttxskb (null), dnld_send 0
<7>[   84.180000] libertas thread: 3: currenttxskb (null), dnld_sent 0
<7>[   84.180000] libertas thread: 4: currenttxskb (null), dnld_sent 0
<6>[   84.180000] libertas: requeueing command 0x001e due to timeout
(#1)
<7>[   84.180000] libertas enter: lbs_execute_next_command()
<7>[   84.180000] libertas host: EXEC_NEXT_CMD: sending command 0x001e
<7>[   84.180000] libertas enter: lbs_submit_command()
<7>[   84.180000] libertas cmd: DNLD_CMD: command 0x001e, seq 2, size 14
<4>[   84.180000] libertas DNLD_CMD: 1e 00 0e 00 02 00 00 00 00 00 00 00
00 00 
<7>[   84.190000] libertas enter: if_sdio_host_to_card(type 1, bytes 14)
<7>[   84.190000] libertas leave: if_sdio_host_to_card(), ret 0
<7>[   84.190000] libertas leave: lbs_submit_command()
<7>[   84.190000] libertas leave: lbs_execute_next_command()
<7>[   84.190000] libertas thread: 1: currenttxskb (null), dnld_sent 2
<7>[   84.190000] libertas thread: sleeping, connect_status 1, psmode 0,
psstate 0
<7>[   84.190000] libertas enter: if_sdio_host_to_card_worker()
<7>[   84.190000] libertas leave: if_sdio_host_to_card_worker()
<7>[   84.190000] libertas enter: if_sdio_interrupt()
<7>[   84.190000] libertas sdio: interrupt: 0x3
<7>[   84.190000] libertas enter: lbs_host_to_card_done()
<7>[   84.190000] libertas leave: lbs_host_to_card_done()
<7>[   84.190000] libertas enter: if_sdio_card_to_host()
<7>[   84.190000] libertas sdio: packet of type 1 and size 18 bytes
<7>[   84.190000] libertas enter: if_sdio_handle_cmd()
<7>[   84.190000] libertas enter: lbs_notify_command_response()
<7>[   84.190000] libertas leave: lbs_notify_command_response()
<7>[   84.190000] libertas leave: if_sdio_handle_cmd(), ret 0
<7>[   84.190000] libertas leave: if_sdio_card_to_host(), ret 0
<7>[   84.190000] libertas leave: if_sdio_interrupt(), ret 0
<7>[   84.190000] libertas thread: 2: currenttxskb (null), dnld_send 0
<7>[   84.190000] libertas thread: 3: currenttxskb (null), dnld_sent 0
<7>[   84.190000] libertas thread: 4: currenttxskb (null), dnld_sent 0
<7>[   84.190000] libertas enter: lbs_process_command_response()
<7>[   84.190000] libertas cmd: CMD_RESP: response 0x801e, seq 2, size
14
<4>[   84.190000] libertas CMD_RESP: 1e 80 0e 00 02 00 00 00 00 00 12 00
14 00 
<6>[   84.190000] libertas: Received result 0 to command 1e after 1
retries
<7>[   84.200000] libertas leave: lbs_process_command_response(), ret 0
<7>[   84.200000] libertas enter: lbs_execute_next_command()
<7>[   84.200000] libertas leave: lbs_execute_next_command()
<7>[   84.200000] libertas thread: 1: currenttxskb (null), dnld_sent 0
<7>[   84.200000] libertas thread: sleeping, connect_status 1, psmode 0,
psstate 0
<7>[   84.200000] libertas enter: __lbs_cleanup_and_insert_cmd()
<7>[   84.200000] libertas leave: __lbs_cleanup_and_insert_cmd()
<7>[   84.200000] libertas leave: __lbs_cmd(), ret 0
<7>[   84.200000] libertas leave: lbs_get_tx_power()
<7>[   84.200000] libertas enter: lbs_set_mac_control()
<7>[   84.200000] libertas enter: lbs_cmd_async()
<7>[   84.200000] libertas enter: __lbs_cmd_async()
<7>[   84.200000] libertas enter: lbs_get_cmd_ctrl_node()
<7>[   84.200000] libertas leave: lbs_get_cmd_ctrl_node()
<7>[   84.200000] libertas host: PREP_CMD: command 0x0028
<7>[   84.200000] libertas enter: lbs_queue_cmd()
<7>[   84.200000] libertas host: QUEUE_CMD: inserted command 0x0028 into
cmdpendingq
<7>[   84.200000] libertas leave: lbs_queue_cmd()
<7>[   84.200000] libertas leave: __lbs_cmd_async(), ret c2ff5a48
<7>[   84.200000] libertas leave: lbs_cmd_async()
<7>[   84.200000] libertas leave: lbs_set_mac_control()
<7>[   84.200000] libertas leave: lbs_setup_firmware(), ret 0
<7>[   84.220000] libertas thread: 2: currenttxskb (null), dnld_send 0
<7>[   84.220000] libertas thread: 3: currenttxskb (null), dnld_sent 0
<7>[   84.220000] libertas thread: 4: currenttxskb (null), dnld_sent 0
<7>[   84.220000] libertas enter: lbs_execute_next_command()
<7>[   84.220000] libertas host: EXEC_NEXT_CMD: sending command 0x0028
<7>[   84.220000] libertas enter: lbs_submit_command()
<7>[   84.220000] libertas cmd: DNLD_CMD: command 0x0028, seq 3, size 12
<4>[   84.220000] libertas DNLD_CMD: 28 00 0c 00 03 00 00 00 03 00 00
00 
<7>[   84.220000] libertas enter: if_sdio_host_to_card(type 1, bytes 12)
<7>[   84.220000] libertas leave: if_sdio_host_to_card(), ret 0
<7>[   84.220000] libertas leave: lbs_submit_command()
<7>[   84.220000] libertas leave: lbs_execute_next_command()
<7>[   84.220000] libertas thread: 1: currenttxskb (null), dnld_sent 2
<7>[   84.220000] libertas thread: sleeping, connect_status 1, psmode 0,
psstate 0
<7>[   84.220000] libertas enter: if_sdio_host_to_card_worker()
<7>[   84.220000] libertas leave: if_sdio_host_to_card_worker()
<7>[   84.220000] libertas enter: if_sdio_interrupt()
<7>[   84.220000] libertas sdio: interrupt: 0x3
<7>[   84.220000] libertas enter: lbs_host_to_card_done()
<7>[   84.220000] libertas leave: lbs_host_to_card_done()
<7>[   84.220000] libertas enter: if_sdio_card_to_host()
<7>[   84.220000] libertas sdio: packet of type 1 and size 18 bytes
<7>[   84.220000] libertas enter: if_sdio_handle_cmd()
<7>[   84.220000] libertas enter: lbs_notify_command_response()
<7>[   84.220000] libertas leave: lbs_notify_command_response()
<7>[   84.220000] libertas leave: if_sdio_handle_cmd(), ret 0
<7>[   84.220000] libertas leave: if_sdio_card_to_host(), ret 0
<7>[   84.220000] libertas leave: if_sdio_interrupt(), ret 0
<7>[   84.220000] libertas thread: 2: currenttxskb (null), dnld_send 0
<7>[   84.220000] libertas thread: 3: currenttxskb (null), dnld_sent 0
<7>[   84.220000] libertas thread: 4: currenttxskb (null), dnld_sent 0
<7>[   84.220000] libertas enter: lbs_process_command_response()
<7>[   84.220000] libertas cmd: CMD_RESP: response 0x801e, seq 2, size
14
<4>[   84.220000] libertas CMD_RESP: 1e 80 0e 00 02 00 00 00 00 00 12 00
14 00 
<6>[   84.220000] libertas: Received CMD_RESP with invalid sequence 2
(expected 3)
<7>[   84.230000] libertas leave: lbs_process_command_response(), ret -1
<7>[   84.230000] libertas thread: 1: currenttxskb (null), dnld_sent 0
<7>[   84.230000] libertas thread: sleeping, connect_status 1, psmode 0,
psstate 0
<7>[   84.230000] libertas enter: lbs_update_channel()
<7>[   84.230000] libertas enter: lbs_get_channel()
<7>[   84.230000] libertas enter: __lbs_cmd()
<7>[   84.230000] libertas enter: __lbs_cmd_async()
<7>[   84.230000] libertas enter: lbs_get_cmd_ctrl_node()
<7>[   84.230000] libertas leave: lbs_get_cmd_ctrl_node()




More information about the libertas-dev mailing list