Lockdep warning when using REGCACHE_RBTREE

Lockdep warning when using REGCACHE_RBTREE

[Stefan Agner]

Hi Mark,

I currently work on the DCU DRM driver (drivers/gpu/drm/fsl-dcu/) on a
Linux 4.4 kernel. With CONFIG_LOCKDEP enabled I get the following
warning on startup:

[    1.327284] ------------[ cut here ]------------
[    1.332010] WARNING: CPU: 0 PID: 1 at kernel/locking/lockdep.c:2755
lockdep_trace_alloc+0x120/0x124()
[    1.341358] DEBUG_LOCKS_WARN_ON(irqs_disabled_flags(flags))
[    1.346807] Modules linked in:
[    1.350161] CPU: 0 PID: 1 Comm: swapper Not tainted
4.4.0-00013-g7e569bc-dirty #41
[    1.357851] Hardware name: Freescale Vybrid VF5xx/VF6xx (Device Tree)
[    1.364376] Backtrace:
[    1.366924] [<80013ba0>] (dump_backtrace) from [<80013d98>]
(show_stack+0x18/0x1c)
[    1.374609]  r7:80054ac4 r6:00000ac3 r5:00000009 r4:00000000
[    1.380434] [<80013d80>] (show_stack) from [<8028eb84>]
(dump_stack+0x24/0x28)
[    1.387795] [<8028eb60>] (dump_stack) from [<80021ecc>]
(warn_slowpath_common+0x88/0xb4)
[    1.396021] [<80021e44>] (warn_slowpath_common) from [<80021f30>]
(warn_slowpath_fmt+0x38/0x40)
[    1.404842]  r8:000001fc r7:80378238 r6:024080c0 r5:8f801f00
r4:808d63fc
[    1.411743] [<80021efc>] (warn_slowpath_fmt) from [<80054ac4>]
(lockdep_trace_alloc+0x120/0x124)
[    1.420654]  r3:808d98e0 r2:808d63fc
[    1.424325]  r4:600000d3
[    1.426950] [<800549a4>] (lockdep_trace_alloc) from [<800dad44>]
(kmem_cache_alloc+0x30/0x110)
[    1.435684]  r5:8f801f00 r4:024080c0
[    1.439380] [<800dad14>] (kmem_cache_alloc) from [<80378238>]
(regcache_rbtree_write+0x138/0x504)
[    1.448374]  r7:8fa1b5c0 r6:8fa14800 r5:00000218 r4:00000000
[    1.454196] [<80378100>] (regcache_rbtree_write) from [<803773e0>]
(regcache_write+0x5c/0x64)
[    1.462838]  r10:8fa1b588 r9:00000001 r8:00000004 r7:00000000
r6:00000000 r5:000001fc
[    1.470882]  r4:8fa14800
[    1.473504] [<80377384>] (regcache_write) from [<80375d20>]
(_regmap_raw_write+0x124/0x5fc)
[    1.481972]  r7:00000000 r6:8fa1b584 r5:00000004 r4:8fa14800
[    1.487796] [<80375bfc>] (_regmap_raw_write) from [<8037626c>]
(_regmap_bus_raw_write+0x74/0x90)
[    1.496703]  r10:00000000 r9:00000024 r8:00000000 r7:8fa14800
r6:00000000 r5:000001fc
[    1.504745]  r4:8fa14800
[    1.507365] [<803761f8>] (_regmap_bus_raw_write) from [<80375368>]
(_regmap_write+0x60/0x9c)
[    1.515923]  r7:8fa14800 r6:00000000 r5:000001fc r4:8fa14800
[    1.521744] [<80375308>] (_regmap_write) from [<80376760>]
(regmap_write+0x48/0x68)
[    1.529516]  r7:000001fc r6:00000000 r5:000001fc r4:8fa14800
[    1.535348] [<80376718>] (regmap_write) from [<803538e8>]
(fsl_dcu_drm_crtc_create+0x98/0xe8)
[    1.543998]  r7:000001fc r6:00000220 r5:8f9a6810 r4:00000200
[    1.549824] [<80353850>] (fsl_dcu_drm_crtc_create) from [<80352df0>]
(fsl_dcu_drm_modeset_init+0x5c/0xfc)
[    1.559522]  r9:809a25ec r8:8f9a7000 r7:8f8bd410 r6:8f9a6810
r5:8f9a7000 r4:8f9a6810
[    1.567490] [<80352d94>] (fsl_dcu_drm_modeset_init) from [<80352894>]
(fsl_dcu_load+0x34/0x1d8)
[    1.576308]  r7:8f8bd410 r6:8f9a6810 r5:8f9a7000 r4:8f9a7000
[    1.582141] [<80352860>] (fsl_dcu_load) from [<803330bc>]
(drm_dev_register+0xb4/0xc4)
[    1.590180]  r9:809a25ec r8:8f9a7000 r7:8f8bd400 r6:00000000
r5:00000000 r4:8f9a7000
[    1.598140] [<80333008>] (drm_dev_register) from [<80352c8c>]
(fsl_dcu_drm_probe+0x254/0x2cc)
[    1.606785]  r7:8f8bd400 r6:8f9a6810 r5:8f8bd410 r4:00000000
[    1.612620] [<80352a38>] (fsl_dcu_drm_probe) from [<80362d3c>]
(platform_drv_probe+0x58/0xb4)
[    1.621270]  r8:00000000 r7:fffffdfb r6:80a0aee8 r5:8f8bd410
r4:ffffffed
[    1.628159] [<80362ce4>] (platform_drv_probe) from [<803611c8>]
(driver_probe_device+0x210/0x304)
[    1.637153]  r7:80a0aee8 r6:00000000 r5:8f8bd410 r4:81242468
[    1.642971] [<80360fb8>] (driver_probe_device) from [<80361358>]
(__driver_attach+0x9c/0xa0)
[    1.651530]  r9:809a25ec r8:000000cd r7:00000000 r6:8f8bd444
r5:80a0aee8 r4:8f8bd410
[    1.659503] [<803612bc>] (__driver_attach) from [<8035f41c>]
(bus_for_each_dev+0x70/0xa4)
[    1.667801]  r7:00000000 r6:803612bc r5:80a0aee8 r4:00000000
[    1.673639] [<8035f3ac>] (bus_for_each_dev) from [<80360c10>]
(driver_attach+0x24/0x28)
[    1.681763]  r6:80a0b7f0 r5:8fa19580 r4:80a0aee8
[    1.686517] [<80360bec>] (driver_attach) from [<8036083c>]
(bus_add_driver+0x1a8/0x220)
[    1.694657] [<80360694>] (bus_add_driver) from [<80361bfc>]
(driver_register+0x80/0x100)
[    1.702869]  r7:8fa16a40 r6:809eb3e0 r5:809bc6fc r4:80a0aee8
[    1.708685] [<80361b7c>] (driver_register) from [<80362c60>]
(__platform_driver_register+0x48/0x50)
[    1.717855]  r5:809bc6fc r4:80a0b7f0
[    1.721543] [<80362c18>] (__platform_driver_register) from
[<809bc718>] (fsl_dcu_drm_platform_driver_init+0x1c/0x20)
[    1.732202]  r5:809bc6fc r4:809eb3e0
[    1.735894] [<809bc6fc>] (fsl_dcu_drm_platform_driver_init) from
[<800096b4>] (do_one_initcall+0x98/0x1e4)
[    1.745689] [<8000961c>] (do_one_initcall) from [<809a2e3c>]
(kernel_init_freeable+0x138/0x1dc)
[    1.754510]  r10:809d6850 r9:809a25ec r8:000000cd r7:80a40d40
r6:80a40d40 r5:00000006
[    1.762553]  r4:809e5840
[    1.765175] [<809a2d04>] (kernel_init_freeable) from [<8073ef00>]
(kernel_init+0x18/0xf0)
[    1.773468]  r10:00000000 r9:00000000 r8:00000000 r7:00000000
r6:00000000 r5:8073eee8
[    1.781506]  r4:80a40d40
[    1.784128] [<8073eee8>] (kernel_init) from [<8000f9d0>]
(ret_from_fork+0x14/0x24)
[    1.791810]  r5:8073eee8 r4:00000000
[    1.795539] ---[ end trace e76a00401296776a ]---

I do use REGCACHE_RBTREE along with regmap_write from within the probe
code path of the driver. This ultimately leads to an allocation.
However, what I don't understand is why the allocation is leading to
that error. The actual allocation happens in regcache_rbtree_node_alloc
and seems to be a rather common kzalloc with GFP_KERNEL...

The comment in __lockdep_trace_alloc says:
"Oi! Can't be having __GFP_FS allocations with IRQs disabled.".

Not sure if this is a Linux 4.4 issue, Fabio Estevam reported a similar
issue just recently, not sure if that is related:
https://lkml.org/lkml/2016/1/11/284

--
Stefan

Re: Lockdep warning when using REGCACHE_RBTREE

[Mark Brown]

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

On Thu, Jan 14, 2016 at 02:30:50PM -0800, Stefan Agner wrote:

> I currently work on the DCU DRM driver (drivers/gpu/drm/fsl-dcu/) on a
> Linux 4.4 kernel. With CONFIG_LOCKDEP enabled I get the following
> warning on startup:

Please don't paste entire stack dumps into e-mail, they're completely
unedifying and obscure the actual content in your e-mail.  Edit down
relevant pieces of information.

> [    1.327284] ------------[ cut here ]------------
> [    1.332010] WARNING: CPU: 0 PID: 1 at kernel/locking/lockdep.c:2755
> lockdep_trace_alloc+0x120/0x124()
> [    1.341358] DEBUG_LOCKS_WARN_ON(irqs_disabled_flags(flags))

> I do use REGCACHE_RBTREE along with regmap_write from within the probe
> code path of the driver. This ultimately leads to an allocation.
> However, what I don't understand is why the allocation is leading to
> that error. The actual allocation happens in regcache_rbtree_node_alloc
> and seems to be a rather common kzalloc with GFP_KERNEL...

> The comment in __lockdep_trace_alloc says:
> "Oi! Can't be having __GFP_FS allocations with IRQs disabled.".

That appears to match with the warning printed.  Either this is a false
positive from lockdep or you are actually trying to cache a new register
in atomic context which is not and has never been supported, are any of
the functions in the backtrace taking relevant locks?

> Not sure if this is a Linux 4.4 issue, Fabio Estevam reported a similar
> issue just recently, not sure if that is related:
> https://lkml.org/lkml/2016/1/11/284

Nothing has changed here in lockdep, doing allocations in atomic context
has never been supported.

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 473 bytes --]

Re: Lockdep warning when using REGCACHE_RBTREE

[Stefan Agner]

On 2016-01-14 16:01, Mark Brown wrote:
> On Thu, Jan 14, 2016 at 02:30:50PM -0800, Stefan Agner wrote:
> 
>> I currently work on the DCU DRM driver (drivers/gpu/drm/fsl-dcu/) on a
>> Linux 4.4 kernel. With CONFIG_LOCKDEP enabled I get the following
>> warning on startup:
> 
> Please don't paste entire stack dumps into e-mail, they're completely
> unedifying and obscure the actual content in your e-mail.  Edit down
> relevant pieces of information.
> 
>> [    1.327284] ------------[ cut here ]------------
>> [    1.332010] WARNING: CPU: 0 PID: 1 at kernel/locking/lockdep.c:2755
>> lockdep_trace_alloc+0x120/0x124()
>> [    1.341358] DEBUG_LOCKS_WARN_ON(irqs_disabled_flags(flags))
> 
>> I do use REGCACHE_RBTREE along with regmap_write from within the probe
>> code path of the driver. This ultimately leads to an allocation.
>> However, what I don't understand is why the allocation is leading to
>> that error. The actual allocation happens in regcache_rbtree_node_alloc
>> and seems to be a rather common kzalloc with GFP_KERNEL...
> 
>> The comment in __lockdep_trace_alloc says:
>> "Oi! Can't be having __GFP_FS allocations with IRQs disabled.".
> 
> That appears to match with the warning printed.  Either this is a false
> positive from lockdep or you are actually trying to cache a new register
> in atomic context which is not and has never been supported, are any of
> the functions in the backtrace taking relevant locks?

Hm, I see. in_atomic at least doesn't report that I am in a atomic
context. None of the functions in the DCU driver use a spinlock
directly, I also checked some of the DRM core functions, there is the
drm_global_mutex, but not a spinlock.

When calling debug_check_no_locks_held() just before regmap_write I get
this:

[    1.441918]
[    1.443479] =====================================
[    1.448268] [ BUG: swapper/1 still has locks held! ]
[    1.453465] 4.4.0-00013-g7e569bc-dirty #59 Not tainted
[    1.458695] -------------------------------------
[    1.463598] 3 locks held by swapper/1:
[    1.467430]  #0:  (&dev->mutex){......}, at: [<80372f40>]
__driver_attach+0x50/0xa0
[    1.475446]  #1:  (&dev->mutex){......}, at: [<80372f50>]
__driver_attach+0x60/0xa0
[    1.483419]  #2:  (drm_global_mutex){+.+.+.}, at: [<80344bb0>]
drm_dev_register+0x24/0xc4
[    1.491924]

On a slightly other topic, I question whether REGCACHE_RBTREE is the
right cache type for the DCU DRM driver. The driver has uses a regmap
area of 1144 32-bit registers, the most space is used by the layer
configuration registers which are 0x40 apart and 0x0-0x20 for each layer
are actually used (hence somewhat above 50%).

Would FLAT be the better cache type?

--
Stefan

> 
>> Not sure if this is a Linux 4.4 issue, Fabio Estevam reported a similar
>> issue just recently, not sure if that is related:
>> https://lkml.org/lkml/2016/1/11/284
> 
> Nothing has changed here in lockdep, doing allocations in atomic context
> has never been supported.

Re: Lockdep warning when using REGCACHE_RBTREE

[Mark Brown]

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

On Thu, Jan 14, 2016 at 05:14:47PM -0800, Stefan Agner wrote:

> On a slightly other topic, I question whether REGCACHE_RBTREE is the
> right cache type for the DCU DRM driver. The driver has uses a regmap
> area of 1144 32-bit registers, the most space is used by the layer
> configuration registers which are 0x40 apart and 0x0-0x20 for each layer
> are actually used (hence somewhat above 50%).

> Would FLAT be the better cache type?

Yes, and if it's a MMIO device the performance of a flat cache is more
in line with the device performance.

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 473 bytes --]

Re: Lockdep warning when using REGCACHE_RBTREE

[Stefan Agner]

On 2016-01-15 08:28, Mark Brown wrote:
> On Thu, Jan 14, 2016 at 05:14:47PM -0800, Stefan Agner wrote:
> 
>> On a slightly other topic, I question whether REGCACHE_RBTREE is the
>> right cache type for the DCU DRM driver. The driver has uses a regmap
>> area of 1144 32-bit registers, the most space is used by the layer
>> configuration registers which are 0x40 apart and 0x0-0x20 for each layer
>> are actually used (hence somewhat above 50%).
> 
>> Would FLAT be the better cache type?
> 
> Yes, and if it's a MMIO device the performance of a flat cache is more
> in line with the device performance.

Thanks for confirming that. I will switch to REGCACHE_FLAT then, I found
a second driver with the very same issue, also a MMIO mapped device:
drivers/pwm/pwm-fsl-ftm.c...

--
Stefan

Re: Lockdep warning when using REGCACHE_RBTREE

[Peter Zijlstra]

On Thu, Jan 14, 2016 at 02:30:50PM -0800, Stefan Agner wrote:
> Hi Mark,
> 
> I currently work on the DCU DRM driver (drivers/gpu/drm/fsl-dcu/) on a
> Linux 4.4 kernel. With CONFIG_LOCKDEP enabled I get the following
> warning on startup:
> 
> [    1.327284] ------------[ cut here ]------------
> [    1.332010] WARNING: CPU: 0 PID: 1 at kernel/locking/lockdep.c:2755 lockdep_trace_alloc+0x120/0x124()
> [    1.341358] DEBUG_LOCKS_WARN_ON(irqs_disabled_flags(flags))

> [    1.521744] [<80375308>] (_regmap_write) from [<80376760>] (regmap_write+0x48/0x68)
> [    1.535348] [<80376718>] (regmap_write) from [<803538e8>] (fsl_dcu_drm_crtc_create+0x98/0xe8)
> [    1.549824] [<80353850>] (fsl_dcu_drm_crtc_create) from [<80352df0>] (fsl_dcu_drm_modeset_init+0x5c/0xfc)


> The comment in __lockdep_trace_alloc says:
> "Oi! Can't be having __GFP_FS allocations with IRQs disabled.".

So _regmap_write() does: map->lock(map->lock_arg)

Which isn't very enlightening, since that can be a mutex or a spinlock,
the above strongly suggests spinlock though.

Looking at __regmap_init(), this seems to depend on:

  (bus && bus->fast_io) || config->fast_io

now, afaict, regmap_mmio is used in this case, which has .fast_io =
true.

So yeah, fail.

Re: Lockdep warning when using REGCACHE_RBTREE

[Mark Brown]

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

On Fri, Jan 15, 2016 at 10:45:41AM +0100, Peter Zijlstra wrote:

> So _regmap_write() does: map->lock(map->lock_arg)

> Which isn't very enlightening, since that can be a mutex or a spinlock,
> the above strongly suggests spinlock though.

> Looking at __regmap_init(), this seems to depend on:

>   (bus && bus->fast_io) || config->fast_io

> now, afaict, regmap_mmio is used in this case, which has .fast_io =
> true.

> So yeah, fail.

Indeed, that'd do it.  It hadn't occurred to me that someone would be
using MMIO with an rbtree cache.

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 473 bytes --]