g_file_storage: handle_exception() handled too late after the usb device sleep and wakeup

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 



Dear friends,
   It's my first time to post, please feel free to correct me if any concern.

   I have one ARM board with linux version (Linux localhost
2.6.27-default #3 PREEMPT Thu Dec 10 15:17:44 CST 2009 armv6l
unknown), and the usb device controller used for mass storage. it's
normal if without sleep/wakeup procedure, however, if the procedure
happen and the host is Linux Ubuntu OS, the device can't be
enumerated, it's ok with the host as Window XP since
USB_REQ_CLEAR_FEATURE will be sent to the device.
   after adding some debug info in the file_storage.c, and I found
there are several raise_exception() called, but no corresponding
handle_exception() when comparing the plug/unplug usb cable procedure,
 so the fsg->state not reset properly.
   it' ok if commenting the "if (fsg->state <= new_state) " in
function raise_exception(). but I think it may be not the formal way.

cat /proc/usb/bus/devices
T:  Bus=07 Lev=01 Prnt=01 Port=05 Cnt=01 Dev#=  9 Spd=480 MxCh= 0
D:  Ver= 2.00 Cls=00(>ifc ) Sub=00 Prot=00 MxPS=64 #Cfgs=  1
P:  Vendor=0525 ProdID=a4a5 Rev= 3.22
S:  Manufacturer=Linux 2.6.27-default with SiRFSOC USB
S:  Product=File-backed Storage Gadget
S:  SerialNumber=372041756775
C:* #Ifs= 1 Cfg#= 1 Atr=c0 MxPwr=  2mA
I:* If#= 0 Alt= 0 #EPs= 2 Cls=08(stor.) Sub=06 Prot=50 Driver=usb-storage
E:  Ad=81(I) Atr=02(Bulk) MxPS= 512 Ivl=0ms
E:  Ad=01(O) Atr=02(Bulk) MxPS= 512 Ivl=125us

the log as following:  (note: "if (fsg->state <= new_state)" already commented)

===============Sleep=================================
# [  735.164747] request_suspend_state: sleep (0->3) at 1321055604000
(1970-01-02 03:04:26.055598000 UTC)
[  740.234255] PM: Syncing filesystems ... done.
[  740.235889] suspend: exit suspend (1970-01-02 03:04:31.126765000 UTC)
[  741.265118] Freezing user space processes ... (elapsed 0.00 seconds) done.
[  741.270366] Freezing remaining freezable tasks ... (elapsed 0.00
seconds) done.
[  741.277406] Suspending console(s) (use no_console_suspend to debug)
[  741.286285] SPI: sirfsoc_spi.1 suspened
[  741.286308] SPI: sirfsoc_spi.0 suspened
[  741.319245] deinit_device_mode
[  741.319263]  pcd_change_state: 1 0
[  741.319276] pcd_flush_and_disable_all_eps
[  741.324102] deinit_device_mode
[  741.324112]  pcd_change_state: 2 0
[  741.324120] pcd_flush_and_disable_all_eps

[  741.324413] fsg_disconnect:disconnect or port reset
[  741.324438] raise_exception BEFORE: fsg state:0,new state 5
[  741.324461] raise_exception AFTER: fsg state:5
[  741.329525] PM-pm_s_done: (741329515)

[    0.108994] L2X0 cache controller enabled
[    0.109024] PM-pm_w_initiate: (109021)
[    0.109268] wakeup wake lock: alarm
[    0.353210] usbcd_do_resume

[    0.372122] SIRFSOC-FB: VPP resumed
[    0.402194] SIRFSOC-FB: LCD resumed
[    0.402319] SiRFSoC Backlight: Resumed
[    0.443342] soc-audio soc-audio: scheduling resume work
[    0.443376] soc-audio soc-audio: starting resume work
[    0.514489] soc-audio soc-audio: resume work completed

[    0.532668] pcd_intr_handler: reset interrupt detected
[    0.532702] pcd_flush_and_disable_all_eps

[    0.532718] fsg_disconnect:disconnect or port reset
[    0.532743] raise_exception BEFORE: fsg state:5,new state 5
[    0.532762] raise_exception AFTER: fsg state:5

[    0.532778] pcd_start_enumeration
[    0.640820] standard_setup_req:bRequest 6,w_index 0,w_value 256
[    0.640845] fsg_setup, rc 18
[    0.641746] ep0_complete: req status 0
[    0.641793] start_out_status_phase
[    0.647649] pcd_intr_handler: reset interrupt detected
[    0.647660] pcd_flush_and_disable_all_eps
[    0.647672] pcd_core_ep_flush: ep 0 out
[    0.647684] fsg_disconnect:disconnect or port reset
[    0.647706] raise_exception BEFORE: fsg state:5,new state 5
[    0.647720] raise_exception AFTER: fsg state:5
[    0.647733] pcd_start_enumeration
[    0.752785] pcd_ep0_process_setup: USB_REQ_SET_ADDRESS
[    0.752803] Dev Addr: 0x5
[    0.752811] start_in_status_phase
[    0.772862] standard_setup_req:bRequest 6,w_index 0,w_value 256
[    0.772885] fsg_setup, rc 18
[    0.773735] ep0_complete: req status 0
[    0.773779] start_out_status_phase
[    0.774786] standard_setup_req:bRequest 6,w_index 0,w_value 512
[    0.774817] fsg_setup, rc 32
[    0.775733] ep0_complete: req status 0
[    0.775764] start_out_status_phase
[    0.776785] standard_setup_req:bRequest 6,w_index 0,w_value 512
[    0.776809] fsg_setup, rc 32
[    0.777733] ep0_complete: req status 0
[    0.777781] start_out_status_phase
[    0.778784] standard_setup_req:bRequest 6,w_index 0,w_value 768
[    0.778807] fsg_setup, rc 4
[    0.779738] ep0_complete: req status 0
[    0.779771] start_out_status_phase
[    0.780789] standard_setup_req:bRequest 6,w_index 1033,w_value 770
[    0.780815] fsg_setup, rc 54
[    0.781734] ep0_complete: req status 0
[    0.781806] start_out_status_phase
[    0.782786] standard_setup_req:bRequest 6,w_index 1033,w_value 769
[    0.782811] fsg_setup, rc 76
[    0.783733] ep0_complete: req status 0
[    0.783821] start_out_status_phase
[    0.784790] standard_setup_req:bRequest 6,w_index 1033,w_value 771
[    0.784814] fsg_setup, rc 26
[    0.785733] ep0_complete: req status 0
[    0.785779] start_out_status_phase
[    1.237255] standard_setup_req:bRequest 9,w_index 0,w_value 1
[    1.237269] standard_setup_req :USB_REQ_SET_CONFIGURATION
,bRequestType 0x0,w_value 1
[    1.237293] raise exception :FSG_STATE_CONFIG_CHANGE
[    1.237305] raise_exception BEFORE: fsg state:5,new state 4
[    1.237319] raise_exception AFTER: fsg state:4
[    1.237329] fsg_setup, rc 1255
[    1.285785] Restarting tasks ... <6>handle_exception:bulk-in-en
1,bulk-out-en 1,intr-in-en 0
[    1.297951] FIFO Flush for Ep:1
[    1.304981] FIFO Flush for Ep:1
[    1.308109] handle_exception:old_state 4,new_config 1
[    1.313194] handle_exception : FSG_STATE_CONFIG_CHANGE
[    1.318264] do_set_config:new_config 1...
[    1.322316]  Disabling ep1in
[    1.325128]  Disabling ep1out
[    1.328090] Enabling ep1in, type 2 in MaxSz:512
[    1.332632] Enabling ep1out, type 2 out MaxSz:512
[    1.357939] g_file_storage gadget: high speed config #1

it seem that the fsg_main_thread() rescheduled very late by the system.
another log is the usb cable unplug/plug procedure for comparison.

=========unplug the usb cable ===============
[  411.232492] fsg_disconnect:disconnect or port reset
[  411.237346] raise_exception BEFORE: fsg state:0,new state 5
[  411.242905] raise_exception AFTER: fsg state:5
[  411.250708] USB Disconnected

[  411.269895] handle_exception:bulk-in-en 1,bulk-out-en 1,intr-in-en 0
[  411.273418] pcd_ep_fifo_flush: ep ep1in
[  411.277231] FIFO Flush for Ep:1
[  411.286680] pcd_ep_fifo_flush: ep ep1out
[  411.287772] FIFO Flush for Ep:1

[  411.291043] handle_exception:old_state 5,new_config 1
[  411.295944] handle_exception:FSG_STATE_DISCONNECT
[  411.301060] do_set_config:new_config 0...
[  411.304642]  Disabling ep1in
[  411.307479]  Disabling ep1out

========= plug the usb cable ===============

# [  482.292614] pcd_intr_handler: reset interrupt detected
[  482.298322] pcd_flush_and_disable_all_eps
[  482.302326] fsg_disconnect:disconnect or port reset
[  482.307191] raise_exception BEFORE: fsg state:0,new state 5
[  482.312745] raise_exception AFTER: fsg state:5
[  482.317152] pcd_start_enumeration
[  482.320499] handle_exception:bulk-in-en 0,bulk-out-en 0,intr-in-en 0
[  482.326786] handle_exception:old_state 5,new_config 1
[  482.331849] handle_exception:FSG_STATE_DISCONNECT
[  482.336546] do_set_config:new_config 0...
[  482.410051] standard_setup_req:bRequest 6,w_index 0,w_value 256
[  482.415898] fsg_setup, rc 18
[  482.418775] ep0_complete: req status 0
[  482.422536] start_out_status_phase
[  482.442863] fsg_disconnect:disconnect or port reset
[  482.447711] raise_exception BEFORE: fsg state:0,new state 5
[  482.453295] raise_exception AFTER: fsg state:5
[  482.457681] pcd_start_enumeration
[  482.461048] handle_exception:bulk-in-en 0,bulk-out-en 0,intr-in-en 0
[  482.467323] handle_exception:old_state 5,new_config 1
[  482.472375] handle_exception:FSG_STATE_DISCONNECT
[  482.477070] do_set_config:new_config 0...
[  482.536758] pcd_ep0_process_setup: USB_REQ_SET_ADDRESS
[  482.539075] Dev Addr: 0x6
[  482.541777] start_in_status_phase
[  482.573794] standard_setup_req:bRequest 6,w_index 0,w_value 256
[  482.579663] fsg_setup, rc 18
[  482.582539] ep0_complete: req status 0
[  482.586280] start_out_status_phase
[  482.601474] standard_setup_req:bRequest 6,w_index 0,w_value 512
[  482.607349] fsg_setup, rc 32
[  482.610233] ep0_complete: req status 0
[  482.613966] start_out_status_phase
[  482.629159] standard_setup_req:bRequest 6,w_index 0,w_value 512
[  482.635043] fsg_setup, rc 32
[  482.637910] ep0_complete: req status 0
[  482.641683] start_out_status_phase
[  482.656847] standard_setup_req:bRequest 6,w_index 0,w_value 768
[  482.662729] fsg_setup, rc 4
[  482.665509] ep0_complete: req status 0
[  482.669242] start_out_status_phase
[  482.684699] standard_setup_req:bRequest 6,w_index 1033,w_value 770
[  482.690846] fsg_setup, rc 54
[  482.693738] ep0_complete: req status 0
[  482.697503] start_out_status_phase
[  482.712939] standard_setup_req:bRequest 6,w_index 1033,w_value 769
[  482.719055] fsg_setup, rc 76
[  482.721949] ep0_complete: req status 0
[  482.725743] start_out_status_phase
[  482.741118] standard_setup_req:bRequest 6,w_index 1033,w_value 771
[  482.747276] fsg_setup, rc 26
[  482.750142] ep0_complete: req status 0
[  482.753900] start_out_status_phase
[  482.762873] pcd_ep0_process_setup: USB_REQ_SET_CONFIGURATION
[  482.774380] standard_setup_req:bRequest 9,w_index 0,w_value 1
[  482.780061] standard_setup_req :USB_REQ_SET_CONFIGURATION
,bRequestType 0x0,w_value 1
[  482.787883] raise exception :FSG_STATE_CONFIG_CHANGE
[  482.792833] raise_exception BEFORE: fsg state:0,new state 4
[  482.798389] raise_exception AFTER: fsg state:4
[  482.802801] fsg_setup, rc 1255
[  482.805876] handle_exception:bulk-in-en 0,bulk-out-en 0,intr-in-en 0
[  482.812220] handle_exception:old_state 4,new_config 1
[  482.817210] handle_exception : FSG_STATE_CONFIG_CHANGE
[  482.822368] do_set_config:new_config 1...
[  482.826352] Enabling ep1in, type 2 in MaxSz:512
[  482.830864] Enabling ep1out, type 2 out MaxSz:512
[  482.856196] g_file_storage gadget: high speed config #1


Many thanks.
Yuping Luo
--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at  http://vger.kernel.org/majordomo-info.html

[Index of Archives]     [Linux Media]     [Linux Input]     [Linux Audio Users]     [Yosemite News]     [Linux Kernel]     [Linux SCSI]     [Old Linux USB Devel Archive]

  Powered by Linux