2019-06-06 22:33:40

by Qian Cai

[permalink] [raw]
Subject: "locking/lockdep: Consolidate lock usage bit initialization" is buggy

The linux-next commit "locking/lockdep: Consolidate lock usage bit
initialization" [1] will always generate a warning below. Looking through the
commit that when mark_irqflags() returns 1 and check = 1, it will do one less
mark_lock() call than it used to.

[1] https://lore.kernel.org/lkml/tip-091806515124b20f8cff7927b4b7ff399483b109@gi
t.kernel.org/

# cat /proc/lockdep_stats,

[ 7410.877772] DEBUG_LOCKS_WARN_ON(debug_atomic_read(nr_unused_locks) !=
nr_unused)
[ 7410.877798] WARNING: CPU: 58 PID: 126655 at kernel/locking/lockdep_proc.c:249
lockdep_stats_show+0xe44/0x11e0
[ 7410.877841] Modules linked in: brd ext4 crc16 mbcache jbd2 loop i2c_opal
i2c_core ip_tables x_tables xfs sd_mod bnx2x ahci mdio libahci tg3 libphy libata
firmware_class dm_mirror dm_region_hash dm_log dm_mod [last unloaded:
dummy_del_mod]
[ 7410.877954] CPU: 58 PID: 126655 Comm: proc01 Tainted:
G        W  O      5.2.0-rc3-next-20190606+ #2
[ 7410.877987] NIP:  c0000000001a4ae4 LR: c0000000001a4ae0 CTR: c0000000008afa30
[ 7410.878027] REGS: c00000176c5af8e0 TRAP: 0700   Tainted:
G        W  O       (5.2.0-rc3-next-20190606+)
[ 7410.878059] MSR:  9000000000029033 <SF,HV,EE,ME,IR,DR,RI,LE>  CR:
28888402  XER: 20040000
[ 7410.878101] CFAR: c000000000118c44 IRQMASK: 0 
               GPR00: c0000000001a4ae0 c00000176c5afb70 c0000000016e5400
0000000000000044 
               GPR04: c00000000171c250 c0000000001b44e8 4e5241575f534b43
75626564284e4f5f 
               GPR08: 0000001ffdf50000 0000000000000000 0000000000000000
212029736b636f6c 
               GPR12: 756e755f726e203d c000001ffffcfe00 0000000000000000
c0000000015ad1d0 
               GPR16: 0000000000000000 0000000000000000 0000000000000000
0000000000000dd7 
               GPR20: 0000000000000000 0000000000000000 0000000000000000
0000000000000000 
               GPR24: 0000000000000000 0000000000000000 0000000000000000
c00000079dd0e158 
               GPR28: 0000000000000000 c00000000171c270 c00000000171c4c4
c00000000171ba18 
[ 7410.878371] NIP [c0000000001a4ae4] lockdep_stats_show+0xe44/0x11e0
[ 7410.878406] LR [c0000000001a4ae0] lockdep_stats_show+0xe40/0x11e0
[ 7410.878443] Call Trace:
[ 7410.878468] [c00000176c5afb70] [c0000000001a4ae0]
lockdep_stats_show+0xe40/0x11e0 (unreliable)
[ 7410.878529] [c00000176c5afca0] [c000000000489c34] seq_read+0x1d4/0x620
[ 7410.878581] [c00000176c5afd30] [c00000000050cd40] proc_reg_read+0x90/0x130
[ 7410.878622] [c00000176c5afd60] [c00000000044b1cc] __vfs_read+0x3c/0x70
[ 7410.878653] [c00000176c5afd80] [c00000000044b2bc] vfs_read+0xbc/0x1a0
[ 7410.878680] [c00000176c5afdd0] [c00000000044b74c] ksys_read+0x7c/0x140
[ 7410.878722] [c00000176c5afe20] [c00000000000b108] system_call+0x5c/0x70
[ 7410.878773] Instruction dump:
[ 7410.878798] 419ef3b0 3d220004 3929abfc 81290000 2f890000 409ef39c 3c82ff33
3c62ff33 
[ 7410.878843] 38840a98 3863f8a8 4bf74101 60000000 <0fe00000> 4bfff37c 60000000
39200000 
[ 7410.878887] ---[ end trace 6a712a083aa01d23 ]---


2019-06-07 03:34:51

by Yuyang Du

[permalink] [raw]
Subject: Re: "locking/lockdep: Consolidate lock usage bit initialization" is buggy

Thanks for the report, but

On Fri, 7 Jun 2019 at 05:14, Qian Cai <[email protected]> wrote:
>
> The linux-next commit "locking/lockdep: Consolidate lock usage bit
> initialization" [1] will always generate a warning below.

I never had such warning.

> Looking through the
> commit that when mark_irqflags() returns 1 and check = 1, it will do one less
> mark_lock() call than it used to.

The four cases:

1. When check == 1 and mark_irqflags() returns 1;
2. When check == 1 and mark_irqflags() returns 0;
3. When check == 0 and mark_irqflags() returns 1;
4. When check == 0 and mark_irqflags() returns 0;

Before and after have exactly the same code to do.

2019-06-07 14:17:08

by Qian Cai

[permalink] [raw]
Subject: Re: "locking/lockdep: Consolidate lock usage bit initialization" is buggy

On Fri, 2019-06-07 at 11:21 +0800, Yuyang Du wrote:
> Thanks for the report, but
>
> On Fri, 7 Jun 2019 at 05:14, Qian Cai <[email protected]> wrote:
> >
> > The linux-next commit "locking/lockdep: Consolidate lock usage bit
> > initialization" [1] will always generate a warning below.
>
> I never had such warning.
>
> > Looking through the
> > commit that when mark_irqflags() returns 1 and check = 1, it will do one
> > less
> > mark_lock() call than it used to.
>
> The four cases:
>
> 1. When check == 1 and mark_irqflags() returns 1;
> 2. When check == 1 and mark_irqflags() returns 0;
> 3. When check == 0 and mark_irqflags() returns 1;
> 4. When check == 0 and mark_irqflags() returns 0;
>
> Before and after have exactly the same code to do.

Reverted the commit on the top of linux-next fixed the issue.

With the commit (triggering the warning
DEBUG_LOCKS_WARN_ON(debug_atomic_read(nr_unused_locks) != nr_unused)),

# cat /proc/lockdep_stats
lock-classes:                         1110 [max: 8192]
stack-trace entries:                     0 [max: 524288]
combined max dependencies:               1
uncategorized locks:                     0
unused locks:                         1110
max locking depth:                      14
debug_locks:                             0

Without the commit (no warning),

# cat /proc/lockdep_stats
lock-classes:                         1110 [max: 8192]
stack-trace entries:                  9932 [max: 524288]
combined max dependencies:               1
uncategorized locks:                  1113
unused locks:                            0
max locking depth:                      14
debug_locks:                             1

2019-06-10 02:26:21

by Yuyang Du

[permalink] [raw]
Subject: Re: "locking/lockdep: Consolidate lock usage bit initialization" is buggy

Thanks for the further validation.

On Fri, 7 Jun 2019 at 22:14, Qian Cai <[email protected]> wrote:
> Reverted the commit on the top of linux-next fixed the issue.
>
> With the commit (triggering the warning
> DEBUG_LOCKS_WARN_ON(debug_atomic_read(nr_unused_locks) != nr_unused)),
>
> # cat /proc/lockdep_stats
> lock-classes: 1110 [max: 8192]
> stack-trace entries: 0 [max: 524288]
> combined max dependencies: 1
> uncategorized locks: 0
> unused locks: 1110
> max locking depth: 14
> debug_locks: 0
>
> Without the commit (no warning),
>
> # cat /proc/lockdep_stats
> lock-classes: 1110 [max: 8192]
> stack-trace entries: 9932 [max: 524288]
> combined max dependencies: 1
> uncategorized locks: 1113
> unused locks: 0
> max locking depth: 14
> debug_locks: 1

Then it is obviously we are talking on different things; then it is
obviously a configuration problem. Fix will be posted soon.

Sorry the bug.

Thanks,
Yuyang