kernel/dma/debug.c | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-)
__dma_entry_alloc_check_leak() calls printk -> serial console
output (qcom geni) and grabs port->lock under free_entries_lock,
which is a conflicting locking dependency chain as qcom_geni IRQ
handler can call into dma-debug code and grab free_entries_lock
under port->lock.
Use deferred printk in __dma_entry_alloc_check_leak() so that we
don't acquire serial console's port->lock under free_entries_lock.
Trimmed-down lockdep splat:
The existing dependency chain (in reverse order) is:
-> #2 (free_entries_lock){-.-.}-{2:2}:
_raw_spin_lock_irqsave+0x60/0x80
dma_entry_alloc+0x38/0x110
debug_dma_map_page+0x60/0xf8
dma_map_page_attrs+0x1e0/0x230
dma_map_single_attrs.constprop.0+0x6c/0xc8
geni_se_rx_dma_prep+0x40/0xcc
qcom_geni_serial_isr+0x310/0x510
__handle_irq_event_percpu+0x110/0x244
handle_irq_event_percpu+0x20/0x54
handle_irq_event+0x50/0x88
handle_fasteoi_irq+0xa4/0xcc
handle_irq_desc+0x28/0x40
generic_handle_domain_irq+0x24/0x30
gic_handle_irq+0xc4/0x148
do_interrupt_handler+0xa4/0xb0
el1_interrupt+0x34/0x64
el1h_64_irq_handler+0x18/0x24
el1h_64_irq+0x64/0x68
arch_local_irq_enable+0x4/0x8
____do_softirq+0x18/0x24
...
-> #1 (&port_lock_key){-.-.}-{2:2}:
_raw_spin_lock_irqsave+0x60/0x80
qcom_geni_serial_console_write+0x184/0x1dc
console_flush_all+0x344/0x454
console_unlock+0x94/0xf0
vprintk_emit+0x238/0x24c
vprintk_default+0x3c/0x48
vprintk+0xb4/0xbc
_printk+0x68/0x90
register_console+0x230/0x38c
uart_add_one_port+0x338/0x494
qcom_geni_serial_probe+0x390/0x424
platform_probe+0x70/0xc0
really_probe+0x148/0x280
__driver_probe_device+0xfc/0x114
driver_probe_device+0x44/0x100
__device_attach_driver+0x64/0xdc
bus_for_each_drv+0xb0/0xd8
__device_attach+0xe4/0x140
device_initial_probe+0x1c/0x28
bus_probe_device+0x44/0xb0
device_add+0x538/0x668
of_device_add+0x44/0x50
of_platform_device_create_pdata+0x94/0xc8
of_platform_bus_create+0x270/0x304
of_platform_populate+0xac/0xc4
devm_of_platform_populate+0x60/0xac
geni_se_probe+0x154/0x160
platform_probe+0x70/0xc0
...
-> #0 (console_owner){-...}-{0:0}:
__lock_acquire+0xdf8/0x109c
lock_acquire+0x234/0x284
console_flush_all+0x330/0x454
console_unlock+0x94/0xf0
vprintk_emit+0x238/0x24c
vprintk_default+0x3c/0x48
vprintk+0xb4/0xbc
_printk+0x68/0x90
dma_entry_alloc+0xb4/0x110
debug_dma_map_sg+0xdc/0x2f8
__dma_map_sg_attrs+0xac/0xe4
dma_map_sgtable+0x30/0x4c
get_pages+0x1d4/0x1e4 [msm]
msm_gem_pin_pages_locked+0x38/0xac [msm]
msm_gem_pin_vma_locked+0x58/0x88 [msm]
msm_ioctl_gem_submit+0xde4/0x13ac [msm]
drm_ioctl_kernel+0xe0/0x15c
drm_ioctl+0x2e8/0x3f4
vfs_ioctl+0x30/0x50
...
Chain exists of:
console_owner --> &port_lock_key --> free_entries_lock
Possible unsafe locking scenario:
CPU0 CPU1
---- ----
lock(free_entries_lock);
lock(&port_lock_key);
lock(free_entries_lock);
lock(console_owner);
*** DEADLOCK ***
Call trace:
dump_backtrace+0xb4/0xf0
show_stack+0x20/0x30
dump_stack_lvl+0x60/0x84
dump_stack+0x18/0x24
print_circular_bug+0x1cc/0x234
check_noncircular+0x78/0xac
__lock_acquire+0xdf8/0x109c
lock_acquire+0x234/0x284
console_flush_all+0x330/0x454
console_unlock+0x94/0xf0
vprintk_emit+0x238/0x24c
vprintk_default+0x3c/0x48
vprintk+0xb4/0xbc
_printk+0x68/0x90
dma_entry_alloc+0xb4/0x110
debug_dma_map_sg+0xdc/0x2f8
__dma_map_sg_attrs+0xac/0xe4
dma_map_sgtable+0x30/0x4c
get_pages+0x1d4/0x1e4 [msm]
msm_gem_pin_pages_locked+0x38/0xac [msm]
msm_gem_pin_vma_locked+0x58/0x88 [msm]
msm_ioctl_gem_submit+0xde4/0x13ac [msm]
drm_ioctl_kernel+0xe0/0x15c
drm_ioctl+0x2e8/0x3f4
vfs_ioctl+0x30/0x50
...
Reported-by: Rob Clark <robdclark@chromium.org>
Signed-off-by: Sergey Senozhatsky <senozhatsky@chromium.org>
---
kernel/dma/debug.c | 6 +++---
1 file changed, 3 insertions(+), 3 deletions(-)
diff --git a/kernel/dma/debug.c b/kernel/dma/debug.c
index f190651bcadd..9e11ceadc69d 100644
--- a/kernel/dma/debug.c
+++ b/kernel/dma/debug.c
@@ -643,9 +643,9 @@ static void __dma_entry_alloc_check_leak(void)
/* Shout each time we tick over some multiple of the initial pool */
if (tmp < DMA_DEBUG_DYNAMIC_ENTRIES) {
- pr_info("dma_debug_entry pool grown to %u (%u00%%)\n",
- nr_total_entries,
- (nr_total_entries / nr_prealloc_entries));
+ printk_deferred(KERN_INFO "dma_debug_entry pool grown to %u (%u00%%)\n",
+ nr_total_entries,
+ (nr_total_entries / nr_prealloc_entries));
}
}
--
2.41.0.694.ge786442a9b-googOn 15/08/2023 4:26 pm, Sergey Senozhatsky wrote:
> __dma_entry_alloc_check_leak() calls printk -> serial console
> output (qcom geni) and grabs port->lock under free_entries_lock,
> which is a conflicting locking dependency chain as qcom_geni IRQ
> handler can call into dma-debug code and grab free_entries_lock
> under port->lock.
>
> Use deferred printk in __dma_entry_alloc_check_leak() so that we
> don't acquire serial console's port->lock under free_entries_lock.
Hmm, the print really doesn't need to be under the lock anyway, it only
needs to key off whether the "num_free_entries == 0" condition was hit
or not. TBH I think I'd rather just shuffle that code around a bit than
have to remember the significance of magic printk variants.
Thanks,
Robin.
>
> Trimmed-down lockdep splat:
>
> The existing dependency chain (in reverse order) is:
>
> -> #2 (free_entries_lock){-.-.}-{2:2}:
> _raw_spin_lock_irqsave+0x60/0x80
> dma_entry_alloc+0x38/0x110
> debug_dma_map_page+0x60/0xf8
> dma_map_page_attrs+0x1e0/0x230
> dma_map_single_attrs.constprop.0+0x6c/0xc8
> geni_se_rx_dma_prep+0x40/0xcc
> qcom_geni_serial_isr+0x310/0x510
> __handle_irq_event_percpu+0x110/0x244
> handle_irq_event_percpu+0x20/0x54
> handle_irq_event+0x50/0x88
> handle_fasteoi_irq+0xa4/0xcc
> handle_irq_desc+0x28/0x40
> generic_handle_domain_irq+0x24/0x30
> gic_handle_irq+0xc4/0x148
> do_interrupt_handler+0xa4/0xb0
> el1_interrupt+0x34/0x64
> el1h_64_irq_handler+0x18/0x24
> el1h_64_irq+0x64/0x68
> arch_local_irq_enable+0x4/0x8
> ____do_softirq+0x18/0x24
> ...
>
> -> #1 (&port_lock_key){-.-.}-{2:2}:
> _raw_spin_lock_irqsave+0x60/0x80
> qcom_geni_serial_console_write+0x184/0x1dc
> console_flush_all+0x344/0x454
> console_unlock+0x94/0xf0
> vprintk_emit+0x238/0x24c
> vprintk_default+0x3c/0x48
> vprintk+0xb4/0xbc
> _printk+0x68/0x90
> register_console+0x230/0x38c
> uart_add_one_port+0x338/0x494
> qcom_geni_serial_probe+0x390/0x424
> platform_probe+0x70/0xc0
> really_probe+0x148/0x280
> __driver_probe_device+0xfc/0x114
> driver_probe_device+0x44/0x100
> __device_attach_driver+0x64/0xdc
> bus_for_each_drv+0xb0/0xd8
> __device_attach+0xe4/0x140
> device_initial_probe+0x1c/0x28
> bus_probe_device+0x44/0xb0
> device_add+0x538/0x668
> of_device_add+0x44/0x50
> of_platform_device_create_pdata+0x94/0xc8
> of_platform_bus_create+0x270/0x304
> of_platform_populate+0xac/0xc4
> devm_of_platform_populate+0x60/0xac
> geni_se_probe+0x154/0x160
> platform_probe+0x70/0xc0
> ...
>
> -> #0 (console_owner){-...}-{0:0}:
> __lock_acquire+0xdf8/0x109c
> lock_acquire+0x234/0x284
> console_flush_all+0x330/0x454
> console_unlock+0x94/0xf0
> vprintk_emit+0x238/0x24c
> vprintk_default+0x3c/0x48
> vprintk+0xb4/0xbc
> _printk+0x68/0x90
> dma_entry_alloc+0xb4/0x110
> debug_dma_map_sg+0xdc/0x2f8
> __dma_map_sg_attrs+0xac/0xe4
> dma_map_sgtable+0x30/0x4c
> get_pages+0x1d4/0x1e4 [msm]
> msm_gem_pin_pages_locked+0x38/0xac [msm]
> msm_gem_pin_vma_locked+0x58/0x88 [msm]
> msm_ioctl_gem_submit+0xde4/0x13ac [msm]
> drm_ioctl_kernel+0xe0/0x15c
> drm_ioctl+0x2e8/0x3f4
> vfs_ioctl+0x30/0x50
> ...
>
> Chain exists of:
> console_owner --> &port_lock_key --> free_entries_lock
>
> Possible unsafe locking scenario:
>
> CPU0 CPU1
> ---- ----
> lock(free_entries_lock);
> lock(&port_lock_key);
> lock(free_entries_lock);
> lock(console_owner);
>
> *** DEADLOCK ***
>
> Call trace:
> dump_backtrace+0xb4/0xf0
> show_stack+0x20/0x30
> dump_stack_lvl+0x60/0x84
> dump_stack+0x18/0x24
> print_circular_bug+0x1cc/0x234
> check_noncircular+0x78/0xac
> __lock_acquire+0xdf8/0x109c
> lock_acquire+0x234/0x284
> console_flush_all+0x330/0x454
> console_unlock+0x94/0xf0
> vprintk_emit+0x238/0x24c
> vprintk_default+0x3c/0x48
> vprintk+0xb4/0xbc
> _printk+0x68/0x90
> dma_entry_alloc+0xb4/0x110
> debug_dma_map_sg+0xdc/0x2f8
> __dma_map_sg_attrs+0xac/0xe4
> dma_map_sgtable+0x30/0x4c
> get_pages+0x1d4/0x1e4 [msm]
> msm_gem_pin_pages_locked+0x38/0xac [msm]
> msm_gem_pin_vma_locked+0x58/0x88 [msm]
> msm_ioctl_gem_submit+0xde4/0x13ac [msm]
> drm_ioctl_kernel+0xe0/0x15c
> drm_ioctl+0x2e8/0x3f4
> vfs_ioctl+0x30/0x50
> ...
>
> Reported-by: Rob Clark <robdclark@chromium.org>
> Signed-off-by: Sergey Senozhatsky <senozhatsky@chromium.org>
> ---
> kernel/dma/debug.c | 6 +++---
> 1 file changed, 3 insertions(+), 3 deletions(-)
>
> diff --git a/kernel/dma/debug.c b/kernel/dma/debug.c
> index f190651bcadd..9e11ceadc69d 100644
> --- a/kernel/dma/debug.c
> +++ b/kernel/dma/debug.c
> @@ -643,9 +643,9 @@ static void __dma_entry_alloc_check_leak(void)
>
> /* Shout each time we tick over some multiple of the initial pool */
> if (tmp < DMA_DEBUG_DYNAMIC_ENTRIES) {
> - pr_info("dma_debug_entry pool grown to %u (%u00%%)\n",
> - nr_total_entries,
> - (nr_total_entries / nr_prealloc_entries));
> + printk_deferred(KERN_INFO "dma_debug_entry pool grown to %u (%u00%%)\n",
> + nr_total_entries,
> + (nr_total_entries / nr_prealloc_entries));
> }
> }
>
On (23/08/15 17:42), Robin Murphy wrote: > On 15/08/2023 4:26 pm, Sergey Senozhatsky wrote: > > __dma_entry_alloc_check_leak() calls printk -> serial console > > output (qcom geni) and grabs port->lock under free_entries_lock, > > which is a conflicting locking dependency chain as qcom_geni IRQ > > handler can call into dma-debug code and grab free_entries_lock > > under port->lock. > > > > Use deferred printk in __dma_entry_alloc_check_leak() so that we > > don't acquire serial console's port->lock under free_entries_lock. > > Hmm, the print really doesn't need to be under the lock anyway, it only > needs to key off whether the "num_free_entries == 0" condition was hit or > not. I thought about it, briefly. __dma_entry_alloc_check_leak() reads global nr_total_entries / nr_prealloc_entries which are updated (inc/dec) under free_entries_lock, so I didn't want to move __dma_entry_alloc_check_leak() outside of free_entries_lock scope.
On (23/08/16 01:52), Sergey Senozhatsky wrote:
> On (23/08/15 17:42), Robin Murphy wrote:
> > On 15/08/2023 4:26 pm, Sergey Senozhatsky wrote:
> > > __dma_entry_alloc_check_leak() calls printk -> serial console
> > > output (qcom geni) and grabs port->lock under free_entries_lock,
> > > which is a conflicting locking dependency chain as qcom_geni IRQ
> > > handler can call into dma-debug code and grab free_entries_lock
> > > under port->lock.
> > >
> > > Use deferred printk in __dma_entry_alloc_check_leak() so that we
> > > don't acquire serial console's port->lock under free_entries_lock.
> >
> > Hmm, the print really doesn't need to be under the lock anyway, it only
> > needs to key off whether the "num_free_entries == 0" condition was hit or
> > not.
>
> I thought about it, briefly. __dma_entry_alloc_check_leak() reads
> global nr_total_entries / nr_prealloc_entries which are updated
> (inc/dec) under free_entries_lock, so I didn't want to move
> __dma_entry_alloc_check_leak() outside of free_entries_lock scope.
Something like this?
---
diff --git a/kernel/dma/debug.c b/kernel/dma/debug.c
index 9e11ceadc69d..ca0508de4e78 100644
--- a/kernel/dma/debug.c
+++ b/kernel/dma/debug.c
@@ -637,15 +637,15 @@ static struct dma_debug_entry *__dma_entry_alloc(void)
return entry;
}
-static void __dma_entry_alloc_check_leak(void)
+static void __dma_entry_alloc_check_leak(u32 total_entries)
{
- u32 tmp = nr_total_entries % nr_prealloc_entries;
+ u32 tmp = total_entries % nr_prealloc_entries;
/* Shout each time we tick over some multiple of the initial pool */
if (tmp < DMA_DEBUG_DYNAMIC_ENTRIES) {
- printk_deferred(KERN_INFO "dma_debug_entry pool grown to %u (%u00%%)\n",
- nr_total_entries,
- (nr_total_entries / nr_prealloc_entries));
+ pr_info("dma_debug_entry pool grown to %u (%u00%%)\n",
+ total_entries,
+ (total_entries / nr_prealloc_entries));
}
}
@@ -658,6 +658,8 @@ static struct dma_debug_entry *dma_entry_alloc(void)
{
struct dma_debug_entry *entry;
unsigned long flags;
+ bool alloc_check_leak = false;
+ u32 total_entries;
spin_lock_irqsave(&free_entries_lock, flags);
if (num_free_entries == 0) {
@@ -667,13 +669,17 @@ static struct dma_debug_entry *dma_entry_alloc(void)
pr_err("debugging out of memory - disabling\n");
return NULL;
}
- __dma_entry_alloc_check_leak();
+ alloc_check_leak = true;
+ total_entries = nr_total_entries;
}
entry = __dma_entry_alloc();
spin_unlock_irqrestore(&free_entries_lock, flags);
+ if (alloc_check_leak)
+ __dma_entry_alloc_check_leak(total_entries);
+
#ifdef CONFIG_STACKTRACE
entry->stack_len = stack_trace_save(entry->stack_entries,
ARRAY_SIZE(entry->stack_entries),
On Tue, Aug 15, 2023 at 8:28 AM Sergey Senozhatsky
<senozhatsky@chromium.org> wrote:
>
> __dma_entry_alloc_check_leak() calls printk -> serial console
> output (qcom geni) and grabs port->lock under free_entries_lock,
> which is a conflicting locking dependency chain as qcom_geni IRQ
> handler can call into dma-debug code and grab free_entries_lock
> under port->lock.
>
> Use deferred printk in __dma_entry_alloc_check_leak() so that we
> don't acquire serial console's port->lock under free_entries_lock.
>
> Trimmed-down lockdep splat:
>
> The existing dependency chain (in reverse order) is:
>
> -> #2 (free_entries_lock){-.-.}-{2:2}:
> _raw_spin_lock_irqsave+0x60/0x80
> dma_entry_alloc+0x38/0x110
> debug_dma_map_page+0x60/0xf8
> dma_map_page_attrs+0x1e0/0x230
> dma_map_single_attrs.constprop.0+0x6c/0xc8
> geni_se_rx_dma_prep+0x40/0xcc
> qcom_geni_serial_isr+0x310/0x510
> __handle_irq_event_percpu+0x110/0x244
> handle_irq_event_percpu+0x20/0x54
> handle_irq_event+0x50/0x88
> handle_fasteoi_irq+0xa4/0xcc
> handle_irq_desc+0x28/0x40
> generic_handle_domain_irq+0x24/0x30
> gic_handle_irq+0xc4/0x148
> do_interrupt_handler+0xa4/0xb0
> el1_interrupt+0x34/0x64
> el1h_64_irq_handler+0x18/0x24
> el1h_64_irq+0x64/0x68
> arch_local_irq_enable+0x4/0x8
> ____do_softirq+0x18/0x24
> ...
>
> -> #1 (&port_lock_key){-.-.}-{2:2}:
> _raw_spin_lock_irqsave+0x60/0x80
> qcom_geni_serial_console_write+0x184/0x1dc
> console_flush_all+0x344/0x454
> console_unlock+0x94/0xf0
> vprintk_emit+0x238/0x24c
> vprintk_default+0x3c/0x48
> vprintk+0xb4/0xbc
> _printk+0x68/0x90
> register_console+0x230/0x38c
> uart_add_one_port+0x338/0x494
> qcom_geni_serial_probe+0x390/0x424
> platform_probe+0x70/0xc0
> really_probe+0x148/0x280
> __driver_probe_device+0xfc/0x114
> driver_probe_device+0x44/0x100
> __device_attach_driver+0x64/0xdc
> bus_for_each_drv+0xb0/0xd8
> __device_attach+0xe4/0x140
> device_initial_probe+0x1c/0x28
> bus_probe_device+0x44/0xb0
> device_add+0x538/0x668
> of_device_add+0x44/0x50
> of_platform_device_create_pdata+0x94/0xc8
> of_platform_bus_create+0x270/0x304
> of_platform_populate+0xac/0xc4
> devm_of_platform_populate+0x60/0xac
> geni_se_probe+0x154/0x160
> platform_probe+0x70/0xc0
> ...
>
> -> #0 (console_owner){-...}-{0:0}:
> __lock_acquire+0xdf8/0x109c
> lock_acquire+0x234/0x284
> console_flush_all+0x330/0x454
> console_unlock+0x94/0xf0
> vprintk_emit+0x238/0x24c
> vprintk_default+0x3c/0x48
> vprintk+0xb4/0xbc
> _printk+0x68/0x90
> dma_entry_alloc+0xb4/0x110
> debug_dma_map_sg+0xdc/0x2f8
> __dma_map_sg_attrs+0xac/0xe4
> dma_map_sgtable+0x30/0x4c
> get_pages+0x1d4/0x1e4 [msm]
> msm_gem_pin_pages_locked+0x38/0xac [msm]
> msm_gem_pin_vma_locked+0x58/0x88 [msm]
> msm_ioctl_gem_submit+0xde4/0x13ac [msm]
> drm_ioctl_kernel+0xe0/0x15c
> drm_ioctl+0x2e8/0x3f4
> vfs_ioctl+0x30/0x50
> ...
>
> Chain exists of:
> console_owner --> &port_lock_key --> free_entries_lock
>
> Possible unsafe locking scenario:
>
> CPU0 CPU1
> ---- ----
> lock(free_entries_lock);
> lock(&port_lock_key);
> lock(free_entries_lock);
> lock(console_owner);
>
> *** DEADLOCK ***
>
> Call trace:
> dump_backtrace+0xb4/0xf0
> show_stack+0x20/0x30
> dump_stack_lvl+0x60/0x84
> dump_stack+0x18/0x24
> print_circular_bug+0x1cc/0x234
> check_noncircular+0x78/0xac
> __lock_acquire+0xdf8/0x109c
> lock_acquire+0x234/0x284
> console_flush_all+0x330/0x454
> console_unlock+0x94/0xf0
> vprintk_emit+0x238/0x24c
> vprintk_default+0x3c/0x48
> vprintk+0xb4/0xbc
> _printk+0x68/0x90
> dma_entry_alloc+0xb4/0x110
> debug_dma_map_sg+0xdc/0x2f8
> __dma_map_sg_attrs+0xac/0xe4
> dma_map_sgtable+0x30/0x4c
> get_pages+0x1d4/0x1e4 [msm]
> msm_gem_pin_pages_locked+0x38/0xac [msm]
> msm_gem_pin_vma_locked+0x58/0x88 [msm]
> msm_ioctl_gem_submit+0xde4/0x13ac [msm]
> drm_ioctl_kernel+0xe0/0x15c
> drm_ioctl+0x2e8/0x3f4
> vfs_ioctl+0x30/0x50
> ...
>
> Reported-by: Rob Clark <robdclark@chromium.org>
> Signed-off-by: Sergey Senozhatsky <senozhatsky@chromium.org>
Tested-by: Rob Clark <robdclark@chromium.org>
> ---
> kernel/dma/debug.c | 6 +++---
> 1 file changed, 3 insertions(+), 3 deletions(-)
>
> diff --git a/kernel/dma/debug.c b/kernel/dma/debug.c
> index f190651bcadd..9e11ceadc69d 100644
> --- a/kernel/dma/debug.c
> +++ b/kernel/dma/debug.c
> @@ -643,9 +643,9 @@ static void __dma_entry_alloc_check_leak(void)
>
> /* Shout each time we tick over some multiple of the initial pool */
> if (tmp < DMA_DEBUG_DYNAMIC_ENTRIES) {
> - pr_info("dma_debug_entry pool grown to %u (%u00%%)\n",
> - nr_total_entries,
> - (nr_total_entries / nr_prealloc_entries));
> + printk_deferred(KERN_INFO "dma_debug_entry pool grown to %u (%u00%%)\n",
> + nr_total_entries,
> + (nr_total_entries / nr_prealloc_entries));
> }
> }
>
> --
> 2.41.0.694.ge786442a9b-goog
>
© 2016 - 2025 Red Hat, Inc.