Re: WARNING: locking bug in lock_downgrade

[Tetsuo Handa <penguin-kernel@xxxxxxxxxxxxxxxxxxx>]

On 2018/12/14 4:46, Waiman Long wrote:
> On 12/12/2018 08:14 PM, Yang Shi wrote:
>> By looking into lockdep code, I'm not sure if lockdep may get confused
>> by such sequence or not?
>>
>>
>> Any hint is appreciated.
>>
>>
>> Regards,
>>
>> Yang 
> 
> The warning was printed because hlock->read was set when doing the
> downgrade_write(). So it is either downgrade_write() was called a second
> time or a read lock was held originally. It is hard to tell what is the
> root cause without a reproducer.
> 
> Cheers,
> Longman
> 

Comparing with output from

        struct rw_semaphore *sem = &current->mm->mmap_sem;

        down_write(sem);
        pr_warn("mmap_sem: count=%ld current=%px, owner=%px\n", atomic_long_read(&sem->count), current, READ_ONCE(sem->owner));
        /* mmap_sem: count=-4294967295 current=ffff88813095ca80, owner=ffff88813095ca80 */
        downgrade_write(sem);
        pr_warn("mmap_sem: count=%ld current=%px, owner=%px\n", atomic_long_read(&sem->count), current, READ_ONCE(sem->owner));
        /* mmap_sem: count=1 current=ffff88813095ca80, owner=ffff88813095ca83 */
        up_read(sem);
        pr_warn("mmap_sem: count=%ld current=%px, owner=%px\n", atomic_long_read(&sem->count), current, READ_ONCE(sem->owner));
        /* mmap_sem: count=0 current=ffff88813095ca80, owner=0000000000000003 */

what we got with debug printk() patch

  https://syzkaller.appspot.com/text?tag=CrashLog&x=169dbb9b400000

  [ 2580.337550][ T3645] mmap_sem: hlock->read=1 count=-4294967295 current=ffff888050e04140, owner=ffff888050e04140
  [ 2580.353526][ T3645] ------------[ cut here ]------------
  [ 2580.367859][ T3645] downgrading a read lock
  [ 2580.367935][ T3645] WARNING: CPU: 1 PID: 3645 at kernel/locking/lockdep.c:3572 lock_downgrade+0x35d/0xbe0
  [ 2580.382206][ T3645] Kernel panic - not syncing: panic_on_warn set ...

  https://syzkaller.appspot.com/text?tag=CrashLog&x=1542da4f400000

  [  386.342585][T16698] mmap_sem: hlock->read=1 count=-4294967295 current=ffff8880512ae180, owner=ffff8880512ae180
  [  386.348586][T16698] ------------[ cut here ]------------
  [  386.357203][T16698] downgrading a read lock
  [  386.357294][T16698] WARNING: CPU: 1 PID: 16698 at kernel/locking/lockdep.c:3572 lock_downgrade+0x35d/0xbe0
  [  386.372148][T16698] Kernel panic - not syncing: panic_on_warn set ...

indicates that lockdep is saying that "current->mm->mmap_sem is held for read"
while "struct rw_semaphore" is saying that "current->mm->mmap_sem is held for write".
Something made lockdep confused. Possibly a lockdep bug.