[Letux-kernel] USB3-port on OMAP5432EVM

Chanwoo Choi cw00.choi at samsung.com
Fri Feb 17 01:02:45 CET 2017


Hi Roger,

On 2017년 02월 16일 22:43, Roger Quadros wrote:
> +Chanwoo
>
> On 15/02/17 23:36, Tony Lindgren wrote:
>> * Tony Lindgren <tony at atomide.com> [170215 13:01]:
>>> * Roger Quadros <rogerq at ti.com> [170214 01:44]:
>>>> You can enable dwc3 trace events.
>>>>
>>>> cd /sys/kernel/debug/tracing
>>>> echo 1 > events/dwc3/enable
>>>> echo 0 > events/dwc3/dwc3_readl/enable
>>>> echo 0 > events/dwc3/dwc3_writel/enable
>>>> echo 1 > free_buffer
>>>> echo 2048 > buffer_size_kb
>>> For me the issue was I had to change my sysfs scripts to start doing
>>> echo -n instead of just echo. Things are working for me now with Linux
>>> next.
>> Then in host mode after connecting a device, I see the following warnings
>> with Linux next and lockdep enabled if host mode is forced with
>> dr_mode = "host":
>>
>> CONFIG_DEBUG_LOCKDEP=y
>> CONFIG_DEBUG_ATOMIC_SLEEP=y
> Looks like extcon is calling the notifiers while atomic. (spinlocks held, IRQs disabled?)
> Does this needs to be fixed at extcon layer or dwc3-omap should
> execute the mailbox in a workqueue?

Right, Now extcon layer is working withing the spinlock range
because of reducing the latency to notifier the status of external connector.
I recommend that dwc3-opap better to use the workqueue.

> cheers,
> -roger
>
>> Regards,
>>
>> Tony
>>
>> 8< --------------------------------
>> [   48.431095] BUG: sleeping function called from invalid context at kernel/locking/mutex.c:745
>> [   48.439609] in_atomic(): 1, irqs_disabled(): 128, pid: 416, name: kworker/1:2
>> [   48.446774] 3 locks held by kworker/1:2/416:
>> [   48.451058]  #0:  ("events_power_efficient"){.+.+.+}, at: [<c01565b0>] process_one_work+0x1f8/0x808
>> [   48.460168]  #1:  ((&(&palmas_usb->wq_detectid)->work)){+.+...}, at: [<c01565b0>] process_one_work+0x1f8/0x808
>> [   48.470226]  #2:  (&(&edev->lock)->rlock){......}, at: [<bf028324>] extcon_sync+0x70/0x1c8 [extcon_core]
>> [   48.479770] irq event stamp: 7468
>> [   48.483102] hardirqs last  enabled at (7467): [<c083a970>] _raw_spin_unlock_irqrestore+0x30/0x5c
>> [   48.491925] hardirqs last disabled at (7468): [<c083a7bc>] _raw_spin_lock_irqsave+0x1c/0x64
>> [   48.500315] softirqs last  enabled at (5354): [<c01f0b2c>] css_release_work_fn+0xf4/0x264
>> [   48.508528] softirqs last disabled at (5352): [<c01f0b14>] css_release_work_fn+0xdc/0x264
>> [   48.516741] CPU: 1 PID: 416 Comm: kworker/1:2 Not tainted 4.10.0-rc8-next-20170215+ #123
>> [   48.524864] Hardware name: Generic OMAP5 (Flattened Device Tree)
>> [   48.530898] Workqueue: events_power_efficient palmas_gpio_id_detect [extcon_palmas]
>> [   48.538597] [<c0110228>] (unwind_backtrace) from [<c010c224>] (show_stack+0x10/0x14)
>> [   48.546379] [<c010c224>] (show_stack) from [<c04ca860>] (dump_stack+0xac/0xe0)
>> [   48.553637] [<c04ca860>] (dump_stack) from [<c0165fa0>] (___might_sleep+0x17c/0x2a4)
>> [   48.561416] [<c0165fa0>] (___might_sleep) from [<c0835fec>] (__mutex_lock+0x28/0x9f8)
>> [   48.569281] [<c0835fec>] (__mutex_lock) from [<c08369d8>] (mutex_lock_nested+0x1c/0x24)
>> [   48.577322] [<c08369d8>] (mutex_lock_nested) from [<c05478dc>] (regulator_enable+0x40/0x1dc)
>> [   48.585803] [<c05478dc>] (regulator_enable) from [<bf29d32c>] (dwc3_omap_set_mailbox+0xcc/0x184 [dwc3_omap])
>> [   48.595705] [<bf29d32c>] (dwc3_omap_set_mailbox [dwc3_omap]) from [<bf29d7ec>] (dwc3_omap_id_notifier+0x14/0x1c [dwc3_omap])
>> [   48.606979] [<bf29d7ec>] (dwc3_omap_id_notifier [dwc3_omap]) from [<c015f3ac>] (notifier_call_chain+0x44/0x80)
>> [   48.617028] [<c015f3ac>] (notifier_call_chain) from [<c015f520>] (raw_notifier_call_chain+0x18/0x20)
>> [   48.626209] [<c015f520>] (raw_notifier_call_chain) from [<bf028344>] (extcon_sync+0x90/0x1c8 [extcon_core])
>> [   48.636004] [<bf028344>] (extcon_sync [extcon_core]) from [<c015666c>] (process_one_work+0x2b4/0x808)
>> [   48.645268] [<c015666c>] (process_one_work) from [<c0157794>] (worker_thread+0x3c/0x550)
>> [   48.653396] [<c0157794>] (worker_thread) from [<c015d664>] (kthread+0x104/0x148)
>> [   48.660828] [<c015d664>] (kthread) from [<c0107830>] (ret_from_fork+0x14/0x24)
>> [   48.668313] BUG: scheduling while atomic: kworker/1:2/416/0x00000002
>> [   48.674717] 5 locks held by kworker/1:2/416:
>> [   48.679003]  #0:  ("events_power_efficient"){.+.+.+}, at: [<c01565b0>] process_one_work+0x1f8/0x808
>> [   48.688140]  #1:  ((&(&palmas_usb->wq_detectid)->work)){+.+...}, at: [<c01565b0>] process_one_work+0x1f8/0x808
>> [   48.698231]  #2:  (&(&edev->lock)->rlock){+.+...}, at: [<bf028324>] extcon_sync+0x70/0x1c8 [extcon_core]
>> [   48.707807]  #3:  (&rdev->mutex){+.+.+.}, at: [<c05478dc>] regulator_enable+0x40/0x1dc
>> [   48.715803]  #4:  (palmas:546:(&palmas_regmap_config[i])->lock){+.+.+.}, at: [<c05aa170>] regmap_read+0x2c/0x5c
>> [   48.725983] Modules linked in: usb_f_ecm usb_storage cppi41 am35x musb_dsps musb_am335x omap2430 phy_cpcap_usb phy_dm816x_usb phy_am335x phy_am335x_control phy_twl6030_usb phy_twl4030_usb musb_hdrc mwifiex_sdio mwifiex arc4 wlcore_sdio wl18xx wl12xx wlcore mac80211 cfg80211 omapdrm drm_kms_helper syscopyarea sysfillrect sysimgblt fb_sys_fops drm panel_dsi_cm lm3532_bl atmel_mxt_ts omap4_keypad matrix_keymap evdev ti_lmu_backlight ti_lmu connector_hdmi omapdss cfbimgblt cfbfillrect cfbcopyarea gpio_pca953x hid_generic usbhid smsc95xx smsc75xx usbnet usb_f_acm u_ether usb_f_mass_storage usb_f_serial u_serial xhci_plat_hcd xhci_hcd dwc3_omap dwc3 ohci_omap3 ohci_hcd ehci_omap ehci_hcd phy_omap_usb2 phy_generic libcomposite udc_core snd_soc_simple_card snd_soc_simple_card_utils snd_usb_audio snd_usbmidi_lib
>> [   48.797725]  usbcore usb_common snd_soc_omap_mcbsp snd_soc_omap_dmic snd_soc_omap_twl4030 snd_soc_omap_abe_twl6040 snd_soc_omap_mcpdm snd_soc_twl6040 snd_soc_twl4030 snd_soc_omap snd_soc_core snd_hwdep snd_pcm_dmaengine snd_pcm snd_timer snd_rawmidi snd soundcore rtc_ds1307 hwmon rtc_palmas rtc_twl palmas_pwrbutton extcon_palmas extcon_core ti_soc_thermal clk_palmas lib80211 ccm
>> [   48.831540] CPU: 1 PID: 416 Comm: kworker/1:2 Tainted: G        W       4.10.0-rc8-next-20170215+ #123
>> [   48.840892] Hardware name: Generic OMAP5 (Flattened Device Tree)
>> [   48.846926] Workqueue: events_power_efficient palmas_gpio_id_detect [extcon_palmas]
>> [   48.854623] [<c0110228>] (unwind_backtrace) from [<c010c224>] (show_stack+0x10/0x14)
>> [   48.862403] [<c010c224>] (show_stack) from [<c04ca860>] (dump_stack+0xac/0xe0)
>> [   48.869661] [<c04ca860>] (dump_stack) from [<c0165dec>] (__schedule_bug+0x6c/0xa4)
>> [   48.877270] [<c0165dec>] (__schedule_bug) from [<c0834820>] (__schedule+0xa38/0xe84)
>> [   48.885051] [<c0834820>] (__schedule) from [<c0834cc0>] (schedule+0x54/0xb8)
>> [   48.892133] [<c0834cc0>] (schedule) from [<c0839b98>] (schedule_timeout+0x23c/0x4a0)
>> [   48.899921] [<c0839b98>] (schedule_timeout) from [<c08357b4>] (wait_for_common+0xa8/0x164)
>> [   48.908230] [<c08357b4>] (wait_for_common) from [<c066c6e0>] (omap_i2c_xfer+0x3d8/0x550)
>> [   48.916356] [<c066c6e0>] (omap_i2c_xfer) from [<c0667f14>] (__i2c_transfer+0x13c/0x9d8)
>> [   48.924396] [<c0667f14>] (__i2c_transfer) from [<c0668820>] (i2c_transfer+0x70/0xb4)
>> [   48.932175] [<c0668820>] (i2c_transfer) from [<c05b0f7c>] (regmap_i2c_read+0x48/0x64)
>> [   48.940048] [<c05b0f7c>] (regmap_i2c_read) from [<c05aabd4>] (_regmap_raw_read+0xe4/0x488)
>> [   48.948350] [<c05aabd4>] (_regmap_raw_read) from [<c05aaf9c>] (_regmap_bus_read+0x24/0x4c)
>> [   48.956651] [<c05aaf9c>] (_regmap_bus_read) from [<c05a9f3c>] (_regmap_read+0x64/0x26c)
>> [   48.964690] [<c05a9f3c>] (_regmap_read) from [<c05aa180>] (regmap_read+0x3c/0x5c)
>> [   48.972207] [<c05aa180>] (regmap_read) from [<c05490c8>] (regulator_is_enabled_regmap+0x20/0x9c)
>> [   48.981033] [<c05490c8>] (regulator_is_enabled_regmap) from [<c05479f4>] (regulator_enable+0x158/0x1dc)
>> [   48.990472] [<c05479f4>] (regulator_enable) from [<bf29d32c>] (dwc3_omap_set_mailbox+0xcc/0x184 [dwc3_omap])
>> [   49.000387] [<bf29d32c>] (dwc3_omap_set_mailbox [dwc3_omap]) from [<bf29d7ec>] (dwc3_omap_id_notifier+0x14/0x1c [dwc3_omap])
>> [   49.011661] [<bf29d7ec>] (dwc3_omap_id_notifier [dwc3_omap]) from [<c015f3ac>] (notifier_call_chain+0x44/0x80)
>> [   49.021710] [<c015f3ac>] (notifier_call_chain) from [<c015f520>] (raw_notifier_call_chain+0x18/0x20)
>> [   49.030892] [<c015f520>] (raw_notifier_call_chain) from [<bf028344>] (extcon_sync+0x90/0x1c8 [extcon_core])
>> [   49.040688] [<bf028344>] (extcon_sync [extcon_core]) from [<c015666c>] (process_one_work+0x2b4/0x808)
>> [   49.049952] [<c015666c>] (process_one_work) from [<c0157794>] (worker_thread+0x3c/0x550)
>> [   49.058080] [<c0157794>] (worker_thread) from [<c015d664>] (kthread+0x104/0x148)
>> [   49.065509] [<c015d664>] (kthread) from [<c0107830>] (ret_from_fork+0x14/0x24)
>>
>> [   49.075275] ===============================
>> [   49.079503] [ ERR: suspicious RCU usage.  ]
>> [   49.083774] 4.10.0-rc8-next-20170215+ #123 Tainted: G        W      
>> [   49.090211] -------------------------------
>> [   49.094454] ./include/trace/events/kmem.h:51 suspicious rcu_dereference_check() usage!
>> [   49.102470] 
>>                other info that might help us debug this:
>>
>> [   49.110581] 
>>                rcu_scheduler_active = 2, debug_locks = 0
>> [   49.117181] 2 locks held by kworker/1:2/416:
>> [   49.121551]  #0:  ("events_power_efficient"){.+.+.+}, at: [<c01565b0>] process_one_work+0x1f8/0x808
>> [   49.130715]  #1:  ((&(&palmas_usb->wq_detectid)->work)){+.+.+.}, at: [<c01565b0>] process_one_work+0x1f8/0x808
>> [   49.140845] 
>>                stack backtrace:
>> [   49.145264] CPU: 1 PID: 416 Comm: kworker/1:2 Tainted: G        W       4.10.0-rc8-next-20170215+ #123
>> [   49.154614] Hardware name: Generic OMAP5 (Flattened Device Tree)
>> [   49.160649] Workqueue: events_power_efficient palmas_gpio_id_detect [extcon_palmas]
>> [   49.168345] [<c0110228>] (unwind_backtrace) from [<c010c224>] (show_stack+0x10/0x14)
>> [   49.176123] [<c010c224>] (show_stack) from [<c04ca860>] (dump_stack+0xac/0xe0)
>> [   49.183385] [<c04ca860>] (dump_stack) from [<c02aa500>] (kmem_cache_alloc_trace+0x2fc/0x364)
>> [   49.191865] [<c02aa500>] (kmem_cache_alloc_trace) from [<c04cd05c>] (kobject_uevent_env+0xac/0x4f4)
>> [   49.200959] [<c04cd05c>] (kobject_uevent_env) from [<bf028424>] (extcon_sync+0x170/0x1c8 [extcon_core])
>> [   49.210403] [<bf028424>] (extcon_sync [extcon_core]) from [<c015666c>] (process_one_work+0x2b4/0x808)
>> [   49.219666] [<c015666c>] (process_one_work) from [<c0157794>] (worker_thread+0x3c/0x550)
>> [   49.227794] [<c0157794>] (worker_thread) from [<c015d664>] (kthread+0x104/0x148)
>> [   49.235225] [<c015d664>] (kthread) from [<c0107830>] (ret_from_fork+0x14/0x24)
>> [   49.242589] BUG: workqueue leaked lock or atomic: kworker/1:2/0xffffffff/416
>>                     last function: palmas_gpio_id_detect [extcon_palmas]
>> [   49.256144] INFO: lockdep is turned off.
>> [   49.260099] CPU: 1 PID: 416 Comm: kworker/1:2 Tainted: G        W       4.10.0-rc8-next-20170215+ #123
>> [   49.269442] Hardware name: Generic OMAP5 (Flattened Device Tree)
>> [   49.275477] Workqueue: events_power_efficient palmas_gpio_id_detect [extcon_palmas]
>> [   49.283174] [<c0110228>] (unwind_backtrace) from [<c010c224>] (show_stack+0x10/0x14)
>> [   49.290953] [<c010c224>] (show_stack) from [<c04ca860>] (dump_stack+0xac/0xe0)
>> [   49.298210] [<c04ca860>] (dump_stack) from [<c0156998>] (process_one_work+0x5e0/0x808)
>> [   49.306165] [<c0156998>] (process_one_work) from [<c0157794>] (worker_thread+0x3c/0x550)
>> [   49.314293] [<c0157794>] (worker_thread) from [<c015d664>] (kthread+0x104/0x148)
>> [   49.321723] [<c015d664>] (kthread) from [<c0107830>] (ret_from_fork+0x14/0x24)
>> [   49.328998] BUG: scheduling while atomic: kworker/1:2/416/0x00000000
>> [   49.335450] INFO: lockdep is turned off.
>> [   49.339433] Modules linked in: usb_f_ecm usb_storage cppi41 am35x musb_dsps musb_am335x omap2430 phy_cpcap_usb phy_dm816x_usb phy_am335x phy_am335x_control phy_twl6030_usb phy_twl4030_usb musb_hdrc mwifiex_sdio mwifiex arc4 wlcore_sdio wl18xx wl12xx wlcore mac80211 cfg80211 omapdrm drm_kms_helper syscopyarea sysfillrect sysimgblt fb_sys_fops drm panel_dsi_cm lm3532_bl atmel_mxt_ts omap4_keypad matrix_keymap evdev ti_lmu_backlight ti_lmu connector_hdmi omapdss cfbimgblt cfbfillrect cfbcopyarea gpio_pca953x hid_generic usbhid smsc95xx smsc75xx usbnet usb_f_acm u_ether usb_f_mass_storage usb_f_serial u_serial xhci_plat_hcd xhci_hcd dwc3_omap dwc3 ohci_omap3 ohci_hcd ehci_omap ehci_hcd phy_omap_usb2 phy_generic libcomposite udc_core snd_soc_simple_card snd_soc_simple_card_utils snd_usb_audio snd_usbmidi_lib
>> [   49.339938] usb 3-1: new high-speed USB device number 2 using xhci-hcd
>> [   49.417777]  usbcore usb_common snd_soc_omap_mcbsp snd_soc_omap_dmic snd_soc_omap_twl4030 snd_soc_omap_abe_twl6040 snd_soc_omap_mcpdm snd_soc_twl6040 snd_soc_twl4030 snd_soc_omap snd_soc_core snd_hwdep snd_pcm_dmaengine snd_pcm snd_timer snd_rawmidi snd soundcore rtc_ds1307 hwmon rtc_palmas rtc_twl palmas_pwrbutton extcon_palmas extcon_core ti_soc_thermal clk_palmas lib80211 ccm
>> [   49.451601] CPU: 1 PID: 416 Comm: kworker/1:2 Tainted: G        W       4.10.0-rc8-next-20170215+ #123
>> [   49.460944] Hardware name: Generic OMAP5 (Flattened Device Tree)
>> [   49.466986] [<c0110228>] (unwind_backtrace) from [<c010c224>] (show_stack+0x10/0x14)
>> [   49.474764] [<c010c224>] (show_stack) from [<c04ca860>] (dump_stack+0xac/0xe0)
>> [   49.482021] [<c04ca860>] (dump_stack) from [<c0165dec>] (__schedule_bug+0x6c/0xa4)
>> [   49.489628] [<c0165dec>] (__schedule_bug) from [<c0834820>] (__schedule+0xa38/0xe84)
>> [   49.497408] [<c0834820>] (__schedule) from [<c0834cc0>] (schedule+0x54/0xb8)
>> [   49.504491] [<c0834cc0>] (schedule) from [<c015780c>] (worker_thread+0xb4/0x550)
>> [   49.511921] [<c015780c>] (worker_thread) from [<c015d664>] (kthread+0x104/0x148)
>> [   49.519351] [<c015d664>] (kthread) from [<c0107830>] (ret_from_fork+0x14/0x24)
>> [   49.563684] usb 3-1: New USB device found, idVendor=05e3, idProduct=0745
>> [   49.570522] usb 3-1: New USB device strings: Mfr=0, Product=1, SerialNumber=2
>> [   49.577684] usb 3-1: Product: USB Storage
>> [   49.581887] usb 3-1: SerialNumber: 000000000902
>> [   49.587894] usb-storage 3-1:1.0: USB Mass Storage device detected
>> [   49.596532] scsi host1: usb-storage 3-1:1.0
>> [   49.601738] of_get_named_gpiod_flags: can't parse 'hpd-gpios' property of node '/connector[0]'
>> [   49.610869] connector-hdmi connector: failed to find video source
>> [   50.661720] scsi 1:0:0:0: Direct-Access     Generic  STORAGE DEVICE   0902 PQ: 0 ANSI: 6
>> [   50.672125] of_get_named_gpiod_flags: can't parse 'hpd-gpios' property of node '/connector[0]'
>> [   50.681001] connector-hdmi connector: failed to find video source
>> [   50.918830] sd 1:0:0:0: [sda] 7882752 512-byte logical blocks: (4.04 GB/3.76 GiB)
>> [   50.927672] sd 1:0:0:0: [sda] Write Protect is off
>> [   50.932539] sd 1:0:0:0: [sda] Mode Sense: 21 00 00 00
>> [   50.938860] sd 1:0:0:0: [sda] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA
>> [   50.954522]  sda: sda1
>> [   50.960682] sd 1:0:0:0: [sda] Attached SCSI removable disk
>>


-- 
Best Regards,
Chanwoo Choi
Samsung Electronics



More information about the Letux-kernel mailing list