All of lore.kernel.org
 help / color / mirror / Atom feed
* Odroid XU4 deadlock
@ 2016-04-08 13:51 ` Anand Moon
  0 siblings, 0 replies; 11+ messages in thread
From: Anand Moon @ 2016-04-08 13:51 UTC (permalink / raw)
  To: Krzysztof Kozłowski, Javier Martinez Canillas, Viresh Kumar,
	Bartlomiej Zolnierkiewicz, Lukasz Majewski
  Cc: linux-samsung-soc, Linux Kernel

Hi All,

I am observing this deadlock or warning on my Odroid XU4.
I thinks the is related to clk from exynos5_i2c_xfer .... clk_prepare_enable
but I am not able to figure out which clk.

[   11.640221] ======================================================
[   11.646343] [ INFO: possible circular locking dependency detected ]
[   11.652590] 4.6.0-rc2-xu4ml #35 Not tainted
[   11.656749] -------------------------------------------------------
[   11.662992] kworker/1:1/85 is trying to acquire lock:
[   11.668010]  (prepare_lock){+.+...}, at: [<c05bfed8>]
clk_prepare_lock+0x50/0xf8
[   11.675375]
[   11.675375] but task is already holding lock:
[   11.681185]  (sec_core:428:(regmap)->lock){+.+...}, at:
[<c0481aec>] regmap_read+0x2c/0x5c
[   11.689417]
[   11.689417] which lock already depends on the new lock.
[   11.689417]
[   11.697561]
[   11.697561] the existing dependency chain (in reverse order) is:
[   11.705008]
[   11.705008] -> #1 (sec_core:428:(regmap)->lock){+.+...}:
[   11.710467]        [<c0482d30>] regmap_update_bits_base+0x30/0x70
[   11.716545]        [<c05c617c>] s2mps11_clk_prepare+0x30/0x38
[   11.722262]        [<c05c01f0>] clk_core_prepare+0x98/0xbc
[   11.727711]        [<c05c12bc>] clk_prepare+0x1c/0x2c
[   11.732734]        [<c0556fe4>] s3c_rtc_probe+0x2d0/0x43c
[   11.738108]        [<c046b9fc>] platform_drv_probe+0x4c/0xb0
[   11.743749]        [<c046a1fc>] driver_probe_device+0x20c/0x2b8
[   11.749641]        [<c0468594>] bus_for_each_drv+0x60/0x94
[   11.755103]        [<c0469f10>] __device_attach+0xb4/0x118
[   11.760558]        [<c04693b4>] bus_probe_device+0x88/0x90
[   11.766020]        [<c0469850>] deferred_probe_work_func+0x6c/0x9c
[   11.772169]        [<c013b52c>] process_one_work+0x1a8/0x514
[   11.777806]        [<c013b8d0>] worker_thread+0x38/0x56c
[   11.783082]        [<c0141d14>] kthread+0xf4/0x10c
[   11.787847]        [<c0107950>] ret_from_fork+0x14/0x24
[   11.793050]
[   11.793050] -> #0 (prepare_lock){+.+...}:
[   11.797212]        [<c0768dd8>] mutex_lock_nested+0x78/0x4dc
[   11.802845]        [<c05bfed8>] clk_prepare_lock+0x50/0xf8
[   11.808304]        [<c05c19c4>] clk_unprepare+0x1c/0x2c
[   11.813499]        [<c055d720>] exynos5_i2c_xfer+0x1dc/0x304
[   11.819129]        [<c0559620>] __i2c_transfer+0x13c/0x278
[   11.824589]        [<c05597f0>] i2c_transfer+0x94/0xc4
[   11.829701]        [<c04868f0>] regmap_i2c_read+0x48/0x64
[   11.835074]        [<c0482048>] _regmap_raw_read+0xb4/0x114
[   11.840630]        [<c04820cc>] _regmap_bus_read+0x24/0x58
[   11.846084]        [<c0481a68>] _regmap_read+0x60/0xb8
[   11.851201]        [<c0481afc>] regmap_read+0x3c/0x5c
[   11.856224]        [<c03e2354>] regulator_get_voltage_sel_regmap+0x20/0x54
[   11.863109]        [<c03dc5d4>] _regulator_get_voltage+0x20/0xb8
[   11.863141]        [<c03df058>] _regulator_do_set_voltage+0x240/0x370
[   11.863173]        [<c03df254>] regulator_set_voltage_unlocked+0xcc/0x230
[   11.863205]        [<c03df3e0>] regulator_set_voltage+0x28/0x54
[   11.863234]        [<c0478a94>] _set_opp_voltage+0x30/0x98
[   11.863264]        [<c0479ba8>] dev_pm_opp_set_rate+0x1e0/0x540
[   11.863337]        [<c0580824>] __cpufreq_driver_target+0x168/0x290
[   11.863375]        [<c0583b48>] od_dbs_timer+0xdc/0x164
[   11.863407]        [<c0584114>] dbs_work_handler+0x30/0x58
[   11.863437]        [<c013b52c>] process_one_work+0x1a8/0x514
[   11.863465]        [<c013b8d0>] worker_thread+0x38/0x56c
[   11.863496]        [<c0141d14>] kthread+0xf4/0x10c
[   11.863528]        [<c0107950>] ret_from_fork+0x14/0x24
[   11.863538]
[   11.863538] other info that might help us debug this:
[   11.863538]
[   11.863548]  Possible unsafe locking scenario:
[   11.863548]
[   11.863557]        CPU0                    CPU1
[   11.863565]        ----                    ----
[   11.863589]   lock(sec_core:428:(regmap)->lock);
[   11.863612]                                lock(prepare_lock);
[   11.863634]                                lock(sec_core:428:(regmap)->lock);
[   11.863655]   lock(prepare_lock);
[   11.863664]
[   11.863664]  *** DEADLOCK ***
[   11.863664]
[   11.863678] 5 locks held by kworker/1:1/85:
[   11.863734]  #0:  ("events"){.+.+.+}, at: [<c013b4bc>]
process_one_work+0x138/0x514
[   11.863788]  #1:  ((&policy_dbs->work)){+.+...}, at: [<c013b4bc>]
process_one_work+0x138/0x514
[   11.863845]  #2:  (&policy_dbs->timer_mutex){+.+...}, at:
[<c0584108>] dbs_work_handler+0x24/0x58
[   11.863899]  #3:  (&rdev->mutex){+.+.+.}, at: [<c03dc980>]
regulator_lock_supply+0x1c/0x3c
[   11.863950]  #4:  (sec_core:428:(regmap)->lock){+.+...}, at:
[<c0481aec>] regmap_read+0x2c/0x5c
[   11.863959]
[   11.863959] stack backtrace:
[   11.863984] CPU: 1 PID: 85 Comm: kworker/1:1 Not tainted 4.6.0-rc2-xu4ml #35
[   11.863995] Hardware name: SAMSUNG EXYNOS (Flattened Device Tree)
[   11.864030] Workqueue: events dbs_work_handler
[   11.864098] [<c010ee2c>] (unwind_backtrace) from [<c010bab8>]
(show_stack+0x10/0x14)
[   11.864139] [<c010bab8>] (show_stack) from [<c037d460>]
(dump_stack+0x98/0xc4)
[   11.864189] [<c037d460>] (dump_stack) from [<c016f198>]
(print_circular_bug+0x214/0x33c)
[   11.864229] [<c016f198>] (print_circular_bug) from [<c0172e24>]
(__lock_acquire+0x1c2c/0x202c)
[   11.864268] [<c0172e24>] (__lock_acquire) from [<c0173e14>]
(lock_acquire+0xa8/0xd0)
[   11.864304] [<c0173e14>] (lock_acquire) from [<c0768dd8>]
(mutex_lock_nested+0x78/0x4dc)
[   11.864342] [<c0768dd8>] (mutex_lock_nested) from [<c05bfed8>]
(clk_prepare_lock+0x50/0xf8)
[   11.864377] [<c05bfed8>] (clk_prepare_lock) from [<c05c19c4>]
(clk_unprepare+0x1c/0x2c)
[   11.864414] [<c05c19c4>] (clk_unprepare) from [<c055d720>]
(exynos5_i2c_xfer+0x1dc/0x304)
[   11.864452] [<c055d720>] (exynos5_i2c_xfer) from [<c0559620>]
(__i2c_transfer+0x13c/0x278)
[   11.864484] [<c0559620>] (__i2c_transfer) from [<c05597f0>]
(i2c_transfer+0x94/0xc4)
[   11.864518] [<c05597f0>] (i2c_transfer) from [<c04868f0>]
(regmap_i2c_read+0x48/0x64)
[   11.864551] [<c04868f0>] (regmap_i2c_read) from [<c0482048>]
(_regmap_raw_read+0xb4/0x114)
[   11.864580] [<c0482048>] (_regmap_raw_read) from [<c04820cc>]
(_regmap_bus_read+0x24/0x58)
[   11.864617] [<c04820cc>] (_regmap_bus_read) from [<c0481a68>]
(_regmap_read+0x60/0xb8)
[   11.864651] [<c0481a68>] (_regmap_read) from [<c0481afc>]
(regmap_read+0x3c/0x5c)
[   11.864687] [<c0481afc>] (regmap_read) from [<c03e2354>]
(regulator_get_voltage_sel_regmap+0x20/0x54)
[   11.864725] [<c03e2354>] (regulator_get_voltage_sel_regmap) from
[<c03dc5d4>] (_regulator_get_voltage+0x20/0xb8)
[   11.864761] [<c03dc5d4>] (_regulator_get_voltage) from [<c03df058>]
(_regulator_do_set_voltage+0x240/0x370)
[   11.864798] [<c03df058>] (_regulator_do_set_voltage) from
[<c03df254>] (regulator_set_voltage_unlocked+0xcc/0x230)
[   11.864835] [<c03df254>] (regulator_set_voltage_unlocked) from
[<c03df3e0>] (regulator_set_voltage+0x28/0x54)
[   11.864868] [<c03df3e0>] (regulator_set_voltage) from [<c0478a94>]
(_set_opp_voltage+0x30/0x98)
[   11.864901] [<c0478a94>] (_set_opp_voltage) from [<c0479ba8>]
(dev_pm_opp_set_rate+0x1e0/0x540)
[   11.864935] [<c0479ba8>] (dev_pm_opp_set_rate) from [<c0580824>]
(__cpufreq_driver_target+0x168/0x290)
[   11.864973] [<c0580824>] (__cpufreq_driver_target) from
[<c0583b48>] (od_dbs_timer+0xdc/0x164)
[   11.865011] [<c0583b48>] (od_dbs_timer) from [<c0584114>]
(dbs_work_handler+0x30/0x58)
[   11.865048] [<c0584114>] (dbs_work_handler) from [<c013b52c>]
(process_one_work+0x1a8/0x514)
[   11.865082] [<c013b52c>] (process_one_work) from [<c013b8d0>]
(worker_thread+0x38/0x56c)
[   11.865118] [<c013b8d0>] (worker_thread) from [<c0141d14>]
(kthread+0xf4/0x10c)
[   11.865156] [<c0141d14>] (kthread) from [<c0107950>]
(ret_from_fork+0x14/0x24)

Best Regards
-Anand Moon

^ permalink raw reply	[flat|nested] 11+ messages in thread

* Odroid XU4 deadlock
@ 2016-04-08 13:51 ` Anand Moon
  0 siblings, 0 replies; 11+ messages in thread
From: Anand Moon @ 2016-04-08 13:51 UTC (permalink / raw)
  To: Krzysztof Kozłowski, Javier Martinez Canillas, Viresh Kumar,
	Bartlomiej Zolnierkiewicz, Lukasz Majewski
  Cc: linux-samsung-soc, Linux Kernel

Hi All,

I am observing this deadlock or warning on my Odroid XU4.
I thinks the is related to clk from exynos5_i2c_xfer .... clk_prepare_enable
but I am not able to figure out which clk.

[   11.640221] ======================================================
[   11.646343] [ INFO: possible circular locking dependency detected ]
[   11.652590] 4.6.0-rc2-xu4ml #35 Not tainted
[   11.656749] -------------------------------------------------------
[   11.662992] kworker/1:1/85 is trying to acquire lock:
[   11.668010]  (prepare_lock){+.+...}, at: [<c05bfed8>]
clk_prepare_lock+0x50/0xf8
[   11.675375]
[   11.675375] but task is already holding lock:
[   11.681185]  (sec_core:428:(regmap)->lock){+.+...}, at:
[<c0481aec>] regmap_read+0x2c/0x5c
[   11.689417]
[   11.689417] which lock already depends on the new lock.
[   11.689417]
[   11.697561]
[   11.697561] the existing dependency chain (in reverse order) is:
[   11.705008]
[   11.705008] -> #1 (sec_core:428:(regmap)->lock){+.+...}:
[   11.710467]        [<c0482d30>] regmap_update_bits_base+0x30/0x70
[   11.716545]        [<c05c617c>] s2mps11_clk_prepare+0x30/0x38
[   11.722262]        [<c05c01f0>] clk_core_prepare+0x98/0xbc
[   11.727711]        [<c05c12bc>] clk_prepare+0x1c/0x2c
[   11.732734]        [<c0556fe4>] s3c_rtc_probe+0x2d0/0x43c
[   11.738108]        [<c046b9fc>] platform_drv_probe+0x4c/0xb0
[   11.743749]        [<c046a1fc>] driver_probe_device+0x20c/0x2b8
[   11.749641]        [<c0468594>] bus_for_each_drv+0x60/0x94
[   11.755103]        [<c0469f10>] __device_attach+0xb4/0x118
[   11.760558]        [<c04693b4>] bus_probe_device+0x88/0x90
[   11.766020]        [<c0469850>] deferred_probe_work_func+0x6c/0x9c
[   11.772169]        [<c013b52c>] process_one_work+0x1a8/0x514
[   11.777806]        [<c013b8d0>] worker_thread+0x38/0x56c
[   11.783082]        [<c0141d14>] kthread+0xf4/0x10c
[   11.787847]        [<c0107950>] ret_from_fork+0x14/0x24
[   11.793050]
[   11.793050] -> #0 (prepare_lock){+.+...}:
[   11.797212]        [<c0768dd8>] mutex_lock_nested+0x78/0x4dc
[   11.802845]        [<c05bfed8>] clk_prepare_lock+0x50/0xf8
[   11.808304]        [<c05c19c4>] clk_unprepare+0x1c/0x2c
[   11.813499]        [<c055d720>] exynos5_i2c_xfer+0x1dc/0x304
[   11.819129]        [<c0559620>] __i2c_transfer+0x13c/0x278
[   11.824589]        [<c05597f0>] i2c_transfer+0x94/0xc4
[   11.829701]        [<c04868f0>] regmap_i2c_read+0x48/0x64
[   11.835074]        [<c0482048>] _regmap_raw_read+0xb4/0x114
[   11.840630]        [<c04820cc>] _regmap_bus_read+0x24/0x58
[   11.846084]        [<c0481a68>] _regmap_read+0x60/0xb8
[   11.851201]        [<c0481afc>] regmap_read+0x3c/0x5c
[   11.856224]        [<c03e2354>] regulator_get_voltage_sel_regmap+0x20/0x54
[   11.863109]        [<c03dc5d4>] _regulator_get_voltage+0x20/0xb8
[   11.863141]        [<c03df058>] _regulator_do_set_voltage+0x240/0x370
[   11.863173]        [<c03df254>] regulator_set_voltage_unlocked+0xcc/0x230
[   11.863205]        [<c03df3e0>] regulator_set_voltage+0x28/0x54
[   11.863234]        [<c0478a94>] _set_opp_voltage+0x30/0x98
[   11.863264]        [<c0479ba8>] dev_pm_opp_set_rate+0x1e0/0x540
[   11.863337]        [<c0580824>] __cpufreq_driver_target+0x168/0x290
[   11.863375]        [<c0583b48>] od_dbs_timer+0xdc/0x164
[   11.863407]        [<c0584114>] dbs_work_handler+0x30/0x58
[   11.863437]        [<c013b52c>] process_one_work+0x1a8/0x514
[   11.863465]        [<c013b8d0>] worker_thread+0x38/0x56c
[   11.863496]        [<c0141d14>] kthread+0xf4/0x10c
[   11.863528]        [<c0107950>] ret_from_fork+0x14/0x24
[   11.863538]
[   11.863538] other info that might help us debug this:
[   11.863538]
[   11.863548]  Possible unsafe locking scenario:
[   11.863548]
[   11.863557]        CPU0                    CPU1
[   11.863565]        ----                    ----
[   11.863589]   lock(sec_core:428:(regmap)->lock);
[   11.863612]                                lock(prepare_lock);
[   11.863634]                                lock(sec_core:428:(regmap)->lock);
[   11.863655]   lock(prepare_lock);
[   11.863664]
[   11.863664]  *** DEADLOCK ***
[   11.863664]
[   11.863678] 5 locks held by kworker/1:1/85:
[   11.863734]  #0:  ("events"){.+.+.+}, at: [<c013b4bc>]
process_one_work+0x138/0x514
[   11.863788]  #1:  ((&policy_dbs->work)){+.+...}, at: [<c013b4bc>]
process_one_work+0x138/0x514
[   11.863845]  #2:  (&policy_dbs->timer_mutex){+.+...}, at:
[<c0584108>] dbs_work_handler+0x24/0x58
[   11.863899]  #3:  (&rdev->mutex){+.+.+.}, at: [<c03dc980>]
regulator_lock_supply+0x1c/0x3c
[   11.863950]  #4:  (sec_core:428:(regmap)->lock){+.+...}, at:
[<c0481aec>] regmap_read+0x2c/0x5c
[   11.863959]
[   11.863959] stack backtrace:
[   11.863984] CPU: 1 PID: 85 Comm: kworker/1:1 Not tainted 4.6.0-rc2-xu4ml #35
[   11.863995] Hardware name: SAMSUNG EXYNOS (Flattened Device Tree)
[   11.864030] Workqueue: events dbs_work_handler
[   11.864098] [<c010ee2c>] (unwind_backtrace) from [<c010bab8>]
(show_stack+0x10/0x14)
[   11.864139] [<c010bab8>] (show_stack) from [<c037d460>]
(dump_stack+0x98/0xc4)
[   11.864189] [<c037d460>] (dump_stack) from [<c016f198>]
(print_circular_bug+0x214/0x33c)
[   11.864229] [<c016f198>] (print_circular_bug) from [<c0172e24>]
(__lock_acquire+0x1c2c/0x202c)
[   11.864268] [<c0172e24>] (__lock_acquire) from [<c0173e14>]
(lock_acquire+0xa8/0xd0)
[   11.864304] [<c0173e14>] (lock_acquire) from [<c0768dd8>]
(mutex_lock_nested+0x78/0x4dc)
[   11.864342] [<c0768dd8>] (mutex_lock_nested) from [<c05bfed8>]
(clk_prepare_lock+0x50/0xf8)
[   11.864377] [<c05bfed8>] (clk_prepare_lock) from [<c05c19c4>]
(clk_unprepare+0x1c/0x2c)
[   11.864414] [<c05c19c4>] (clk_unprepare) from [<c055d720>]
(exynos5_i2c_xfer+0x1dc/0x304)
[   11.864452] [<c055d720>] (exynos5_i2c_xfer) from [<c0559620>]
(__i2c_transfer+0x13c/0x278)
[   11.864484] [<c0559620>] (__i2c_transfer) from [<c05597f0>]
(i2c_transfer+0x94/0xc4)
[   11.864518] [<c05597f0>] (i2c_transfer) from [<c04868f0>]
(regmap_i2c_read+0x48/0x64)
[   11.864551] [<c04868f0>] (regmap_i2c_read) from [<c0482048>]
(_regmap_raw_read+0xb4/0x114)
[   11.864580] [<c0482048>] (_regmap_raw_read) from [<c04820cc>]
(_regmap_bus_read+0x24/0x58)
[   11.864617] [<c04820cc>] (_regmap_bus_read) from [<c0481a68>]
(_regmap_read+0x60/0xb8)
[   11.864651] [<c0481a68>] (_regmap_read) from [<c0481afc>]
(regmap_read+0x3c/0x5c)
[   11.864687] [<c0481afc>] (regmap_read) from [<c03e2354>]
(regulator_get_voltage_sel_regmap+0x20/0x54)
[   11.864725] [<c03e2354>] (regulator_get_voltage_sel_regmap) from
[<c03dc5d4>] (_regulator_get_voltage+0x20/0xb8)
[   11.864761] [<c03dc5d4>] (_regulator_get_voltage) from [<c03df058>]
(_regulator_do_set_voltage+0x240/0x370)
[   11.864798] [<c03df058>] (_regulator_do_set_voltage) from
[<c03df254>] (regulator_set_voltage_unlocked+0xcc/0x230)
[   11.864835] [<c03df254>] (regulator_set_voltage_unlocked) from
[<c03df3e0>] (regulator_set_voltage+0x28/0x54)
[   11.864868] [<c03df3e0>] (regulator_set_voltage) from [<c0478a94>]
(_set_opp_voltage+0x30/0x98)
[   11.864901] [<c0478a94>] (_set_opp_voltage) from [<c0479ba8>]
(dev_pm_opp_set_rate+0x1e0/0x540)
[   11.864935] [<c0479ba8>] (dev_pm_opp_set_rate) from [<c0580824>]
(__cpufreq_driver_target+0x168/0x290)
[   11.864973] [<c0580824>] (__cpufreq_driver_target) from
[<c0583b48>] (od_dbs_timer+0xdc/0x164)
[   11.865011] [<c0583b48>] (od_dbs_timer) from [<c0584114>]
(dbs_work_handler+0x30/0x58)
[   11.865048] [<c0584114>] (dbs_work_handler) from [<c013b52c>]
(process_one_work+0x1a8/0x514)
[   11.865082] [<c013b52c>] (process_one_work) from [<c013b8d0>]
(worker_thread+0x38/0x56c)
[   11.865118] [<c013b8d0>] (worker_thread) from [<c0141d14>]
(kthread+0xf4/0x10c)
[   11.865156] [<c0141d14>] (kthread) from [<c0107950>]
(ret_from_fork+0x14/0x24)

Best Regards
-Anand Moon

^ permalink raw reply	[flat|nested] 11+ messages in thread

* Re: Odroid XU4 deadlock
  2016-04-08 13:51 ` Anand Moon
@ 2016-04-08 14:55   ` Javier Martinez Canillas
  -1 siblings, 0 replies; 11+ messages in thread
From: Javier Martinez Canillas @ 2016-04-08 14:55 UTC (permalink / raw)
  To: Anand Moon, Krzysztof Kozłowski, Viresh Kumar,
	Bartlomiej Zolnierkiewicz, Lukasz Majewski
  Cc: linux-samsung-soc, Linux Kernel

Hello Anand,

On 04/08/2016 09:51 AM, Anand Moon wrote:
> Hi All,
> 
> I am observing this deadlock or warning on my Odroid XU4.
> I thinks the is related to clk from exynos5_i2c_xfer .... clk_prepare_enable
> but I am not able to figure out which clk.
>

By reading your logs, it seems the problem is a possible ABBA deadlock since
the S3C RTC driver grabs the prepare_lock and then the regmap->lock, and the
CPUFreq driver leads to the locks being grabbed in the inverse order.

> [   11.640221] ======================================================
> [   11.646343] [ INFO: possible circular locking dependency detected ]
> [   11.652590] 4.6.0-rc2-xu4ml #35 Not tainted
> [   11.656749] -------------------------------------------------------
> [   11.662992] kworker/1:1/85 is trying to acquire lock:
> [   11.668010]  (prepare_lock){+.+...}, at: [<c05bfed8>]
> clk_prepare_lock+0x50/0xf8
> [   11.675375]
> [   11.675375] but task is already holding lock:
> [   11.681185]  (sec_core:428:(regmap)->lock){+.+...}, at:
> [<c0481aec>] regmap_read+0x2c/0x5c
> [   11.689417]
> [   11.689417] which lock already depends on the new lock.
> [   11.689417]
> [   11.697561]
> [   11.697561] the existing dependency chain (in reverse order) is:
> [   11.705008]
> [   11.705008] -> #1 (sec_core:428:(regmap)->lock){+.+...}:
> [   11.710467]        [<c0482d30>] regmap_update_bits_base+0x30/0x70
> [   11.716545]        [<c05c617c>] s2mps11_clk_prepare+0x30/0x38
> [   11.722262]        [<c05c01f0>] clk_core_prepare+0x98/0xbc
> [   11.727711]        [<c05c12bc>] clk_prepare+0x1c/0x2c
> [   11.732734]        [<c0556fe4>] s3c_rtc_probe+0x2d0/0x43c

the S3C RTC driver tries to prepare the RTC source clock S2MPS11_CLK_AP
and that leads to the prepare_lock to be held and then the regmap->lock
since s2mps11_clk_prepare() calls regmap_update_bits().

> [   11.738108]        [<c046b9fc>] platform_drv_probe+0x4c/0xb0
> [   11.743749]        [<c046a1fc>] driver_probe_device+0x20c/0x2b8
> [   11.749641]        [<c0468594>] bus_for_each_drv+0x60/0x94
> [   11.755103]        [<c0469f10>] __device_attach+0xb4/0x118
> [   11.760558]        [<c04693b4>] bus_probe_device+0x88/0x90
> [   11.766020]        [<c0469850>] deferred_probe_work_func+0x6c/0x9c
> [   11.772169]        [<c013b52c>] process_one_work+0x1a8/0x514
> [   11.777806]        [<c013b8d0>] worker_thread+0x38/0x56c
> [   11.783082]        [<c0141d14>] kthread+0xf4/0x10c
> [   11.787847]        [<c0107950>] ret_from_fork+0x14/0x24
> [   11.793050]
> [   11.793050] -> #0 (prepare_lock){+.+...}:
> [   11.797212]        [<c0768dd8>] mutex_lock_nested+0x78/0x4dc
> [   11.802845]        [<c05bfed8>] clk_prepare_lock+0x50/0xf8
> [   11.808304]        [<c05c19c4>] clk_unprepare+0x1c/0x2c
> [   11.813499]        [<c055d720>] exynos5_i2c_xfer+0x1dc/0x304

and here the locks are grabbed in the inverse order, since the regulator
driver uses regmap read (grabbing the regmap->lock) and then a clock is
prepared in exynos5_i2c_xfer.

> [   11.819129]        [<c0559620>] __i2c_transfer+0x13c/0x278
> [   11.824589]        [<c05597f0>] i2c_transfer+0x94/0xc4
> [   11.829701]        [<c04868f0>] regmap_i2c_read+0x48/0x64
> [   11.835074]        [<c0482048>] _regmap_raw_read+0xb4/0x114
> [   11.840630]        [<c04820cc>] _regmap_bus_read+0x24/0x58
> [   11.846084]        [<c0481a68>] _regmap_read+0x60/0xb8
> [   11.851201]        [<c0481afc>] regmap_read+0x3c/0x5c
> [   11.856224]        [<c03e2354>] regulator_get_voltage_sel_regmap+0x20/0x54
> [   11.863109]        [<c03dc5d4>] _regulator_get_voltage+0x20/0xb8
> [   11.863141]        [<c03df058>] _regulator_do_set_voltage+0x240/0x370
> [   11.863173]        [<c03df254>] regulator_set_voltage_unlocked+0xcc/0x230
> [   11.863205]        [<c03df3e0>] regulator_set_voltage+0x28/0x54
> [   11.863234]        [<c0478a94>] _set_opp_voltage+0x30/0x98
> [   11.863264]        [<c0479ba8>] dev_pm_opp_set_rate+0x1e0/0x540
> [   11.863337]        [<c0580824>] __cpufreq_driver_target+0x168/0x290
> [   11.863375]        [<c0583b48>] od_dbs_timer+0xdc/0x164
> [   11.863407]        [<c0584114>] dbs_work_handler+0x30/0x58
> [   11.863437]        [<c013b52c>] process_one_work+0x1a8/0x514
> [   11.863465]        [<c013b8d0>] worker_thread+0x38/0x56c
> [   11.863496]        [<c0141d14>] kthread+0xf4/0x10c
> [   11.863528]        [<c0107950>] ret_from_fork+0x14/0x24
> [   11.863538]
> [   11.863538] other info that might help us debug this:
> [   11.863538]
> [   11.863548]  Possible unsafe locking scenario:
> [   11.863548]
> [   11.863557]        CPU0                    CPU1
> [   11.863565]        ----                    ----
> [   11.863589]   lock(sec_core:428:(regmap)->lock);
> [   11.863612]                                lock(prepare_lock);
> [   11.863634]                                lock(sec_core:428:(regmap)->lock);
> [   11.863655]   lock(prepare_lock);
> [   11.863664]
> [   11.863664]  *** DEADLOCK ***
> [   11.863664]

I should take a look in deep to the regmap and clock subsystems to better
understand the issue on how to solve it. But AFAICT the problem is that
the prepare_lock is a global mutex and the same regmap is used for both
the s2mps11 clocks and regulators, so the ABBA deadlock described below
can happen.

Best regards,
-- 
Javier Martinez Canillas
Open Source Group
Samsung Research America

^ permalink raw reply	[flat|nested] 11+ messages in thread

* Re: Odroid XU4 deadlock
@ 2016-04-08 14:55   ` Javier Martinez Canillas
  0 siblings, 0 replies; 11+ messages in thread
From: Javier Martinez Canillas @ 2016-04-08 14:55 UTC (permalink / raw)
  To: Anand Moon, Krzysztof Kozłowski, Viresh Kumar,
	Bartlomiej Zolnierkiewicz, Lukasz Majewski
  Cc: linux-samsung-soc, Linux Kernel

Hello Anand,

On 04/08/2016 09:51 AM, Anand Moon wrote:
> Hi All,
> 
> I am observing this deadlock or warning on my Odroid XU4.
> I thinks the is related to clk from exynos5_i2c_xfer .... clk_prepare_enable
> but I am not able to figure out which clk.
>

By reading your logs, it seems the problem is a possible ABBA deadlock since
the S3C RTC driver grabs the prepare_lock and then the regmap->lock, and the
CPUFreq driver leads to the locks being grabbed in the inverse order.

> [   11.640221] ======================================================
> [   11.646343] [ INFO: possible circular locking dependency detected ]
> [   11.652590] 4.6.0-rc2-xu4ml #35 Not tainted
> [   11.656749] -------------------------------------------------------
> [   11.662992] kworker/1:1/85 is trying to acquire lock:
> [   11.668010]  (prepare_lock){+.+...}, at: [<c05bfed8>]
> clk_prepare_lock+0x50/0xf8
> [   11.675375]
> [   11.675375] but task is already holding lock:
> [   11.681185]  (sec_core:428:(regmap)->lock){+.+...}, at:
> [<c0481aec>] regmap_read+0x2c/0x5c
> [   11.689417]
> [   11.689417] which lock already depends on the new lock.
> [   11.689417]
> [   11.697561]
> [   11.697561] the existing dependency chain (in reverse order) is:
> [   11.705008]
> [   11.705008] -> #1 (sec_core:428:(regmap)->lock){+.+...}:
> [   11.710467]        [<c0482d30>] regmap_update_bits_base+0x30/0x70
> [   11.716545]        [<c05c617c>] s2mps11_clk_prepare+0x30/0x38
> [   11.722262]        [<c05c01f0>] clk_core_prepare+0x98/0xbc
> [   11.727711]        [<c05c12bc>] clk_prepare+0x1c/0x2c
> [   11.732734]        [<c0556fe4>] s3c_rtc_probe+0x2d0/0x43c

the S3C RTC driver tries to prepare the RTC source clock S2MPS11_CLK_AP
and that leads to the prepare_lock to be held and then the regmap->lock
since s2mps11_clk_prepare() calls regmap_update_bits().

> [   11.738108]        [<c046b9fc>] platform_drv_probe+0x4c/0xb0
> [   11.743749]        [<c046a1fc>] driver_probe_device+0x20c/0x2b8
> [   11.749641]        [<c0468594>] bus_for_each_drv+0x60/0x94
> [   11.755103]        [<c0469f10>] __device_attach+0xb4/0x118
> [   11.760558]        [<c04693b4>] bus_probe_device+0x88/0x90
> [   11.766020]        [<c0469850>] deferred_probe_work_func+0x6c/0x9c
> [   11.772169]        [<c013b52c>] process_one_work+0x1a8/0x514
> [   11.777806]        [<c013b8d0>] worker_thread+0x38/0x56c
> [   11.783082]        [<c0141d14>] kthread+0xf4/0x10c
> [   11.787847]        [<c0107950>] ret_from_fork+0x14/0x24
> [   11.793050]
> [   11.793050] -> #0 (prepare_lock){+.+...}:
> [   11.797212]        [<c0768dd8>] mutex_lock_nested+0x78/0x4dc
> [   11.802845]        [<c05bfed8>] clk_prepare_lock+0x50/0xf8
> [   11.808304]        [<c05c19c4>] clk_unprepare+0x1c/0x2c
> [   11.813499]        [<c055d720>] exynos5_i2c_xfer+0x1dc/0x304

and here the locks are grabbed in the inverse order, since the regulator
driver uses regmap read (grabbing the regmap->lock) and then a clock is
prepared in exynos5_i2c_xfer.

> [   11.819129]        [<c0559620>] __i2c_transfer+0x13c/0x278
> [   11.824589]        [<c05597f0>] i2c_transfer+0x94/0xc4
> [   11.829701]        [<c04868f0>] regmap_i2c_read+0x48/0x64
> [   11.835074]        [<c0482048>] _regmap_raw_read+0xb4/0x114
> [   11.840630]        [<c04820cc>] _regmap_bus_read+0x24/0x58
> [   11.846084]        [<c0481a68>] _regmap_read+0x60/0xb8
> [   11.851201]        [<c0481afc>] regmap_read+0x3c/0x5c
> [   11.856224]        [<c03e2354>] regulator_get_voltage_sel_regmap+0x20/0x54
> [   11.863109]        [<c03dc5d4>] _regulator_get_voltage+0x20/0xb8
> [   11.863141]        [<c03df058>] _regulator_do_set_voltage+0x240/0x370
> [   11.863173]        [<c03df254>] regulator_set_voltage_unlocked+0xcc/0x230
> [   11.863205]        [<c03df3e0>] regulator_set_voltage+0x28/0x54
> [   11.863234]        [<c0478a94>] _set_opp_voltage+0x30/0x98
> [   11.863264]        [<c0479ba8>] dev_pm_opp_set_rate+0x1e0/0x540
> [   11.863337]        [<c0580824>] __cpufreq_driver_target+0x168/0x290
> [   11.863375]        [<c0583b48>] od_dbs_timer+0xdc/0x164
> [   11.863407]        [<c0584114>] dbs_work_handler+0x30/0x58
> [   11.863437]        [<c013b52c>] process_one_work+0x1a8/0x514
> [   11.863465]        [<c013b8d0>] worker_thread+0x38/0x56c
> [   11.863496]        [<c0141d14>] kthread+0xf4/0x10c
> [   11.863528]        [<c0107950>] ret_from_fork+0x14/0x24
> [   11.863538]
> [   11.863538] other info that might help us debug this:
> [   11.863538]
> [   11.863548]  Possible unsafe locking scenario:
> [   11.863548]
> [   11.863557]        CPU0                    CPU1
> [   11.863565]        ----                    ----
> [   11.863589]   lock(sec_core:428:(regmap)->lock);
> [   11.863612]                                lock(prepare_lock);
> [   11.863634]                                lock(sec_core:428:(regmap)->lock);
> [   11.863655]   lock(prepare_lock);
> [   11.863664]
> [   11.863664]  *** DEADLOCK ***
> [   11.863664]

I should take a look in deep to the regmap and clock subsystems to better
understand the issue on how to solve it. But AFAICT the problem is that
the prepare_lock is a global mutex and the same regmap is used for both
the s2mps11 clocks and regulators, so the ABBA deadlock described below
can happen.

Best regards,
-- 
Javier Martinez Canillas
Open Source Group
Samsung Research America

^ permalink raw reply	[flat|nested] 11+ messages in thread

* Re: Odroid XU4 deadlock
  2016-04-08 14:55   ` Javier Martinez Canillas
  (?)
@ 2016-04-08 15:36   ` Anand Moon
  2016-04-09 11:00       ` Krzysztof Kozlowski
  -1 siblings, 1 reply; 11+ messages in thread
From: Anand Moon @ 2016-04-08 15:36 UTC (permalink / raw)
  To: Javier Martinez Canillas
  Cc: Krzysztof Kozłowski, Viresh Kumar,
	Bartlomiej Zolnierkiewicz, Lukasz Majewski, linux-samsung-soc,
	Linux Kernel

hi Javier,

On 8 April 2016 at 20:25, Javier Martinez Canillas
<javier@osg.samsung.com> wrote:
> Hello Anand,
>
> On 04/08/2016 09:51 AM, Anand Moon wrote:
>> Hi All,
>>
>> I am observing this deadlock or warning on my Odroid XU4.
>> I thinks the is related to clk from exynos5_i2c_xfer .... clk_prepare_enable
>> but I am not able to figure out which clk.
>>
>
> By reading your logs, it seems the problem is a possible ABBA deadlock since
> the S3C RTC driver grabs the prepare_lock and then the regmap->lock, and the
> CPUFreq driver leads to the locks being grabbed in the inverse order.
>
>> [   11.640221] ======================================================
>> [   11.646343] [ INFO: possible circular locking dependency detected ]
>> [   11.652590] 4.6.0-rc2-xu4ml #35 Not tainted
>> [   11.656749] -------------------------------------------------------
>> [   11.662992] kworker/1:1/85 is trying to acquire lock:
>> [   11.668010]  (prepare_lock){+.+...}, at: [<c05bfed8>]
>> clk_prepare_lock+0x50/0xf8
>> [   11.675375]
>> [   11.675375] but task is already holding lock:
>> [   11.681185]  (sec_core:428:(regmap)->lock){+.+...}, at:
>> [<c0481aec>] regmap_read+0x2c/0x5c
>> [   11.689417]
>> [   11.689417] which lock already depends on the new lock.
>> [   11.689417]
>> [   11.697561]
>> [   11.697561] the existing dependency chain (in reverse order) is:
>> [   11.705008]
>> [   11.705008] -> #1 (sec_core:428:(regmap)->lock){+.+...}:
>> [   11.710467]        [<c0482d30>] regmap_update_bits_base+0x30/0x70
>> [   11.716545]        [<c05c617c>] s2mps11_clk_prepare+0x30/0x38
>> [   11.722262]        [<c05c01f0>] clk_core_prepare+0x98/0xbc
>> [   11.727711]        [<c05c12bc>] clk_prepare+0x1c/0x2c
>> [   11.732734]        [<c0556fe4>] s3c_rtc_probe+0x2d0/0x43c
>
> the S3C RTC driver tries to prepare the RTC source clock S2MPS11_CLK_AP
> and that leads to the prepare_lock to be held and then the regmap->lock
> since s2mps11_clk_prepare() calls regmap_update_bits().
>
>> [   11.738108]        [<c046b9fc>] platform_drv_probe+0x4c/0xb0
>> [   11.743749]        [<c046a1fc>] driver_probe_device+0x20c/0x2b8
>> [   11.749641]        [<c0468594>] bus_for_each_drv+0x60/0x94
>> [   11.755103]        [<c0469f10>] __device_attach+0xb4/0x118
>> [   11.760558]        [<c04693b4>] bus_probe_device+0x88/0x90
>> [   11.766020]        [<c0469850>] deferred_probe_work_func+0x6c/0x9c
>> [   11.772169]        [<c013b52c>] process_one_work+0x1a8/0x514
>> [   11.777806]        [<c013b8d0>] worker_thread+0x38/0x56c
>> [   11.783082]        [<c0141d14>] kthread+0xf4/0x10c
>> [   11.787847]        [<c0107950>] ret_from_fork+0x14/0x24
>> [   11.793050]
>> [   11.793050] -> #0 (prepare_lock){+.+...}:
>> [   11.797212]        [<c0768dd8>] mutex_lock_nested+0x78/0x4dc
>> [   11.802845]        [<c05bfed8>] clk_prepare_lock+0x50/0xf8
>> [   11.808304]        [<c05c19c4>] clk_unprepare+0x1c/0x2c
>> [   11.813499]        [<c055d720>] exynos5_i2c_xfer+0x1dc/0x304
>
> and here the locks are grabbed in the inverse order, since the regulator
> driver uses regmap read (grabbing the regmap->lock) and then a clock is
> prepared in exynos5_i2c_xfer.
>
>> [   11.819129]        [<c0559620>] __i2c_transfer+0x13c/0x278
>> [   11.824589]        [<c05597f0>] i2c_transfer+0x94/0xc4
>> [   11.829701]        [<c04868f0>] regmap_i2c_read+0x48/0x64
>> [   11.835074]        [<c0482048>] _regmap_raw_read+0xb4/0x114
>> [   11.840630]        [<c04820cc>] _regmap_bus_read+0x24/0x58
>> [   11.846084]        [<c0481a68>] _regmap_read+0x60/0xb8
>> [   11.851201]        [<c0481afc>] regmap_read+0x3c/0x5c
>> [   11.856224]        [<c03e2354>] regulator_get_voltage_sel_regmap+0x20/0x54
>> [   11.863109]        [<c03dc5d4>] _regulator_get_voltage+0x20/0xb8
>> [   11.863141]        [<c03df058>] _regulator_do_set_voltage+0x240/0x370
>> [   11.863173]        [<c03df254>] regulator_set_voltage_unlocked+0xcc/0x230
>> [   11.863205]        [<c03df3e0>] regulator_set_voltage+0x28/0x54
>> [   11.863234]        [<c0478a94>] _set_opp_voltage+0x30/0x98
>> [   11.863264]        [<c0479ba8>] dev_pm_opp_set_rate+0x1e0/0x540
>> [   11.863337]        [<c0580824>] __cpufreq_driver_target+0x168/0x290
>> [   11.863375]        [<c0583b48>] od_dbs_timer+0xdc/0x164
>> [   11.863407]        [<c0584114>] dbs_work_handler+0x30/0x58
>> [   11.863437]        [<c013b52c>] process_one_work+0x1a8/0x514
>> [   11.863465]        [<c013b8d0>] worker_thread+0x38/0x56c
>> [   11.863496]        [<c0141d14>] kthread+0xf4/0x10c
>> [   11.863528]        [<c0107950>] ret_from_fork+0x14/0x24
>> [   11.863538]
>> [   11.863538] other info that might help us debug this:
>> [   11.863538]
>> [   11.863548]  Possible unsafe locking scenario:
>> [   11.863548]
>> [   11.863557]        CPU0                    CPU1
>> [   11.863565]        ----                    ----
>> [   11.863589]   lock(sec_core:428:(regmap)->lock);
>> [   11.863612]                                lock(prepare_lock);
>> [   11.863634]                                lock(sec_core:428:(regmap)->lock);
>> [   11.863655]   lock(prepare_lock);
>> [   11.863664]
>> [   11.863664]  *** DEADLOCK ***
>> [   11.863664]
>
> I should take a look in deep to the regmap and clock subsystems to better
> understand the issue on how to solve it. But AFAICT the problem is that
> the prepare_lock is a global mutex and the same regmap is used for both
> the s2mps11 clocks and regulators, so the ABBA deadlock described below
> can happen.
>
> Best regards,
> --
> Javier Martinez Canillas
> Open Source Group
> Samsung Research America

Thanks for this quick analysis.
I was just wondering where it's going wrong.

Best Regards
-Anand Moon

^ permalink raw reply	[flat|nested] 11+ messages in thread

* Re: Odroid XU4 deadlock
  2016-04-08 15:36   ` Anand Moon
@ 2016-04-09 11:00       ` Krzysztof Kozlowski
  0 siblings, 0 replies; 11+ messages in thread
From: Krzysztof Kozlowski @ 2016-04-09 11:00 UTC (permalink / raw)
  To: Anand Moon
  Cc: Javier Martinez Canillas, Viresh Kumar,
	Bartlomiej Zolnierkiewicz, Lukasz Majewski, linux-samsung-soc,
	Linux Kernel

On Fri, Apr 8, 2016 at 5:36 PM, Anand Moon <linux.amoon@gmail.com> wrote:
> hi Javier,
>
> On 8 April 2016 at 20:25, Javier Martinez Canillas
> <javier@osg.samsung.com> wrote:
>> Hello Anand,
>>
>> On 04/08/2016 09:51 AM, Anand Moon wrote:
>>> Hi All,
>>>
>>> I am observing this deadlock or warning on my Odroid XU4.
>>> I thinks the is related to clk from exynos5_i2c_xfer .... clk_prepare_enable
>>> but I am not able to figure out which clk.
>>>
>>
>> By reading your logs, it seems the problem is a possible ABBA deadlock since
>> the S3C RTC driver grabs the prepare_lock and then the regmap->lock, and the
>> CPUFreq driver leads to the locks being grabbed in the inverse order.

First of all this is not a deadlock. Yet. :) This is just lockdep
report of possible deadlock. This is deadlock:
http://www.krzk.eu/builders/boot-odroid-xu3-multi_v7/builds/13/steps/Boot%20odroid/logs/serial

...and I believe it is the same as the report from lockdep. Which
means that this report truly a predicted deadlock. There are minor
differences between deadlock on my board and report from Anand but
still the same devices are involved. In Anands report the involved
S2MPS11 regulator and S2MPS11 clock use the same regmap. In my case
one path comes from S5M RTC which uses different regmap than S2MPS11
clock. This is the difference which puzzles me.

Anyway this is known issue. In case of my board mentioned deadlock
happens only on multi_v7 on around 15% of boots. I noticed it around
v4.4 and it happens still.

>>
>>> [   11.640221] ======================================================
>>> [   11.646343] [ INFO: possible circular locking dependency detected ]
>>> [   11.652590] 4.6.0-rc2-xu4ml #35 Not tainted
>>> [   11.656749] -------------------------------------------------------
>>> [   11.662992] kworker/1:1/85 is trying to acquire lock:
>>> [   11.668010]  (prepare_lock){+.+...}, at: [<c05bfed8>]
>>> clk_prepare_lock+0x50/0xf8
>>> [   11.675375]
>>> [   11.675375] but task is already holding lock:
>>> [   11.681185]  (sec_core:428:(regmap)->lock){+.+...}, at:
>>> [<c0481aec>] regmap_read+0x2c/0x5c
>>> [   11.689417]
>>> [   11.689417] which lock already depends on the new lock.
>>> [   11.689417]
>>> [   11.697561]
>>> [   11.697561] the existing dependency chain (in reverse order) is:
>>> [   11.705008]
>>> [   11.705008] -> #1 (sec_core:428:(regmap)->lock){+.+...}:
>>> [   11.710467]        [<c0482d30>] regmap_update_bits_base+0x30/0x70
>>> [   11.716545]        [<c05c617c>] s2mps11_clk_prepare+0x30/0x38
>>> [   11.722262]        [<c05c01f0>] clk_core_prepare+0x98/0xbc
>>> [   11.727711]        [<c05c12bc>] clk_prepare+0x1c/0x2c
>>> [   11.732734]        [<c0556fe4>] s3c_rtc_probe+0x2d0/0x43c
>>
>> the S3C RTC driver tries to prepare the RTC source clock S2MPS11_CLK_AP
>> and that leads to the prepare_lock to be held and then the regmap->lock
>> since s2mps11_clk_prepare() calls regmap_update_bits().
>>
>>> [   11.738108]        [<c046b9fc>] platform_drv_probe+0x4c/0xb0
>>> [   11.743749]        [<c046a1fc>] driver_probe_device+0x20c/0x2b8
>>> [   11.749641]        [<c0468594>] bus_for_each_drv+0x60/0x94
>>> [   11.755103]        [<c0469f10>] __device_attach+0xb4/0x118
>>> [   11.760558]        [<c04693b4>] bus_probe_device+0x88/0x90
>>> [   11.766020]        [<c0469850>] deferred_probe_work_func+0x6c/0x9c
>>> [   11.772169]        [<c013b52c>] process_one_work+0x1a8/0x514
>>> [   11.777806]        [<c013b8d0>] worker_thread+0x38/0x56c
>>> [   11.783082]        [<c0141d14>] kthread+0xf4/0x10c
>>> [   11.787847]        [<c0107950>] ret_from_fork+0x14/0x24
>>> [   11.793050]
>>> [   11.793050] -> #0 (prepare_lock){+.+...}:
>>> [   11.797212]        [<c0768dd8>] mutex_lock_nested+0x78/0x4dc
>>> [   11.802845]        [<c05bfed8>] clk_prepare_lock+0x50/0xf8
>>> [   11.808304]        [<c05c19c4>] clk_unprepare+0x1c/0x2c
>>> [   11.813499]        [<c055d720>] exynos5_i2c_xfer+0x1dc/0x304
>>
>> and here the locks are grabbed in the inverse order, since the regulator
>> driver uses regmap read (grabbing the regmap->lock) and then a clock is
>> prepared in exynos5_i2c_xfer.
>>
>>> [   11.819129]        [<c0559620>] __i2c_transfer+0x13c/0x278
>>> [   11.824589]        [<c05597f0>] i2c_transfer+0x94/0xc4
>>> [   11.829701]        [<c04868f0>] regmap_i2c_read+0x48/0x64
>>> [   11.835074]        [<c0482048>] _regmap_raw_read+0xb4/0x114
>>> [   11.840630]        [<c04820cc>] _regmap_bus_read+0x24/0x58
>>> [   11.846084]        [<c0481a68>] _regmap_read+0x60/0xb8
>>> [   11.851201]        [<c0481afc>] regmap_read+0x3c/0x5c
>>> [   11.856224]        [<c03e2354>] regulator_get_voltage_sel_regmap+0x20/0x54
>>> [   11.863109]        [<c03dc5d4>] _regulator_get_voltage+0x20/0xb8
>>> [   11.863141]        [<c03df058>] _regulator_do_set_voltage+0x240/0x370
>>> [   11.863173]        [<c03df254>] regulator_set_voltage_unlocked+0xcc/0x230
>>> [   11.863205]        [<c03df3e0>] regulator_set_voltage+0x28/0x54
>>> [   11.863234]        [<c0478a94>] _set_opp_voltage+0x30/0x98
>>> [   11.863264]        [<c0479ba8>] dev_pm_opp_set_rate+0x1e0/0x540
>>> [   11.863337]        [<c0580824>] __cpufreq_driver_target+0x168/0x290
>>> [   11.863375]        [<c0583b48>] od_dbs_timer+0xdc/0x164
>>> [   11.863407]        [<c0584114>] dbs_work_handler+0x30/0x58
>>> [   11.863437]        [<c013b52c>] process_one_work+0x1a8/0x514
>>> [   11.863465]        [<c013b8d0>] worker_thread+0x38/0x56c
>>> [   11.863496]        [<c0141d14>] kthread+0xf4/0x10c
>>> [   11.863528]        [<c0107950>] ret_from_fork+0x14/0x24
>>> [   11.863538]
>>> [   11.863538] other info that might help us debug this:
>>> [   11.863538]
>>> [   11.863548]  Possible unsafe locking scenario:
>>> [   11.863548]
>>> [   11.863557]        CPU0                    CPU1
>>> [   11.863565]        ----                    ----
>>> [   11.863589]   lock(sec_core:428:(regmap)->lock);
>>> [   11.863612]                                lock(prepare_lock);
>>> [   11.863634]                                lock(sec_core:428:(regmap)->lock);
>>> [   11.863655]   lock(prepare_lock);
>>> [   11.863664]
>>> [   11.863664]  *** DEADLOCK ***
>>> [   11.863664]
>>
>> I should take a look in deep to the regmap and clock subsystems to better
>> understand the issue on how to solve it. But AFAICT the problem is that
>> the prepare_lock is a global mutex and the same regmap is used for both
>> the s2mps11 clocks and regulators, so the ABBA deadlock described below
>> can happen.

Exactly. One of ideas I remember was to make clocks mutex more
granular but I did not see any patches doing that. Another interesting
point is (in my case) deadlock itself (not lockdep report) happens
only on multi_v7, not on exynos defconfig.

BTW, Anand, if you report please provide more details for
reproduction: kernel config and reproduction steps.

Best regards,
Krzysztof

^ permalink raw reply	[flat|nested] 11+ messages in thread

* Re: Odroid XU4 deadlock
@ 2016-04-09 11:00       ` Krzysztof Kozlowski
  0 siblings, 0 replies; 11+ messages in thread
From: Krzysztof Kozlowski @ 2016-04-09 11:00 UTC (permalink / raw)
  To: Anand Moon
  Cc: Javier Martinez Canillas, Viresh Kumar,
	Bartlomiej Zolnierkiewicz, Lukasz Majewski, linux-samsung-soc,
	Linux Kernel

On Fri, Apr 8, 2016 at 5:36 PM, Anand Moon <linux.amoon@gmail.com> wrote:
> hi Javier,
>
> On 8 April 2016 at 20:25, Javier Martinez Canillas
> <javier@osg.samsung.com> wrote:
>> Hello Anand,
>>
>> On 04/08/2016 09:51 AM, Anand Moon wrote:
>>> Hi All,
>>>
>>> I am observing this deadlock or warning on my Odroid XU4.
>>> I thinks the is related to clk from exynos5_i2c_xfer .... clk_prepare_enable
>>> but I am not able to figure out which clk.
>>>
>>
>> By reading your logs, it seems the problem is a possible ABBA deadlock since
>> the S3C RTC driver grabs the prepare_lock and then the regmap->lock, and the
>> CPUFreq driver leads to the locks being grabbed in the inverse order.

First of all this is not a deadlock. Yet. :) This is just lockdep
report of possible deadlock. This is deadlock:
http://www.krzk.eu/builders/boot-odroid-xu3-multi_v7/builds/13/steps/Boot%20odroid/logs/serial

...and I believe it is the same as the report from lockdep. Which
means that this report truly a predicted deadlock. There are minor
differences between deadlock on my board and report from Anand but
still the same devices are involved. In Anands report the involved
S2MPS11 regulator and S2MPS11 clock use the same regmap. In my case
one path comes from S5M RTC which uses different regmap than S2MPS11
clock. This is the difference which puzzles me.

Anyway this is known issue. In case of my board mentioned deadlock
happens only on multi_v7 on around 15% of boots. I noticed it around
v4.4 and it happens still.

>>
>>> [   11.640221] ======================================================
>>> [   11.646343] [ INFO: possible circular locking dependency detected ]
>>> [   11.652590] 4.6.0-rc2-xu4ml #35 Not tainted
>>> [   11.656749] -------------------------------------------------------
>>> [   11.662992] kworker/1:1/85 is trying to acquire lock:
>>> [   11.668010]  (prepare_lock){+.+...}, at: [<c05bfed8>]
>>> clk_prepare_lock+0x50/0xf8
>>> [   11.675375]
>>> [   11.675375] but task is already holding lock:
>>> [   11.681185]  (sec_core:428:(regmap)->lock){+.+...}, at:
>>> [<c0481aec>] regmap_read+0x2c/0x5c
>>> [   11.689417]
>>> [   11.689417] which lock already depends on the new lock.
>>> [   11.689417]
>>> [   11.697561]
>>> [   11.697561] the existing dependency chain (in reverse order) is:
>>> [   11.705008]
>>> [   11.705008] -> #1 (sec_core:428:(regmap)->lock){+.+...}:
>>> [   11.710467]        [<c0482d30>] regmap_update_bits_base+0x30/0x70
>>> [   11.716545]        [<c05c617c>] s2mps11_clk_prepare+0x30/0x38
>>> [   11.722262]        [<c05c01f0>] clk_core_prepare+0x98/0xbc
>>> [   11.727711]        [<c05c12bc>] clk_prepare+0x1c/0x2c
>>> [   11.732734]        [<c0556fe4>] s3c_rtc_probe+0x2d0/0x43c
>>
>> the S3C RTC driver tries to prepare the RTC source clock S2MPS11_CLK_AP
>> and that leads to the prepare_lock to be held and then the regmap->lock
>> since s2mps11_clk_prepare() calls regmap_update_bits().
>>
>>> [   11.738108]        [<c046b9fc>] platform_drv_probe+0x4c/0xb0
>>> [   11.743749]        [<c046a1fc>] driver_probe_device+0x20c/0x2b8
>>> [   11.749641]        [<c0468594>] bus_for_each_drv+0x60/0x94
>>> [   11.755103]        [<c0469f10>] __device_attach+0xb4/0x118
>>> [   11.760558]        [<c04693b4>] bus_probe_device+0x88/0x90
>>> [   11.766020]        [<c0469850>] deferred_probe_work_func+0x6c/0x9c
>>> [   11.772169]        [<c013b52c>] process_one_work+0x1a8/0x514
>>> [   11.777806]        [<c013b8d0>] worker_thread+0x38/0x56c
>>> [   11.783082]        [<c0141d14>] kthread+0xf4/0x10c
>>> [   11.787847]        [<c0107950>] ret_from_fork+0x14/0x24
>>> [   11.793050]
>>> [   11.793050] -> #0 (prepare_lock){+.+...}:
>>> [   11.797212]        [<c0768dd8>] mutex_lock_nested+0x78/0x4dc
>>> [   11.802845]        [<c05bfed8>] clk_prepare_lock+0x50/0xf8
>>> [   11.808304]        [<c05c19c4>] clk_unprepare+0x1c/0x2c
>>> [   11.813499]        [<c055d720>] exynos5_i2c_xfer+0x1dc/0x304
>>
>> and here the locks are grabbed in the inverse order, since the regulator
>> driver uses regmap read (grabbing the regmap->lock) and then a clock is
>> prepared in exynos5_i2c_xfer.
>>
>>> [   11.819129]        [<c0559620>] __i2c_transfer+0x13c/0x278
>>> [   11.824589]        [<c05597f0>] i2c_transfer+0x94/0xc4
>>> [   11.829701]        [<c04868f0>] regmap_i2c_read+0x48/0x64
>>> [   11.835074]        [<c0482048>] _regmap_raw_read+0xb4/0x114
>>> [   11.840630]        [<c04820cc>] _regmap_bus_read+0x24/0x58
>>> [   11.846084]        [<c0481a68>] _regmap_read+0x60/0xb8
>>> [   11.851201]        [<c0481afc>] regmap_read+0x3c/0x5c
>>> [   11.856224]        [<c03e2354>] regulator_get_voltage_sel_regmap+0x20/0x54
>>> [   11.863109]        [<c03dc5d4>] _regulator_get_voltage+0x20/0xb8
>>> [   11.863141]        [<c03df058>] _regulator_do_set_voltage+0x240/0x370
>>> [   11.863173]        [<c03df254>] regulator_set_voltage_unlocked+0xcc/0x230
>>> [   11.863205]        [<c03df3e0>] regulator_set_voltage+0x28/0x54
>>> [   11.863234]        [<c0478a94>] _set_opp_voltage+0x30/0x98
>>> [   11.863264]        [<c0479ba8>] dev_pm_opp_set_rate+0x1e0/0x540
>>> [   11.863337]        [<c0580824>] __cpufreq_driver_target+0x168/0x290
>>> [   11.863375]        [<c0583b48>] od_dbs_timer+0xdc/0x164
>>> [   11.863407]        [<c0584114>] dbs_work_handler+0x30/0x58
>>> [   11.863437]        [<c013b52c>] process_one_work+0x1a8/0x514
>>> [   11.863465]        [<c013b8d0>] worker_thread+0x38/0x56c
>>> [   11.863496]        [<c0141d14>] kthread+0xf4/0x10c
>>> [   11.863528]        [<c0107950>] ret_from_fork+0x14/0x24
>>> [   11.863538]
>>> [   11.863538] other info that might help us debug this:
>>> [   11.863538]
>>> [   11.863548]  Possible unsafe locking scenario:
>>> [   11.863548]
>>> [   11.863557]        CPU0                    CPU1
>>> [   11.863565]        ----                    ----
>>> [   11.863589]   lock(sec_core:428:(regmap)->lock);
>>> [   11.863612]                                lock(prepare_lock);
>>> [   11.863634]                                lock(sec_core:428:(regmap)->lock);
>>> [   11.863655]   lock(prepare_lock);
>>> [   11.863664]
>>> [   11.863664]  *** DEADLOCK ***
>>> [   11.863664]
>>
>> I should take a look in deep to the regmap and clock subsystems to better
>> understand the issue on how to solve it. But AFAICT the problem is that
>> the prepare_lock is a global mutex and the same regmap is used for both
>> the s2mps11 clocks and regulators, so the ABBA deadlock described below
>> can happen.

Exactly. One of ideas I remember was to make clocks mutex more
granular but I did not see any patches doing that. Another interesting
point is (in my case) deadlock itself (not lockdep report) happens
only on multi_v7, not on exynos defconfig.

BTW, Anand, if you report please provide more details for
reproduction: kernel config and reproduction steps.

Best regards,
Krzysztof

^ permalink raw reply	[flat|nested] 11+ messages in thread

* Re: Odroid XU4 deadlock
  2016-04-09 11:00       ` Krzysztof Kozlowski
@ 2016-04-11  4:35         ` Anand Moon
  -1 siblings, 0 replies; 11+ messages in thread
From: Anand Moon @ 2016-04-11  4:35 UTC (permalink / raw)
  To: Krzysztof Kozlowski
  Cc: Javier Martinez Canillas, Viresh Kumar,
	Bartlomiej Zolnierkiewicz, Lukasz Majewski, linux-samsung-soc,
	Linux Kernel

[-- Attachment #1: Type: text/plain, Size: 7347 bytes --]

Hi Krzysztof,

On 9 April 2016 at 16:30, Krzysztof Kozlowski <k.kozlowski@samsung.com> wrote:
> On Fri, Apr 8, 2016 at 5:36 PM, Anand Moon <linux.amoon@gmail.com> wrote:
>> hi Javier,
>>
>> On 8 April 2016 at 20:25, Javier Martinez Canillas
>> <javier@osg.samsung.com> wrote:
>>> Hello Anand,
>>>
>>> On 04/08/2016 09:51 AM, Anand Moon wrote:
>>>> Hi All,
>>>>
>>>> I am observing this deadlock or warning on my Odroid XU4.
>>>> I thinks the is related to clk from exynos5_i2c_xfer .... clk_prepare_enable
>>>> but I am not able to figure out which clk.
>>>>
>>>
>>> By reading your logs, it seems the problem is a possible ABBA deadlock since
>>> the S3C RTC driver grabs the prepare_lock and then the regmap->lock, and the
>>> CPUFreq driver leads to the locks being grabbed in the inverse order.
>
> First of all this is not a deadlock. Yet. :) This is just lockdep
> report of possible deadlock. This is deadlock:
> http://www.krzk.eu/builders/boot-odroid-xu3-multi_v7/builds/13/steps/Boot%20odroid/logs/serial
>
> ...and I believe it is the same as the report from lockdep. Which
> means that this report truly a predicted deadlock. There are minor
> differences between deadlock on my board and report from Anand but
> still the same devices are involved. In Anands report the involved
> S2MPS11 regulator and S2MPS11 clock use the same regmap. In my case
> one path comes from S5M RTC which uses different regmap than S2MPS11
> clock. This is the difference which puzzles me.
>
> Anyway this is known issue. In case of my board mentioned deadlock
> happens only on multi_v7 on around 15% of boots. I noticed it around
> v4.4 and it happens still.
>
>>>
>>>> [   11.640221] ======================================================
>>>> [   11.646343] [ INFO: possible circular locking dependency detected ]
>>>> [   11.652590] 4.6.0-rc2-xu4ml #35 Not tainted
>>>> [   11.656749] -------------------------------------------------------
>>>> [   11.662992] kworker/1:1/85 is trying to acquire lock:
>>>> [   11.668010]  (prepare_lock){+.+...}, at: [<c05bfed8>]
>>>> clk_prepare_lock+0x50/0xf8
>>>> [   11.675375]
>>>> [   11.675375] but task is already holding lock:
>>>> [   11.681185]  (sec_core:428:(regmap)->lock){+.+...}, at:
>>>> [<c0481aec>] regmap_read+0x2c/0x5c
>>>> [   11.689417]
>>>> [   11.689417] which lock already depends on the new lock.
>>>> [   11.689417]
>>>> [   11.697561]
>>>> [   11.697561] the existing dependency chain (in reverse order) is:
>>>> [   11.705008]
>>>> [   11.705008] -> #1 (sec_core:428:(regmap)->lock){+.+...}:
>>>> [   11.710467]        [<c0482d30>] regmap_update_bits_base+0x30/0x70
>>>> [   11.716545]        [<c05c617c>] s2mps11_clk_prepare+0x30/0x38
>>>> [   11.722262]        [<c05c01f0>] clk_core_prepare+0x98/0xbc
>>>> [   11.727711]        [<c05c12bc>] clk_prepare+0x1c/0x2c
>>>> [   11.732734]        [<c0556fe4>] s3c_rtc_probe+0x2d0/0x43c
>>>
>>> the S3C RTC driver tries to prepare the RTC source clock S2MPS11_CLK_AP
>>> and that leads to the prepare_lock to be held and then the regmap->lock
>>> since s2mps11_clk_prepare() calls regmap_update_bits().
>>>
>>>> [   11.738108]        [<c046b9fc>] platform_drv_probe+0x4c/0xb0
>>>> [   11.743749]        [<c046a1fc>] driver_probe_device+0x20c/0x2b8
>>>> [   11.749641]        [<c0468594>] bus_for_each_drv+0x60/0x94
>>>> [   11.755103]        [<c0469f10>] __device_attach+0xb4/0x118
>>>> [   11.760558]        [<c04693b4>] bus_probe_device+0x88/0x90
>>>> [   11.766020]        [<c0469850>] deferred_probe_work_func+0x6c/0x9c
>>>> [   11.772169]        [<c013b52c>] process_one_work+0x1a8/0x514
>>>> [   11.777806]        [<c013b8d0>] worker_thread+0x38/0x56c
>>>> [   11.783082]        [<c0141d14>] kthread+0xf4/0x10c
>>>> [   11.787847]        [<c0107950>] ret_from_fork+0x14/0x24
>>>> [   11.793050]
>>>> [   11.793050] -> #0 (prepare_lock){+.+...}:
>>>> [   11.797212]        [<c0768dd8>] mutex_lock_nested+0x78/0x4dc
>>>> [   11.802845]        [<c05bfed8>] clk_prepare_lock+0x50/0xf8
>>>> [   11.808304]        [<c05c19c4>] clk_unprepare+0x1c/0x2c
>>>> [   11.813499]        [<c055d720>] exynos5_i2c_xfer+0x1dc/0x304
>>>
>>> and here the locks are grabbed in the inverse order, since the regulator
>>> driver uses regmap read (grabbing the regmap->lock) and then a clock is
>>> prepared in exynos5_i2c_xfer.
>>>
>>>> [   11.819129]        [<c0559620>] __i2c_transfer+0x13c/0x278
>>>> [   11.824589]        [<c05597f0>] i2c_transfer+0x94/0xc4
>>>> [   11.829701]        [<c04868f0>] regmap_i2c_read+0x48/0x64
>>>> [   11.835074]        [<c0482048>] _regmap_raw_read+0xb4/0x114
>>>> [   11.840630]        [<c04820cc>] _regmap_bus_read+0x24/0x58
>>>> [   11.846084]        [<c0481a68>] _regmap_read+0x60/0xb8
>>>> [   11.851201]        [<c0481afc>] regmap_read+0x3c/0x5c
>>>> [   11.856224]        [<c03e2354>] regulator_get_voltage_sel_regmap+0x20/0x54
>>>> [   11.863109]        [<c03dc5d4>] _regulator_get_voltage+0x20/0xb8
>>>> [   11.863141]        [<c03df058>] _regulator_do_set_voltage+0x240/0x370
>>>> [   11.863173]        [<c03df254>] regulator_set_voltage_unlocked+0xcc/0x230
>>>> [   11.863205]        [<c03df3e0>] regulator_set_voltage+0x28/0x54
>>>> [   11.863234]        [<c0478a94>] _set_opp_voltage+0x30/0x98
>>>> [   11.863264]        [<c0479ba8>] dev_pm_opp_set_rate+0x1e0/0x540
>>>> [   11.863337]        [<c0580824>] __cpufreq_driver_target+0x168/0x290
>>>> [   11.863375]        [<c0583b48>] od_dbs_timer+0xdc/0x164
>>>> [   11.863407]        [<c0584114>] dbs_work_handler+0x30/0x58
>>>> [   11.863437]        [<c013b52c>] process_one_work+0x1a8/0x514
>>>> [   11.863465]        [<c013b8d0>] worker_thread+0x38/0x56c
>>>> [   11.863496]        [<c0141d14>] kthread+0xf4/0x10c
>>>> [   11.863528]        [<c0107950>] ret_from_fork+0x14/0x24
>>>> [   11.863538]
>>>> [   11.863538] other info that might help us debug this:
>>>> [   11.863538]
>>>> [   11.863548]  Possible unsafe locking scenario:
>>>> [   11.863548]
>>>> [   11.863557]        CPU0                    CPU1
>>>> [   11.863565]        ----                    ----
>>>> [   11.863589]   lock(sec_core:428:(regmap)->lock);
>>>> [   11.863612]                                lock(prepare_lock);
>>>> [   11.863634]                                lock(sec_core:428:(regmap)->lock);
>>>> [   11.863655]   lock(prepare_lock);
>>>> [   11.863664]
>>>> [   11.863664]  *** DEADLOCK ***
>>>> [   11.863664]
>>>
>>> I should take a look in deep to the regmap and clock subsystems to better
>>> understand the issue on how to solve it. But AFAICT the problem is that
>>> the prepare_lock is a global mutex and the same regmap is used for both
>>> the s2mps11 clocks and regulators, so the ABBA deadlock described below
>>> can happen.
>
> Exactly. One of ideas I remember was to make clocks mutex more
> granular but I did not see any patches doing that. Another interesting
> point is (in my case) deadlock itself (not lockdep report) happens
> only on multi_v7, not on exynos defconfig.
>
> BTW, Anand, if you report please provide more details for
> reproduction: kernel config and reproduction steps.
>
> Best regards,
> Krzysztof

Please find the attached exynosd_defconfig.

I have tried to enable almost all the kernel hacking flags in this
config just for testing.
Please ignore the CONFIG_PM_DEVFREQ changes in this config file.

Best Regards
-Anand Moon

[-- Attachment #2: exynosd_defconfig --]
[-- Type: application/octet-stream, Size: 7291 bytes --]

# CONFIG_LOCALVERSION_AUTO is not set
CONFIG_SYSVIPC=y
CONFIG_FHANDLE=y
CONFIG_IRQ_DOMAIN_DEBUG=y
CONFIG_NO_HZ=y
CONFIG_HIGH_RES_TIMERS=y
CONFIG_IRQ_TIME_ACCOUNTING=y
CONFIG_TASKSTATS=y
CONFIG_TASK_DELAY_ACCT=y
CONFIG_TASK_XACCT=y
CONFIG_TASK_IO_ACCOUNTING=y
CONFIG_RCU_EXPERT=y
CONFIG_RCU_FAST_NO_HZ=y
CONFIG_RCU_BOOST=y
CONFIG_CGROUPS=y
CONFIG_BLK_DEV_INITRD=y
CONFIG_EMBEDDED=y
CONFIG_PERF_EVENTS=y
CONFIG_MODULES=y
CONFIG_MODULE_UNLOAD=y
# CONFIG_BLK_DEV_BSG is not set
CONFIG_PARTITION_ADVANCED=y
CONFIG_ARCH_EXYNOS=y
CONFIG_ARCH_EXYNOS3=y
CONFIG_EXYNOS5420_MCPM=y
CONFIG_SMP=y
CONFIG_BIG_LITTLE=y
CONFIG_NR_CPUS=8
CONFIG_PREEMPT=y
CONFIG_AEABI=y
CONFIG_HIGHMEM=y
CONFIG_CMA=y
CONFIG_ZBOOT_ROM_TEXT=0x0
CONFIG_ZBOOT_ROM_BSS=0x0
CONFIG_ARM_APPENDED_DTB=y
CONFIG_ARM_ATAG_DTB_COMPAT=y
CONFIG_CMDLINE="root=/dev/ram0 rw ramdisk=8192 initrd=0x41000000,8M console=ttySAC1,115200 init=/linuxrc mem=256M"
CONFIG_CPU_FREQ=y
CONFIG_CPU_FREQ_STAT_DETAILS=y
CONFIG_CPU_FREQ_DEFAULT_GOV_ONDEMAND=y
CONFIG_CPU_FREQ_GOV_POWERSAVE=m
CONFIG_CPU_FREQ_GOV_USERSPACE=m
CONFIG_CPU_FREQ_GOV_CONSERVATIVE=m
CONFIG_CPUFREQ_DT=y
CONFIG_CPU_IDLE=y
CONFIG_ARM_EXYNOS_CPUIDLE=y
CONFIG_VFP=y
CONFIG_NEON=y
CONFIG_KERNEL_MODE_NEON=y
CONFIG_NET=y
CONFIG_PACKET=y
CONFIG_UNIX=y
CONFIG_NET_KEY=y
CONFIG_INET=y
CONFIG_IP_PNP=y
CONFIG_IP_PNP_DHCP=y
CONFIG_IP_PNP_BOOTP=y
CONFIG_IP_PNP_RARP=y
CONFIG_BT=m
CONFIG_BT_RFCOMM=m
CONFIG_BT_RFCOMM_TTY=y
CONFIG_BT_BNEP=m
CONFIG_BT_BNEP_MC_FILTER=y
CONFIG_BT_BNEP_PROTO_FILTER=y
CONFIG_BT_HIDP=m
# CONFIG_BT_DEBUGFS is not set
CONFIG_BT_HCIBTUSB=m
CONFIG_BT_HCIUART=m
CONFIG_BT_HCIUART_BCSP=y
CONFIG_BT_HCIUART_ATH3K=y
CONFIG_BT_HCIUART_LL=y
CONFIG_BT_HCIUART_3WIRE=y
CONFIG_BT_HCIBCM203X=m
CONFIG_BT_HCIBPA10X=m
CONFIG_BT_HCIBFUSB=m
CONFIG_CFG80211=y
CONFIG_RFKILL_REGULATOR=y
CONFIG_DEVTMPFS=y
CONFIG_DEVTMPFS_MOUNT=y
CONFIG_DMA_CMA=y
CONFIG_CMA_SIZE_MBYTES=64
CONFIG_BLK_DEV_LOOP=y
CONFIG_BLK_DEV_CRYPTOLOOP=y
CONFIG_BLK_DEV_RAM=y
CONFIG_BLK_DEV_RAM_SIZE=8192
CONFIG_SCSI=y
CONFIG_BLK_DEV_SD=y
CONFIG_CHR_DEV_SG=y
CONFIG_MD=y
CONFIG_BLK_DEV_DM=y
CONFIG_DM_CRYPT=m
CONFIG_NETDEVICES=y
CONFIG_SMSC911X=y
CONFIG_USB_RTL8152=y
CONFIG_USB_USBNET=y
CONFIG_USB_NET_SMSC75XX=y
CONFIG_USB_NET_SMSC95XX=y
CONFIG_MWIFIEX=m
CONFIG_MWIFIEX_SDIO=m
CONFIG_INPUT_EVDEV=y
CONFIG_KEYBOARD_GPIO=y
CONFIG_KEYBOARD_CROS_EC=y
# CONFIG_MOUSE_PS2 is not set
CONFIG_MOUSE_CYAPA=y
CONFIG_INPUT_TOUCHSCREEN=y
CONFIG_TOUCHSCREEN_ATMEL_MXT=y
CONFIG_INPUT_MISC=y
CONFIG_INPUT_MAX77693_HAPTIC=y
CONFIG_INPUT_MAX8997_HAPTIC=y
CONFIG_SERIAL_8250=y
CONFIG_SERIAL_OF_PLATFORM=y
CONFIG_SERIAL_SAMSUNG=y
CONFIG_SERIAL_SAMSUNG_CONSOLE=y
CONFIG_HW_RANDOM=y
CONFIG_TCG_TPM=y
CONFIG_TCG_TIS_I2C_INFINEON=y
CONFIG_I2C_CHARDEV=y
CONFIG_I2C_MUX=y
CONFIG_I2C_ARB_GPIO_CHALLENGE=y
CONFIG_I2C_GPIO=y
CONFIG_I2C_CROS_EC_TUNNEL=y
CONFIG_SPI=y
CONFIG_SPI_GPIO=y
CONFIG_SPI_S3C64XX=y
CONFIG_DEBUG_GPIO=y
CONFIG_GPIO_SYSFS=y
CONFIG_POWER_SUPPLY=y
CONFIG_BATTERY_SBS=y
CONFIG_BATTERY_MAX17040=y
CONFIG_BATTERY_MAX17042=y
CONFIG_CHARGER_MAX14577=y
CONFIG_CHARGER_MAX77693=y
CONFIG_CHARGER_MAX8997=y
CONFIG_CHARGER_TPS65090=y
CONFIG_SENSORS_LM90=y
CONFIG_SENSORS_NTC_THERMISTOR=y
CONFIG_SENSORS_PWM_FAN=y
CONFIG_SENSORS_INA2XX=y
CONFIG_CPU_THERMAL=y
CONFIG_THERMAL_EMULATION=y
CONFIG_WATCHDOG=y
CONFIG_S3C2410_WATCHDOG=y
CONFIG_MFD_CROS_EC=y
CONFIG_MFD_CROS_EC_I2C=y
CONFIG_MFD_CROS_EC_SPI=y
CONFIG_MFD_MAX14577=y
CONFIG_MFD_MAX77686=y
CONFIG_MFD_MAX77693=y
CONFIG_MFD_MAX8997=y
CONFIG_MFD_MAX8998=y
CONFIG_MFD_SEC_CORE=y
CONFIG_MFD_TPS65090=y
CONFIG_REGULATOR=y
CONFIG_REGULATOR_FIXED_VOLTAGE=y
CONFIG_REGULATOR_GPIO=y
CONFIG_REGULATOR_MAX14577=y
CONFIG_REGULATOR_MAX8997=y
CONFIG_REGULATOR_MAX8998=y
CONFIG_REGULATOR_MAX77686=y
CONFIG_REGULATOR_MAX77693=y
CONFIG_REGULATOR_MAX77802=y
CONFIG_REGULATOR_S2MPA01=y
CONFIG_REGULATOR_S2MPS11=y
CONFIG_REGULATOR_S5M8767=y
CONFIG_REGULATOR_TPS65090=y
CONFIG_MEDIA_SUPPORT=m
CONFIG_MEDIA_CAMERA_SUPPORT=y
CONFIG_MEDIA_USB_SUPPORT=y
CONFIG_USB_VIDEO_CLASS=m
CONFIG_DRM=y
CONFIG_DRM_EXYNOS=y
CONFIG_DRM_EXYNOS_FIMD=y
CONFIG_DRM_EXYNOS_MIXER=y
CONFIG_DRM_EXYNOS_DPI=y
CONFIG_DRM_EXYNOS_DSI=y
CONFIG_DRM_EXYNOS_HDMI=y
CONFIG_DRM_PANEL_SIMPLE=y
CONFIG_DRM_PANEL_SAMSUNG_LD9040=y
CONFIG_DRM_PANEL_SAMSUNG_S6E8AA0=y
CONFIG_DRM_NXP_PTN3460=y
CONFIG_DRM_PARADE_PS8622=y
CONFIG_EXYNOS_VIDEO=y
CONFIG_EXYNOS_MIPI_DSI=y
CONFIG_LCD_CLASS_DEVICE=y
CONFIG_LCD_PLATFORM=y
CONFIG_BACKLIGHT_PWM=y
CONFIG_LOGO=y
CONFIG_SOUND=y
CONFIG_SND=y
CONFIG_SND_SOC=y
CONFIG_SND_SOC_SAMSUNG=y
CONFIG_SND_SOC_SNOW=y
CONFIG_SND_SOC_ODROIDX2=y
CONFIG_SND_SIMPLE_CARD=y
CONFIG_USB=y
CONFIG_USB_ANNOUNCE_NEW_DEVICES=y
CONFIG_USB_XHCI_HCD=y
CONFIG_USB_EHCI_HCD=y
CONFIG_USB_EHCI_EXYNOS=y
CONFIG_USB_OHCI_HCD=y
CONFIG_USB_OHCI_EXYNOS=y
CONFIG_USB_STORAGE=y
CONFIG_USB_DWC3=y
CONFIG_USB_DWC2=y
CONFIG_USB_HSIC_USB3503=y
CONFIG_USB_GADGET=y
CONFIG_USB_ETH=y
CONFIG_MMC=y
CONFIG_MMC_BLOCK_MINORS=16
CONFIG_MMC_SDHCI=y
CONFIG_MMC_SDHCI_S3C=y
CONFIG_MMC_SDHCI_S3C_DMA=y
CONFIG_MMC_DW=y
CONFIG_MMC_DW_EXYNOS=y
CONFIG_NEW_LEDS=y
CONFIG_LEDS_CLASS=y
CONFIG_LEDS_CLASS_FLASH=y
CONFIG_LEDS_GPIO=y
CONFIG_LEDS_PWM=y
CONFIG_LEDS_MAX77693=y
CONFIG_LEDS_MAX8997=y
CONFIG_LEDS_TRIGGERS=y
CONFIG_LEDS_TRIGGER_HEARTBEAT=y
CONFIG_RTC_CLASS=y
CONFIG_RTC_DRV_MAX8997=y
CONFIG_RTC_DRV_MAX77686=y
CONFIG_RTC_DRV_S5M=y
CONFIG_RTC_DRV_S3C=y
CONFIG_DMADEVICES=y
CONFIG_PL330_DMA=y
CONFIG_CROS_EC_CHARDEV=y
CONFIG_COMMON_CLK_MAX77686=y
CONFIG_COMMON_CLK_MAX77802=y
CONFIG_COMMON_CLK_S2MPS11=y
CONFIG_EXYNOS_IOMMU=y
CONFIG_EXYNOS_IOMMU_DEBUG=y
CONFIG_ARM_SMMU=y
CONFIG_PM_DEVFREQ=y
CONFIG_DEVFREQ_GOV_PERFORMANCE=m
CONFIG_DEVFREQ_GOV_POWERSAVE=m
CONFIG_DEVFREQ_GOV_USERSPACE=m
CONFIG_ARM_EXYNOS_BUS_DEVFREQ=y
CONFIG_DEVFREQ_EVENT_EXYNOS_NOCP=y
CONFIG_EXTCON=y
CONFIG_EXTCON_ADC_JACK=y
CONFIG_EXTCON_GPIO=y
CONFIG_EXTCON_MAX14577=y
CONFIG_EXTCON_MAX77693=y
CONFIG_EXTCON_MAX8997=y
CONFIG_IIO=y
CONFIG_EXYNOS_ADC=y
CONFIG_PWM=y
CONFIG_PWM_SAMSUNG=y
CONFIG_PHY_EXYNOS5250_SATA=y
CONFIG_EXT2_FS=y
CONFIG_EXT3_FS=y
CONFIG_AUTOFS4_FS=y
CONFIG_MSDOS_FS=y
CONFIG_VFAT_FS=y
CONFIG_TMPFS=y
CONFIG_TMPFS_POSIX_ACL=y
CONFIG_CRAMFS=y
CONFIG_ROMFS_FS=y
CONFIG_NFS_FS=y
CONFIG_NFS_V4=y
CONFIG_ROOT_NFS=y
CONFIG_NLS_CODEPAGE_437=y
CONFIG_NLS_ASCII=y
CONFIG_NLS_ISO8859_1=y
CONFIG_PRINTK_TIME=y
CONFIG_DEBUG_INFO=y
CONFIG_MAGIC_SYSRQ=y
CONFIG_DEBUG_PAGEALLOC=y
CONFIG_DEBUG_OBJECTS=y
CONFIG_DEBUG_OBJECTS_SELFTEST=y
CONFIG_DEBUG_OBJECTS_FREE=y
CONFIG_DEBUG_OBJECTS_TIMERS=y
CONFIG_DEBUG_OBJECTS_WORK=y
CONFIG_DEBUG_OBJECTS_RCU_HEAD=y
CONFIG_DEBUG_OBJECTS_PERCPU_COUNTER=y
CONFIG_DEBUG_SHIRQ=y
CONFIG_LOCKUP_DETECTOR=y
CONFIG_SCHEDSTATS=y
CONFIG_SCHED_STACK_END_CHECK=y
CONFIG_TIMER_STATS=y
CONFIG_DEBUG_RT_MUTEXES=y
CONFIG_DEBUG_WW_MUTEX_SLOWPATH=y
CONFIG_PROVE_LOCKING=y
CONFIG_LOCK_STAT=y
CONFIG_DEBUG_LOCKDEP=y
CONFIG_DEBUG_ATOMIC_SLEEP=y
CONFIG_DEBUG_LOCKING_API_SELFTESTS=y
CONFIG_LOCK_TORTURE_TEST=m
CONFIG_DEBUG_PI_LIST=y
CONFIG_DEBUG_SG=y
CONFIG_DEBUG_NOTIFIERS=y
CONFIG_DEBUG_CREDENTIALS=y
CONFIG_PROVE_RCU_REPEATEDLY=y
CONFIG_SPARSE_RCU_POINTER=y
CONFIG_RCU_TORTURE_TEST=m
CONFIG_RCU_TORTURE_TEST_SLOW_PREINIT=y
CONFIG_RCU_TRACE=y
CONFIG_DEBUG_USER=y
CONFIG_CRYPTO_DEV_S5P=y
CONFIG_ARM_CRYPTO=y
CONFIG_CRYPTO_SHA1_ARM_NEON=m
CONFIG_CRYPTO_SHA256_ARM=m
CONFIG_CRYPTO_SHA512_ARM=m
CONFIG_CRYPTO_AES_ARM_BS=m
CONFIG_CRC_CCITT=y
CONFIG_FONTS=y
CONFIG_FONT_7x14=y

^ permalink raw reply	[flat|nested] 11+ messages in thread

* Re: Odroid XU4 deadlock
@ 2016-04-11  4:35         ` Anand Moon
  0 siblings, 0 replies; 11+ messages in thread
From: Anand Moon @ 2016-04-11  4:35 UTC (permalink / raw)
  To: Krzysztof Kozlowski
  Cc: Javier Martinez Canillas, Viresh Kumar,
	Bartlomiej Zolnierkiewicz, Lukasz Majewski, linux-samsung-soc,
	Linux Kernel

[-- Attachment #1: Type: text/plain, Size: 7347 bytes --]

Hi Krzysztof,

On 9 April 2016 at 16:30, Krzysztof Kozlowski <k.kozlowski@samsung.com> wrote:
> On Fri, Apr 8, 2016 at 5:36 PM, Anand Moon <linux.amoon@gmail.com> wrote:
>> hi Javier,
>>
>> On 8 April 2016 at 20:25, Javier Martinez Canillas
>> <javier@osg.samsung.com> wrote:
>>> Hello Anand,
>>>
>>> On 04/08/2016 09:51 AM, Anand Moon wrote:
>>>> Hi All,
>>>>
>>>> I am observing this deadlock or warning on my Odroid XU4.
>>>> I thinks the is related to clk from exynos5_i2c_xfer .... clk_prepare_enable
>>>> but I am not able to figure out which clk.
>>>>
>>>
>>> By reading your logs, it seems the problem is a possible ABBA deadlock since
>>> the S3C RTC driver grabs the prepare_lock and then the regmap->lock, and the
>>> CPUFreq driver leads to the locks being grabbed in the inverse order.
>
> First of all this is not a deadlock. Yet. :) This is just lockdep
> report of possible deadlock. This is deadlock:
> http://www.krzk.eu/builders/boot-odroid-xu3-multi_v7/builds/13/steps/Boot%20odroid/logs/serial
>
> ...and I believe it is the same as the report from lockdep. Which
> means that this report truly a predicted deadlock. There are minor
> differences between deadlock on my board and report from Anand but
> still the same devices are involved. In Anands report the involved
> S2MPS11 regulator and S2MPS11 clock use the same regmap. In my case
> one path comes from S5M RTC which uses different regmap than S2MPS11
> clock. This is the difference which puzzles me.
>
> Anyway this is known issue. In case of my board mentioned deadlock
> happens only on multi_v7 on around 15% of boots. I noticed it around
> v4.4 and it happens still.
>
>>>
>>>> [   11.640221] ======================================================
>>>> [   11.646343] [ INFO: possible circular locking dependency detected ]
>>>> [   11.652590] 4.6.0-rc2-xu4ml #35 Not tainted
>>>> [   11.656749] -------------------------------------------------------
>>>> [   11.662992] kworker/1:1/85 is trying to acquire lock:
>>>> [   11.668010]  (prepare_lock){+.+...}, at: [<c05bfed8>]
>>>> clk_prepare_lock+0x50/0xf8
>>>> [   11.675375]
>>>> [   11.675375] but task is already holding lock:
>>>> [   11.681185]  (sec_core:428:(regmap)->lock){+.+...}, at:
>>>> [<c0481aec>] regmap_read+0x2c/0x5c
>>>> [   11.689417]
>>>> [   11.689417] which lock already depends on the new lock.
>>>> [   11.689417]
>>>> [   11.697561]
>>>> [   11.697561] the existing dependency chain (in reverse order) is:
>>>> [   11.705008]
>>>> [   11.705008] -> #1 (sec_core:428:(regmap)->lock){+.+...}:
>>>> [   11.710467]        [<c0482d30>] regmap_update_bits_base+0x30/0x70
>>>> [   11.716545]        [<c05c617c>] s2mps11_clk_prepare+0x30/0x38
>>>> [   11.722262]        [<c05c01f0>] clk_core_prepare+0x98/0xbc
>>>> [   11.727711]        [<c05c12bc>] clk_prepare+0x1c/0x2c
>>>> [   11.732734]        [<c0556fe4>] s3c_rtc_probe+0x2d0/0x43c
>>>
>>> the S3C RTC driver tries to prepare the RTC source clock S2MPS11_CLK_AP
>>> and that leads to the prepare_lock to be held and then the regmap->lock
>>> since s2mps11_clk_prepare() calls regmap_update_bits().
>>>
>>>> [   11.738108]        [<c046b9fc>] platform_drv_probe+0x4c/0xb0
>>>> [   11.743749]        [<c046a1fc>] driver_probe_device+0x20c/0x2b8
>>>> [   11.749641]        [<c0468594>] bus_for_each_drv+0x60/0x94
>>>> [   11.755103]        [<c0469f10>] __device_attach+0xb4/0x118
>>>> [   11.760558]        [<c04693b4>] bus_probe_device+0x88/0x90
>>>> [   11.766020]        [<c0469850>] deferred_probe_work_func+0x6c/0x9c
>>>> [   11.772169]        [<c013b52c>] process_one_work+0x1a8/0x514
>>>> [   11.777806]        [<c013b8d0>] worker_thread+0x38/0x56c
>>>> [   11.783082]        [<c0141d14>] kthread+0xf4/0x10c
>>>> [   11.787847]        [<c0107950>] ret_from_fork+0x14/0x24
>>>> [   11.793050]
>>>> [   11.793050] -> #0 (prepare_lock){+.+...}:
>>>> [   11.797212]        [<c0768dd8>] mutex_lock_nested+0x78/0x4dc
>>>> [   11.802845]        [<c05bfed8>] clk_prepare_lock+0x50/0xf8
>>>> [   11.808304]        [<c05c19c4>] clk_unprepare+0x1c/0x2c
>>>> [   11.813499]        [<c055d720>] exynos5_i2c_xfer+0x1dc/0x304
>>>
>>> and here the locks are grabbed in the inverse order, since the regulator
>>> driver uses regmap read (grabbing the regmap->lock) and then a clock is
>>> prepared in exynos5_i2c_xfer.
>>>
>>>> [   11.819129]        [<c0559620>] __i2c_transfer+0x13c/0x278
>>>> [   11.824589]        [<c05597f0>] i2c_transfer+0x94/0xc4
>>>> [   11.829701]        [<c04868f0>] regmap_i2c_read+0x48/0x64
>>>> [   11.835074]        [<c0482048>] _regmap_raw_read+0xb4/0x114
>>>> [   11.840630]        [<c04820cc>] _regmap_bus_read+0x24/0x58
>>>> [   11.846084]        [<c0481a68>] _regmap_read+0x60/0xb8
>>>> [   11.851201]        [<c0481afc>] regmap_read+0x3c/0x5c
>>>> [   11.856224]        [<c03e2354>] regulator_get_voltage_sel_regmap+0x20/0x54
>>>> [   11.863109]        [<c03dc5d4>] _regulator_get_voltage+0x20/0xb8
>>>> [   11.863141]        [<c03df058>] _regulator_do_set_voltage+0x240/0x370
>>>> [   11.863173]        [<c03df254>] regulator_set_voltage_unlocked+0xcc/0x230
>>>> [   11.863205]        [<c03df3e0>] regulator_set_voltage+0x28/0x54
>>>> [   11.863234]        [<c0478a94>] _set_opp_voltage+0x30/0x98
>>>> [   11.863264]        [<c0479ba8>] dev_pm_opp_set_rate+0x1e0/0x540
>>>> [   11.863337]        [<c0580824>] __cpufreq_driver_target+0x168/0x290
>>>> [   11.863375]        [<c0583b48>] od_dbs_timer+0xdc/0x164
>>>> [   11.863407]        [<c0584114>] dbs_work_handler+0x30/0x58
>>>> [   11.863437]        [<c013b52c>] process_one_work+0x1a8/0x514
>>>> [   11.863465]        [<c013b8d0>] worker_thread+0x38/0x56c
>>>> [   11.863496]        [<c0141d14>] kthread+0xf4/0x10c
>>>> [   11.863528]        [<c0107950>] ret_from_fork+0x14/0x24
>>>> [   11.863538]
>>>> [   11.863538] other info that might help us debug this:
>>>> [   11.863538]
>>>> [   11.863548]  Possible unsafe locking scenario:
>>>> [   11.863548]
>>>> [   11.863557]        CPU0                    CPU1
>>>> [   11.863565]        ----                    ----
>>>> [   11.863589]   lock(sec_core:428:(regmap)->lock);
>>>> [   11.863612]                                lock(prepare_lock);
>>>> [   11.863634]                                lock(sec_core:428:(regmap)->lock);
>>>> [   11.863655]   lock(prepare_lock);
>>>> [   11.863664]
>>>> [   11.863664]  *** DEADLOCK ***
>>>> [   11.863664]
>>>
>>> I should take a look in deep to the regmap and clock subsystems to better
>>> understand the issue on how to solve it. But AFAICT the problem is that
>>> the prepare_lock is a global mutex and the same regmap is used for both
>>> the s2mps11 clocks and regulators, so the ABBA deadlock described below
>>> can happen.
>
> Exactly. One of ideas I remember was to make clocks mutex more
> granular but I did not see any patches doing that. Another interesting
> point is (in my case) deadlock itself (not lockdep report) happens
> only on multi_v7, not on exynos defconfig.
>
> BTW, Anand, if you report please provide more details for
> reproduction: kernel config and reproduction steps.
>
> Best regards,
> Krzysztof

Please find the attached exynosd_defconfig.

I have tried to enable almost all the kernel hacking flags in this
config just for testing.
Please ignore the CONFIG_PM_DEVFREQ changes in this config file.

Best Regards
-Anand Moon

[-- Attachment #2: exynosd_defconfig --]
[-- Type: application/octet-stream, Size: 7291 bytes --]

# CONFIG_LOCALVERSION_AUTO is not set
CONFIG_SYSVIPC=y
CONFIG_FHANDLE=y
CONFIG_IRQ_DOMAIN_DEBUG=y
CONFIG_NO_HZ=y
CONFIG_HIGH_RES_TIMERS=y
CONFIG_IRQ_TIME_ACCOUNTING=y
CONFIG_TASKSTATS=y
CONFIG_TASK_DELAY_ACCT=y
CONFIG_TASK_XACCT=y
CONFIG_TASK_IO_ACCOUNTING=y
CONFIG_RCU_EXPERT=y
CONFIG_RCU_FAST_NO_HZ=y
CONFIG_RCU_BOOST=y
CONFIG_CGROUPS=y
CONFIG_BLK_DEV_INITRD=y
CONFIG_EMBEDDED=y
CONFIG_PERF_EVENTS=y
CONFIG_MODULES=y
CONFIG_MODULE_UNLOAD=y
# CONFIG_BLK_DEV_BSG is not set
CONFIG_PARTITION_ADVANCED=y
CONFIG_ARCH_EXYNOS=y
CONFIG_ARCH_EXYNOS3=y
CONFIG_EXYNOS5420_MCPM=y
CONFIG_SMP=y
CONFIG_BIG_LITTLE=y
CONFIG_NR_CPUS=8
CONFIG_PREEMPT=y
CONFIG_AEABI=y
CONFIG_HIGHMEM=y
CONFIG_CMA=y
CONFIG_ZBOOT_ROM_TEXT=0x0
CONFIG_ZBOOT_ROM_BSS=0x0
CONFIG_ARM_APPENDED_DTB=y
CONFIG_ARM_ATAG_DTB_COMPAT=y
CONFIG_CMDLINE="root=/dev/ram0 rw ramdisk=8192 initrd=0x41000000,8M console=ttySAC1,115200 init=/linuxrc mem=256M"
CONFIG_CPU_FREQ=y
CONFIG_CPU_FREQ_STAT_DETAILS=y
CONFIG_CPU_FREQ_DEFAULT_GOV_ONDEMAND=y
CONFIG_CPU_FREQ_GOV_POWERSAVE=m
CONFIG_CPU_FREQ_GOV_USERSPACE=m
CONFIG_CPU_FREQ_GOV_CONSERVATIVE=m
CONFIG_CPUFREQ_DT=y
CONFIG_CPU_IDLE=y
CONFIG_ARM_EXYNOS_CPUIDLE=y
CONFIG_VFP=y
CONFIG_NEON=y
CONFIG_KERNEL_MODE_NEON=y
CONFIG_NET=y
CONFIG_PACKET=y
CONFIG_UNIX=y
CONFIG_NET_KEY=y
CONFIG_INET=y
CONFIG_IP_PNP=y
CONFIG_IP_PNP_DHCP=y
CONFIG_IP_PNP_BOOTP=y
CONFIG_IP_PNP_RARP=y
CONFIG_BT=m
CONFIG_BT_RFCOMM=m
CONFIG_BT_RFCOMM_TTY=y
CONFIG_BT_BNEP=m
CONFIG_BT_BNEP_MC_FILTER=y
CONFIG_BT_BNEP_PROTO_FILTER=y
CONFIG_BT_HIDP=m
# CONFIG_BT_DEBUGFS is not set
CONFIG_BT_HCIBTUSB=m
CONFIG_BT_HCIUART=m
CONFIG_BT_HCIUART_BCSP=y
CONFIG_BT_HCIUART_ATH3K=y
CONFIG_BT_HCIUART_LL=y
CONFIG_BT_HCIUART_3WIRE=y
CONFIG_BT_HCIBCM203X=m
CONFIG_BT_HCIBPA10X=m
CONFIG_BT_HCIBFUSB=m
CONFIG_CFG80211=y
CONFIG_RFKILL_REGULATOR=y
CONFIG_DEVTMPFS=y
CONFIG_DEVTMPFS_MOUNT=y
CONFIG_DMA_CMA=y
CONFIG_CMA_SIZE_MBYTES=64
CONFIG_BLK_DEV_LOOP=y
CONFIG_BLK_DEV_CRYPTOLOOP=y
CONFIG_BLK_DEV_RAM=y
CONFIG_BLK_DEV_RAM_SIZE=8192
CONFIG_SCSI=y
CONFIG_BLK_DEV_SD=y
CONFIG_CHR_DEV_SG=y
CONFIG_MD=y
CONFIG_BLK_DEV_DM=y
CONFIG_DM_CRYPT=m
CONFIG_NETDEVICES=y
CONFIG_SMSC911X=y
CONFIG_USB_RTL8152=y
CONFIG_USB_USBNET=y
CONFIG_USB_NET_SMSC75XX=y
CONFIG_USB_NET_SMSC95XX=y
CONFIG_MWIFIEX=m
CONFIG_MWIFIEX_SDIO=m
CONFIG_INPUT_EVDEV=y
CONFIG_KEYBOARD_GPIO=y
CONFIG_KEYBOARD_CROS_EC=y
# CONFIG_MOUSE_PS2 is not set
CONFIG_MOUSE_CYAPA=y
CONFIG_INPUT_TOUCHSCREEN=y
CONFIG_TOUCHSCREEN_ATMEL_MXT=y
CONFIG_INPUT_MISC=y
CONFIG_INPUT_MAX77693_HAPTIC=y
CONFIG_INPUT_MAX8997_HAPTIC=y
CONFIG_SERIAL_8250=y
CONFIG_SERIAL_OF_PLATFORM=y
CONFIG_SERIAL_SAMSUNG=y
CONFIG_SERIAL_SAMSUNG_CONSOLE=y
CONFIG_HW_RANDOM=y
CONFIG_TCG_TPM=y
CONFIG_TCG_TIS_I2C_INFINEON=y
CONFIG_I2C_CHARDEV=y
CONFIG_I2C_MUX=y
CONFIG_I2C_ARB_GPIO_CHALLENGE=y
CONFIG_I2C_GPIO=y
CONFIG_I2C_CROS_EC_TUNNEL=y
CONFIG_SPI=y
CONFIG_SPI_GPIO=y
CONFIG_SPI_S3C64XX=y
CONFIG_DEBUG_GPIO=y
CONFIG_GPIO_SYSFS=y
CONFIG_POWER_SUPPLY=y
CONFIG_BATTERY_SBS=y
CONFIG_BATTERY_MAX17040=y
CONFIG_BATTERY_MAX17042=y
CONFIG_CHARGER_MAX14577=y
CONFIG_CHARGER_MAX77693=y
CONFIG_CHARGER_MAX8997=y
CONFIG_CHARGER_TPS65090=y
CONFIG_SENSORS_LM90=y
CONFIG_SENSORS_NTC_THERMISTOR=y
CONFIG_SENSORS_PWM_FAN=y
CONFIG_SENSORS_INA2XX=y
CONFIG_CPU_THERMAL=y
CONFIG_THERMAL_EMULATION=y
CONFIG_WATCHDOG=y
CONFIG_S3C2410_WATCHDOG=y
CONFIG_MFD_CROS_EC=y
CONFIG_MFD_CROS_EC_I2C=y
CONFIG_MFD_CROS_EC_SPI=y
CONFIG_MFD_MAX14577=y
CONFIG_MFD_MAX77686=y
CONFIG_MFD_MAX77693=y
CONFIG_MFD_MAX8997=y
CONFIG_MFD_MAX8998=y
CONFIG_MFD_SEC_CORE=y
CONFIG_MFD_TPS65090=y
CONFIG_REGULATOR=y
CONFIG_REGULATOR_FIXED_VOLTAGE=y
CONFIG_REGULATOR_GPIO=y
CONFIG_REGULATOR_MAX14577=y
CONFIG_REGULATOR_MAX8997=y
CONFIG_REGULATOR_MAX8998=y
CONFIG_REGULATOR_MAX77686=y
CONFIG_REGULATOR_MAX77693=y
CONFIG_REGULATOR_MAX77802=y
CONFIG_REGULATOR_S2MPA01=y
CONFIG_REGULATOR_S2MPS11=y
CONFIG_REGULATOR_S5M8767=y
CONFIG_REGULATOR_TPS65090=y
CONFIG_MEDIA_SUPPORT=m
CONFIG_MEDIA_CAMERA_SUPPORT=y
CONFIG_MEDIA_USB_SUPPORT=y
CONFIG_USB_VIDEO_CLASS=m
CONFIG_DRM=y
CONFIG_DRM_EXYNOS=y
CONFIG_DRM_EXYNOS_FIMD=y
CONFIG_DRM_EXYNOS_MIXER=y
CONFIG_DRM_EXYNOS_DPI=y
CONFIG_DRM_EXYNOS_DSI=y
CONFIG_DRM_EXYNOS_HDMI=y
CONFIG_DRM_PANEL_SIMPLE=y
CONFIG_DRM_PANEL_SAMSUNG_LD9040=y
CONFIG_DRM_PANEL_SAMSUNG_S6E8AA0=y
CONFIG_DRM_NXP_PTN3460=y
CONFIG_DRM_PARADE_PS8622=y
CONFIG_EXYNOS_VIDEO=y
CONFIG_EXYNOS_MIPI_DSI=y
CONFIG_LCD_CLASS_DEVICE=y
CONFIG_LCD_PLATFORM=y
CONFIG_BACKLIGHT_PWM=y
CONFIG_LOGO=y
CONFIG_SOUND=y
CONFIG_SND=y
CONFIG_SND_SOC=y
CONFIG_SND_SOC_SAMSUNG=y
CONFIG_SND_SOC_SNOW=y
CONFIG_SND_SOC_ODROIDX2=y
CONFIG_SND_SIMPLE_CARD=y
CONFIG_USB=y
CONFIG_USB_ANNOUNCE_NEW_DEVICES=y
CONFIG_USB_XHCI_HCD=y
CONFIG_USB_EHCI_HCD=y
CONFIG_USB_EHCI_EXYNOS=y
CONFIG_USB_OHCI_HCD=y
CONFIG_USB_OHCI_EXYNOS=y
CONFIG_USB_STORAGE=y
CONFIG_USB_DWC3=y
CONFIG_USB_DWC2=y
CONFIG_USB_HSIC_USB3503=y
CONFIG_USB_GADGET=y
CONFIG_USB_ETH=y
CONFIG_MMC=y
CONFIG_MMC_BLOCK_MINORS=16
CONFIG_MMC_SDHCI=y
CONFIG_MMC_SDHCI_S3C=y
CONFIG_MMC_SDHCI_S3C_DMA=y
CONFIG_MMC_DW=y
CONFIG_MMC_DW_EXYNOS=y
CONFIG_NEW_LEDS=y
CONFIG_LEDS_CLASS=y
CONFIG_LEDS_CLASS_FLASH=y
CONFIG_LEDS_GPIO=y
CONFIG_LEDS_PWM=y
CONFIG_LEDS_MAX77693=y
CONFIG_LEDS_MAX8997=y
CONFIG_LEDS_TRIGGERS=y
CONFIG_LEDS_TRIGGER_HEARTBEAT=y
CONFIG_RTC_CLASS=y
CONFIG_RTC_DRV_MAX8997=y
CONFIG_RTC_DRV_MAX77686=y
CONFIG_RTC_DRV_S5M=y
CONFIG_RTC_DRV_S3C=y
CONFIG_DMADEVICES=y
CONFIG_PL330_DMA=y
CONFIG_CROS_EC_CHARDEV=y
CONFIG_COMMON_CLK_MAX77686=y
CONFIG_COMMON_CLK_MAX77802=y
CONFIG_COMMON_CLK_S2MPS11=y
CONFIG_EXYNOS_IOMMU=y
CONFIG_EXYNOS_IOMMU_DEBUG=y
CONFIG_ARM_SMMU=y
CONFIG_PM_DEVFREQ=y
CONFIG_DEVFREQ_GOV_PERFORMANCE=m
CONFIG_DEVFREQ_GOV_POWERSAVE=m
CONFIG_DEVFREQ_GOV_USERSPACE=m
CONFIG_ARM_EXYNOS_BUS_DEVFREQ=y
CONFIG_DEVFREQ_EVENT_EXYNOS_NOCP=y
CONFIG_EXTCON=y
CONFIG_EXTCON_ADC_JACK=y
CONFIG_EXTCON_GPIO=y
CONFIG_EXTCON_MAX14577=y
CONFIG_EXTCON_MAX77693=y
CONFIG_EXTCON_MAX8997=y
CONFIG_IIO=y
CONFIG_EXYNOS_ADC=y
CONFIG_PWM=y
CONFIG_PWM_SAMSUNG=y
CONFIG_PHY_EXYNOS5250_SATA=y
CONFIG_EXT2_FS=y
CONFIG_EXT3_FS=y
CONFIG_AUTOFS4_FS=y
CONFIG_MSDOS_FS=y
CONFIG_VFAT_FS=y
CONFIG_TMPFS=y
CONFIG_TMPFS_POSIX_ACL=y
CONFIG_CRAMFS=y
CONFIG_ROMFS_FS=y
CONFIG_NFS_FS=y
CONFIG_NFS_V4=y
CONFIG_ROOT_NFS=y
CONFIG_NLS_CODEPAGE_437=y
CONFIG_NLS_ASCII=y
CONFIG_NLS_ISO8859_1=y
CONFIG_PRINTK_TIME=y
CONFIG_DEBUG_INFO=y
CONFIG_MAGIC_SYSRQ=y
CONFIG_DEBUG_PAGEALLOC=y
CONFIG_DEBUG_OBJECTS=y
CONFIG_DEBUG_OBJECTS_SELFTEST=y
CONFIG_DEBUG_OBJECTS_FREE=y
CONFIG_DEBUG_OBJECTS_TIMERS=y
CONFIG_DEBUG_OBJECTS_WORK=y
CONFIG_DEBUG_OBJECTS_RCU_HEAD=y
CONFIG_DEBUG_OBJECTS_PERCPU_COUNTER=y
CONFIG_DEBUG_SHIRQ=y
CONFIG_LOCKUP_DETECTOR=y
CONFIG_SCHEDSTATS=y
CONFIG_SCHED_STACK_END_CHECK=y
CONFIG_TIMER_STATS=y
CONFIG_DEBUG_RT_MUTEXES=y
CONFIG_DEBUG_WW_MUTEX_SLOWPATH=y
CONFIG_PROVE_LOCKING=y
CONFIG_LOCK_STAT=y
CONFIG_DEBUG_LOCKDEP=y
CONFIG_DEBUG_ATOMIC_SLEEP=y
CONFIG_DEBUG_LOCKING_API_SELFTESTS=y
CONFIG_LOCK_TORTURE_TEST=m
CONFIG_DEBUG_PI_LIST=y
CONFIG_DEBUG_SG=y
CONFIG_DEBUG_NOTIFIERS=y
CONFIG_DEBUG_CREDENTIALS=y
CONFIG_PROVE_RCU_REPEATEDLY=y
CONFIG_SPARSE_RCU_POINTER=y
CONFIG_RCU_TORTURE_TEST=m
CONFIG_RCU_TORTURE_TEST_SLOW_PREINIT=y
CONFIG_RCU_TRACE=y
CONFIG_DEBUG_USER=y
CONFIG_CRYPTO_DEV_S5P=y
CONFIG_ARM_CRYPTO=y
CONFIG_CRYPTO_SHA1_ARM_NEON=m
CONFIG_CRYPTO_SHA256_ARM=m
CONFIG_CRYPTO_SHA512_ARM=m
CONFIG_CRYPTO_AES_ARM_BS=m
CONFIG_CRC_CCITT=y
CONFIG_FONTS=y
CONFIG_FONT_7x14=y

^ permalink raw reply	[flat|nested] 11+ messages in thread

* Re: Odroid XU4 deadlock
  2016-04-09 11:00       ` Krzysztof Kozlowski
@ 2016-04-11 15:33         ` Javier Martinez Canillas
  -1 siblings, 0 replies; 11+ messages in thread
From: Javier Martinez Canillas @ 2016-04-11 15:33 UTC (permalink / raw)
  To: Krzysztof Kozlowski, Anand Moon
  Cc: Viresh Kumar, Bartlomiej Zolnierkiewicz, Lukasz Majewski,
	linux-samsung-soc, Linux Kernel

Hello Krzysztof,

On 04/09/2016 07:00 AM, Krzysztof Kozlowski wrote:
> On Fri, Apr 8, 2016 at 5:36 PM, Anand Moon <linux.amoon@gmail.com> wrote:
>> hi Javier,
>>
>> On 8 April 2016 at 20:25, Javier Martinez Canillas
>> <javier@osg.samsung.com> wrote:
>>> Hello Anand,
>>>
>>> On 04/08/2016 09:51 AM, Anand Moon wrote:
>>>> Hi All,
>>>>
>>>> I am observing this deadlock or warning on my Odroid XU4.
>>>> I thinks the is related to clk from exynos5_i2c_xfer .... clk_prepare_enable
>>>> but I am not able to figure out which clk.
>>>>
>>>
>>> By reading your logs, it seems the problem is a possible ABBA deadlock since
>>> the S3C RTC driver grabs the prepare_lock and then the regmap->lock, and the
>>> CPUFreq driver leads to the locks being grabbed in the inverse order.
> 
> First of all this is not a deadlock. Yet. :) This is just lockdep

Yes, that's why I said the problem seemed to be a possible deadlock :)

> report of possible deadlock. This is deadlock:
> http://www.krzk.eu/builders/boot-odroid-xu3-multi_v7/builds/13/steps/Boot%20odroid/logs/serial
> 
> ...and I believe it is the same as the report from lockdep. Which
> means that this report truly a predicted deadlock. There are minor
> differences between deadlock on my board and report from Anand but
> still the same devices are involved. In Anands report the involved
> S2MPS11 regulator and S2MPS11 clock use the same regmap. In my case
> one path comes from S5M RTC which uses different regmap than S2MPS11
> clock. This is the difference which puzzles me.
> 

Yeah, that is puzzling indeed...

> Anyway this is known issue. In case of my board mentioned deadlock
> happens only on multi_v7 on around 15% of boots. I noticed it around
> v4.4 and it happens still.
> 
>>>
>>>> [   11.640221] ======================================================
>>>> [   11.646343] [ INFO: possible circular locking dependency detected ]
>>>> [   11.652590] 4.6.0-rc2-xu4ml #35 Not tainted
>>>> [   11.656749] -------------------------------------------------------
>>>> [   11.662992] kworker/1:1/85 is trying to acquire lock:
>>>> [   11.668010]  (prepare_lock){+.+...}, at: [<c05bfed8>]
>>>> clk_prepare_lock+0x50/0xf8
>>>> [   11.675375]
>>>> [   11.675375] but task is already holding lock:
>>>> [   11.681185]  (sec_core:428:(regmap)->lock){+.+...}, at:
>>>> [<c0481aec>] regmap_read+0x2c/0x5c
>>>> [   11.689417]
>>>> [   11.689417] which lock already depends on the new lock.
>>>> [   11.689417]
>>>> [   11.697561]
>>>> [   11.697561] the existing dependency chain (in reverse order) is:
>>>> [   11.705008]
>>>> [   11.705008] -> #1 (sec_core:428:(regmap)->lock){+.+...}:
>>>> [   11.710467]        [<c0482d30>] regmap_update_bits_base+0x30/0x70
>>>> [   11.716545]        [<c05c617c>] s2mps11_clk_prepare+0x30/0x38
>>>> [   11.722262]        [<c05c01f0>] clk_core_prepare+0x98/0xbc
>>>> [   11.727711]        [<c05c12bc>] clk_prepare+0x1c/0x2c
>>>> [   11.732734]        [<c0556fe4>] s3c_rtc_probe+0x2d0/0x43c
>>>
>>> the S3C RTC driver tries to prepare the RTC source clock S2MPS11_CLK_AP
>>> and that leads to the prepare_lock to be held and then the regmap->lock
>>> since s2mps11_clk_prepare() calls regmap_update_bits().
>>>
>>>> [   11.738108]        [<c046b9fc>] platform_drv_probe+0x4c/0xb0
>>>> [   11.743749]        [<c046a1fc>] driver_probe_device+0x20c/0x2b8
>>>> [   11.749641]        [<c0468594>] bus_for_each_drv+0x60/0x94
>>>> [   11.755103]        [<c0469f10>] __device_attach+0xb4/0x118
>>>> [   11.760558]        [<c04693b4>] bus_probe_device+0x88/0x90
>>>> [   11.766020]        [<c0469850>] deferred_probe_work_func+0x6c/0x9c
>>>> [   11.772169]        [<c013b52c>] process_one_work+0x1a8/0x514
>>>> [   11.777806]        [<c013b8d0>] worker_thread+0x38/0x56c
>>>> [   11.783082]        [<c0141d14>] kthread+0xf4/0x10c
>>>> [   11.787847]        [<c0107950>] ret_from_fork+0x14/0x24
>>>> [   11.793050]
>>>> [   11.793050] -> #0 (prepare_lock){+.+...}:
>>>> [   11.797212]        [<c0768dd8>] mutex_lock_nested+0x78/0x4dc
>>>> [   11.802845]        [<c05bfed8>] clk_prepare_lock+0x50/0xf8
>>>> [   11.808304]        [<c05c19c4>] clk_unprepare+0x1c/0x2c
>>>> [   11.813499]        [<c055d720>] exynos5_i2c_xfer+0x1dc/0x304
>>>
>>> and here the locks are grabbed in the inverse order, since the regulator
>>> driver uses regmap read (grabbing the regmap->lock) and then a clock is
>>> prepared in exynos5_i2c_xfer.
>>>
>>>> [   11.819129]        [<c0559620>] __i2c_transfer+0x13c/0x278
>>>> [   11.824589]        [<c05597f0>] i2c_transfer+0x94/0xc4
>>>> [   11.829701]        [<c04868f0>] regmap_i2c_read+0x48/0x64
>>>> [   11.835074]        [<c0482048>] _regmap_raw_read+0xb4/0x114
>>>> [   11.840630]        [<c04820cc>] _regmap_bus_read+0x24/0x58
>>>> [   11.846084]        [<c0481a68>] _regmap_read+0x60/0xb8
>>>> [   11.851201]        [<c0481afc>] regmap_read+0x3c/0x5c
>>>> [   11.856224]        [<c03e2354>] regulator_get_voltage_sel_regmap+0x20/0x54
>>>> [   11.863109]        [<c03dc5d4>] _regulator_get_voltage+0x20/0xb8
>>>> [   11.863141]        [<c03df058>] _regulator_do_set_voltage+0x240/0x370
>>>> [   11.863173]        [<c03df254>] regulator_set_voltage_unlocked+0xcc/0x230
>>>> [   11.863205]        [<c03df3e0>] regulator_set_voltage+0x28/0x54
>>>> [   11.863234]        [<c0478a94>] _set_opp_voltage+0x30/0x98
>>>> [   11.863264]        [<c0479ba8>] dev_pm_opp_set_rate+0x1e0/0x540
>>>> [   11.863337]        [<c0580824>] __cpufreq_driver_target+0x168/0x290
>>>> [   11.863375]        [<c0583b48>] od_dbs_timer+0xdc/0x164
>>>> [   11.863407]        [<c0584114>] dbs_work_handler+0x30/0x58
>>>> [   11.863437]        [<c013b52c>] process_one_work+0x1a8/0x514
>>>> [   11.863465]        [<c013b8d0>] worker_thread+0x38/0x56c
>>>> [   11.863496]        [<c0141d14>] kthread+0xf4/0x10c
>>>> [   11.863528]        [<c0107950>] ret_from_fork+0x14/0x24
>>>> [   11.863538]
>>>> [   11.863538] other info that might help us debug this:
>>>> [   11.863538]
>>>> [   11.863548]  Possible unsafe locking scenario:
>>>> [   11.863548]
>>>> [   11.863557]        CPU0                    CPU1
>>>> [   11.863565]        ----                    ----
>>>> [   11.863589]   lock(sec_core:428:(regmap)->lock);
>>>> [   11.863612]                                lock(prepare_lock);
>>>> [   11.863634]                                lock(sec_core:428:(regmap)->lock);
>>>> [   11.863655]   lock(prepare_lock);
>>>> [   11.863664]
>>>> [   11.863664]  *** DEADLOCK ***
>>>> [   11.863664]
>>>
>>> I should take a look in deep to the regmap and clock subsystems to better
>>> understand the issue on how to solve it. But AFAICT the problem is that
>>> the prepare_lock is a global mutex and the same regmap is used for both
>>> the s2mps11 clocks and regulators, so the ABBA deadlock described below
>>> can happen.
> 
> Exactly. One of ideas I remember was to make clocks mutex more
> granular but I did not see any patches doing that. Another interesting
> point is (in my case) deadlock itself (not lockdep report) happens
> only on multi_v7, not on exynos defconfig.
> 

I see that RTC_DRV_S5M is enabled as a module in multi_v7 but built-in
in exynos_defconfig. Maybe that could cause the behavior difference?

> BTW, Anand, if you report please provide more details for
> reproduction: kernel config and reproduction steps.
>

I see that Anand provided his defconfig, so I'll try to reproduce the
lockdep report and look at the issue deeper this week.
 
> Best regards,
> Krzysztof
> 

Best regards,
-- 
Javier Martinez Canillas
Open Source Group
Samsung Research America

^ permalink raw reply	[flat|nested] 11+ messages in thread

* Re: Odroid XU4 deadlock
@ 2016-04-11 15:33         ` Javier Martinez Canillas
  0 siblings, 0 replies; 11+ messages in thread
From: Javier Martinez Canillas @ 2016-04-11 15:33 UTC (permalink / raw)
  To: Krzysztof Kozlowski, Anand Moon
  Cc: Viresh Kumar, Bartlomiej Zolnierkiewicz, Lukasz Majewski,
	linux-samsung-soc, Linux Kernel

Hello Krzysztof,

On 04/09/2016 07:00 AM, Krzysztof Kozlowski wrote:
> On Fri, Apr 8, 2016 at 5:36 PM, Anand Moon <linux.amoon@gmail.com> wrote:
>> hi Javier,
>>
>> On 8 April 2016 at 20:25, Javier Martinez Canillas
>> <javier@osg.samsung.com> wrote:
>>> Hello Anand,
>>>
>>> On 04/08/2016 09:51 AM, Anand Moon wrote:
>>>> Hi All,
>>>>
>>>> I am observing this deadlock or warning on my Odroid XU4.
>>>> I thinks the is related to clk from exynos5_i2c_xfer .... clk_prepare_enable
>>>> but I am not able to figure out which clk.
>>>>
>>>
>>> By reading your logs, it seems the problem is a possible ABBA deadlock since
>>> the S3C RTC driver grabs the prepare_lock and then the regmap->lock, and the
>>> CPUFreq driver leads to the locks being grabbed in the inverse order.
> 
> First of all this is not a deadlock. Yet. :) This is just lockdep

Yes, that's why I said the problem seemed to be a possible deadlock :)

> report of possible deadlock. This is deadlock:
> http://www.krzk.eu/builders/boot-odroid-xu3-multi_v7/builds/13/steps/Boot%20odroid/logs/serial
> 
> ...and I believe it is the same as the report from lockdep. Which
> means that this report truly a predicted deadlock. There are minor
> differences between deadlock on my board and report from Anand but
> still the same devices are involved. In Anands report the involved
> S2MPS11 regulator and S2MPS11 clock use the same regmap. In my case
> one path comes from S5M RTC which uses different regmap than S2MPS11
> clock. This is the difference which puzzles me.
> 

Yeah, that is puzzling indeed...

> Anyway this is known issue. In case of my board mentioned deadlock
> happens only on multi_v7 on around 15% of boots. I noticed it around
> v4.4 and it happens still.
> 
>>>
>>>> [   11.640221] ======================================================
>>>> [   11.646343] [ INFO: possible circular locking dependency detected ]
>>>> [   11.652590] 4.6.0-rc2-xu4ml #35 Not tainted
>>>> [   11.656749] -------------------------------------------------------
>>>> [   11.662992] kworker/1:1/85 is trying to acquire lock:
>>>> [   11.668010]  (prepare_lock){+.+...}, at: [<c05bfed8>]
>>>> clk_prepare_lock+0x50/0xf8
>>>> [   11.675375]
>>>> [   11.675375] but task is already holding lock:
>>>> [   11.681185]  (sec_core:428:(regmap)->lock){+.+...}, at:
>>>> [<c0481aec>] regmap_read+0x2c/0x5c
>>>> [   11.689417]
>>>> [   11.689417] which lock already depends on the new lock.
>>>> [   11.689417]
>>>> [   11.697561]
>>>> [   11.697561] the existing dependency chain (in reverse order) is:
>>>> [   11.705008]
>>>> [   11.705008] -> #1 (sec_core:428:(regmap)->lock){+.+...}:
>>>> [   11.710467]        [<c0482d30>] regmap_update_bits_base+0x30/0x70
>>>> [   11.716545]        [<c05c617c>] s2mps11_clk_prepare+0x30/0x38
>>>> [   11.722262]        [<c05c01f0>] clk_core_prepare+0x98/0xbc
>>>> [   11.727711]        [<c05c12bc>] clk_prepare+0x1c/0x2c
>>>> [   11.732734]        [<c0556fe4>] s3c_rtc_probe+0x2d0/0x43c
>>>
>>> the S3C RTC driver tries to prepare the RTC source clock S2MPS11_CLK_AP
>>> and that leads to the prepare_lock to be held and then the regmap->lock
>>> since s2mps11_clk_prepare() calls regmap_update_bits().
>>>
>>>> [   11.738108]        [<c046b9fc>] platform_drv_probe+0x4c/0xb0
>>>> [   11.743749]        [<c046a1fc>] driver_probe_device+0x20c/0x2b8
>>>> [   11.749641]        [<c0468594>] bus_for_each_drv+0x60/0x94
>>>> [   11.755103]        [<c0469f10>] __device_attach+0xb4/0x118
>>>> [   11.760558]        [<c04693b4>] bus_probe_device+0x88/0x90
>>>> [   11.766020]        [<c0469850>] deferred_probe_work_func+0x6c/0x9c
>>>> [   11.772169]        [<c013b52c>] process_one_work+0x1a8/0x514
>>>> [   11.777806]        [<c013b8d0>] worker_thread+0x38/0x56c
>>>> [   11.783082]        [<c0141d14>] kthread+0xf4/0x10c
>>>> [   11.787847]        [<c0107950>] ret_from_fork+0x14/0x24
>>>> [   11.793050]
>>>> [   11.793050] -> #0 (prepare_lock){+.+...}:
>>>> [   11.797212]        [<c0768dd8>] mutex_lock_nested+0x78/0x4dc
>>>> [   11.802845]        [<c05bfed8>] clk_prepare_lock+0x50/0xf8
>>>> [   11.808304]        [<c05c19c4>] clk_unprepare+0x1c/0x2c
>>>> [   11.813499]        [<c055d720>] exynos5_i2c_xfer+0x1dc/0x304
>>>
>>> and here the locks are grabbed in the inverse order, since the regulator
>>> driver uses regmap read (grabbing the regmap->lock) and then a clock is
>>> prepared in exynos5_i2c_xfer.
>>>
>>>> [   11.819129]        [<c0559620>] __i2c_transfer+0x13c/0x278
>>>> [   11.824589]        [<c05597f0>] i2c_transfer+0x94/0xc4
>>>> [   11.829701]        [<c04868f0>] regmap_i2c_read+0x48/0x64
>>>> [   11.835074]        [<c0482048>] _regmap_raw_read+0xb4/0x114
>>>> [   11.840630]        [<c04820cc>] _regmap_bus_read+0x24/0x58
>>>> [   11.846084]        [<c0481a68>] _regmap_read+0x60/0xb8
>>>> [   11.851201]        [<c0481afc>] regmap_read+0x3c/0x5c
>>>> [   11.856224]        [<c03e2354>] regulator_get_voltage_sel_regmap+0x20/0x54
>>>> [   11.863109]        [<c03dc5d4>] _regulator_get_voltage+0x20/0xb8
>>>> [   11.863141]        [<c03df058>] _regulator_do_set_voltage+0x240/0x370
>>>> [   11.863173]        [<c03df254>] regulator_set_voltage_unlocked+0xcc/0x230
>>>> [   11.863205]        [<c03df3e0>] regulator_set_voltage+0x28/0x54
>>>> [   11.863234]        [<c0478a94>] _set_opp_voltage+0x30/0x98
>>>> [   11.863264]        [<c0479ba8>] dev_pm_opp_set_rate+0x1e0/0x540
>>>> [   11.863337]        [<c0580824>] __cpufreq_driver_target+0x168/0x290
>>>> [   11.863375]        [<c0583b48>] od_dbs_timer+0xdc/0x164
>>>> [   11.863407]        [<c0584114>] dbs_work_handler+0x30/0x58
>>>> [   11.863437]        [<c013b52c>] process_one_work+0x1a8/0x514
>>>> [   11.863465]        [<c013b8d0>] worker_thread+0x38/0x56c
>>>> [   11.863496]        [<c0141d14>] kthread+0xf4/0x10c
>>>> [   11.863528]        [<c0107950>] ret_from_fork+0x14/0x24
>>>> [   11.863538]
>>>> [   11.863538] other info that might help us debug this:
>>>> [   11.863538]
>>>> [   11.863548]  Possible unsafe locking scenario:
>>>> [   11.863548]
>>>> [   11.863557]        CPU0                    CPU1
>>>> [   11.863565]        ----                    ----
>>>> [   11.863589]   lock(sec_core:428:(regmap)->lock);
>>>> [   11.863612]                                lock(prepare_lock);
>>>> [   11.863634]                                lock(sec_core:428:(regmap)->lock);
>>>> [   11.863655]   lock(prepare_lock);
>>>> [   11.863664]
>>>> [   11.863664]  *** DEADLOCK ***
>>>> [   11.863664]
>>>
>>> I should take a look in deep to the regmap and clock subsystems to better
>>> understand the issue on how to solve it. But AFAICT the problem is that
>>> the prepare_lock is a global mutex and the same regmap is used for both
>>> the s2mps11 clocks and regulators, so the ABBA deadlock described below
>>> can happen.
> 
> Exactly. One of ideas I remember was to make clocks mutex more
> granular but I did not see any patches doing that. Another interesting
> point is (in my case) deadlock itself (not lockdep report) happens
> only on multi_v7, not on exynos defconfig.
> 

I see that RTC_DRV_S5M is enabled as a module in multi_v7 but built-in
in exynos_defconfig. Maybe that could cause the behavior difference?

> BTW, Anand, if you report please provide more details for
> reproduction: kernel config and reproduction steps.
>

I see that Anand provided his defconfig, so I'll try to reproduce the
lockdep report and look at the issue deeper this week.
 
> Best regards,
> Krzysztof
> 

Best regards,
-- 
Javier Martinez Canillas
Open Source Group
Samsung Research America

^ permalink raw reply	[flat|nested] 11+ messages in thread

end of thread, other threads:[~2016-04-11 15:34 UTC | newest]

Thread overview: 11+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2016-04-08 13:51 Odroid XU4 deadlock Anand Moon
2016-04-08 13:51 ` Anand Moon
2016-04-08 14:55 ` Javier Martinez Canillas
2016-04-08 14:55   ` Javier Martinez Canillas
2016-04-08 15:36   ` Anand Moon
2016-04-09 11:00     ` Krzysztof Kozlowski
2016-04-09 11:00       ` Krzysztof Kozlowski
2016-04-11  4:35       ` Anand Moon
2016-04-11  4:35         ` Anand Moon
2016-04-11 15:33       ` Javier Martinez Canillas
2016-04-11 15:33         ` Javier Martinez Canillas

This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.