#8301 BLOC 8.2.0 (: Fast suspend/resume cycle causes a libertas crash

Zarro Boogs per Child bugtracker at laptop.org
Mon Sep 8 15:43:12 EDT 2008


#8301: Fast suspend/resume cycle causes a libertas crash
------------------------+---------------------------------------------------
   Reporter:  cjb       |       Owner:  dsaxena                        
       Type:  defect    |      Status:  new                            
   Priority:  blocker   |   Milestone:  8.2.0 (was Update.2)           
  Component:  kernel    |     Version:  not specified                  
 Resolution:            |    Keywords:  blocks-:8.2.0 cjbfor8.2 relnote
Next_action:  diagnose  |    Verified:  0                              
  Blockedby:            |    Blocking:                                 
------------------------+---------------------------------------------------

Comment(by cjb):

 And here's one with 0x6 in-flight:

 {{{
 [  470.505596] libertas host: QUEUE_CMD: inserted command 0x001e into
 cmdpending q
 [  470.527453] libertas leave: lbs_queue_cmd():1217
 [  470.530521] libertas thread: main-thread 222 (waking up): intcounter=0
 currenttxskb=00000000 dnld_sent=0
 [  470.530606] libertas thread: main-thread 333: intcounter=0
 currenttxskb=00000000 dnld_sent=0
 [  470.544146] libertas thread: main-thread 444: intcounter=0
 currenttxskb=00000000 dnld_sent=0
 [  470.552538] libertas thread: main-thread 111: intcounter=0
 currenttxskb=00000000 dnld_sent=0
 [  470.562543] libertas thread: main-thread sleeping... Conn=1 IntC=0
 PS_mode=0 PS_State=0
 [  470.572782] libertas host: PREP_CMD: wait for response
 [  470.827009] olpm-pm:  PM_PWRBTN event received
 [  470.913102] usb8xxx enter (INT): if_usb_receive():712
 [  470.918193] usb8xxx usbd (INT): 2-1:Recv length = 0x442, Recv type =
 0xF00DFACE
 [  470.919999] libertas enter (INT): lbs_interrupt():1530
 [  470.919999] libertas thread (INT): lbs_interrupt: intcounter=0
 [  470.919999] libertas leave (INT): lbs_interrupt():1538
 [  470.919999] usb8xxx usbd (INT): 2-1:Wake up main thread to handle cmd
 response
 [  470.919999] usb8xxx leave (INT): if_usb_receive():772
 [  470.920116] libertas thread: main-thread 222 (waking up): intcounter=1
 currenttxskb=00000000 dnld_sent=0
 [  470.930150] libertas thread: main-thread 333: intcounter=1
 currenttxskb=00000000 dnld_sent=0
 [  470.938711] usb8xxx usbd: 2-1:Int cause is 0x8
 [  470.939999] libertas thread: main-thread 444: intcounter=0
 currenttxskb=00000000 dnld_sent=0
 [  470.939999] libertas thread: main-thread: cmd response ready
 [  470.940095] libertas enter: lbs_process_rx_command():550
 [  470.945437] libertas cmd: CMD_RESP: response 0x8006, seq 14, size 1086,
 jiffies 23836
 [  470.950080] libertas enter: handle_cmd_response():401
 [  470.955195] libertas leave: handle_cmd_response():538
 [  470.960086] libertas enter: __lbs_cleanup_and_insert_cmd():1273
 [  470.966021] libertas leave: __lbs_cleanup_and_insert_cmd():1285
 [  470.970083] libertas host: PREP_CMD: done waiting for command 0x6
 [  470.976191] libertas leave: lbs_prepare_and_send_command():1640, ret 0
 [  470.980145] libertas enter: lbs_prepare_and_send_command():1388
 [  470.986080] libertas enter: lbs_get_cmd_ctrl_node():1742
 [  470.990079] libertas leave: lbs_get_cmd_ctrl_node():1760
 [  470.995403] libertas enter: lbs_set_cmd_ctrl_node():1783
 [  471.000075] libertas leave: lbs_set_cmd_ctrl_node():1791
 [  471.005402] libertas host: PREP_CMD: command 0x0006
 [  471.010089] libertas enter: lbs_queue_cmd():1182
 [  471.014723] libertas host: QUEUE_CMD: inserted command 0x0006 into
 cmdpending q
 [  471.020159] libertas leave: lbs_queue_cmd():1217
 [  471.024796] libertas host: PREP_CMD: wait for response
 [  471.030173] libertas leave: lbs_process_rx_command():700, ret 0
 [  471.036106] libertas enter: lbs_execute_next_command():1812
 [  471.040283] libertas host: EXEC_NEXT_CMD: sending command 0x0010
 [  471.046310] libertas enter: lbs_submit_command():1230
 [  471.050087] libertas cmd: DNLD_CMD: command 0x0010, seq 15, size 24,
 jiffies 23849
 [  471.073229] usb8xxx usbd: 2-1:*** type = 1
 [  471.077352] usb8xxx usbd: 2-1:size after = 24
 [  471.080080] libertas leave: lbs_submit_command():1263
 [  471.085170] libertas enter (INT): lbs_host_to_card_done():510
 [  471.090000] libertas leave (INT): lbs_host_to_card_done():521
 [  471.090000] usb8xxx enter (INT): if_usb_receive():712
 [  471.090000] usb8xxx usbd (INT): 2-1:Recv length = 0x1c, Recv type =
 0xF00DFACE
 [  471.090000] libertas enter (INT): lbs_interrupt():1530
 [  471.090000] libertas thread (INT): lbs_interrupt: intcounter=0
 [  471.090000] libertas leave (INT): lbs_interrupt():1538
 [  471.090000] usb8xxx usbd (INT): 2-1:Wake up main thread to handle cmd
 response
 [  471.090000] usb8xxx leave (INT): if_usb_receive():772
 [  471.090108] libertas leave: lbs_execute_next_command():1947
 [  471.095709] usb8xxx usbd: 2-1:*** type = 0
 [  471.099817] usb8xxx usbd: 2-1:size after = 105
 [  471.100096] libertas enter (INT): lbs_host_to_card_done():510
 [  471.105855] libertas leave (INT): lbs_host_to_card_done():521
 [  471.110116] libertas thread: main-thread 111: intcounter=1
 currenttxskb=00000000 dnld_sent=0
 [  471.120104] libertas thread: main-thread 222 (waking up): intcounter=1
 currenttxskb=00000000 dnld_sent=0
 [  471.130103] libertas thread: main-thread 333: intcounter=1
 currenttxskb=00000000 dnld_sent=0
 [  471.140075] usb8xxx usbd: 2-1:Int cause is 0x8
 [  471.144541] libertas thread: main-thread 444: intcounter=0
 currenttxskb=00000000 dnld_sent=0
 [  471.150000] libertas thread: main-thread: cmd response ready
 [  471.150078] libertas enter: lbs_process_rx_command():550
 [  471.155414] libertas cmd: CMD_RESP: response 0x8010, seq 15, size 24,
 jiffies 23865
 [  471.161524] libertas enter: __lbs_cleanup_and_insert_cmd():1273
 [  471.167467] libertas leave: __lbs_cleanup_and_insert_cmd():1285
 [  471.170074] libertas leave: lbs_process_rx_command():700, ret 0
 [  471.176009] libertas enter: lbs_execute_next_command():1812
 [  471.189837] libertas host: EXEC_NEXT_CMD: sending command 0x0010
 [  471.190371] libertas enter: lbs_submit_command():1230
 [  471.195734] libertas cmd: DNLD_CMD: command 0x0010, seq 16, size 30,
 jiffies 23870
 [  471.201994] usb8xxx usbd: 2-1:*** type = 1
 [  471.206392] usb8xxx usbd: 2-1:size after = 30
 [  471.211926] libertas leave: lbs_submit_command():1263
 [  471.217021] libertas enter (INT): lbs_host_to_card_done():510
 [  471.220000] libertas leave (INT): lbs_host_to_card_done():521
 [  471.220000] usb8xxx enter (INT): if_usb_receive():712
 [  471.220000] usb8xxx usbd (INT): 2-1:Recv length = 0x22, Recv type =
 0xF00DFACE
 [  471.220000] libertas enter (INT): lbs_interrupt():1530
 [  471.220000] libertas thread (INT): lbs_interrupt: intcounter=0
 [  471.220000] libertas leave (INT): lbs_interrupt():1538
 [  471.220000] usb8xxx usbd (INT): 2-1:Wake up main thread to handle cmd
 response
 [  471.220000] usb8xxx leave (INT): if_usb_receive():772
 [  471.226739] libertas leave: lbs_execute_next_command():1947
 [  471.231920] libertas thread: main-thread 111: intcounter=1
 currenttxskb=00000000 dnld_sent=0
 [  471.241769] libertas thread: main-thread 222 (waking up): intcounter=1
 currenttxskb=00000000 dnld_sent=0
 [  471.260097] libertas thread: main-thread 333: intcounter=1
 currenttxskb=00000000 dnld_sent=0
 [  471.272057] usb8xxx usbd: 2-1:Int cause is 0x8
 [  471.276530] libertas thread: main-thread 444: intcounter=0
 currenttxskb=00000000 dnld_sent=0
 [  471.280000] libertas thread: main-thread: cmd response ready
 [  471.281393] libertas enter: lbs_process_rx_command():550
 [  471.296947] libertas cmd: CMD_RESP: response 0x8010, seq 16, size 30,
 jiffies 23887
 [  471.301272] libertas enter: __lbs_cleanup_and_insert_cmd():1273
 [  471.307220] libertas leave: __lbs_cleanup_and_insert_cmd():1285
 [  471.310629] libertas leave: lbs_process_rx_command():700, ret 0
 [  471.316756] libertas enter: lbs_execute_next_command():1812
 [  471.320994] libertas host: EXEC_NEXT_CMD: sending command 0x0010
 [  471.327206] libertas enter: lbs_submit_command():1230
 [  471.340095] libertas cmd: DNLD_CMD: command 0x0010, seq 17, size 30,
 jiffies 23893
 [  471.348056] usb8xxx usbd: 2-1:*** type = 1
 [  471.351914] usb8xxx usbd: 2-1:size after = 30
 [  471.356493] libertas leave: lbs_submit_command():1263
 [  471.360093] libertas enter (INT): lbs_host_to_card_done():510
 [  471.365854] libertas leave (INT): lbs_host_to_card_done():521
 [  471.370000] usb8xxx enter (INT): if_usb_receive():712
 [  471.370000] usb8xxx usbd (INT): 2-1:Recv length = 0x22, Recv type =
 0xF00DFACE
 [  471.370000] libertas enter (INT): lbs_interrupt():1530
 [  471.370000] libertas thread (INT): lbs_interrupt: intcounter=0
 [  471.370000] libertas leave (INT): lbs_interrupt():1538
 [  471.370000] usb8xxx usbd (INT): 2-1:Wake up main thread to handle cmd
 response
 [  471.370000] usb8xxx leave (INT): if_usb_receive():772
 [  471.380096] libertas leave: lbs_execute_next_command():1947
 [  471.386047] libertas thread: main-thread 111: intcounter=1
 currenttxskb=00000000 dnld_sent=0
 [  471.390408] libertas thread: main-thread 222 (waking up): intcounter=1
 currenttxskb=00000000 dnld_sent=0
 [  471.400313] libertas thread: main-thread 333: intcounter=1
 currenttxskb=00000000 dnld_sent=0
 [  471.420095] usb8xxx usbd: 2-1:Int cause is 0x8
 [  471.424576] libertas thread: main-thread 444: intcounter=0
 currenttxskb=00000000 dnld_sent=0
 [  471.430000] libertas thread: main-thread: cmd response ready
 [  471.431986] libertas enter: lbs_process_rx_command():550
 [  471.437512] libertas cmd: CMD_RESP: response 0x8010, seq 17, size 30,
 jiffies 23907
 [  471.440273] libertas enter: __lbs_cleanup_and_insert_cmd():1273
 [  471.446216] libertas leave: __lbs_cleanup_and_insert_cmd():1285
 [  471.458192] libertas leave: lbs_process_rx_command():700, ret 0
 [  471.460000] libertas enter: lbs_execute_next_command():1812
 [  471.462198] libertas host: EXEC_NEXT_CMD: sending command 0x001e
 [  471.468416] libertas enter: lbs_submit_command():1230
 [  471.470995] libertas cmd: DNLD_CMD: command 0x001e, seq 18, size 12,
 jiffies 23913
 [  471.490091] usb8xxx usbd: 2-1:*** type = 1
 [  471.495990] usb8xxx usbd: 2-1:size after = 12
 [  471.500000] libertas leave: lbs_submit_command():1263
 [  471.500105] libertas enter (INT): lbs_host_to_card_done():510
 [  471.505864] libertas leave (INT): lbs_host_to_card_done():521
 [  471.510000] usb8xxx enter (INT): if_usb_receive():712
 [  471.510000] usb8xxx usbd (INT): 2-1:Recv length = 0x10, Recv type =
 0xF00DFACE
 [  471.510000] libertas enter (INT): lbs_interrupt():1530
 [  471.510000] libertas thread (INT): lbs_interrupt: intcounter=0
 [  471.510000] libertas leave (INT): lbs_interrupt():1538
 [  471.510000] usb8xxx usbd (INT): 2-1:Wake up main thread to handle cmd
 response
 [  471.510000] usb8xxx leave (INT): if_usb_receive():772
 [  471.511052] libertas leave: lbs_execute_next_command():1947
 [  471.516839] libertas thread: main-thread 111: intcounter=1
 currenttxskb=00000000 dnld_sent=0
 [  471.521014] libertas thread: main-thread 222 (waking up): intcounter=1
 currenttxskb=00000000 dnld_sent=0
 [  471.540101] libertas thread: main-thread 333: intcounter=1
 currenttxskb=00000000 dnld_sent=0
 [  471.551132] usb8xxx usbd: 2-1:Int cause is 0x8
 [  471.555602] libertas thread: main-thread 444: intcounter=0
 currenttxskb=00000000 dnld_sent=0
 [  471.560000] libertas thread: main-thread: cmd response ready
 [  471.568369] libertas enter: lbs_process_rx_command():550
 [  471.570000] libertas cmd: CMD_RESP: response 0x801e, seq 18, size 12,
 jiffies 23928
 [  471.570000] libertas host: CMD_RESP: error 0x0001 in command reply
 0x801e
 [  471.570000] libertas enter: __lbs_cleanup_and_insert_cmd():1273
 [  471.570000] libertas leave: __lbs_cleanup_and_insert_cmd():1285
 [  471.570154] libertas host: PREP_CMD: done waiting for command 0x1E
 [  471.576349] libertas host: PREP_CMD: command failed with return code 1
 [  471.580154] libertas leave: lbs_prepare_and_send_command():1640, ret -1
 [  471.606061] libertas leave: lbs_process_rx_command():700, ret -1
 [  471.610000] libertas enter: lbs_execute_next_command():1812
 [  471.610996] libertas host: EXEC_NEXT_CMD: sending command 0x0006
 [  471.617212] libertas enter: lbs_submit_command():1230
 [  471.623201] libertas cmd: DNLD_CMD: command 0x0006, seq 19, size 63,
 jiffies 23938
 [  471.640095] usb8xxx usbd: 2-1:*** type = 1
 [  471.646723] usb8xxx usbd: 2-1:size after = 63
 [  471.657067] libertas leave: lbs_submit_command():1263
 [  471.660083] libertas enter (INT): lbs_host_to_card_done():510
 [  471.665848] libertas leave (INT): lbs_host_to_card_done():521
 [  471.680099] libertas leave: lbs_execute_next_command():1947
 [  471.696940] usb8xxx usbd: 2-1:*** type = 0
 [  471.700000] usb8xxx usbd: 2-1:size after = 97
 [  471.700100] libertas enter (INT): lbs_host_to_card_done():510
 [  471.705868] libertas leave (INT): lbs_host_to_card_done():521
 [  471.710816] libertas thread: main-thread 111: intcounter=0
 currenttxskb=00000000 dnld_sent=0
 [  471.721456] libertas enter: lbs_cmd_async():2147
 [  471.726102] libertas enter: __lbs_cmd_async():2102
 [  471.730100] libertas enter: lbs_get_cmd_ctrl_node():1742
 [  471.735425] libertas leave: lbs_get_cmd_ctrl_node():1760
 [  471.740138] libertas host: PREP_CMD: command 0x0010
 [  471.745032] libertas enter: lbs_queue_cmd():1182
 [  471.750096] libertas host: QUEUE_CMD: inserted command 0x0010 into
 cmdpending q
 [  471.760100] libertas leave: lbs_queue_cmd():1217
 [  471.764736] libertas leave: __lbs_cmd_async():2140, ret ce1b91d4
 [  471.770101] libertas leave: lbs_cmd_async():2150
 [  471.776310] libertas thread: main-thread sleeping... Conn=1 IntC=0
 PS_mode=0 PS_State=0
 [  471.781335] libertas enter: lbs_cmd_async():2147
 [  471.786175] libertas enter: __lbs_cmd_async():2102
 [  471.790000] libertas enter: lbs_get_cmd_ctrl_node():1742
 [  471.790251] libertas leave: lbs_get_cmd_ctrl_node():1760
 [  471.795771] libertas host: PREP_CMD: command 0x0010
 [  471.800276] libertas enter: lbs_queue_cmd():1182
 [  471.805097] libertas host: QUEUE_CMD: inserted command 0x0010 into
 cmdpending q
 [  471.811185] libertas leave: lbs_queue_cmd():1217
 [  471.816592] libertas leave: __lbs_cmd_async():2140, ret ce1b9000
 [  471.820000] libertas leave: lbs_cmd_async():2150
 [  471.830280] libertas thread: main-thread 222 (waking up): intcounter=0
 currenttxskb=00000000 dnld_sent=0
 [  471.856953] libertas thread: main-thread 333: intcounter=0
 currenttxskb=00000000 dnld_sent=0
 [  471.860361] libertas thread: main-thread 444: intcounter=0
 currenttxskb=00000000 dnld_sent=0
 [  471.870307] libertas thread: main-thread 111: intcounter=0
 currenttxskb=00000000 dnld_sent=0
 [  471.892243] libertas thread: main-thread sleeping... Conn=1 IntC=0
 PS_mode=0 PS_State=0
 [  471.977910] olpc-ec:  running cmd 0x35
 [  471.980068] devpath 1 ep3in 3strikes
 [  471.983667] usb8xxx enter (INT): if_usb_receive():712
 [  471.988734] usb8xxx leave (INT): if_usb_receive():772
 [  471.990172] usb 2-1: USB disconnect, address 8
 [  471.995281] usb8xxx enter: if_usb_disconnect():340
 [  472.004738] libertas enter: lbs_stop_card():1328
 [  472.009629] libertas main: lbs_stop_card: clearing pending commands
 [  472.010000] libertas main: lbs_stop_card: clearing in-flight command
 0x6
 [  472.010000] libertas main: lbs_stop_card: done clearing commands
 [  472.010156] libertas host: PREP_CMD: done waiting for command 0x6
 [  472.016267] libertas leave: lbs_prepare_and_send_command():1640, ret 0
 [  472.020101] libertas enter: lbs_prepare_and_send_command():1388
 [  472.026033] libertas host: PREP_CMD: card removed
 [  472.030115] libertas leave: lbs_prepare_and_send_command():1640, ret -1
 [  472.036828] libertas: SCAN_CMD failed
 [  472.044631] olpc-ec:  running cmd 0x26
 [  472.049420] olpc-ec:  sending cmd arg 0x0
 [  472.059558] olpc-ec:  running cmd 0x1c
 [  472.060000] olpc-ec:  received 0xff
 [  472.060109] olpc-ec:  running cmd 0x1b
 [  472.064885] olpc-ec:  sending cmd arg 0xdf
 [  472.073765] olpc-ec:  running cmd 0x1c
 [  472.080000] olpc-ec:  received 0xdf
 [  472.080092] olpc-ec:  running cmd 0x1b
 [  472.084865] olpc-ec:  sending cmd arg 0xde
 [  472.150160] libertas leave: lbs_stop_card():1364, ret -1
 [  472.156195] ADDRCONF(NETDEV_CHANGE): msh0: link becomes ready
 [  472.161958] libertas enter: lbs_cmd_async():2147
 [  472.166809] libertas enter: lbs_remove_card():1205
 [  472.171389] libertas enter: __lbs_cmd_async():2102
 [  472.176594] libertas host: PREP_CMD: card removed
 [  472.180415] libertas leave: __lbs_cmd_async():2140, ret fffffffe
 [  472.186729] libertas leave: lbs_cmd_async():2150
 [  472.190804] olpc-ec:  running cmd 0x1c
 [  472.197596] olpc-ec:  received 0xde
 [  472.200086] olpc-ec:  running cmd 0x1b
 [  472.204855] olpc-ec:  sending cmd arg 0x9e
 [  472.210000] libertas enter: lbs_set_mac_control():1356
 [  472.210000] libertas enter: lbs_cmd_async():2147
 [  472.211991] libertas enter: __lbs_cmd_async():2102
 [  472.217078] libertas host: PREP_CMD: card removed
 [  472.222015] libertas leave: __lbs_cmd_async():2140, ret fffffffe
 [  472.228324] libertas leave: lbs_cmd_async():2150
 [  472.231592] libertas leave: lbs_set_mac_control():1364
 [  472.327374] olpc-ec:  running cmd 0x1c
 [  472.330000] olpc-ec:  received 0x9e
 [  472.330080] olpc-ec:  running cmd 0x1b
 [  472.334851] olpc-ec:  sending cmd arg 0x96
 [  472.410530] olpc-ec:  running cmd 0x1c
 [  472.417329] olpc-ec:  received 0x96
 [  472.420094] olpc-ec:  running cmd 0x1b
 [  472.424865] olpc-ec:  sending cmd arg 0x92
 [  472.500592] olpc-ec:  running cmd 0x1c
 [  472.507393] olpc-ec:  received 0x92
 [  472.510074] olpc-ec:  running cmd 0x1b
 [  472.514850] olpc-ec:  sending cmd arg 0x90
 [  472.530123] libertas main: lbs_remove_card: 1
 [  472.534518] libertas enter: lbs_remove_rtap():1594
 [  472.541203] libertas main: lbs_remove_card: 2
 [  472.545761] libertas main: lbs_remove_card: 3
 [  472.551086] libertas main: lbs_remove_card: 4
 [  472.555649] libertas main: lbs_remove_card: 5
 [  472.561184] libertas main: lbs_remove_card: 6
 [  472.565745] libertas main: lbs_remove_card: 8
 [  472.571124] libertas main: lbs_remove_card: 9
 [  472.577292] libertas thread: main-thread 222 (waking up): intcounter=0
 currenttxskb=00000000 dnld_sent=0
 [  472.580105] libertas thread: main-thread 333: intcounter=0
 currenttxskb=00000000 dnld_sent=0
 [  472.590443] libertas thread: main-thread: break from main thread
 [  472.596657] libertas leave: lbs_thread():907
 [  472.600336] libertas main: lbs_remove_card: 10
 [  472.604979] libertas enter: lbs_free_adapter():1104
 [  472.610263] libertas enter: lbs_free_cmd_buffer():1701
 [  472.615610] libertas leave: lbs_free_cmd_buffer():1726
 [  472.620277] libertas leave: lbs_free_adapter():1111
 [  472.650169] libertas leave: lbs_remove_card():1247
 [  472.655932] usb8xxx enter: if_usb_free():147
 [  472.660000] usb8xxx leave: if_usb_free():162
 [  472.661087] usb8xxx leave: if_usb_disconnect():359
 [  472.747317] PM: Syncing filesystems ... done.
 [  472.820000] PM: Preparing system for mem sleep
 [  472.820253] Freezing user space processes ... (elapsed 0.00 seconds)
 done.
 [  472.854144] Freezing remaining freezable tasks ... (elapsed 0.00
 seconds) done.
 [  472.863905] PM: Entering mem sleep
 [  472.867318] Suspending console(s)
 }}}

-- 
Ticket URL: <http://dev.laptop.org/ticket/8301#comment:40>
One Laptop Per Child <http://laptop.org/>
OLPC bug tracking system


More information about the Bugs mailing list