Received-SPF: pass (google.com: best guess record for domain of linux-kernel-owner@vger.kernel.org designates 209.132.180.67 as permitted sender) client-ip=209.132.180.67;
Content-Type: text/plain;
        charset=utf-8
Mime-Version: 1.0 (Mac OS X Mail 12.4 \(3445.104.11\))
Subject: Re: [PATCH] locking/lockdep: Fix lock IRQ usage initialization bug
From:   Qian Cai <cai@lca.pw>
In-Reply-To: <CAHttsrbQuHYEYYgx+c7-Q=ffPxoqRQ1PfZ5bhWNhuMAeR9LvuQ@mail.gmail.com>
Date:   Mon, 8 Jul 2019 21:50:40 -0400
Cc:     Peter Zijlstra <peterz@infradead.org>,
        Will Deacon <will.deacon@arm.com>,
        Ingo Molnar <mingo@kernel.org>,
        LKML <linux-kernel@vger.kernel.org>
Content-Transfer-Encoding: quoted-printable
Message-Id: <11BCE650-20B4-4956-B3CD-7E5F5A13409A@lca.pw>
References: <20190610055258.6424-1-duyuyang@gmail.com>
 <1562607152.8510.5.camel@lca.pw>
 <CAHttsrbQuHYEYYgx+c7-Q=ffPxoqRQ1PfZ5bhWNhuMAeR9LvuQ@mail.gmail.com>
To:     Yuyang Du <duyuyang@gmail.com>
Sender: linux-kernel-owner@vger.kernel.org
Precedence: bulk


> On Jul 8, 2019, at 9:21 PM, Yuyang Du <duyuyang@gmail.com> wrote:
>=20
> The problem should have been fixed with this in that pull:
>=20
> locking/lockdep: Move mark_lock() inside CONFIG_TRACE_IRQFLAGS &&
> CONFIG_PROVE_LOCKING
>=20
> and this is a better fix than mine.

I don=E2=80=99t think so. That commit was included in today=E2=80=99s =
linux-next, but I can still reproduce the issue there.

[ 8872.727085] DEBUG_LOCKS_WARN_ON(debug_atomic_read(nr_unused_locks) !=3D=
 nr_unused)
[ 8872.727113] WARNING: CPU: 60 PID: 124801 at =
kernel/locking/lockdep_proc.c:249 lockdep_stats_show+0xe44/0x11e0
[ 8872.727157] Modules linked in: brd ext4 crc16 mbcache jbd2 loop =
i2c_opal i2c_core ip_tables x_tables xfs sd_mod ahci libahci tg3 =
firmware_class libata libphy dm_mirror dm_region_hash dm_log dm_mod =
[last unloaded: dummy_del_mod]
[ 8872.727213] CPU: 60 PID: 124801 Comm: proc01 Tainted: G        W  O   =
   5.2.0-next-20190708+ #1
[ 8872.727253] NIP:  c0000000001a97b4 LR: c0000000001a97b0 CTR: =
c0000000008c4660
[ 8872.727293] REGS: c000001c2e84f8e0 TRAP: 0700   Tainted: G        W  =
O       (5.2.0-next-20190708+)
[ 8872.727326] MSR:  9000000000029033 <SF,HV,EE,ME,IR,DR,RI,LE>  CR: =
28888402  XER: 20040000
[ 8872.727371] CFAR: c00000000011a0d4 IRQMASK: 0=20
               GPR00: c0000000001a97b0 c000001c2e84fb70 c0000000016f8b00 =
0000000000000044=20
               GPR04: c00000000172c258 c0000000001b9288 4e5241575f534b43 =
75626564284e4f5f=20
               GPR08: 0000001ffdd10000 0000000000000000 0000000000000000 =
212029736b636f6c=20
               GPR12: 756e755f726e203d c000001ffffce400 0000000000000000 =
c0000000015bd610=20
               GPR16: 0000000000000000 0000000000000000 0000000000000000 =
0000000000000dfd=20
               GPR20: 0000000000000000 0000000000000000 0000000000000000 =
0000000000000000=20
               GPR24: 0000000000000000 0000000000000000 0000000000000000 =
c000001fb7d0f0a8=20
               GPR28: 0000000000000000 c00000000172c278 c00000000172c4c4 =
c00000000172ba18=20
[ 8872.727698] NIP [c0000000001a97b4] lockdep_stats_show+0xe44/0x11e0
[ 8872.727742] LR [c0000000001a97b0] lockdep_stats_show+0xe40/0x11e0
[ 8872.727775] Call Trace:
[ 8872.727800] [c000001c2e84fb70] [c0000000001a97b0] =
lockdep_stats_show+0xe40/0x11e0 (unreliable)
[ 8872.727831] [c000001c2e84fca0] [c000000000492434] =
seq_read+0x1d4/0x620
[ 8872.727886] [c000001c2e84fd30] [c000000000515520] =
proc_reg_read+0x90/0x130
[ 8872.727938] [c000001c2e84fd60] [c000000000452d6c] =
__vfs_read+0x3c/0x70
[ 8872.727989] [c000001c2e84fd80] [c000000000452e5c] vfs_read+0xbc/0x1a0
[ 8872.728033] [c000001c2e84fdd0] [c0000000004532ec] =
ksys_read+0x7c/0x140
[ 8872.728073] [c000001c2e84fe20] [c00000000000ae08] =
system_call+0x5c/0x70
[ 8872.728126] Instruction dump:
[ 8872.728161] 419ef3b0 3d220003 392974fc 81290000 2f890000 409ef39c =
3c82ff33 3c62ff33=20
[ 8872.728194] 38841af8 386308e8 4bf708c1 60000000 <0fe00000> 4bfff37c =
60000000 39200000=20
[ 8872.728251] ---[ end trace 42d16c13415f9f32 ]---

>=20
> Thanks,
> Yuyang
>=20
> On Tue, 9 Jul 2019 at 01:32, Qian Cai <cai@lca.pw> wrote:
>>=20
>> I saw Ingo send a pull request to Linus for 5.3 [1] includes the =
offensive
>> commit "locking/lockdep: Consolidate lock usage bit initialization" =
but did not
>> include this patch.
>>=20
>> [1] https://lore.kernel.org/lkml/20190708093516.GA57558@gmail.com/
>>=20
>> On Mon, 2019-06-10 at 13:52 +0800, Yuyang Du wrote:
>>> The commit:
>>>=20
>>>  091806515124b20 ("locking/lockdep: Consolidate lock usage bit
>>> initialization")
>>>=20
>>> misses marking LOCK_USED flag at IRQ usage initialization when
>>> CONFIG_TRACE_IRQFLAGS
>>> or CONFIG_PROVE_LOCKING is not defined. Fix it.
>>>=20
>>> Reported-by: Qian Cai <cai@lca.pw>
>>> Signed-off-by: Yuyang Du <duyuyang@gmail.com>
>>> ---
>>> kernel/locking/lockdep.c | 110 =
+++++++++++++++++++++++-----------------------
>>> -
>>> 1 file changed, 53 insertions(+), 57 deletions(-)
>>>=20
>>> diff --git a/kernel/locking/lockdep.c b/kernel/locking/lockdep.c
>>> index 48a840a..c3db987 100644
>>> --- a/kernel/locking/lockdep.c
>>> +++ b/kernel/locking/lockdep.c
>>> @@ -3460,9 +3460,61 @@ void trace_softirqs_off(unsigned long ip)
>>>              debug_atomic_inc(redundant_softirqs_off);
>>> }
>>>=20
>>> +static inline unsigned int task_irq_context(struct task_struct =
*task)
>>> +{
>>> +     return 2 * !!task->hardirq_context + !!task->softirq_context;
>>> +}
>>> +
>>> +static int separate_irq_context(struct task_struct *curr,
>>> +             struct held_lock *hlock)
>>> +{
>>> +     unsigned int depth =3D curr->lockdep_depth;
>>> +
>>> +     /*
>>> +      * Keep track of points where we cross into an interrupt =
context:
>>> +      */
>>> +     if (depth) {
>>> +             struct held_lock *prev_hlock;
>>> +
>>> +             prev_hlock =3D curr->held_locks + depth-1;
>>> +             /*
>>> +              * If we cross into another context, reset the
>>> +              * hash key (this also prevents the checking and the
>>> +              * adding of the dependency to 'prev'):
>>> +              */
>>> +             if (prev_hlock->irq_context !=3D hlock->irq_context)
>>> +                     return 1;
>>> +     }
>>> +     return 0;
>>> +}
>>> +
>>> +#else /* defined(CONFIG_TRACE_IRQFLAGS) && =
defined(CONFIG_PROVE_LOCKING) */
>>> +
>>> +static inline
>>> +int mark_lock_irq(struct task_struct *curr, struct held_lock *this,
>>> +             enum lock_usage_bit new_bit)
>>> +{
>>> +     WARN_ON(1); /* Impossible innit? when we don't have =
TRACE_IRQFLAG */
>>> +     return 1;
>>> +}
>>> +
>>> +static inline unsigned int task_irq_context(struct task_struct =
*task)
>>> +{
>>> +     return 0;
>>> +}
>>> +
>>> +static inline int separate_irq_context(struct task_struct *curr,
>>> +             struct held_lock *hlock)
>>> +{
>>> +     return 0;
>>> +}
>>> +
>>> +#endif /* defined(CONFIG_TRACE_IRQFLAGS) && =
defined(CONFIG_PROVE_LOCKING) */
>>> +
>>> static int
>>> mark_usage(struct task_struct *curr, struct held_lock *hlock, int =
check)
>>> {
>>> +#if defined(CONFIG_TRACE_IRQFLAGS) && defined(CONFIG_PROVE_LOCKING)
>>>      if (!check)
>>>              goto lock_used;
>>>=20
>>> @@ -3510,6 +3562,7 @@ void trace_softirqs_off(unsigned long ip)
>>>      }
>>>=20
>>> lock_used:
>>> +#endif
>>>      /* mark it as used: */
>>>      if (!mark_lock(curr, hlock, LOCK_USED))
>>>              return 0;
>>> @@ -3517,63 +3570,6 @@ void trace_softirqs_off(unsigned long ip)
>>>      return 1;
>>> }
>>>=20
>>> -static inline unsigned int task_irq_context(struct task_struct =
*task)
>>> -{
>>> -     return 2 * !!task->hardirq_context + !!task->softirq_context;
>>> -}
>>> -
>>> -static int separate_irq_context(struct task_struct *curr,
>>> -             struct held_lock *hlock)
>>> -{
>>> -     unsigned int depth =3D curr->lockdep_depth;
>>> -
>>> -     /*
>>> -      * Keep track of points where we cross into an interrupt =
context:
>>> -      */
>>> -     if (depth) {
>>> -             struct held_lock *prev_hlock;
>>> -
>>> -             prev_hlock =3D curr->held_locks + depth-1;
>>> -             /*
>>> -              * If we cross into another context, reset the
>>> -              * hash key (this also prevents the checking and the
>>> -              * adding of the dependency to 'prev'):
>>> -              */
>>> -             if (prev_hlock->irq_context !=3D hlock->irq_context)
>>> -                     return 1;
>>> -     }
>>> -     return 0;
>>> -}
>>> -
>>> -#else /* defined(CONFIG_TRACE_IRQFLAGS) && =
defined(CONFIG_PROVE_LOCKING) */
>>> -
>>> -static inline
>>> -int mark_lock_irq(struct task_struct *curr, struct held_lock *this,
>>> -             enum lock_usage_bit new_bit)
>>> -{
>>> -     WARN_ON(1); /* Impossible innit? when we don't have =
TRACE_IRQFLAG */
>>> -     return 1;
>>> -}
>>> -
>>> -static inline int
>>> -mark_usage(struct task_struct *curr, struct held_lock *hlock, int =
check)
>>> -{
>>> -     return 1;
>>> -}
>>> -
>>> -static inline unsigned int task_irq_context(struct task_struct =
*task)
>>> -{
>>> -     return 0;
>>> -}
>>> -
>>> -static inline int separate_irq_context(struct task_struct *curr,
>>> -             struct held_lock *hlock)
>>> -{
>>> -     return 0;
>>> -}
>>> -
>>> -#endif /* defined(CONFIG_TRACE_IRQFLAGS) && =
defined(CONFIG_PROVE_LOCKING) */
>>> -
>>> /*
>>>  * Mark a lock with a usage bit, and validate the state transition:
>>>  */