[IMA] Re: possible deadlock in get_user_pages_unlocked (2)

[Eric Biggers]

On Tue, Jun 04, 2019 at 06:16:00PM -0700, syzbot wrote:
> syzbot has bisected this bug to:
> 
> commit 69d61f577d147b396be0991b2ac6f65057f7d445
> Author: Mimi Zohar 
> Date:   Wed Apr 3 21:47:46 2019 +
> 
> ima: verify mprotect change is consistent with mmap policy
> 
> bisection log:  https://syzkaller.appspot.com/x/bisect.txt?x=1055a2f2a0
> start commit:   56b697c6 Add linux-next specific files for 20190604
> git tree:   linux-next
> final crash:https://syzkaller.appspot.com/x/report.txt?x=1255a2f2a0
> console output: https://syzkaller.appspot.com/x/log.txt?x=1455a2f2a0
> kernel config:  https://syzkaller.appspot.com/x/.config?x=4248d6bc70076f7d
> dashboard link: https://syzkaller.appspot.com/bug?extid=e1374b2ec8f6a25ab2e5
> syz repro:  https://syzkaller.appspot.com/x/repro.syz?x=165757eea0
> C reproducer:   https://syzkaller.appspot.com/x/repro.c?x=10dd3e86a0
> 
> Reported-by: syzbot+e1374b2ec8f6a25ab...@syzkaller.appspotmail.com
> Fixes: 69d61f577d14 ("ima: verify mprotect change is consistent with mmap
> policy")
> 
> For information about bisection process see: https://goo.gl/tpsmEJ#bisection
> 

Hi Mimi, it seems your change to call ima_file_mmap() from
security_file_mprotect() violates the locking order by taking i_rwsem while
mmap_sem is held.

- Eric

Re: possible deadlock in get_user_pages_unlocked (2)

[syzbot]

syzbot has bisected this bug to:

commit 69d61f577d147b396be0991b2ac6f65057f7d445
Author: Mimi Zohar 
Date:   Wed Apr 3 21:47:46 2019 +

ima: verify mprotect change is consistent with mmap policy

bisection log:  https://syzkaller.appspot.com/x/bisect.txt?x=1055a2f2a0
start commit:   56b697c6 Add linux-next specific files for 20190604
git tree:   linux-next
final crash:https://syzkaller.appspot.com/x/report.txt?x=1255a2f2a0
console output: https://syzkaller.appspot.com/x/log.txt?x=1455a2f2a0
kernel config:  https://syzkaller.appspot.com/x/.config?x=4248d6bc70076f7d
dashboard link: https://syzkaller.appspot.com/bug?extid=e1374b2ec8f6a25ab2e5
syz repro:  https://syzkaller.appspot.com/x/repro.syz?x=165757eea0
C reproducer:   https://syzkaller.appspot.com/x/repro.c?x=10dd3e86a0

Reported-by: syzbot+e1374b2ec8f6a25ab...@syzkaller.appspotmail.com
Fixes: 69d61f577d14 ("ima: verify mprotect change is consistent with mmap  
policy")


For information about bisection process see: https://goo.gl/tpsmEJ#bisection

Re: possible deadlock in get_user_pages_unlocked (2)

[syzbot]

syzbot has found a reproducer for the following crash on:

HEAD commit:56b697c6 Add linux-next specific files for 20190604
git tree:   linux-next
console output: https://syzkaller.appspot.com/x/log.txt?x=13241716a0
kernel config:  https://syzkaller.appspot.com/x/.config?x=4248d6bc70076f7d
dashboard link: https://syzkaller.appspot.com/bug?extid=e1374b2ec8f6a25ab2e5
compiler:   gcc (GCC) 9.0.0 20181231 (experimental)
syz repro:  https://syzkaller.appspot.com/x/repro.syz?x=165757eea0
C reproducer:   https://syzkaller.appspot.com/x/repro.c?x=10dd3e86a0

IMPORTANT: if you fix the bug, please add the following tag to the commit:
Reported-by: syzbot+e1374b2ec8f6a25ab...@syzkaller.appspotmail.com

IPVS: ftp: loaded support on port[0] = 21
==
WARNING: possible circular locking dependency detected
5.2.0-rc3-next-20190604 #8 Not tainted
--
syz-executor842/8767 is trying to acquire lock:
badb3a6d (&mm->mmap_sem#2){}, at:  
get_user_pages_unlocked+0xfc/0x4a0 mm/gup.c:1174


but task is already holding lock:
52562d44 (&sb->s_type->i_mutex_key#10){+.+.}, at: inode_trylock  
include/linux/fs.h:798 [inline]
52562d44 (&sb->s_type->i_mutex_key#10){+.+.}, at:  
ext4_file_write_iter+0x246/0x1070 fs/ext4/file.c:232


which lock already depends on the new lock.


the existing dependency chain (in reverse order) is:

-> #1 (&sb->s_type->i_mutex_key#10){+.+.}:
   down_write+0x38/0xa0 kernel/locking/rwsem.c:66
   inode_lock include/linux/fs.h:778 [inline]
   process_measurement+0x15ae/0x15e0  
security/integrity/ima/ima_main.c:228

   ima_file_mmap+0x11a/0x130 security/integrity/ima/ima_main.c:370
   security_file_mprotect+0xd5/0x100 security/security.c:1426
   do_mprotect_pkey+0x537/0xa30 mm/mprotect.c:550
   __do_sys_mprotect mm/mprotect.c:582 [inline]
   __se_sys_mprotect mm/mprotect.c:579 [inline]
   __x64_sys_mprotect+0x78/0xb0 mm/mprotect.c:579
   do_syscall_64+0xfd/0x680 arch/x86/entry/common.c:301
   entry_SYSCALL_64_after_hwframe+0x49/0xbe

-> #0 (&mm->mmap_sem#2){}:
   lock_acquire+0x16f/0x3f0 kernel/locking/lockdep.c:4300
   down_read+0x3f/0x1e0 kernel/locking/rwsem.c:24
   get_user_pages_unlocked+0xfc/0x4a0 mm/gup.c:1174
   __gup_longterm_unlocked mm/gup.c:2193 [inline]
   get_user_pages_fast+0x43f/0x530 mm/gup.c:2245
   iov_iter_get_pages+0x2c2/0xf80 lib/iov_iter.c:1287
   dio_refill_pages fs/direct-io.c:171 [inline]
   dio_get_page fs/direct-io.c:215 [inline]
   do_direct_IO fs/direct-io.c:983 [inline]
   do_blockdev_direct_IO+0x3f7b/0x8e00 fs/direct-io.c:1336
   __blockdev_direct_IO+0xa1/0xca fs/direct-io.c:1422
   ext4_direct_IO_write fs/ext4/inode.c:3782 [inline]
   ext4_direct_IO+0xaa7/0x1bb0 fs/ext4/inode.c:3909
   generic_file_direct_write+0x20a/0x4a0 mm/filemap.c:3110
   __generic_file_write_iter+0x2ee/0x630 mm/filemap.c:3293
   ext4_file_write_iter+0x332/0x1070 fs/ext4/file.c:266
   call_write_iter include/linux/fs.h:1870 [inline]
   new_sync_write+0x4d3/0x770 fs/read_write.c:483
   __vfs_write+0xe1/0x110 fs/read_write.c:496
   vfs_write+0x268/0x5d0 fs/read_write.c:558
   ksys_write+0x14f/0x290 fs/read_write.c:611
   __do_sys_write fs/read_write.c:623 [inline]
   __se_sys_write fs/read_write.c:620 [inline]
   __x64_sys_write+0x73/0xb0 fs/read_write.c:620
   do_syscall_64+0xfd/0x680 arch/x86/entry/common.c:301
   entry_SYSCALL_64_after_hwframe+0x49/0xbe

other info that might help us debug this:

 Possible unsafe locking scenario:

   CPU0CPU1
   
  lock(&sb->s_type->i_mutex_key#10);
   lock(&mm->mmap_sem#2);
   lock(&sb->s_type->i_mutex_key#10);
  lock(&mm->mmap_sem#2);

 *** DEADLOCK ***

2 locks held by syz-executor842/8767:
 #0: 65e8e19a (sb_writers#3){.+.+}, at: file_start_write  
include/linux/fs.h:2836 [inline]
 #0: 65e8e19a (sb_writers#3){.+.+}, at: vfs_write+0x485/0x5d0  
fs/read_write.c:557
 #1: 52562d44 (&sb->s_type->i_mutex_key#10){+.+.}, at:  
inode_trylock include/linux/fs.h:798 [inline]
 #1: 52562d44 (&sb->s_type->i_mutex_key#10){+.+.}, at:  
ext4_file_write_iter+0x246/0x1070 fs/ext4/file.c:232


stack backtrace:
CPU: 0 PID: 8767 Comm: syz-executor842 Not tainted 5.2.0-rc3-next-20190604  
#8
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS  
Google 01/01/2011

Call Trace:
 __dump_stack lib/dump_stack.c:77 [inline]
 dump_stack+0x172/0x1f0 lib/dump_stack.c:113
 print_circular_bug.cold+0x1cc/0x28f kernel/locking/lockdep.c:1566
 check_prev_add kernel/locking/lockdep.c:2311 [inline]
 check_prevs_add kernel/locking/lockdep.c:2419 [inline]
 validate_chain kernel/locking/lockdep.c:2801 [inline]
 __lock_acquire+0x3755/0x5490 kernel/lo

Re: possible deadlock in get_user_pages_unlocked

[Eric Biggers]

On Fri, Feb 09, 2018 at 07:19:25PM -0800, Eric Biggers wrote:
> Hi Al,
> 
> On Sat, Feb 10, 2018 at 01:36:40AM +, Al Viro wrote:
> > On Fri, Feb 02, 2018 at 09:57:27AM +0100, Dmitry Vyukov wrote:
> > 
> > > syzbot tests for up to 5 minutes. However, if there is a race involved
> > > then you may need more time because the crash is probabilistic.
> > > But from what I see most of the time, if one can't reproduce it
> > > easily, it's usually due to some differences in setup that just don't
> > > allow the crash to happen at all.
> > > FWIW syzbot re-runs each reproducer on a freshly booted dedicated VM
> > > and what it provided is the kernel output it got during run of the
> > > provided program. So we have reasonably high assurance that this
> > > reproducer worked in at least one setup.
> > 
> > Could you guys check if the following fixes the reproducer?
> > 
> > diff --git a/mm/gup.c b/mm/gup.c
> > index 61015793f952..058a9a8e4e2e 100644
> > --- a/mm/gup.c
> > +++ b/mm/gup.c
> > @@ -861,6 +861,9 @@ static __always_inline long 
> > __get_user_pages_locked(struct task_struct *tsk,
> > BUG_ON(*locked != 1);
> > }
> >  
> > +   if (flags & FOLL_NOWAIT)
> > +   locked = NULL;
> > +
> > if (pages)
> > flags |= FOLL_GET;
> >  
> 
> Yes that fixes the reproducer for me.
> 

Just to follow up on this: it seems that Al's suggested fix didn't go anywhere,
but someone else eventually ran into this bug (which was a real deadlock) and a
slightly different fix was merged, commit 96312e61282ae.  It fixes the
reproducer for me too.  Telling syzbot so that it can close the bug:

#syz fix: mm/gup.c: teach get_user_pages_unlocked to handle FOLL_NOWAIT

- Eric

Re: possible deadlock in get_user_pages_unlocked

[Eric Biggers]

Hi Al,

On Sat, Feb 10, 2018 at 01:36:40AM +, Al Viro wrote:
> On Fri, Feb 02, 2018 at 09:57:27AM +0100, Dmitry Vyukov wrote:
> 
> > syzbot tests for up to 5 minutes. However, if there is a race involved
> > then you may need more time because the crash is probabilistic.
> > But from what I see most of the time, if one can't reproduce it
> > easily, it's usually due to some differences in setup that just don't
> > allow the crash to happen at all.
> > FWIW syzbot re-runs each reproducer on a freshly booted dedicated VM
> > and what it provided is the kernel output it got during run of the
> > provided program. So we have reasonably high assurance that this
> > reproducer worked in at least one setup.
> 
> Could you guys check if the following fixes the reproducer?
> 
> diff --git a/mm/gup.c b/mm/gup.c
> index 61015793f952..058a9a8e4e2e 100644
> --- a/mm/gup.c
> +++ b/mm/gup.c
> @@ -861,6 +861,9 @@ static __always_inline long 
> __get_user_pages_locked(struct task_struct *tsk,
>   BUG_ON(*locked != 1);
>   }
>  
> + if (flags & FOLL_NOWAIT)
> + locked = NULL;
> +
>   if (pages)
>   flags |= FOLL_GET;
>  

Yes that fixes the reproducer for me.

- Eric

Re: possible deadlock in get_user_pages_unlocked

[Al Viro]

On Fri, Feb 02, 2018 at 09:57:27AM +0100, Dmitry Vyukov wrote:

> syzbot tests for up to 5 minutes. However, if there is a race involved
> then you may need more time because the crash is probabilistic.
> But from what I see most of the time, if one can't reproduce it
> easily, it's usually due to some differences in setup that just don't
> allow the crash to happen at all.
> FWIW syzbot re-runs each reproducer on a freshly booted dedicated VM
> and what it provided is the kernel output it got during run of the
> provided program. So we have reasonably high assurance that this
> reproducer worked in at least one setup.

Could you guys check if the following fixes the reproducer?

diff --git a/mm/gup.c b/mm/gup.c
index 61015793f952..058a9a8e4e2e 100644
--- a/mm/gup.c
+++ b/mm/gup.c
@@ -861,6 +861,9 @@ static __always_inline long __get_user_pages_locked(struct 
task_struct *tsk,
BUG_ON(*locked != 1);
}
 
+   if (flags & FOLL_NOWAIT)
+   locked = NULL;
+
if (pages)
flags |= FOLL_GET;
 

Re: possible deadlock in get_user_pages_unlocked

[Dmitry Vyukov]

On Fri, Feb 2, 2018 at 7:20 AM, Al Viro  wrote:
> On Fri, Feb 02, 2018 at 05:46:26AM +, Al Viro wrote:
>> On Thu, Feb 01, 2018 at 09:35:02PM -0800, Eric Biggers wrote:
>>
>> > Try starting up multiple instances of the program; that sometimes helps 
>> > with
>> > these races that are hard to hit (since you may e.g. have a different 
>> > number of
>> > CPUs than syzbot used).  If I start up 4 instances I see the lockdep splat 
>> > after
>> > around 2-5 seconds.
>>
>> 5 instances in parallel, 10 minutes into the run...
>>
>> >  This is on latest Linus tree (4bf772b1467).  Also note the
>> > reproducer uses KVM, so if you're running it in a VM it will only work if 
>> > you've
>> > enabled nested virtualization on the host (kvm_intel.nested=1).
>>
>> cat /sys/module/kvm_amd/parameters/nested
>> 1
>>
>> on host
>>
>> > Also it appears to go away if I revert ce53053ce378c21 ("kvm: switch
>> > get_user_page_nowait() to get_user_pages_unlocked()").
>>
>> That simply prevents this reproducer hitting get_user_pages_unlocked()
>> instead of grab mmap_sem/get_user_pages/drop mmap_sem.  I.e. does not
>> allow __get_user_pages_locked() to drop/regain ->mmap_sem.
>>
>> The bug may be in the way we call get_user_pages_unlocked() in that
>> commit, but it might easily be a bug in __get_user_pages_locked()
>> exposed by that reproducer somehow.
>
> I think I understand what's going on.  FOLL_NOWAIT handling is a serious
> mess ;-/  I'll probably have something to test tomorrow - I still can't
> reproduce it here, unfortunately.

Hi Al,

syzbot tests for up to 5 minutes. However, if there is a race involved
then you may need more time because the crash is probabilistic.
But from what I see most of the time, if one can't reproduce it
easily, it's usually due to some differences in setup that just don't
allow the crash to happen at all.
FWIW syzbot re-runs each reproducer on a freshly booted dedicated VM
and what it provided is the kernel output it got during run of the
provided program. So we have reasonably high assurance that this
reproducer worked in at least one setup.

Even if you can't reproduce it locally, you can use syzbot testing
service, see "syz test" here:
https://github.com/google/syzkaller/blob/master/docs/syzbot.md#communication-with-syzbot

We also try to collect known causes of non-working reproducers, so if
you get any hints as to why it does not reproduce for you, we can add
it here:
https://github.com/google/syzkaller/blob/master/docs/syzbot.md#crash-does-not-reproduce
Since kvm/ept are present in the stacks, I suspect that it may be due
to a different host CPU unfortunately.

Re: possible deadlock in get_user_pages_unlocked

[Al Viro]

On Fri, Feb 02, 2018 at 05:46:26AM +, Al Viro wrote:
> On Thu, Feb 01, 2018 at 09:35:02PM -0800, Eric Biggers wrote:
> 
> > Try starting up multiple instances of the program; that sometimes helps with
> > these races that are hard to hit (since you may e.g. have a different 
> > number of
> > CPUs than syzbot used).  If I start up 4 instances I see the lockdep splat 
> > after
> > around 2-5 seconds.
> 
> 5 instances in parallel, 10 minutes into the run...
> 
> >  This is on latest Linus tree (4bf772b1467).  Also note the
> > reproducer uses KVM, so if you're running it in a VM it will only work if 
> > you've
> > enabled nested virtualization on the host (kvm_intel.nested=1).
> 
> cat /sys/module/kvm_amd/parameters/nested 
> 1
> 
> on host
> 
> > Also it appears to go away if I revert ce53053ce378c21 ("kvm: switch
> > get_user_page_nowait() to get_user_pages_unlocked()").
> 
> That simply prevents this reproducer hitting get_user_pages_unlocked()
> instead of grab mmap_sem/get_user_pages/drop mmap_sem.  I.e. does not
> allow __get_user_pages_locked() to drop/regain ->mmap_sem.
> 
> The bug may be in the way we call get_user_pages_unlocked() in that
> commit, but it might easily be a bug in __get_user_pages_locked()
> exposed by that reproducer somehow.

I think I understand what's going on.  FOLL_NOWAIT handling is a serious
mess ;-/  I'll probably have something to test tomorrow - I still can't
reproduce it here, unfortunately.

Re: possible deadlock in get_user_pages_unlocked

[Al Viro]

On Thu, Feb 01, 2018 at 09:35:02PM -0800, Eric Biggers wrote:

> Try starting up multiple instances of the program; that sometimes helps with
> these races that are hard to hit (since you may e.g. have a different number 
> of
> CPUs than syzbot used).  If I start up 4 instances I see the lockdep splat 
> after
> around 2-5 seconds.

5 instances in parallel, 10 minutes into the run...

>  This is on latest Linus tree (4bf772b1467).  Also note the
> reproducer uses KVM, so if you're running it in a VM it will only work if 
> you've
> enabled nested virtualization on the host (kvm_intel.nested=1).

cat /sys/module/kvm_amd/parameters/nested 
1

on host

> Also it appears to go away if I revert ce53053ce378c21 ("kvm: switch
> get_user_page_nowait() to get_user_pages_unlocked()").

That simply prevents this reproducer hitting get_user_pages_unlocked()
instead of grab mmap_sem/get_user_pages/drop mmap_sem.  I.e. does not
allow __get_user_pages_locked() to drop/regain ->mmap_sem.

The bug may be in the way we call get_user_pages_unlocked() in that
commit, but it might easily be a bug in __get_user_pages_locked()
exposed by that reproducer somehow.

Re: possible deadlock in get_user_pages_unlocked

[Eric Biggers]

On Fri, Feb 02, 2018 at 04:50:20AM +, Al Viro wrote:
> On Thu, Feb 01, 2018 at 04:58:00PM -0800, syzbot wrote:
> > Hello,
> > 
> > syzbot hit the following crash on upstream commit
> > 7109a04eae81c41ed529da9f3c48c3655ccea741 (Thu Feb 1 17:37:30 2018 +)
> > Merge git://git.kernel.org/pub/scm/linux/kernel/git/davem/ide
> > 
> > So far this crash happened 2 times on upstream.
> > C reproducer is attached.
> 
> Umm...  How reproducible that is?
> 
> > syzkaller reproducer is attached.
> > Raw console output is attached.
> > compiler: gcc (GCC) 7.1.1 20170620
> > .config is attached.
> 
> Can't reproduce with gcc 5.4.1 (same .config, same C reproducer).
> 
> It looks like __get_user_pages_locked() returning with *locked zeroed,
> but ->mmap_sem not dropped.  I don't see what could've lead to it and
> attempts to reproduce had not succeeded so far...
> 
> How long does it normally take for lockdep splat to trigger?
> 

Try starting up multiple instances of the program; that sometimes helps with
these races that are hard to hit (since you may e.g. have a different number of
CPUs than syzbot used).  If I start up 4 instances I see the lockdep splat after
around 2-5 seconds.  This is on latest Linus tree (4bf772b1467).  Also note the
reproducer uses KVM, so if you're running it in a VM it will only work if you've
enabled nested virtualization on the host (kvm_intel.nested=1).

Also it appears to go away if I revert ce53053ce378c21 ("kvm: switch
get_user_page_nowait() to get_user_pages_unlocked()").

- Eric

Re: possible deadlock in get_user_pages_unlocked

[Al Viro]

On Thu, Feb 01, 2018 at 04:58:00PM -0800, syzbot wrote:
> Hello,
> 
> syzbot hit the following crash on upstream commit
> 7109a04eae81c41ed529da9f3c48c3655ccea741 (Thu Feb 1 17:37:30 2018 +)
> Merge git://git.kernel.org/pub/scm/linux/kernel/git/davem/ide
> 
> So far this crash happened 2 times on upstream.
> C reproducer is attached.

Umm...  How reproducible that is?

> syzkaller reproducer is attached.
> Raw console output is attached.
> compiler: gcc (GCC) 7.1.1 20170620
> .config is attached.

Can't reproduce with gcc 5.4.1 (same .config, same C reproducer).

It looks like __get_user_pages_locked() returning with *locked zeroed,
but ->mmap_sem not dropped.  I don't see what could've lead to it and
attempts to reproduce had not succeeded so far...

How long does it normally take for lockdep splat to trigger?