Hi all, I finally made the twl6040 respond :)
There were some bugs I want to share:
1. two missing wires in the schematics and layout (I didn't recognize that two nets are the same in the EVM schematics and therefore did not connect them). This can easily be fixed for the prototypes by two tiny wires.
2. To analyse #1 I had modified the DT to have ti,audpwron-gpio = <0>; i.e. no explicit gpio
This forces the driver to use twl6040_power_up_manual() which is easier to debug by adding printk to see which registers are written.
So I could check for the bug #1 that the first two i2c commands were sent while the third one made the twl6040 get stuck (incl. strange malfunctions on I2C1).
The reason of #1 seems to be that the DPLL is not running but the I2C commands enable the DPLL.
But even after fixing the hardware for #1 with gpio = <0> the kernel still doesn't work well!
Interestingly, it is exactly the same on the 5432EVM. So I assume there is some bug in twl6040_power_up_manual() which someone might be interested to fix.
Here is the relevant log:
root@letux:~# dmesg|fgrep twl6040 [ 1.806151] driver_register 'twl6040' [ 2.167067] driver_register 'twl6040-clk' [ 4.504801] driver_register 'twl6040-gpo' [ 5.512941] driver_register 'twl6040-codec' [ 5.546052] driver_register 'omap-abe-twl6040' [ 5.552065] twl6040_power(1) [ 5.580273] twl6040_power_up_manual write TWL6040_REG_LDOCTL c4 => 0 [ 5.638471] twl6040_power_up_manual write TWL6040_REG_NCPCTL 01 => 0 [ 5.695951] twl6040_power_up_manual write TWL6040_REG_LDOCTL c5 => 0 [ 5.720330] twl6040_power_up_manual write TWL6040_REG_LPPLLCTL 01 => -121 [ 5.760155] twl6040 0-004b: manual power-up failed [ 5.868581] omap-abe-twl6040 sound: twl6040-legacy <-> 40132000.mcpdm mapping ok [ 5.878215] twl6040_power(1) [ 5.888584] twl6040_power_up_manual write TWL6040_REG_LDOCTL c4 => 0 [ 5.907665] twl6040_power_up_manual write TWL6040_REG_NCPCTL 01 => 0 [ 5.922287] twl6040_power_up_manual write TWL6040_REG_LDOCTL c5 => 0 [ 5.967645] twl6040_power_up_manual write TWL6040_REG_LPPLLCTL 01 => 0 [ 6.010201] twl6040_power_up_manual write TWL6040_REG_LDOCTL 45 => 0 [ 6.026169] twl6040 0-004b: Unable to sync registers 0x4-0x6. -121 root@letux:~# root@letux:~# dmesg|fgrep pdm [ 4.316219] driver_register 'omap-mcpdm' [ 5.797800] omap_hwmod: mcpdm: _wait_target_ready failed: -16 [ 5.868581] omap-abe-twl6040 sound: twl6040-legacy <-> 40132000.mcpdm mapping ok
Running aplay in this state ends up with an imprecise external abort in omap_mcpdm_dai_startup.
After restoring the correct ti,audpwron-gpio it works on the EVM.
And - most importantly - also on the Pyra!
I am now able to run some aplay command and see that there are signals on the speaker output pins.
Since I can't connect them yet (I have no good Pyra case prototype) I could not yet test the real sound...
3. I have configured the twl6040-vibra driver and done some fixes (there is a NULL pointer dereference), but it still does not work.
My twl6040-vibra patches are here:
http://git.goldelico.com/?p=gta04-kernel.git;a=shortlog;h=refs/heads/work/hn...
(I want to clean them up a little and post to LKML soon).
Log is appended. Any hints for deciphering these kernel error message are welcome.
BR, Nikolaus
root@letux:~# ./vibra.py [ 49.684034] input input4: work is already on queue [ 49.689067] input input4: work is already on queue [ 49.980307] [ 49.981866] ========================================================= [ 49.988614] [ INFO: possible irq lock inversion dependency detected ] [ 49.995364] 4.5.0-rc4-letux+ #2003 Tainted: G W [ 50.001299] --------------------------------------------------------- [ 50.008055] swapper/0 just changed the state of lock: [ 50.013354] (&(&dev->event_lock)->rlock){..-...}, at: [<c040cb5c>] ml_effect_timer+0x18/0x34 [ 50.022321] but this lock took another, SOFTIRQ-unsafe lock in the past: [ 50.029348] (twl6040:652:(&twl6040_regmap_config)->lock){+.+...}
and interrupts could create inverse lock ordering between them.
[ 50.042027] [ 50.042027] other info that might help us debug this: [ 50.048874] Possible interrupt unsafe locking scenario: [ 50.048874] [ 50.055984] CPU0 CPU1 [ 50.060732] ---- ---- [ 50.065476] lock(twl6040:652:(&twl6040_regmap_config)->lock); [ 50.071685] local_irq_disable(); [ 50.077882] lock(&(&dev->event_lock)->rlock); [ 50.085275] lock(twl6040:652:(&twl6040_regmap_config)->lock); [ 50.094120] <Interrupt> [ 50.096861] lock(&(&dev->event_lock)->rlock); [ 50.101798] [ 50.101798] *** DEADLOCK *** [ 50.101798] [ 50.108010] 1 lock held by swapper/0: [ 50.111838] #0: (((&ml->timer))){+.-...}, at: [<c007f940>] call_timer_fn+0x0/0x1a8 [ 50.119984] [ 50.119984] the shortest dependencies between 2nd lock and 1st lock: [ 50.128213] -> (twl6040:652:(&twl6040_regmap_config)->lock){+.+...} ops: 732 { [ 50.135900] HARDIRQ-ON-W at: [ 50.139279] [<c006c8b0>] lock_acquire+0x100/0x124 [ 50.146222] [<c05783c8>] mutex_lock_nested+0x38/0x30c [ 50.153536] [<c0349ed4>] regmap_register_patch+0xa4/0x104 [ 50.161201] [<c0357c64>] twl6040_probe+0x150/0x3fc [ 50.168240] [<c041b738>] i2c_device_probe+0x198/0x1ec [ 50.175545] [<c0332c3c>] really_probe+0xf8/0x250 [ 50.182388] [<c0332f38>] driver_probe_device+0x44/0x70 [ 50.189776] [<c033163c>] bus_for_each_drv+0x4c/0x84 [ 50.196900] [<c0332e60>] __device_attach+0x84/0xf8 [ 50.203924] [<c0332280>] bus_probe_device+0x28/0x84 [ 50.211045] [<c0330940>] device_add+0x204/0x34c [ 50.217797] [<c041c744>] i2c_new_device+0x10c/0x18c [ 50.224917] [<c041caa4>] of_i2c_register_device+0x15c/0x180 [ 50.232758] [<c041cd7c>] i2c_register_adapter+0x1f0/0x32c [ 50.240421] [<c04207e8>] omap_i2c_probe+0x33c/0x430 [ 50.247537] [<c0334570>] platform_drv_probe+0x50/0x98 [ 50.254835] [<c0332c3c>] really_probe+0xf8/0x250 [ 50.261681] [<c0332f38>] driver_probe_device+0x44/0x70 [ 50.269076] [<c033163c>] bus_for_each_drv+0x4c/0x84 [ 50.276190] [<c0332e60>] __device_attach+0x84/0xf8 [ 50.283211] [<c0332280>] bus_probe_device+0x28/0x84 [ 50.290324] [<c03326e8>] deferred_probe_work_func+0x5c/0x8c [ 50.298175] [<c004ef40>] process_one_work+0x284/0x48c [ 50.305476] [<c004f370>] worker_thread+0x1f8/0x30c [ 50.312502] [<c0053e34>] kthread+0xcc/0xe0 [ 50.318793] [<c000ef30>] ret_from_fork+0x14/0x24 [ 50.325640] SOFTIRQ-ON-W at: [ 50.329020] [<c006c8b0>] lock_acquire+0x100/0x124 [ 50.335961] [<c05783c8>] mutex_lock_nested+0x38/0x30c [ 50.343269] [<c0349ed4>] regmap_register_patch+0xa4/0x104 [ 50.350926] [<c0357c64>] twl6040_probe+0x150/0x3fc [ 50.357950] [<c041b738>] i2c_device_probe+0x198/0x1ec [ 50.365248] [<c0332c3c>] really_probe+0xf8/0x250 [ 50.372086] [<c0332f38>] driver_probe_device+0x44/0x70 [ 50.379473] [<c033163c>] bus_for_each_drv+0x4c/0x84 [ 50.386587] [<c0332e60>] __device_attach+0x84/0xf8 [ 50.393618] [<c0332280>] bus_probe_device+0x28/0x84 [ 50.400737] [<c0330940>] device_add+0x204/0x34c [ 50.407491] [<c041c744>] i2c_new_device+0x10c/0x18c [ 50.414608] [<c041caa4>] of_i2c_register_device+0x15c/0x180 [ 50.422451] [<c041cd7c>] i2c_register_adapter+0x1f0/0x32c [ 50.430120] [<c04207e8>] omap_i2c_probe+0x33c/0x430 [ 50.437231] [<c0334570>] platform_drv_probe+0x50/0x98 [ 50.444533] [<c0332c3c>] really_probe+0xf8/0x250 [ 50.451372] [<c0332f38>] driver_probe_device+0x44/0x70 [ 50.458763] [<c033163c>] bus_for_each_drv+0x4c/0x84 [ 50.465882] [<c0332e60>] __device_attach+0x84/0xf8 [ 50.472905] [<c0332280>] bus_probe_device+0x28/0x84 [ 50.480021] [<c03326e8>] deferred_probe_work_func+0x5c/0x8c [ 50.487872] [<c004ef40>] process_one_work+0x284/0x48c [ 50.495173] [<c004f370>] worker_thread+0x1f8/0x30c [ 50.502198] [<c0053e34>] kthread+0xcc/0xe0 [ 50.508501] [<c000ef30>] ret_from_fork+0x14/0x24 [ 50.515346] INITIAL USE at: [ 50.518640] [<c05783c8>] mutex_lock_nested+0x38/0x30c [ 50.525839] [<c0349ed4>] regmap_register_patch+0xa4/0x104 [ 50.533412] [<c0357c64>] twl6040_probe+0x150/0x3fc [ 50.540349] [<c041b738>] i2c_device_probe+0x198/0x1ec [ 50.547556] [<c0332c3c>] really_probe+0xf8/0x250 [ 50.554311] [<c0332f38>] driver_probe_device+0x44/0x70 [ 50.561613] [<c033163c>] bus_for_each_drv+0x4c/0x84 [ 50.568634] [<c0332e60>] __device_attach+0x84/0xf8 [ 50.575574] [<c0332280>] bus_probe_device+0x28/0x84 [ 50.582603] [<c0330940>] device_add+0x204/0x34c [ 50.589263] [<c041c744>] i2c_new_device+0x10c/0x18c [ 50.596287] [<c041caa4>] of_i2c_register_device+0x15c/0x180 [ 50.604045] [<c041cd7c>] i2c_register_adapter+0x1f0/0x32c [ 50.611620] [<c04207e8>] omap_i2c_probe+0x33c/0x430 [ 50.618646] [<c0334570>] platform_drv_probe+0x50/0x98 [ 50.625858] [<c0332c3c>] really_probe+0xf8/0x250 [ 50.632614] [<c0332f38>] driver_probe_device+0x44/0x70 [ 50.639905] [<c033163c>] bus_for_each_drv+0x4c/0x84 [ 50.646934] [<c0332e60>] __device_attach+0x84/0xf8 [ 50.653870] [<c0332280>] bus_probe_device+0x28/0x84 [ 50.660892] [<c03326e8>] deferred_probe_work_func+0x5c/0x8c [ 50.668648] [<c004ef40>] process_one_work+0x284/0x48c [ 50.675856] [<c004f370>] worker_thread+0x1f8/0x30c [ 50.682792] [<c0053e34>] kthread+0xcc/0xe0 [ 50.688997] [<c000ef30>] ret_from_fork+0x14/0x24 [ 50.695755] } [ 50.697581] ... key at: [<c10b20ec>] _key.21993+0x0/0x8 [ 50.703701] ... acquired at: [ 50.706898] [<c006c2b8>] __lock_acquire+0x7e0/0x8fc [ 50.712286] [<c006c8b0>] lock_acquire+0x100/0x124 [ 50.717501] [<c05783c8>] mutex_lock_nested+0x38/0x30c [ 50.723072] [<c03484b4>] regmap_read+0x30/0x58 [ 50.728008] [<c0357ac8>] twl6040_get_vibralr_status+0x18/0x48 [ 50.734302] [<bf06770c>] vibra_play+0x18/0x98 [twl6040_vibra] [ 50.740603] [<c040ca58>] ml_play_effects+0x34/0x5c [ 50.745901] [<c040cb38>] ml_ff_playback+0x88/0x94 [ 50.751106] [<c040bcac>] input_ff_event+0x9c/0xa4 [ 50.756314] [<c040aac8>] input_handle_event+0x4c/0x134 [ 50.761976] [<c040acc4>] input_inject_event+0x114/0x1ac [ 50.767732] [<c0410f80>] evdev_write+0x88/0xc0 [ 50.772666] [<c011d524>] __vfs_write+0x18/0x38 [ 50.777602] [<c011e0f4>] vfs_write+0xac/0x130 [ 50.782440] [<c011e318>] SyS_write+0x40/0x78 [ 50.787192] [<c000eea0>] ret_fast_syscall+0x0/0x1c [ 50.792487] [ 50.794042] -> (&(&dev->event_lock)->rlock){..-...} ops: 90 { [ 50.800087] IN-SOFTIRQ-W at: [ 50.803378] [<c006c8b0>] lock_acquire+0x100/0x124 [ 50.810136] [<c0579f4c>] _raw_spin_lock_irqsave+0x38/0x4c [ 50.817616] [<c040cb5c>] ml_effect_timer+0x18/0x34 [ 50.824458] [<c007fa00>] call_timer_fn+0xc0/0x1a8 [ 50.831221] [<c0080600>] run_timer_softirq.part.1+0x1d8/0x23c [ 50.839065] [<c003ad90>] __do_softirq+0x140/0x33c [ 50.845819] [<c003b230>] irq_exit+0x80/0x100 [ 50.852120] [<c007582c>] __handle_domain_irq+0x84/0xa4 [ 50.859337] [<c00094ac>] gic_handle_irq+0x50/0x84 [ 50.866092] [<c057a9f8>] __irq_svc+0x58/0x78 [ 50.872392] [<c000f7c4>] arch_cpu_idle+0x30/0x3c [ 50.879056] [<c000f7c4>] arch_cpu_idle+0x30/0x3c [ 50.885714] [<c0063fa8>] cpu_idle_loop+0x128/0x1a0 [ 50.892564] [<c006402c>] schedstat_start+0x0/0x2c [ 50.899309] INITIAL USE at: [ 50.902510] [<c0579f4c>] _raw_spin_lock_irqsave+0x38/0x4c [ 50.909900] [<c040ad94>] input_event+0x38/0x60 [ 50.916293] [<c0414228>] gpio_keys_gpio_report_event+0x88/0xa4 [ 50.924146] [<c0414280>] gpio_keys_report_state+0x3c/0x6c [ 50.931548] [<c04142e0>] gpio_keys_open+0x30/0x38 [ 50.938200] [<c0408a64>] input_open_device+0x68/0xa4 [ 50.945144] [<c0314048>] kbd_connect+0x50/0x7c [ 50.951529] [<c0408eb8>] input_attach_handler+0x34/0x64 [ 50.958740] [<c040946c>] input_register_device+0x18c/0x248 [ 50.966224] [<c0414e4c>] gpio_keys_probe+0x198/0x208 [ 50.973164] [<c0334570>] platform_drv_probe+0x50/0x98 [ 50.980195] [<c0332c3c>] really_probe+0xf8/0x250 [ 50.986763] [<c0332f38>] driver_probe_device+0x44/0x70 [ 50.993878] [<c0332fcc>] __driver_attach+0x68/0x8c [ 51.000629] [<c03316c4>] bus_for_each_dev+0x50/0x84 [ 51.007465] [<c0332494>] bus_add_driver+0xcc/0x1e4 [ 51.014218] [<c0333964>] driver_register+0xac/0xf4 [ 51.020963] [<c0009728>] do_one_initcall+0x100/0x1bc [ 51.027891] [<c07e8d30>] do_basic_setup+0x98/0xd4 [ 51.034556] [<c07e8dcc>] kernel_init_freeable+0x60/0xfc [ 51.041763] [<c0574834>] kernel_init+0x8/0xe4 [ 51.048064] [<c000ef30>] ret_from_fork+0x14/0x24 [ 51.054631] } [ 51.056370] ... key at: [<c10b455c>] __key.22698+0x0/0x8 [ 51.062492] ... acquired at: [ 51.065595] [<c006b814>] mark_lock+0x2c0/0x3f8 [ 51.070528] [<c006b9ec>] mark_irqflags+0xa0/0x18c [ 51.075737] [<c006c11c>] __lock_acquire+0x644/0x8fc [ 51.081118] [<c006c8b0>] lock_acquire+0x100/0x124 [ 51.086323] [<c0579f4c>] _raw_spin_lock_irqsave+0x38/0x4c [ 51.092256] [<c040cb5c>] ml_effect_timer+0x18/0x34 [ 51.097553] [<c007fa00>] call_timer_fn+0xc0/0x1a8 [ 51.102752] [<c0080600>] run_timer_softirq.part.1+0x1d8/0x23c [ 51.109056] [<c003ad90>] __do_softirq+0x140/0x33c [ 51.114259] [<c003b230>] irq_exit+0x80/0x100 [ 51.119017] [<c007582c>] __handle_domain_irq+0x84/0xa4 [ 51.124681] [<c00094ac>] gic_handle_irq+0x50/0x84 [ 51.129888] [<c057a9f8>] __irq_svc+0x58/0x78 [ 51.134634] [<c000f7c4>] arch_cpu_idle+0x30/0x3c [ 51.139752] [<c000f7c4>] arch_cpu_idle+0x30/0x3c [ 51.144865] [<c0063fa8>] cpu_idle_loop+0x128/0x1a0 [ 51.150156] [<c006402c>] schedstat_start+0x0/0x2c [ 51.155357] [ 51.156912] [ 51.156912] stack backtrace: [ 51.161483] CPU: 0 PID: 0 Comm: swapper Tainted: G W 4.5.0-rc4-letux+ #2003 [ 51.169963] Hardware name: Generic OMAP5 (Flattened Device Tree) [ 51.176257] [<c0014518>] (unwind_backtrace) from [<c0012700>] (show_stack+0x10/0x14) [ 51.184384] [<c0012700>] (show_stack) from [<c0069e10>] (print_irq_inversion_bug.part.12+0x16c/0x1a4) [ 51.194060] [<c0069e10>] (print_irq_inversion_bug.part.12) from [<c0069f50>] (check_usage_forwards+0x108/0x13c) [ 51.204657] [<c0069f50>] (check_usage_forwards) from [<c00d5cb0>] (mark_lock_irq+0xcc/0x294) [ 51.213511] [<c00d5cb0>] (mark_lock_irq) from [<c006b814>] (mark_lock+0x2c0/0x3f8) [ 51.221451] [<c006b814>] (mark_lock) from [<c006b9ec>] (mark_irqflags+0xa0/0x18c) [ 51.229298] [<c006b9ec>] (mark_irqflags) from [<c006c11c>] (__lock_acquire+0x644/0x8fc) [ 51.237700] [<c006c11c>] (__lock_acquire) from [<c006c8b0>] (lock_acquire+0x100/0x124) [ 51.246011] [<c006c8b0>] (lock_acquire) from [<c0579f4c>] (_raw_spin_lock_irqsave+0x38/0x4c) [ 51.254866] [<c0579f4c>] (_raw_spin_lock_irqsave) from [<c040cb5c>] (ml_effect_timer+0x18/0x34) [ 51.264003] [<c040cb5c>] (ml_effect_timer) from [<c007fa00>] (call_timer_fn+0xc0/0x1a8) [ 51.272402] [<c007fa00>] (call_timer_fn) from [<c0080600>] (run_timer_softirq.part.1+0x1d8/0x23c) [ 51.281715] [<c0080600>] (run_timer_softirq.part.1) from [<c003ad90>] (__do_softirq+0x140/0x33c) [ 51.290934] [<c003ad90>] (__do_softirq) from [<c003b230>] (irq_exit+0x80/0x100) [ 51.298604] [<c003b230>] (irq_exit) from [<c007582c>] (__handle_domain_irq+0x84/0xa4) [ 51.306817] [<c007582c>] (__handle_domain_irq) from [<c00094ac>] (gic_handle_irq+0x50/0x84) [ 51.315586] [<c00094ac>] (gic_handle_irq) from [<c057a9f8>] (__irq_svc+0x58/0x78) [ 51.323436] Exception stack(0xc084bf58 to 0xc084bfa0) [ 51.328728] bf40: 00000001 00000004 [ 51.337301] bf60: 00000000 c084f940 c08f0dd0 c08eece0 c084c198 c08516a4 80004059 412fc0f2 [ 51.345873] bf80: 00000000 00000000 00000000 c084bfa8 c006d2a0 c000f7c4 20000013 ffffffff [ 51.354451] [<c057a9f8>] (__irq_svc) from [<c000f7c4>] (arch_cpu_idle+0x30/0x3c) [ 51.362208] [<c000f7c4>] (arch_cpu_idle) from [<c0063fa8>] (cpu_idle_loop+0x128/0x1a0) [ 51.370513] [<c0063fa8>] (cpu_idle_loop) from [<c006402c>] (schedstat_start+0x0/0x2c) [ 51.380244] input input4: work is already on queue [ 51.701464] input input4: work is already on queue [ 51.706491] input input4: work is already on queue [ 51.711537] input input4: work is already on queue [ 51.716562] input input4: work is already on queue [ 51.721608] input input4: work is already on queue [ 51.726641] input input4: work is already on queue [ 51.731683] input input4: work is already on queue [ 51.736707] input input4: work is already on queue [ 51.741738] input input4: work is already on queue [ 51.746761] input input4: work is already on queue [ 51.751797] input input4: work is already on queue [ 51.756828] input input4: work is already on queue [ 51.761872] input input4: work is already on queue root@letux:~#
Hi,
On 02/18/2016 08:05 PM, H. Nikolaus Schaller wrote:
Hi all, I finally made the twl6040 respond :)
There were some bugs I want to share:
- two missing wires in the schematics and layout (I didn't recognize that two nets are
the same in the EVM schematics and therefore did not connect them). This can easily be fixed for the prototypes by two tiny wires.
- To analyse #1 I had modified the DT to have ti,audpwron-gpio = <0>; i.e. no explicit gpio
This forces the driver to use twl6040_power_up_manual() which is easier to debug by adding printk to see which registers are written.
The manual power sequence is based on the datasheet and it was meant for early samples where automatic power up had bug. It should work on newer samples, but it is not the most reliable thing ;)
So I could check for the bug #1 that the first two i2c commands were sent while the third one made the twl6040 get stuck (incl. strange malfunctions on I2C1).
The reason of #1 seems to be that the DPLL is not running but the I2C commands enable the DPLL.
In order to get twl6040 working you must have 32K clock supplied to it. On omap5-uevm it is coming from Palmas. You can switch to High performance PLL only if you have the Hight frequency clock coming in. Again on omap5-uevm this is not yet possible in a clean way as it is coming from OMAP5 and the bit to enable it is in a problematic part of system control register map...
But even after fixing the hardware for #1 with gpio = <0> the kernel still doesn't work well!
Interestingly, it is exactly the same on the 5432EVM. So I assume there is some bug in twl6040_power_up_manual() which someone might be interested to fix.
Here is the relevant log:
root@letux:~# dmesg|fgrep twl6040 [ 1.806151] driver_register 'twl6040' [ 2.167067] driver_register 'twl6040-clk' [ 4.504801] driver_register 'twl6040-gpo' [ 5.512941] driver_register 'twl6040-codec' [ 5.546052] driver_register 'omap-abe-twl6040' [ 5.552065] twl6040_power(1) [ 5.580273] twl6040_power_up_manual write TWL6040_REG_LDOCTL c4 => 0 [ 5.638471] twl6040_power_up_manual write TWL6040_REG_NCPCTL 01 => 0 [ 5.695951] twl6040_power_up_manual write TWL6040_REG_LDOCTL c5 => 0 [ 5.720330] twl6040_power_up_manual write TWL6040_REG_LPPLLCTL 01 => -121 [ 5.760155] twl6040 0-004b: manual power-up failed [ 5.868581] omap-abe-twl6040 sound: twl6040-legacy <-> 40132000.mcpdm mapping ok [ 5.878215] twl6040_power(1) [ 5.888584] twl6040_power_up_manual write TWL6040_REG_LDOCTL c4 => 0 [ 5.907665] twl6040_power_up_manual write TWL6040_REG_NCPCTL 01 => 0 [ 5.922287] twl6040_power_up_manual write TWL6040_REG_LDOCTL c5 => 0 [ 5.967645] twl6040_power_up_manual write TWL6040_REG_LPPLLCTL 01 => 0 [ 6.010201] twl6040_power_up_manual write TWL6040_REG_LDOCTL 45 => 0 [ 6.026169] twl6040 0-004b: Unable to sync registers 0x4-0x6. -121 root@letux:~# root@letux:~# dmesg|fgrep pdm [ 4.316219] driver_register 'omap-mcpdm' [ 5.797800] omap_hwmod: mcpdm: _wait_target_ready failed: -16 [ 5.868581] omap-abe-twl6040 sound: twl6040-legacy <-> 40132000.mcpdm mapping ok
Running aplay in this state ends up with an imprecise external abort in omap_mcpdm_dai_startup.
McPDM needs the PDM clock. If twl6040 is not enabled it is not running the PDM clock -> you can not access McPDM registers.
After restoring the correct ti,audpwron-gpio it works on the EVM.
And - most importantly - also on the Pyra!
I am now able to run some aplay command and see that there are signals on the speaker output pins.
Since I can't connect them yet (I have no good Pyra case prototype) I could not yet test the real sound...
- I have configured the twl6040-vibra driver and done some fixes (there is a NULL
pointer dereference), but it still does not work.
My twl6040-vibra patches are here:
http://git.goldelico.com/?p=gta04-kernel.git;a=shortlog;h=refs/heads/work/hn...
(I want to clean them up a little and post to LKML soon).
Thanks!
I have not tested the vibra for ages... I can try to boot up my OMAP4-blaze and see how they are ATM. But last time I used it it was working fine.
Log is appended. Any hints for deciphering these kernel error message are welcome.
BR, Nikolaus
root@letux:~# ./vibra.py [ 49.684034] input input4: work is already on queue [ 49.689067] input input4: work is already on queue [ 49.980307] [ 49.981866] ========================================================= [ 49.988614] [ INFO: possible irq lock inversion dependency detected ] [ 49.995364] 4.5.0-rc4-letux+ #2003 Tainted: G W [ 50.001299] --------------------------------------------------------- [ 50.008055] swapper/0 just changed the state of lock: [ 50.013354] (&(&dev->event_lock)->rlock){..-...}, at: [<c040cb5c>] ml_effect_timer+0x18/0x34 [ 50.022321] but this lock took another, SOFTIRQ-unsafe lock in the past: [ 50.029348] (twl6040:652:(&twl6040_regmap_config)->lock){+.+...}
and interrupts could create inverse lock ordering between them.
[ 50.042027] [ 50.042027] other info that might help us debug this: [ 50.048874] Possible interrupt unsafe locking scenario: [ 50.048874] [ 50.055984] CPU0 CPU1 [ 50.060732] ---- ---- [ 50.065476] lock(twl6040:652:(&twl6040_regmap_config)->lock); [ 50.071685] local_irq_disable(); [ 50.077882] lock(&(&dev->event_lock)->rlock); [ 50.085275] lock(twl6040:652:(&twl6040_regmap_config)->lock); [ 50.094120] <Interrupt> [ 50.096861] lock(&(&dev->event_lock)->rlock); [ 50.101798] [ 50.101798] *** DEADLOCK *** [ 50.101798] [ 50.108010] 1 lock held by swapper/0: [ 50.111838] #0: (((&ml->timer))){+.-...}, at: [<c007f940>] call_timer_fn+0x0/0x1a8 [ 50.119984] [ 50.119984] the shortest dependencies between 2nd lock and 1st lock: [ 50.128213] -> (twl6040:652:(&twl6040_regmap_config)->lock){+.+...} ops: 732 { [ 50.135900] HARDIRQ-ON-W at: [ 50.139279] [<c006c8b0>] lock_acquire+0x100/0x124 [ 50.146222] [<c05783c8>] mutex_lock_nested+0x38/0x30c [ 50.153536] [<c0349ed4>] regmap_register_patch+0xa4/0x104 [ 50.161201] [<c0357c64>] twl6040_probe+0x150/0x3fc [ 50.168240] [<c041b738>] i2c_device_probe+0x198/0x1ec [ 50.175545] [<c0332c3c>] really_probe+0xf8/0x250 [ 50.182388] [<c0332f38>] driver_probe_device+0x44/0x70 [ 50.189776] [<c033163c>] bus_for_each_drv+0x4c/0x84 [ 50.196900] [<c0332e60>] __device_attach+0x84/0xf8 [ 50.203924] [<c0332280>] bus_probe_device+0x28/0x84 [ 50.211045] [<c0330940>] device_add+0x204/0x34c [ 50.217797] [<c041c744>] i2c_new_device+0x10c/0x18c [ 50.224917] [<c041caa4>] of_i2c_register_device+0x15c/0x180 [ 50.232758] [<c041cd7c>] i2c_register_adapter+0x1f0/0x32c [ 50.240421] [<c04207e8>] omap_i2c_probe+0x33c/0x430 [ 50.247537] [<c0334570>] platform_drv_probe+0x50/0x98 [ 50.254835] [<c0332c3c>] really_probe+0xf8/0x250 [ 50.261681] [<c0332f38>] driver_probe_device+0x44/0x70 [ 50.269076] [<c033163c>] bus_for_each_drv+0x4c/0x84 [ 50.276190] [<c0332e60>] __device_attach+0x84/0xf8 [ 50.283211] [<c0332280>] bus_probe_device+0x28/0x84 [ 50.290324] [<c03326e8>] deferred_probe_work_func+0x5c/0x8c [ 50.298175] [<c004ef40>] process_one_work+0x284/0x48c [ 50.305476] [<c004f370>] worker_thread+0x1f8/0x30c [ 50.312502] [<c0053e34>] kthread+0xcc/0xe0 [ 50.318793] [<c000ef30>] ret_from_fork+0x14/0x24 [ 50.325640] SOFTIRQ-ON-W at: [ 50.329020] [<c006c8b0>] lock_acquire+0x100/0x124 [ 50.335961] [<c05783c8>] mutex_lock_nested+0x38/0x30c [ 50.343269] [<c0349ed4>] regmap_register_patch+0xa4/0x104 [ 50.350926] [<c0357c64>] twl6040_probe+0x150/0x3fc [ 50.357950] [<c041b738>] i2c_device_probe+0x198/0x1ec [ 50.365248] [<c0332c3c>] really_probe+0xf8/0x250 [ 50.372086] [<c0332f38>] driver_probe_device+0x44/0x70 [ 50.379473] [<c033163c>] bus_for_each_drv+0x4c/0x84 [ 50.386587] [<c0332e60>] __device_attach+0x84/0xf8 [ 50.393618] [<c0332280>] bus_probe_device+0x28/0x84 [ 50.400737] [<c0330940>] device_add+0x204/0x34c [ 50.407491] [<c041c744>] i2c_new_device+0x10c/0x18c [ 50.414608] [<c041caa4>] of_i2c_register_device+0x15c/0x180 [ 50.422451] [<c041cd7c>] i2c_register_adapter+0x1f0/0x32c [ 50.430120] [<c04207e8>] omap_i2c_probe+0x33c/0x430 [ 50.437231] [<c0334570>] platform_drv_probe+0x50/0x98 [ 50.444533] [<c0332c3c>] really_probe+0xf8/0x250 [ 50.451372] [<c0332f38>] driver_probe_device+0x44/0x70 [ 50.458763] [<c033163c>] bus_for_each_drv+0x4c/0x84 [ 50.465882] [<c0332e60>] __device_attach+0x84/0xf8 [ 50.472905] [<c0332280>] bus_probe_device+0x28/0x84 [ 50.480021] [<c03326e8>] deferred_probe_work_func+0x5c/0x8c [ 50.487872] [<c004ef40>] process_one_work+0x284/0x48c [ 50.495173] [<c004f370>] worker_thread+0x1f8/0x30c [ 50.502198] [<c0053e34>] kthread+0xcc/0xe0 [ 50.508501] [<c000ef30>] ret_from_fork+0x14/0x24 [ 50.515346] INITIAL USE at: [ 50.518640] [<c05783c8>] mutex_lock_nested+0x38/0x30c [ 50.525839] [<c0349ed4>] regmap_register_patch+0xa4/0x104 [ 50.533412] [<c0357c64>] twl6040_probe+0x150/0x3fc [ 50.540349] [<c041b738>] i2c_device_probe+0x198/0x1ec [ 50.547556] [<c0332c3c>] really_probe+0xf8/0x250 [ 50.554311] [<c0332f38>] driver_probe_device+0x44/0x70 [ 50.561613] [<c033163c>] bus_for_each_drv+0x4c/0x84 [ 50.568634] [<c0332e60>] __device_attach+0x84/0xf8 [ 50.575574] [<c0332280>] bus_probe_device+0x28/0x84 [ 50.582603] [<c0330940>] device_add+0x204/0x34c [ 50.589263] [<c041c744>] i2c_new_device+0x10c/0x18c [ 50.596287] [<c041caa4>] of_i2c_register_device+0x15c/0x180 [ 50.604045] [<c041cd7c>] i2c_register_adapter+0x1f0/0x32c [ 50.611620] [<c04207e8>] omap_i2c_probe+0x33c/0x430 [ 50.618646] [<c0334570>] platform_drv_probe+0x50/0x98 [ 50.625858] [<c0332c3c>] really_probe+0xf8/0x250 [ 50.632614] [<c0332f38>] driver_probe_device+0x44/0x70 [ 50.639905] [<c033163c>] bus_for_each_drv+0x4c/0x84 [ 50.646934] [<c0332e60>] __device_attach+0x84/0xf8 [ 50.653870] [<c0332280>] bus_probe_device+0x28/0x84 [ 50.660892] [<c03326e8>] deferred_probe_work_func+0x5c/0x8c [ 50.668648] [<c004ef40>] process_one_work+0x284/0x48c [ 50.675856] [<c004f370>] worker_thread+0x1f8/0x30c [ 50.682792] [<c0053e34>] kthread+0xcc/0xe0 [ 50.688997] [<c000ef30>] ret_from_fork+0x14/0x24 [ 50.695755] } [ 50.697581] ... key at: [<c10b20ec>] _key.21993+0x0/0x8 [ 50.703701] ... acquired at: [ 50.706898] [<c006c2b8>] __lock_acquire+0x7e0/0x8fc [ 50.712286] [<c006c8b0>] lock_acquire+0x100/0x124 [ 50.717501] [<c05783c8>] mutex_lock_nested+0x38/0x30c [ 50.723072] [<c03484b4>] regmap_read+0x30/0x58 [ 50.728008] [<c0357ac8>] twl6040_get_vibralr_status+0x18/0x48 [ 50.734302] [<bf06770c>] vibra_play+0x18/0x98 [twl6040_vibra] [ 50.740603] [<c040ca58>] ml_play_effects+0x34/0x5c [ 50.745901] [<c040cb38>] ml_ff_playback+0x88/0x94 [ 50.751106] [<c040bcac>] input_ff_event+0x9c/0xa4 [ 50.756314] [<c040aac8>] input_handle_event+0x4c/0x134 [ 50.761976] [<c040acc4>] input_inject_event+0x114/0x1ac [ 50.767732] [<c0410f80>] evdev_write+0x88/0xc0 [ 50.772666] [<c011d524>] __vfs_write+0x18/0x38 [ 50.777602] [<c011e0f4>] vfs_write+0xac/0x130 [ 50.782440] [<c011e318>] SyS_write+0x40/0x78 [ 50.787192] [<c000eea0>] ret_fast_syscall+0x0/0x1c [ 50.792487] [ 50.794042] -> (&(&dev->event_lock)->rlock){..-...} ops: 90 { [ 50.800087] IN-SOFTIRQ-W at: [ 50.803378] [<c006c8b0>] lock_acquire+0x100/0x124 [ 50.810136] [<c0579f4c>] _raw_spin_lock_irqsave+0x38/0x4c [ 50.817616] [<c040cb5c>] ml_effect_timer+0x18/0x34 [ 50.824458] [<c007fa00>] call_timer_fn+0xc0/0x1a8 [ 50.831221] [<c0080600>] run_timer_softirq.part.1+0x1d8/0x23c [ 50.839065] [<c003ad90>] __do_softirq+0x140/0x33c [ 50.845819] [<c003b230>] irq_exit+0x80/0x100 [ 50.852120] [<c007582c>] __handle_domain_irq+0x84/0xa4 [ 50.859337] [<c00094ac>] gic_handle_irq+0x50/0x84 [ 50.866092] [<c057a9f8>] __irq_svc+0x58/0x78 [ 50.872392] [<c000f7c4>] arch_cpu_idle+0x30/0x3c [ 50.879056] [<c000f7c4>] arch_cpu_idle+0x30/0x3c [ 50.885714] [<c0063fa8>] cpu_idle_loop+0x128/0x1a0 [ 50.892564] [<c006402c>] schedstat_start+0x0/0x2c [ 50.899309] INITIAL USE at: [ 50.902510] [<c0579f4c>] _raw_spin_lock_irqsave+0x38/0x4c [ 50.909900] [<c040ad94>] input_event+0x38/0x60 [ 50.916293] [<c0414228>] gpio_keys_gpio_report_event+0x88/0xa4 [ 50.924146] [<c0414280>] gpio_keys_report_state+0x3c/0x6c [ 50.931548] [<c04142e0>] gpio_keys_open+0x30/0x38 [ 50.938200] [<c0408a64>] input_open_device+0x68/0xa4 [ 50.945144] [<c0314048>] kbd_connect+0x50/0x7c [ 50.951529] [<c0408eb8>] input_attach_handler+0x34/0x64 [ 50.958740] [<c040946c>] input_register_device+0x18c/0x248 [ 50.966224] [<c0414e4c>] gpio_keys_probe+0x198/0x208 [ 50.973164] [<c0334570>] platform_drv_probe+0x50/0x98 [ 50.980195] [<c0332c3c>] really_probe+0xf8/0x250 [ 50.986763] [<c0332f38>] driver_probe_device+0x44/0x70 [ 50.993878] [<c0332fcc>] __driver_attach+0x68/0x8c [ 51.000629] [<c03316c4>] bus_for_each_dev+0x50/0x84 [ 51.007465] [<c0332494>] bus_add_driver+0xcc/0x1e4 [ 51.014218] [<c0333964>] driver_register+0xac/0xf4 [ 51.020963] [<c0009728>] do_one_initcall+0x100/0x1bc [ 51.027891] [<c07e8d30>] do_basic_setup+0x98/0xd4 [ 51.034556] [<c07e8dcc>] kernel_init_freeable+0x60/0xfc [ 51.041763] [<c0574834>] kernel_init+0x8/0xe4 [ 51.048064] [<c000ef30>] ret_from_fork+0x14/0x24 [ 51.054631] } [ 51.056370] ... key at: [<c10b455c>] __key.22698+0x0/0x8 [ 51.062492] ... acquired at: [ 51.065595] [<c006b814>] mark_lock+0x2c0/0x3f8 [ 51.070528] [<c006b9ec>] mark_irqflags+0xa0/0x18c [ 51.075737] [<c006c11c>] __lock_acquire+0x644/0x8fc [ 51.081118] [<c006c8b0>] lock_acquire+0x100/0x124 [ 51.086323] [<c0579f4c>] _raw_spin_lock_irqsave+0x38/0x4c [ 51.092256] [<c040cb5c>] ml_effect_timer+0x18/0x34 [ 51.097553] [<c007fa00>] call_timer_fn+0xc0/0x1a8 [ 51.102752] [<c0080600>] run_timer_softirq.part.1+0x1d8/0x23c [ 51.109056] [<c003ad90>] __do_softirq+0x140/0x33c [ 51.114259] [<c003b230>] irq_exit+0x80/0x100 [ 51.119017] [<c007582c>] __handle_domain_irq+0x84/0xa4 [ 51.124681] [<c00094ac>] gic_handle_irq+0x50/0x84 [ 51.129888] [<c057a9f8>] __irq_svc+0x58/0x78 [ 51.134634] [<c000f7c4>] arch_cpu_idle+0x30/0x3c [ 51.139752] [<c000f7c4>] arch_cpu_idle+0x30/0x3c [ 51.144865] [<c0063fa8>] cpu_idle_loop+0x128/0x1a0 [ 51.150156] [<c006402c>] schedstat_start+0x0/0x2c [ 51.155357] [ 51.156912] [ 51.156912] stack backtrace: [ 51.161483] CPU: 0 PID: 0 Comm: swapper Tainted: G W 4.5.0-rc4-letux+ #2003 [ 51.169963] Hardware name: Generic OMAP5 (Flattened Device Tree) [ 51.176257] [<c0014518>] (unwind_backtrace) from [<c0012700>] (show_stack+0x10/0x14) [ 51.184384] [<c0012700>] (show_stack) from [<c0069e10>] (print_irq_inversion_bug.part.12+0x16c/0x1a4) [ 51.194060] [<c0069e10>] (print_irq_inversion_bug.part.12) from [<c0069f50>] (check_usage_forwards+0x108/0x13c) [ 51.204657] [<c0069f50>] (check_usage_forwards) from [<c00d5cb0>] (mark_lock_irq+0xcc/0x294) [ 51.213511] [<c00d5cb0>] (mark_lock_irq) from [<c006b814>] (mark_lock+0x2c0/0x3f8) [ 51.221451] [<c006b814>] (mark_lock) from [<c006b9ec>] (mark_irqflags+0xa0/0x18c) [ 51.229298] [<c006b9ec>] (mark_irqflags) from [<c006c11c>] (__lock_acquire+0x644/0x8fc) [ 51.237700] [<c006c11c>] (__lock_acquire) from [<c006c8b0>] (lock_acquire+0x100/0x124) [ 51.246011] [<c006c8b0>] (lock_acquire) from [<c0579f4c>] (_raw_spin_lock_irqsave+0x38/0x4c) [ 51.254866] [<c0579f4c>] (_raw_spin_lock_irqsave) from [<c040cb5c>] (ml_effect_timer+0x18/0x34) [ 51.264003] [<c040cb5c>] (ml_effect_timer) from [<c007fa00>] (call_timer_fn+0xc0/0x1a8) [ 51.272402] [<c007fa00>] (call_timer_fn) from [<c0080600>] (run_timer_softirq.part.1+0x1d8/0x23c) [ 51.281715] [<c0080600>] (run_timer_softirq.part.1) from [<c003ad90>] (__do_softirq+0x140/0x33c) [ 51.290934] [<c003ad90>] (__do_softirq) from [<c003b230>] (irq_exit+0x80/0x100) [ 51.298604] [<c003b230>] (irq_exit) from [<c007582c>] (__handle_domain_irq+0x84/0xa4) [ 51.306817] [<c007582c>] (__handle_domain_irq) from [<c00094ac>] (gic_handle_irq+0x50/0x84) [ 51.315586] [<c00094ac>] (gic_handle_irq) from [<c057a9f8>] (__irq_svc+0x58/0x78) [ 51.323436] Exception stack(0xc084bf58 to 0xc084bfa0) [ 51.328728] bf40: 00000001 00000004 [ 51.337301] bf60: 00000000 c084f940 c08f0dd0 c08eece0 c084c198 c08516a4 80004059 412fc0f2 [ 51.345873] bf80: 00000000 00000000 00000000 c084bfa8 c006d2a0 c000f7c4 20000013 ffffffff [ 51.354451] [<c057a9f8>] (__irq_svc) from [<c000f7c4>] (arch_cpu_idle+0x30/0x3c) [ 51.362208] [<c000f7c4>] (arch_cpu_idle) from [<c0063fa8>] (cpu_idle_loop+0x128/0x1a0) [ 51.370513] [<c0063fa8>] (cpu_idle_loop) from [<c006402c>] (schedstat_start+0x0/0x2c) [ 51.380244] input input4: work is already on queue [ 51.701464] input input4: work is already on queue [ 51.706491] input input4: work is already on queue [ 51.711537] input input4: work is already on queue [ 51.716562] input input4: work is already on queue [ 51.721608] input input4: work is already on queue [ 51.726641] input input4: work is already on queue [ 51.731683] input input4: work is already on queue [ 51.736707] input input4: work is already on queue [ 51.741738] input input4: work is already on queue [ 51.746761] input input4: work is already on queue [ 51.751797] input input4: work is already on queue [ 51.756828] input input4: work is already on queue [ 51.761872] input input4: work is already on queue root@letux:~#
Hi Peter,
Am 19.02.2016 um 16:47 schrieb Peter Ujfalusi peter.ujfalusi@ti.com:
Hi,
On 02/18/2016 08:05 PM, H. Nikolaus Schaller wrote:
Hi all, I finally made the twl6040 respond :)
There were some bugs I want to share:
- two missing wires in the schematics and layout (I didn't recognize that two nets are
the same in the EVM schematics and therefore did not connect them). This can easily be fixed for the prototypes by two tiny wires.
- To analyse #1 I had modified the DT to have ti,audpwron-gpio = <0>; i.e. no explicit gpio
This forces the driver to use twl6040_power_up_manual() which is easier to debug by adding printk to see which registers are written.
The manual power sequence is based on the datasheet and it was meant for early samples where automatic power up had bug. It should work on newer samples, but it is not the most reliable thing ;)
Ok, I see.
Well, it was helpful to debug my hardware problem because automatic power on silently failed (except for a timeout).
What was wrong is that we missed to power VDDPLL, VDDDL, VDDUL from the VDDLDO output. So the twl6040 simply did not have power to run the PLL or the PDM interface.
So I could check for the bug #1 that the first two i2c commands were sent while the third one made the twl6040 get stuck (incl. strange malfunctions on I2C1).
The reason of #1 seems to be that the DPLL is not running but the I2C commands enable the DPLL.
In order to get twl6040 working you must have 32K clock supplied to it. On omap5-uevm it is coming from Palmas.
That is available from Palmas.
You can switch to High performance PLL only if you have the Hight frequency clock coming in. Again on omap5-uevm this is not yet possible in a clean way as it is coming from OMAP5 and the bit to enable it is in a problematic part of system control register map...
I think you mean the ckobuffer? I have a patch for that as well. Will be submitted soon to LKML for review.
But even after fixing the hardware for #1 with gpio = <0> the kernel still doesn't work well!
Interestingly, it is exactly the same on the 5432EVM. So I assume there is some bug in twl6040_power_up_manual() which someone might be interested to fix.
Here is the relevant log:
root@letux:~# dmesg|fgrep twl6040 [ 1.806151] driver_register 'twl6040' [ 2.167067] driver_register 'twl6040-clk' [ 4.504801] driver_register 'twl6040-gpo' [ 5.512941] driver_register 'twl6040-codec' [ 5.546052] driver_register 'omap-abe-twl6040' [ 5.552065] twl6040_power(1) [ 5.580273] twl6040_power_up_manual write TWL6040_REG_LDOCTL c4 => 0 [ 5.638471] twl6040_power_up_manual write TWL6040_REG_NCPCTL 01 => 0 [ 5.695951] twl6040_power_up_manual write TWL6040_REG_LDOCTL c5 => 0 [ 5.720330] twl6040_power_up_manual write TWL6040_REG_LPPLLCTL 01 => -121 [ 5.760155] twl6040 0-004b: manual power-up failed [ 5.868581] omap-abe-twl6040 sound: twl6040-legacy <-> 40132000.mcpdm mapping ok [ 5.878215] twl6040_power(1) [ 5.888584] twl6040_power_up_manual write TWL6040_REG_LDOCTL c4 => 0 [ 5.907665] twl6040_power_up_manual write TWL6040_REG_NCPCTL 01 => 0 [ 5.922287] twl6040_power_up_manual write TWL6040_REG_LDOCTL c5 => 0 [ 5.967645] twl6040_power_up_manual write TWL6040_REG_LPPLLCTL 01 => 0 [ 6.010201] twl6040_power_up_manual write TWL6040_REG_LDOCTL 45 => 0 [ 6.026169] twl6040 0-004b: Unable to sync registers 0x4-0x6. -121 root@letux:~# root@letux:~# dmesg|fgrep pdm [ 4.316219] driver_register 'omap-mcpdm' [ 5.797800] omap_hwmod: mcpdm: _wait_target_ready failed: -16 [ 5.868581] omap-abe-twl6040 sound: twl6040-legacy <-> 40132000.mcpdm mapping ok
Running aplay in this state ends up with an imprecise external abort in omap_mcpdm_dai_startup.
McPDM needs the PDM clock. If twl6040 is not enabled it is not running the PDM clock -> you can not access McPDM registers.
Ok, that is the explanation since the PDM clock comes from the twl6040.
After restoring the correct ti,audpwron-gpio it works on the EVM.
And - most importantly - also on the Pyra!
I am now able to run some aplay command and see that there are signals on the speaker output pins.
Since I can't connect them yet (I have no good Pyra case prototype) I could not yet test the real sound...
- I have configured the twl6040-vibra driver and done some fixes (there is a NULL
pointer dereference), but it still does not work.
My twl6040-vibra patches are here:
http://git.goldelico.com/?p=gta04-kernel.git;a=shortlog;h=refs/heads/work/hn...
(I want to clean them up a little and post to LKML soon).
Thanks!
I have not tested the vibra for ages... I can try to boot up my OMAP4-blaze and see how they are ATM. But last time I used it it was working fine.
Would be good to know if it works for you. And it would allow to independently evaluate my patches.
I have fixed another bug and removed the "work is already on queue" handler, because the twl4030-vibra doesn't do that and logging shows that the play() function may be called multiple times in short succession - before the work function runs. Maybe once for each ioctl. Therefore it is better to ignore if the work is already scheduled instead of failing.
With all these changes [1] it works!
Pyra can now rumble :)
Well, I also had to set the "weak" motor speed in my test script [2] since our motor is connected to the left channel... That should probably be changed to the right channel in hardware since I assume that most software is assuming a "strong" motor and rarely a secondary "weak" motor.
Finally, I have removed the mutex (the twl4030-vibra hasn't either), but the possible irq lock inversion dependency remains. I think it has something to do with regmap_read().
I must also note that I have enabled several kernel issue detectors in my current .config so you might not get a report with omap2plus_defconfig.
But it does not block my hardware-validation task so it is an exercise for later improvement.
Log is appended. Any hints for deciphering these kernel error message are welcome.
BR, Nikolaus
root@letux:~# ./vibra.py [ 49.684034] input input4: work is already on queue [ 49.689067] input input4: work is already on queue [ 49.980307] [ 49.981866] ========================================================= [ 49.988614] [ INFO: possible irq lock inversion dependency detected ] [ 49.995364] 4.5.0-rc4-letux+ #2003 Tainted: G W [ 50.001299] --------------------------------------------------------- [ 50.008055] swapper/0 just changed the state of lock: [ 50.013354] (&(&dev->event_lock)->rlock){..-...}, at: [<c040cb5c>] ml_effect_timer+0x18/0x34 [ 50.022321] but this lock took another, SOFTIRQ-unsafe lock in the past: [ 50.029348] (twl6040:652:(&twl6040_regmap_config)->lock){+.+...}
and interrupts could create inverse lock ordering between them.
[ 50.042027] [ 50.042027] other info that might help us debug this: [ 50.048874] Possible interrupt unsafe locking scenario: [ 50.048874] [ 50.055984] CPU0 CPU1 [ 50.060732] ---- ---- [ 50.065476] lock(twl6040:652:(&twl6040_regmap_config)->lock); [ 50.071685] local_irq_disable(); [ 50.077882] lock(&(&dev->event_lock)->rlock); [ 50.085275] lock(twl6040:652:(&twl6040_regmap_config)->lock); [ 50.094120] <Interrupt> [ 50.096861] lock(&(&dev->event_lock)->rlock); [ 50.101798] [ 50.101798] *** DEADLOCK *** [ 50.101798] [ 50.108010] 1 lock held by swapper/0: [ 50.111838] #0: (((&ml->timer))){+.-...}, at: [<c007f940>] call_timer_fn+0x0/0x1a8 [ 50.119984] [ 50.119984] the shortest dependencies between 2nd lock and 1st lock: [ 50.128213] -> (twl6040:652:(&twl6040_regmap_config)->lock){+.+...} ops: 732 { [ 50.135900] HARDIRQ-ON-W at: [ 50.139279] [<c006c8b0>] lock_acquire+0x100/0x124 [ 50.146222] [<c05783c8>] mutex_lock_nested+0x38/0x30c [ 50.153536] [<c0349ed4>] regmap_register_patch+0xa4/0x104 [ 50.161201] [<c0357c64>] twl6040_probe+0x150/0x3fc [ 50.168240] [<c041b738>] i2c_device_probe+0x198/0x1ec [ 50.175545] [<c0332c3c>] really_probe+0xf8/0x250 [ 50.182388] [<c0332f38>] driver_probe_device+0x44/0x70 [ 50.189776] [<c033163c>] bus_for_each_drv+0x4c/0x84 [ 50.196900] [<c0332e60>] __device_attach+0x84/0xf8 [ 50.203924] [<c0332280>] bus_probe_device+0x28/0x84 [ 50.211045] [<c0330940>] device_add+0x204/0x34c [ 50.217797] [<c041c744>] i2c_new_device+0x10c/0x18c [ 50.224917] [<c041caa4>] of_i2c_register_device+0x15c/0x180 [ 50.232758] [<c041cd7c>] i2c_register_adapter+0x1f0/0x32c [ 50.240421] [<c04207e8>] omap_i2c_probe+0x33c/0x430 [ 50.247537] [<c0334570>] platform_drv_probe+0x50/0x98 [ 50.254835] [<c0332c3c>] really_probe+0xf8/0x250 [ 50.261681] [<c0332f38>] driver_probe_device+0x44/0x70 [ 50.269076] [<c033163c>] bus_for_each_drv+0x4c/0x84 [ 50.276190] [<c0332e60>] __device_attach+0x84/0xf8 [ 50.283211] [<c0332280>] bus_probe_device+0x28/0x84 [ 50.290324] [<c03326e8>] deferred_probe_work_func+0x5c/0x8c [ 50.298175] [<c004ef40>] process_one_work+0x284/0x48c [ 50.305476] [<c004f370>] worker_thread+0x1f8/0x30c [ 50.312502] [<c0053e34>] kthread+0xcc/0xe0 [ 50.318793] [<c000ef30>] ret_from_fork+0x14/0x24 [ 50.325640] SOFTIRQ-ON-W at: [ 50.329020] [<c006c8b0>] lock_acquire+0x100/0x124 [ 50.335961] [<c05783c8>] mutex_lock_nested+0x38/0x30c [ 50.343269] [<c0349ed4>] regmap_register_patch+0xa4/0x104 [ 50.350926] [<c0357c64>] twl6040_probe+0x150/0x3fc [ 50.357950] [<c041b738>] i2c_device_probe+0x198/0x1ec [ 50.365248] [<c0332c3c>] really_probe+0xf8/0x250 [ 50.372086] [<c0332f38>] driver_probe_device+0x44/0x70 [ 50.379473] [<c033163c>] bus_for_each_drv+0x4c/0x84 [ 50.386587] [<c0332e60>] __device_attach+0x84/0xf8 [ 50.393618] [<c0332280>] bus_probe_device+0x28/0x84 [ 50.400737] [<c0330940>] device_add+0x204/0x34c [ 50.407491] [<c041c744>] i2c_new_device+0x10c/0x18c [ 50.414608] [<c041caa4>] of_i2c_register_device+0x15c/0x180 [ 50.422451] [<c041cd7c>] i2c_register_adapter+0x1f0/0x32c [ 50.430120] [<c04207e8>] omap_i2c_probe+0x33c/0x430 [ 50.437231] [<c0334570>] platform_drv_probe+0x50/0x98 [ 50.444533] [<c0332c3c>] really_probe+0xf8/0x250 [ 50.451372] [<c0332f38>] driver_probe_device+0x44/0x70 [ 50.458763] [<c033163c>] bus_for_each_drv+0x4c/0x84 [ 50.465882] [<c0332e60>] __device_attach+0x84/0xf8 [ 50.472905] [<c0332280>] bus_probe_device+0x28/0x84 [ 50.480021] [<c03326e8>] deferred_probe_work_func+0x5c/0x8c [ 50.487872] [<c004ef40>] process_one_work+0x284/0x48c [ 50.495173] [<c004f370>] worker_thread+0x1f8/0x30c [ 50.502198] [<c0053e34>] kthread+0xcc/0xe0 [ 50.508501] [<c000ef30>] ret_from_fork+0x14/0x24 [ 50.515346] INITIAL USE at: [ 50.518640] [<c05783c8>] mutex_lock_nested+0x38/0x30c [ 50.525839] [<c0349ed4>] regmap_register_patch+0xa4/0x104 [ 50.533412] [<c0357c64>] twl6040_probe+0x150/0x3fc [ 50.540349] [<c041b738>] i2c_device_probe+0x198/0x1ec [ 50.547556] [<c0332c3c>] really_probe+0xf8/0x250 [ 50.554311] [<c0332f38>] driver_probe_device+0x44/0x70 [ 50.561613] [<c033163c>] bus_for_each_drv+0x4c/0x84 [ 50.568634] [<c0332e60>] __device_attach+0x84/0xf8 [ 50.575574] [<c0332280>] bus_probe_device+0x28/0x84 [ 50.582603] [<c0330940>] device_add+0x204/0x34c [ 50.589263] [<c041c744>] i2c_new_device+0x10c/0x18c [ 50.596287] [<c041caa4>] of_i2c_register_device+0x15c/0x180 [ 50.604045] [<c041cd7c>] i2c_register_adapter+0x1f0/0x32c [ 50.611620] [<c04207e8>] omap_i2c_probe+0x33c/0x430 [ 50.618646] [<c0334570>] platform_drv_probe+0x50/0x98 [ 50.625858] [<c0332c3c>] really_probe+0xf8/0x250 [ 50.632614] [<c0332f38>] driver_probe_device+0x44/0x70 [ 50.639905] [<c033163c>] bus_for_each_drv+0x4c/0x84 [ 50.646934] [<c0332e60>] __device_attach+0x84/0xf8 [ 50.653870] [<c0332280>] bus_probe_device+0x28/0x84 [ 50.660892] [<c03326e8>] deferred_probe_work_func+0x5c/0x8c [ 50.668648] [<c004ef40>] process_one_work+0x284/0x48c [ 50.675856] [<c004f370>] worker_thread+0x1f8/0x30c [ 50.682792] [<c0053e34>] kthread+0xcc/0xe0 [ 50.688997] [<c000ef30>] ret_from_fork+0x14/0x24 [ 50.695755] } [ 50.697581] ... key at: [<c10b20ec>] _key.21993+0x0/0x8 [ 50.703701] ... acquired at: [ 50.706898] [<c006c2b8>] __lock_acquire+0x7e0/0x8fc [ 50.712286] [<c006c8b0>] lock_acquire+0x100/0x124 [ 50.717501] [<c05783c8>] mutex_lock_nested+0x38/0x30c [ 50.723072] [<c03484b4>] regmap_read+0x30/0x58 [ 50.728008] [<c0357ac8>] twl6040_get_vibralr_status+0x18/0x48 [ 50.734302] [<bf06770c>] vibra_play+0x18/0x98 [twl6040_vibra] [ 50.740603] [<c040ca58>] ml_play_effects+0x34/0x5c [ 50.745901] [<c040cb38>] ml_ff_playback+0x88/0x94 [ 50.751106] [<c040bcac>] input_ff_event+0x9c/0xa4 [ 50.756314] [<c040aac8>] input_handle_event+0x4c/0x134 [ 50.761976] [<c040acc4>] input_inject_event+0x114/0x1ac [ 50.767732] [<c0410f80>] evdev_write+0x88/0xc0 [ 50.772666] [<c011d524>] __vfs_write+0x18/0x38 [ 50.777602] [<c011e0f4>] vfs_write+0xac/0x130 [ 50.782440] [<c011e318>] SyS_write+0x40/0x78 [ 50.787192] [<c000eea0>] ret_fast_syscall+0x0/0x1c [ 50.792487] [ 50.794042] -> (&(&dev->event_lock)->rlock){..-...} ops: 90 { [ 50.800087] IN-SOFTIRQ-W at: [ 50.803378] [<c006c8b0>] lock_acquire+0x100/0x124 [ 50.810136] [<c0579f4c>] _raw_spin_lock_irqsave+0x38/0x4c [ 50.817616] [<c040cb5c>] ml_effect_timer+0x18/0x34 [ 50.824458] [<c007fa00>] call_timer_fn+0xc0/0x1a8 [ 50.831221] [<c0080600>] run_timer_softirq.part.1+0x1d8/0x23c [ 50.839065] [<c003ad90>] __do_softirq+0x140/0x33c [ 50.845819] [<c003b230>] irq_exit+0x80/0x100 [ 50.852120] [<c007582c>] __handle_domain_irq+0x84/0xa4 [ 50.859337] [<c00094ac>] gic_handle_irq+0x50/0x84 [ 50.866092] [<c057a9f8>] __irq_svc+0x58/0x78 [ 50.872392] [<c000f7c4>] arch_cpu_idle+0x30/0x3c [ 50.879056] [<c000f7c4>] arch_cpu_idle+0x30/0x3c [ 50.885714] [<c0063fa8>] cpu_idle_loop+0x128/0x1a0 [ 50.892564] [<c006402c>] schedstat_start+0x0/0x2c [ 50.899309] INITIAL USE at: [ 50.902510] [<c0579f4c>] _raw_spin_lock_irqsave+0x38/0x4c [ 50.909900] [<c040ad94>] input_event+0x38/0x60 [ 50.916293] [<c0414228>] gpio_keys_gpio_report_event+0x88/0xa4 [ 50.924146] [<c0414280>] gpio_keys_report_state+0x3c/0x6c [ 50.931548] [<c04142e0>] gpio_keys_open+0x30/0x38 [ 50.938200] [<c0408a64>] input_open_device+0x68/0xa4 [ 50.945144] [<c0314048>] kbd_connect+0x50/0x7c [ 50.951529] [<c0408eb8>] input_attach_handler+0x34/0x64 [ 50.958740] [<c040946c>] input_register_device+0x18c/0x248 [ 50.966224] [<c0414e4c>] gpio_keys_probe+0x198/0x208 [ 50.973164] [<c0334570>] platform_drv_probe+0x50/0x98 [ 50.980195] [<c0332c3c>] really_probe+0xf8/0x250 [ 50.986763] [<c0332f38>] driver_probe_device+0x44/0x70 [ 50.993878] [<c0332fcc>] __driver_attach+0x68/0x8c [ 51.000629] [<c03316c4>] bus_for_each_dev+0x50/0x84 [ 51.007465] [<c0332494>] bus_add_driver+0xcc/0x1e4 [ 51.014218] [<c0333964>] driver_register+0xac/0xf4 [ 51.020963] [<c0009728>] do_one_initcall+0x100/0x1bc [ 51.027891] [<c07e8d30>] do_basic_setup+0x98/0xd4 [ 51.034556] [<c07e8dcc>] kernel_init_freeable+0x60/0xfc [ 51.041763] [<c0574834>] kernel_init+0x8/0xe4 [ 51.048064] [<c000ef30>] ret_from_fork+0x14/0x24 [ 51.054631] } [ 51.056370] ... key at: [<c10b455c>] __key.22698+0x0/0x8 [ 51.062492] ... acquired at: [ 51.065595] [<c006b814>] mark_lock+0x2c0/0x3f8 [ 51.070528] [<c006b9ec>] mark_irqflags+0xa0/0x18c [ 51.075737] [<c006c11c>] __lock_acquire+0x644/0x8fc [ 51.081118] [<c006c8b0>] lock_acquire+0x100/0x124 [ 51.086323] [<c0579f4c>] _raw_spin_lock_irqsave+0x38/0x4c [ 51.092256] [<c040cb5c>] ml_effect_timer+0x18/0x34 [ 51.097553] [<c007fa00>] call_timer_fn+0xc0/0x1a8 [ 51.102752] [<c0080600>] run_timer_softirq.part.1+0x1d8/0x23c [ 51.109056] [<c003ad90>] __do_softirq+0x140/0x33c [ 51.114259] [<c003b230>] irq_exit+0x80/0x100 [ 51.119017] [<c007582c>] __handle_domain_irq+0x84/0xa4 [ 51.124681] [<c00094ac>] gic_handle_irq+0x50/0x84 [ 51.129888] [<c057a9f8>] __irq_svc+0x58/0x78 [ 51.134634] [<c000f7c4>] arch_cpu_idle+0x30/0x3c [ 51.139752] [<c000f7c4>] arch_cpu_idle+0x30/0x3c [ 51.144865] [<c0063fa8>] cpu_idle_loop+0x128/0x1a0 [ 51.150156] [<c006402c>] schedstat_start+0x0/0x2c [ 51.155357] [ 51.156912] [ 51.156912] stack backtrace: [ 51.161483] CPU: 0 PID: 0 Comm: swapper Tainted: G W 4.5.0-rc4-letux+ #2003 [ 51.169963] Hardware name: Generic OMAP5 (Flattened Device Tree) [ 51.176257] [<c0014518>] (unwind_backtrace) from [<c0012700>] (show_stack+0x10/0x14) [ 51.184384] [<c0012700>] (show_stack) from [<c0069e10>] (print_irq_inversion_bug.part.12+0x16c/0x1a4) [ 51.194060] [<c0069e10>] (print_irq_inversion_bug.part.12) from [<c0069f50>] (check_usage_forwards+0x108/0x13c) [ 51.204657] [<c0069f50>] (check_usage_forwards) from [<c00d5cb0>] (mark_lock_irq+0xcc/0x294) [ 51.213511] [<c00d5cb0>] (mark_lock_irq) from [<c006b814>] (mark_lock+0x2c0/0x3f8) [ 51.221451] [<c006b814>] (mark_lock) from [<c006b9ec>] (mark_irqflags+0xa0/0x18c) [ 51.229298] [<c006b9ec>] (mark_irqflags) from [<c006c11c>] (__lock_acquire+0x644/0x8fc) [ 51.237700] [<c006c11c>] (__lock_acquire) from [<c006c8b0>] (lock_acquire+0x100/0x124) [ 51.246011] [<c006c8b0>] (lock_acquire) from [<c0579f4c>] (_raw_spin_lock_irqsave+0x38/0x4c) [ 51.254866] [<c0579f4c>] (_raw_spin_lock_irqsave) from [<c040cb5c>] (ml_effect_timer+0x18/0x34) [ 51.264003] [<c040cb5c>] (ml_effect_timer) from [<c007fa00>] (call_timer_fn+0xc0/0x1a8) [ 51.272402] [<c007fa00>] (call_timer_fn) from [<c0080600>] (run_timer_softirq.part.1+0x1d8/0x23c) [ 51.281715] [<c0080600>] (run_timer_softirq.part.1) from [<c003ad90>] (__do_softirq+0x140/0x33c) [ 51.290934] [<c003ad90>] (__do_softirq) from [<c003b230>] (irq_exit+0x80/0x100) [ 51.298604] [<c003b230>] (irq_exit) from [<c007582c>] (__handle_domain_irq+0x84/0xa4) [ 51.306817] [<c007582c>] (__handle_domain_irq) from [<c00094ac>] (gic_handle_irq+0x50/0x84) [ 51.315586] [<c00094ac>] (gic_handle_irq) from [<c057a9f8>] (__irq_svc+0x58/0x78) [ 51.323436] Exception stack(0xc084bf58 to 0xc084bfa0) [ 51.328728] bf40: 00000001 00000004 [ 51.337301] bf60: 00000000 c084f940 c08f0dd0 c08eece0 c084c198 c08516a4 80004059 412fc0f2 [ 51.345873] bf80: 00000000 00000000 00000000 c084bfa8 c006d2a0 c000f7c4 20000013 ffffffff [ 51.354451] [<c057a9f8>] (__irq_svc) from [<c000f7c4>] (arch_cpu_idle+0x30/0x3c) [ 51.362208] [<c000f7c4>] (arch_cpu_idle) from [<c0063fa8>] (cpu_idle_loop+0x128/0x1a0) [ 51.370513] [<c0063fa8>] (cpu_idle_loop) from [<c006402c>] (schedstat_start+0x0/0x2c) [ 51.380244] input input4: work is already on queue [ 51.701464] input input4: work is already on queue [ 51.706491] input input4: work is already on queue [ 51.711537] input input4: work is already on queue [ 51.716562] input input4: work is already on queue [ 51.721608] input input4: work is already on queue [ 51.726641] input input4: work is already on queue [ 51.731683] input input4: work is already on queue [ 51.736707] input input4: work is already on queue [ 51.741738] input input4: work is already on queue [ 51.746761] input input4: work is already on queue [ 51.751797] input input4: work is already on queue [ 51.756828] input input4: work is already on queue [ 51.761872] input input4: work is already on queue root@letux:~#
-- Péter
BR, Nikolaus
[1]: http://git.goldelico.com/?p=gta04-kernel.git;a=shortlog;h=refs/heads/work/hn... [2]: http://git.goldelico.com/?p=gta04-kernel.git;a=commit;h=f7165f9d455400a8f3ae...