+Chanwoo
On 15/02/17 23:36, Tony Lindgren wrote:
> * Tony Lindgren <tony@xxxxxxxxxxx> [170215 13:01]:
>> * Roger Quadros <rogerq@xxxxxx> [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?
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
>
--
cheers,
-roger
--
To unsubscribe from this list: send the line "unsubscribe linux-omap" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html
