[syzbot] KASAN: null-ptr-deref Read in filp_close (2)

[syzbot] KASAN: null-ptr-deref Read in filp_close (2)

[syzbot]

Hello,

syzbot found the following issue on:

HEAD commit:    5ee96fa9 Merge tag 'irq-urgent-2021-03-21' of git://git.ke..
git tree:       upstream
console output: https://syzkaller.appspot.com/x/log.txt?x=17fb84bed00000
kernel config:  https://syzkaller.appspot.com/x/.config?x=6abda3336c698a07
dashboard link: https://syzkaller.appspot.com/bug?extid=283ce5a46486d6acdbaf

Unfortunately, I don't have any reproducer for this issue yet.

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

==================================================================
BUG: KASAN: null-ptr-deref in instrument_atomic_read include/linux/instrumented.h:71 [inline]
BUG: KASAN: null-ptr-deref in atomic64_read include/asm-generic/atomic-instrumented.h:837 [inline]
BUG: KASAN: null-ptr-deref in atomic_long_read include/asm-generic/atomic-long.h:29 [inline]
BUG: KASAN: null-ptr-deref in filp_close+0x22/0x170 fs/open.c:1289
Read of size 8 at addr 0000000000000077 by task syz-executor.4/16965

CPU: 0 PID: 16965 Comm: syz-executor.4 Not tainted 5.12.0-rc3-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Call Trace:
 __dump_stack lib/dump_stack.c:79 [inline]
 dump_stack+0x141/0x1d7 lib/dump_stack.c:120
 __kasan_report mm/kasan/report.c:403 [inline]
 kasan_report.cold+0x5f/0xd8 mm/kasan/report.c:416
 check_region_inline mm/kasan/generic.c:180 [inline]
 kasan_check_range+0x13d/0x180 mm/kasan/generic.c:186
 instrument_atomic_read include/linux/instrumented.h:71 [inline]
 atomic64_read include/asm-generic/atomic-instrumented.h:837 [inline]
 atomic_long_read include/asm-generic/atomic-long.h:29 [inline]
 filp_close+0x22/0x170 fs/open.c:1289
 close_files fs/file.c:403 [inline]
 put_files_struct fs/file.c:418 [inline]
 put_files_struct+0x1d0/0x350 fs/file.c:415
 exit_files+0x7e/0xa0 fs/file.c:435
 do_exit+0xbc2/0x2a60 kernel/exit.c:820
 do_group_exit+0x125/0x310 kernel/exit.c:922
 get_signal+0x42c/0x2100 kernel/signal.c:2773
 arch_do_signal_or_restart+0x2a8/0x1eb0 arch/x86/kernel/signal.c:789
 handle_signal_work kernel/entry/common.c:147 [inline]
 exit_to_user_mode_loop kernel/entry/common.c:171 [inline]
 exit_to_user_mode_prepare+0x148/0x250 kernel/entry/common.c:208
 __syscall_exit_to_user_mode_work kernel/entry/common.c:290 [inline]
 syscall_exit_to_user_mode+0x19/0x60 kernel/entry/common.c:301
 entry_SYSCALL_64_after_hwframe+0x44/0xae
RIP: 0033:0x466459
Code: Unable to access opcode bytes at RIP 0x46642f.
RSP: 002b:00007feb5e334218 EFLAGS: 00000246 ORIG_RAX: 00000000000000ca
RAX: fffffffffffffe00 RBX: 000000000056bf68 RCX: 0000000000466459
RDX: 0000000000000000 RSI: 0000000000000080 RDI: 000000000056bf68
RBP: 000000000056bf60 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 000000000056bf6c
R13: 0000000000a9fb1f R14: 00007feb5e334300 R15: 0000000000022000
==================================================================


---
This report is generated by a bot. It may contain errors.
See https://goo.gl/tpsmEJ for more information about syzbot.
syzbot engineers can be reached at syzkaller@googlegroups.com.

syzbot will keep track of this issue. See:
https://goo.gl/tpsmEJ#status for how to communicate with syzbot.

Re: [syzbot] KASAN: null-ptr-deref Read in filp_close (2)

[Dmitry Vyukov]

On Fri, Mar 26, 2021 at 8:55 AM syzbot
<syzbot+283ce5a46486d6acdbaf@syzkaller.appspotmail.com> wrote:
>
> Hello,
>
> syzbot found the following issue on:
>
> HEAD commit:    5ee96fa9 Merge tag 'irq-urgent-2021-03-21' of git://git.ke..
> git tree:       upstream
> console output: https://syzkaller.appspot.com/x/log.txt?x=17fb84bed00000
> kernel config:  https://syzkaller.appspot.com/x/.config?x=6abda3336c698a07
> dashboard link: https://syzkaller.appspot.com/bug?extid=283ce5a46486d6acdbaf
>
> Unfortunately, I don't have any reproducer for this issue yet.
>
> IMPORTANT: if you fix the issue, please add the following tag to the commit:
> Reported-by: syzbot+283ce5a46486d6acdbaf@syzkaller.appspotmail.com

I was able to reproduce this with the following C program:
https://gist.githubusercontent.com/dvyukov/00fb7aae489f22c60b4e64b45ef14d60/raw/cb368ca523d01986c2917f4414add0893b8f4243/gistfile1.txt

+Christian
The repro also contains close_range as the previous similar crash:
https://syzkaller.appspot.com/bug?id=1bef50bdd9622a1969608d1090b2b4a588d0c6ac
I don't know if it's related or not in this case, but looks suspicious.


> ==================================================================
> BUG: KASAN: null-ptr-deref in instrument_atomic_read include/linux/instrumented.h:71 [inline]
> BUG: KASAN: null-ptr-deref in atomic64_read include/asm-generic/atomic-instrumented.h:837 [inline]
> BUG: KASAN: null-ptr-deref in atomic_long_read include/asm-generic/atomic-long.h:29 [inline]
> BUG: KASAN: null-ptr-deref in filp_close+0x22/0x170 fs/open.c:1289
> Read of size 8 at addr 0000000000000077 by task syz-executor.4/16965
>
> CPU: 0 PID: 16965 Comm: syz-executor.4 Not tainted 5.12.0-rc3-syzkaller #0
> Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
> Call Trace:
>  __dump_stack lib/dump_stack.c:79 [inline]
>  dump_stack+0x141/0x1d7 lib/dump_stack.c:120
>  __kasan_report mm/kasan/report.c:403 [inline]
>  kasan_report.cold+0x5f/0xd8 mm/kasan/report.c:416
>  check_region_inline mm/kasan/generic.c:180 [inline]
>  kasan_check_range+0x13d/0x180 mm/kasan/generic.c:186
>  instrument_atomic_read include/linux/instrumented.h:71 [inline]
>  atomic64_read include/asm-generic/atomic-instrumented.h:837 [inline]
>  atomic_long_read include/asm-generic/atomic-long.h:29 [inline]
>  filp_close+0x22/0x170 fs/open.c:1289
>  close_files fs/file.c:403 [inline]
>  put_files_struct fs/file.c:418 [inline]
>  put_files_struct+0x1d0/0x350 fs/file.c:415
>  exit_files+0x7e/0xa0 fs/file.c:435
>  do_exit+0xbc2/0x2a60 kernel/exit.c:820
>  do_group_exit+0x125/0x310 kernel/exit.c:922
>  get_signal+0x42c/0x2100 kernel/signal.c:2773
>  arch_do_signal_or_restart+0x2a8/0x1eb0 arch/x86/kernel/signal.c:789
>  handle_signal_work kernel/entry/common.c:147 [inline]
>  exit_to_user_mode_loop kernel/entry/common.c:171 [inline]
>  exit_to_user_mode_prepare+0x148/0x250 kernel/entry/common.c:208
>  __syscall_exit_to_user_mode_work kernel/entry/common.c:290 [inline]
>  syscall_exit_to_user_mode+0x19/0x60 kernel/entry/common.c:301
>  entry_SYSCALL_64_after_hwframe+0x44/0xae
> RIP: 0033:0x466459
> Code: Unable to access opcode bytes at RIP 0x46642f.
> RSP: 002b:00007feb5e334218 EFLAGS: 00000246 ORIG_RAX: 00000000000000ca
> RAX: fffffffffffffe00 RBX: 000000000056bf68 RCX: 0000000000466459
> RDX: 0000000000000000 RSI: 0000000000000080 RDI: 000000000056bf68
> RBP: 000000000056bf60 R08: 0000000000000000 R09: 0000000000000000
> R10: 0000000000000000 R11: 0000000000000246 R12: 000000000056bf6c
> R13: 0000000000a9fb1f R14: 00007feb5e334300 R15: 0000000000022000
> ==================================================================
>
>
> ---
> This report is generated by a bot. It may contain errors.
> See https://goo.gl/tpsmEJ for more information about syzbot.
> syzbot engineers can be reached at syzkaller@googlegroups.com.
>
> syzbot will keep track of this issue. See:
> https://goo.gl/tpsmEJ#status for how to communicate with syzbot.
>
> --
> You received this message because you are subscribed to the Google Groups "syzkaller-bugs" group.
> To unsubscribe from this group and stop receiving emails from it, send an email to syzkaller-bugs+unsubscribe@googlegroups.com.
> To view this discussion on the web visit https://groups.google.com/d/msgid/syzkaller-bugs/00000000000069c40405be6bdad4%40google.com.

Re: [syzbot] KASAN: null-ptr-deref Read in filp_close (2)

[Christian Brauner]

On Fri, Mar 26, 2021 at 09:02:08AM +0100, Dmitry Vyukov wrote:
> On Fri, Mar 26, 2021 at 8:55 AM syzbot
> <syzbot+283ce5a46486d6acdbaf@syzkaller.appspotmail.com> wrote:
> >
> > Hello,
> >
> > syzbot found the following issue on:
> >
> > HEAD commit:    5ee96fa9 Merge tag 'irq-urgent-2021-03-21' of git://git.ke..
> > git tree:       upstream
> > console output: https://syzkaller.appspot.com/x/log.txt?x=17fb84bed00000
> > kernel config:  https://syzkaller.appspot.com/x/.config?x=6abda3336c698a07
> > dashboard link: https://syzkaller.appspot.com/bug?extid=283ce5a46486d6acdbaf
> >
> > Unfortunately, I don't have any reproducer for this issue yet.
> >
> > IMPORTANT: if you fix the issue, please add the following tag to the commit:
> > Reported-by: syzbot+283ce5a46486d6acdbaf@syzkaller.appspotmail.com
> 
> I was able to reproduce this with the following C program:
> https://gist.githubusercontent.com/dvyukov/00fb7aae489f22c60b4e64b45ef14d60/raw/cb368ca523d01986c2917f4414add0893b8f4243/gistfile1.txt
> 
> +Christian
> The repro also contains close_range as the previous similar crash:
> https://syzkaller.appspot.com/bug?id=1bef50bdd9622a1969608d1090b2b4a588d0c6ac
> I don't know if it's related or not in this case, but looks suspicious.

Hm, I fail to reproduce this with your repro. Do you need to have it run
for a long time?
One thing that strucky my eye is that binfmt_misc gets setup which made
me go huh and I see commit

commit e7850f4d844e0acfac7e570af611d89deade3146
Author: Lior Ribak <liorribak@gmail.com>
Date:   Fri Mar 12 21:07:41 2021 -0800

    binfmt_misc: fix possible deadlock in bm_register_write

which uses filp_close() after having called open_exec() on the
interpreter which makes me wonder why this doesn't have to use fput()
like in all other codepaths for binfmnt_*.

Can you revert this commit and see if you can reproduce this issue.
Maybe this is a complete red herring but worth a try.

Christian

> 
> 
> > ==================================================================
> > BUG: KASAN: null-ptr-deref in instrument_atomic_read include/linux/instrumented.h:71 [inline]
> > BUG: KASAN: null-ptr-deref in atomic64_read include/asm-generic/atomic-instrumented.h:837 [inline]
> > BUG: KASAN: null-ptr-deref in atomic_long_read include/asm-generic/atomic-long.h:29 [inline]
> > BUG: KASAN: null-ptr-deref in filp_close+0x22/0x170 fs/open.c:1289
> > Read of size 8 at addr 0000000000000077 by task syz-executor.4/16965
> >
> > CPU: 0 PID: 16965 Comm: syz-executor.4 Not tainted 5.12.0-rc3-syzkaller #0
> > Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
> > Call Trace:
> >  __dump_stack lib/dump_stack.c:79 [inline]
> >  dump_stack+0x141/0x1d7 lib/dump_stack.c:120
> >  __kasan_report mm/kasan/report.c:403 [inline]
> >  kasan_report.cold+0x5f/0xd8 mm/kasan/report.c:416
> >  check_region_inline mm/kasan/generic.c:180 [inline]
> >  kasan_check_range+0x13d/0x180 mm/kasan/generic.c:186
> >  instrument_atomic_read include/linux/instrumented.h:71 [inline]
> >  atomic64_read include/asm-generic/atomic-instrumented.h:837 [inline]
> >  atomic_long_read include/asm-generic/atomic-long.h:29 [inline]
> >  filp_close+0x22/0x170 fs/open.c:1289
> >  close_files fs/file.c:403 [inline]
> >  put_files_struct fs/file.c:418 [inline]
> >  put_files_struct+0x1d0/0x350 fs/file.c:415
> >  exit_files+0x7e/0xa0 fs/file.c:435
> >  do_exit+0xbc2/0x2a60 kernel/exit.c:820
> >  do_group_exit+0x125/0x310 kernel/exit.c:922
> >  get_signal+0x42c/0x2100 kernel/signal.c:2773
> >  arch_do_signal_or_restart+0x2a8/0x1eb0 arch/x86/kernel/signal.c:789
> >  handle_signal_work kernel/entry/common.c:147 [inline]
> >  exit_to_user_mode_loop kernel/entry/common.c:171 [inline]
> >  exit_to_user_mode_prepare+0x148/0x250 kernel/entry/common.c:208
> >  __syscall_exit_to_user_mode_work kernel/entry/common.c:290 [inline]
> >  syscall_exit_to_user_mode+0x19/0x60 kernel/entry/common.c:301
> >  entry_SYSCALL_64_after_hwframe+0x44/0xae
> > RIP: 0033:0x466459
> > Code: Unable to access opcode bytes at RIP 0x46642f.
> > RSP: 002b:00007feb5e334218 EFLAGS: 00000246 ORIG_RAX: 00000000000000ca
> > RAX: fffffffffffffe00 RBX: 000000000056bf68 RCX: 0000000000466459
> > RDX: 0000000000000000 RSI: 0000000000000080 RDI: 000000000056bf68
> > RBP: 000000000056bf60 R08: 0000000000000000 R09: 0000000000000000
> > R10: 0000000000000000 R11: 0000000000000246 R12: 000000000056bf6c
> > R13: 0000000000a9fb1f R14: 00007feb5e334300 R15: 0000000000022000
> > ==================================================================
> >
> >
> > ---
> > This report is generated by a bot. It may contain errors.
> > See https://goo.gl/tpsmEJ for more information about syzbot.
> > syzbot engineers can be reached at syzkaller@googlegroups.com.
> >
> > syzbot will keep track of this issue. See:
> > https://goo.gl/tpsmEJ#status for how to communicate with syzbot.
> >
> > --
> > You received this message because you are subscribed to the Google Groups "syzkaller-bugs" group.
> > To unsubscribe from this group and stop receiving emails from it, send an email to syzkaller-bugs+unsubscribe@googlegroups.com.
> > To view this discussion on the web visit https://groups.google.com/d/msgid/syzkaller-bugs/00000000000069c40405be6bdad4%40google.com.

Re: [syzbot] KASAN: null-ptr-deref Read in filp_close (2)

[Dmitry Vyukov]

On Fri, Mar 26, 2021 at 10:12 AM Christian Brauner
<christian.brauner@ubuntu.com> wrote:
>
> On Fri, Mar 26, 2021 at 09:02:08AM +0100, Dmitry Vyukov wrote:
> > On Fri, Mar 26, 2021 at 8:55 AM syzbot
> > <syzbot+283ce5a46486d6acdbaf@syzkaller.appspotmail.com> wrote:
> > >
> > > Hello,
> > >
> > > syzbot found the following issue on:
> > >
> > > HEAD commit:    5ee96fa9 Merge tag 'irq-urgent-2021-03-21' of git://git.ke..
> > > git tree:       upstream
> > > console output: https://syzkaller.appspot.com/x/log.txt?x=17fb84bed00000
> > > kernel config:  https://syzkaller.appspot.com/x/.config?x=6abda3336c698a07
> > > dashboard link: https://syzkaller.appspot.com/bug?extid=283ce5a46486d6acdbaf
> > >
> > > Unfortunately, I don't have any reproducer for this issue yet.
> > >
> > > IMPORTANT: if you fix the issue, please add the following tag to the commit:
> > > Reported-by: syzbot+283ce5a46486d6acdbaf@syzkaller.appspotmail.com
> >
> > I was able to reproduce this with the following C program:
> > https://gist.githubusercontent.com/dvyukov/00fb7aae489f22c60b4e64b45ef14d60/raw/cb368ca523d01986c2917f4414add0893b8f4243/gistfile1.txt
> >
> > +Christian
> > The repro also contains close_range as the previous similar crash:
> > https://syzkaller.appspot.com/bug?id=1bef50bdd9622a1969608d1090b2b4a588d0c6ac
> > I don't know if it's related or not in this case, but looks suspicious.
>
> Hm, I fail to reproduce this with your repro. Do you need to have it run
> for a long time?
> One thing that strucky my eye is that binfmt_misc gets setup which made
> me go huh and I see commit
>
> commit e7850f4d844e0acfac7e570af611d89deade3146
> Author: Lior Ribak <liorribak@gmail.com>
> Date:   Fri Mar 12 21:07:41 2021 -0800
>
>     binfmt_misc: fix possible deadlock in bm_register_write
>
> which uses filp_close() after having called open_exec() on the
> interpreter which makes me wonder why this doesn't have to use fput()
> like in all other codepaths for binfmnt_*.
>
> Can you revert this commit and see if you can reproduce this issue.
> Maybe this is a complete red herring but worth a try.


This program reproduces the crash for me almost immediately. Are you
sure you used the right commit/config?

I tried to revert the commit, but it still crashed:

    Revert "binfmt_misc: pass binfmt_misc flags to the interpreter"
    This reverts commit 2347961b11d4079deace3c81dceed460c08a8fc1.

root@syzkaller:~# ./a.out
[   52.774025][ T8417] cgroup: Unknown subsys name 'cpuset'
[   52.774025][ T8419] cgroup: Unknown subsys name 'cpuset'
[   52.774102][ T8420] cgroup: Unknown subsys name 'cpuset'
[   52.779016][ T8418] cgroup: Unknown subsys name 'cpuset'
[   53.884323][ T8417] IPVS: ftp: loaded support on port[0] = 21
[   53.886698][ T8418] IPVS: ftp: loaded support on port[0] = 21
[   53.902865][ T8420] IPVS: ftp: loaded support on port[0] = 21
[   53.903916][ T8419] IPVS: ftp: loaded support on port[0] = 21
[   53.988507][ T8420] chnl_net:caif_netlink_parms(): no params data found
[   54.047612][ T8417] chnl_net:caif_netlink_parms(): no params data found
[   54.083928][ T8420] bridge0: port 1(bridge_slave_0) entered blocking state
[   54.085630][ T8420] bridge0: port 1(bridge_slave_0) entered disabled state
[   54.087502][ T8420] device bridge_slave_0 entered promiscuous mode
[   54.092748][ T8420] bridge0: port 2(bridge_slave_1) entered blocking state
[   54.094368][ T8420] bridge0: port 2(bridge_slave_1) entered disabled state
[   54.096169][ T8420] device bridge_slave_1 entered promiscuous mode
[   54.147535][ T8418] chnl_net:caif_netlink_parms(): no params data found

[   54.196200][ T8420] bond0: (slave bond_slave_0): Enslaving as an
active interface with an up link
[   54.204123][ T8417] bridge0: port 1(bridge_slave_0) entered blocking state
[   54.205410][ T8417] bridge0: port 1(bridge_slave_0) entered disabled state
[   54.207145][ T8417] device bridge_slave_0 entered promiscuous mode
[   54.210785][ T8417] bridge0: port 2(bridge_slave_1) entered blocking state
[   54.211923][ T8417] bridge0: port 2(bridge_slave_1) entered disabled state
[   54.213488][ T8417] device bridge_slave_1 entered promiscuous mode
[   54.216445][ T8420] bond0: (slave bond_slave_1): Enslaving as an
active interface with an up link
[   54.224477][ T8419] chnl_net:caif_netlink_parms(): no params data found
[   54.239118][ T8417] bond0: (slave bond_slave_0): Enslaving as an
active interface with an up link
[   54.256575][ T8417] bond0: (slave bond_slave_1): Enslaving as an
active interface with an up link
[   54.260275][ T8420] team0: Port device team_slave_0 added
[   54.279533][ T8420] team0: Port device team_slave_1 added
[   54.292773][ T8418] bridge0: port 1(bridge_slave_0) entered blocking state
[   54.322675][ T8418] bridge0: port 1(bridge_slave_0) entered disabled state
[   54.351991][ T8418] device bridge_slave_0 entered promiscuous mode

[   54.383614][ T8418] bridge0: port 2(bridge_slave_1) entered blocking state
[   54.415226][ T8418] bridge0: port 2(bridge_slave_1) entered disabled state
[   54.447532][ T8418] device bridge_slave_1 entered promiscuous mode
[   54.488335][ T8417] team0: Port device team_slave_0 added
[   54.503504][ T8420] batman_adv: batadv0: Adding interface: batadv_slave_0
[   54.504623][ T8420] batman_adv: batadv0: The MTU of interface
batadv_slave_0 is too small (1500) to handle the transport of
batman-adv packets. Packets going over th.
[   54.508710][ T8420] batman_adv: batadv0: Not using interface
batadv_slave_0 (retrying later): interface not active
[   54.512314][ T8417] team0: Port device team_slave_1 added
[   54.514066][ T8420] batman_adv: batadv0: Adding interface: batadv_slave_1
[   54.515198][ T8420] batman_adv: batadv0: The MTU of interface
batadv_slave_1 is too small (1500) to handle the transport of
batman-adv packets. Packets going over th.
[   54.519650][ T8420] batman_adv: batadv0: Not using interface
batadv_slave_1 (retrying later): interface not active
[   54.540431][ T8418] bond0: (slave bond_slave_0): Enslaving as an
active interface with an up link
[   54.542677][ T8419] bridge0: port 1(bridge_slave_0) entered blocking state
[   54.544534][ T8419] bridge0: port 1(bridge_slave_0) entered disabled state
[   54.546775][ T8419] device bridge_slave_0 entered promiscuous mode
[   54.552027][ T8419] bridge0: port 2(bridge_slave_1) entered blocking state
[   54.553578][ T8419] bridge0: port 2(bridge_slave_1) entered disabled state
[   54.555492][ T8419] device bridge_slave_1 entered promiscuous mode
[   54.567672][ T8418] bond0: (slave bond_slave_1): Enslaving as an
active interface with an up link
[   54.573989][ T8417] batman_adv: batadv0: Adding interface: batadv_slave_0
[   54.575868][ T8417] batman_adv: batadv0: The MTU of interface
batadv_slave_0 is too small (1500) to handle the transport of
batman-adv packets. Packets going over th.
[   54.582147][ T8417] batman_adv: batadv0: Not using interface
batadv_slave_0 (retrying later): interface not active
[   54.596432][ T8420] device hsr_slave_0 entered promiscuous mode
[   54.598893][ T8420] device hsr_slave_1 entered promiscuous mode
[   54.607754][ T8417] batman_adv: batadv0: Adding interface: batadv_slave_1
[   54.609041][ T8417] batman_adv: batadv0: The MTU of interface
batadv_slave_1 is too small (1500) to handle the transport of
batman-adv packets. Packets going over th.
[   54.619663][ T8417] batman_adv: batadv0: Not using interface
batadv_slave_1 (retrying later): interface not active
[   54.624989][ T8419] bond0: (slave bond_slave_0): Enslaving as an
active interface with an up link
[   54.629738][ T8418] team0: Port device team_slave_0 added
[   54.636611][ T8418] team0: Port device team_slave_1 added
[   54.638642][ T8419] bond0: (slave bond_slave_1): Enslaving as an
active interface with an up link
[   54.668637][ T8418] batman_adv: batadv0: Adding interface: batadv_slave_0
[   54.669792][ T8418] batman_adv: batadv0: The MTU of interface
batadv_slave_0 is too small (1500) to handle the transport of
batman-adv packets. Packets going over th.
[   54.673749][ T8418] batman_adv: batadv0: Not using interface
batadv_slave_0 (retrying later): interface not active
[   54.680397][ T8419] team0: Port device team_slave_0 added
[   54.684125][ T8417] device hsr_slave_0 entered promiscuous mode
[   54.686156][ T8417] device hsr_slave_1 entered promiscuous mode
[   54.687835][ T8417] debugfs: Directory 'hsr0' with parent 'hsr'
already present!
[   54.689864][ T8417] Cannot create hsr debugfs directory
[   54.691469][ T8418] batman_adv: batadv0: Adding interface: batadv_slave_1
[   54.692806][ T8418] batman_adv: batadv0: The MTU of interface
batadv_slave_1 is too small (1500) to handle the transport of
batman-adv packets. Packets going over th.
[   54.697723][ T8418] batman_adv: batadv0: Not using interface
batadv_slave_1 (retrying later): interface not active
[   54.705348][ T8419] team0: Port device team_slave_1 added
[   54.727458][ T8418] device hsr_slave_0 entered promiscuous mode
[   54.728810][ T8418] device hsr_slave_1 entered promiscuous mode
[   54.730089][ T8418] debugfs: Directory 'hsr0' with parent 'hsr'
already present!
[   54.731279][ T8418] Cannot create hsr debugfs directory
[   54.748153][ T8419] batman_adv: batadv0: Adding interface: batadv_slave_0
[   54.749632][ T8419] batman_adv: batadv0: The MTU of interface
batadv_slave_0 is too small (1500) to handle the transport of
batman-adv packets. Packets going over th.
[   54.755030][ T8419] batman_adv: batadv0: Not using interface
batadv_slave_0 (retrying later): interface not active
[   54.768306][ T8419] batman_adv: batadv0: Adding interface: batadv_slave_1
[   54.769982][ T8419] batman_adv: batadv0: The MTU of interface
batadv_slave_1 is too small (1500) to handle the transport of
batman-adv packets. Packets going over th.
[   54.774855][ T8419] batman_adv: batadv0: Not using interface
batadv_slave_1 (retrying later): interface not active
[   54.829550][ T8419] device hsr_slave_0 entered promiscuous mode
[   54.831300][ T8419] device hsr_slave_1 entered promiscuous mode
[   54.832906][ T8419] debugfs: Directory 'hsr0' with parent 'hsr'
already present!
[   54.834451][ T8419] Cannot create hsr debugfs directory
[   54.887137][ T8420] netdevsim netdevsim3 netdevsim0: renamed from eth0
[   54.891644][ T8420] netdevsim netdevsim3 netdevsim1: renamed from eth1
[   54.900135][ T8420] netdevsim netdevsim3 netdevsim2: renamed from eth2
[   54.904165][ T8420] netdevsim netdevsim3 netdevsim3: renamed from eth3
[   54.925803][ T8417] netdevsim netdevsim0 netdevsim0: renamed from eth0
[   54.930799][ T8417] netdevsim netdevsim0 netdevsim1: renamed from eth1
[   54.933594][ T8417] netdevsim netdevsim0 netdevsim2: renamed from eth2
[   54.938436][ T8417] netdevsim netdevsim0 netdevsim3: renamed from eth3
[   54.941530][ T8420] bridge0: port 2(bridge_slave_1) entered blocking state
[   54.942785][ T8420] bridge0: port 2(bridge_slave_1) entered forwarding state
[   54.944287][ T8420] bridge0: port 1(bridge_slave_0) entered blocking state
[   54.945415][ T8420] bridge0: port 1(bridge_slave_0) entered forwarding state
[   54.962977][ T8418] netdevsim netdevsim2 netdevsim0: renamed from eth0
[   54.965605][ T8418] netdevsim netdevsim2 netdevsim1: renamed from eth1
[   54.968715][ T8418] netdevsim netdevsim2 netdevsim2: renamed from eth2
[   54.971746][ T8418] netdevsim netdevsim2 netdevsim3: renamed from eth3
[   54.994089][ T8417] bridge0: port 2(bridge_slave_1) entered blocking state
[   54.995230][ T8417] bridge0: port 2(bridge_slave_1) entered forwarding state
[   54.996440][ T8417] bridge0: port 1(bridge_slave_0) entered blocking state
[   54.997554][ T8417] bridge0: port 1(bridge_slave_0) entered forwarding state
[   55.006265][ T8419] netdevsim netdevsim1 netdevsim0: renamed from eth0
[   55.015556][ T8419] netdevsim netdevsim1 netdevsim1: renamed from eth1
[   55.019751][ T8419] netdevsim netdevsim1 netdevsim2: renamed from eth2
[   55.024621][ T8418] bridge0: port 2(bridge_slave_1) entered blocking state
[   55.026236][ T8418] bridge0: port 2(bridge_slave_1) entered forwarding state
[   55.027997][ T8418] bridge0: port 1(bridge_slave_0) entered blocking state
[   55.029650][ T8418] bridge0: port 1(bridge_slave_0) entered forwarding state
[   55.033870][ T8419] netdevsim netdevsim1 netdevsim3: renamed from eth3
[   55.045317][ T5237] bridge0: port 1(bridge_slave_0) entered disabled state
[   55.047268][ T5237] bridge0: port 2(bridge_slave_1) entered disabled state
[   55.049895][ T5237] bridge0: port 1(bridge_slave_0) entered disabled state
[   55.051483][ T5237] bridge0: port 2(bridge_slave_1) entered disabled state
[   55.054479][ T5237] bridge0: port 1(bridge_slave_0) entered disabled state
[   55.056295][ T5237] bridge0: port 2(bridge_slave_1) entered disabled state
[   55.082924][ T8420] 8021q: adding VLAN 0 to HW filter on device bond0
[   55.102238][   T12] IPv6: ADDRCONF(NETDEV_CHANGE): veth1: link becomes ready
[   55.104738][   T12] IPv6: ADDRCONF(NETDEV_CHANGE): veth0: link becomes ready
[   55.108466][ T8420] 8021q: adding VLAN 0 to HW filter on device team0
[   55.122029][   T12] IPv6: ADDRCONF(NETDEV_CHANGE): veth0_to_bridge:
link becomes ready
[   55.123807][   T12] IPv6: ADDRCONF(NETDEV_CHANGE): bridge_slave_0:
link becomes ready
[   55.125417][   T12] bridge0: port 1(bridge_slave_0) entered blocking state
[   55.126654][   T12] bridge0: port 1(bridge_slave_0) entered forwarding state
[   55.129601][ T8417] 8021q: adding VLAN 0 to HW filter on device bond0
[   55.139730][   T12] IPv6: ADDRCONF(NETDEV_CHANGE): veth1_to_bridge:
link becomes ready
[   55.141602][   T12] IPv6: ADDRCONF(NETDEV_CHANGE): bridge_slave_1:
link becomes ready
[   55.143115][   T12] bridge0: port 2(bridge_slave_1) entered blocking state
[   55.144228][   T12] bridge0: port 2(bridge_slave_1) entered forwarding state
[   55.153194][ T3916] IPv6: ADDRCONF(NETDEV_CHANGE): veth0_to_bond:
link becomes ready
[   55.159570][ T4945] IPv6: ADDRCONF(NETDEV_CHANGE): veth1: link becomes ready
[   55.162235][ T4945] IPv6: ADDRCONF(NETDEV_CHANGE): veth0: link becomes ready
[   55.166161][ T3916] IPv6: ADDRCONF(NETDEV_CHANGE): veth1_to_bond:
link becomes ready
[   55.175784][ T8417] 8021q: adding VLAN 0 to HW filter on device team0
[   55.178483][ T8418] 8021q: adding VLAN 0 to HW filter on device bond0
[   55.182508][   T12] IPv6: ADDRCONF(NETDEV_CHANGE): veth0_to_team:
link becomes ready
[   55.184444][   T12] IPv6: ADDRCONF(NETDEV_CHANGE): team_slave_0:
link becomes ready
[   55.189340][ T3916] IPv6: ADDRCONF(NETDEV_CHANGE): team0: link becomes ready
[   55.191123][ T3916] IPv6: ADDRCONF(NETDEV_CHANGE): veth0_to_bridge:
link becomes ready
[   55.192865][ T3916] IPv6: ADDRCONF(NETDEV_CHANGE): bridge_slave_0:
link becomes ready
[   55.194478][ T3916] bridge0: port 1(bridge_slave_0) entered blocking state
[   55.195650][ T3916] bridge0: port 1(bridge_slave_0) entered forwarding state
[   55.207785][ T8427] IPv6: ADDRCONF(NETDEV_CHANGE): veth1_to_bridge:
link becomes ready
[   55.209481][ T8427] IPv6: ADDRCONF(NETDEV_CHANGE): bridge_slave_1:
link becomes ready
[   55.211025][ T8427] bridge0: port 2(bridge_slave_1) entered blocking state
[   55.212131][ T8427] bridge0: port 2(bridge_slave_1) entered forwarding state
[   55.213461][ T8427] IPv6: ADDRCONF(NETDEV_CHANGE): veth1_to_team:
link becomes ready
[   55.215100][ T8427] IPv6: ADDRCONF(NETDEV_CHANGE): team_slave_1:
link becomes ready
[   55.216730][ T8427] IPv6: ADDRCONF(NETDEV_CHANGE): veth1: link becomes ready
[   55.218215][ T8427] IPv6: ADDRCONF(NETDEV_CHANGE): veth0: link becomes ready
[   55.227631][ T8460] IPv6: ADDRCONF(NETDEV_CHANGE): veth0_to_hsr:
link becomes ready
[   55.230092][ T8460] IPv6: ADDRCONF(NETDEV_CHANGE): hsr_slave_0:
link becomes ready
[   55.231894][ T8460] IPv6: ADDRCONF(NETDEV_CHANGE): veth0_to_bond:
link becomes ready
[   55.235044][ T8418] 8021q: adding VLAN 0 to HW filter on device team0
[   55.237516][ T8460] IPv6: ADDRCONF(NETDEV_CHANGE): veth1_to_hsr:
link becomes ready
[   55.239461][ T8460] IPv6: ADDRCONF(NETDEV_CHANGE): hsr_slave_1:
link becomes ready
[   55.247613][ T8420] IPv6: ADDRCONF(NETDEV_CHANGE): hsr0: link becomes ready
[   55.251109][ T4945] IPv6: ADDRCONF(NETDEV_CHANGE): veth1_to_bond:
link becomes ready
[   55.253309][ T4945] IPv6: ADDRCONF(NETDEV_CHANGE): veth0_to_team:
link becomes ready
[   55.255350][ T4945] IPv6: ADDRCONF(NETDEV_CHANGE): team_slave_0:
link becomes ready
[   55.264928][ T4945] IPv6: ADDRCONF(NETDEV_CHANGE): team0: link becomes ready
[   55.266460][ T4945] IPv6: ADDRCONF(NETDEV_CHANGE): veth0_to_bridge:
link becomes ready
[   55.267980][ T4945] IPv6: ADDRCONF(NETDEV_CHANGE): bridge_slave_0:
link becomes ready
[   55.269494][ T4945] bridge0: port 1(bridge_slave_0) entered blocking state
[   55.270603][ T4945] bridge0: port 1(bridge_slave_0) entered forwarding state
[   55.271971][ T4945] IPv6: ADDRCONF(NETDEV_CHANGE): veth1_to_team:
link becomes ready
[   55.273575][ T4945] IPv6: ADDRCONF(NETDEV_CHANGE): team_slave_1:
link becomes ready
[   55.279757][ T3916] IPv6: ADDRCONF(NETDEV_CHANGE): veth1_to_bridge:
link becomes ready
[   55.282041][ T3916] IPv6: ADDRCONF(NETDEV_CHANGE): bridge_slave_1:
link becomes ready
[   55.284040][ T3916] bridge0: port 2(bridge_slave_1) entered blocking state
[   55.285560][ T3916] bridge0: port 2(bridge_slave_1) entered forwarding state
[   55.297126][ T8417] hsr0: Slave A (hsr_slave_0) is not up; please
bring it up to get a fully working HSR network
[   55.298778][ T8417] hsr0: Slave B (hsr_slave_1) is not up; please
bring it up to get a fully working HSR network
[   55.303433][ T4945] IPv6: ADDRCONF(NETDEV_CHANGE): veth0_to_bond:
link becomes ready
[   55.305692][ T4945] IPv6: ADDRCONF(NETDEV_CHANGE): veth0_to_hsr:
link becomes ready
[   55.307922][ T4945] IPv6: ADDRCONF(NETDEV_CHANGE): hsr_slave_0:
link becomes ready
[   55.311494][ T4945] IPv6: ADDRCONF(NETDEV_CHANGE): veth1_to_hsr:
link becomes ready
[   55.313580][ T4945] IPv6: ADDRCONF(NETDEV_CHANGE): hsr_slave_1:
link becomes ready
[   55.315713][ T4945] IPv6: ADDRCONF(NETDEV_CHANGE): hsr0: link becomes ready
[   55.322963][ T8419] 8021q: adding VLAN 0 to HW filter on device bond0
[   55.325385][ T3916] IPv6: ADDRCONF(NETDEV_CHANGE): veth1_to_bond:
link becomes ready
[   55.349443][ T8427] IPv6: ADDRCONF(NETDEV_CHANGE): vxcan1: link becomes ready
[   55.350706][ T8427] IPv6: ADDRCONF(NETDEV_CHANGE): vxcan0: link becomes ready
[   55.351959][ T8427] IPv6: ADDRCONF(NETDEV_CHANGE): veth1: link becomes ready
[   55.353372][ T8427] IPv6: ADDRCONF(NETDEV_CHANGE): veth0: link becomes ready
[   55.354769][ T8427] IPv6: ADDRCONF(NETDEV_CHANGE): veth0_to_team:
link becomes ready
[   55.356388][ T8427] IPv6: ADDRCONF(NETDEV_CHANGE): team_slave_0:
link becomes ready
[   55.357942][ T8427] IPv6: ADDRCONF(NETDEV_CHANGE): vxcan1: link becomes ready
[   55.359611][ T8427] IPv6: ADDRCONF(NETDEV_CHANGE): vxcan0: link becomes ready
[   55.360815][ T8427] IPv6: ADDRCONF(NETDEV_CHANGE): veth1_to_team:
link becomes ready
[   55.362478][ T8427] IPv6: ADDRCONF(NETDEV_CHANGE): team_slave_1:
link becomes ready
[   55.364023][ T8427] IPv6: ADDRCONF(NETDEV_CHANGE): hsr_slave_0:
link becomes ready
[   55.370049][ T8417] 8021q: adding VLAN 0 to HW filter on device batadv0
[   55.371639][ T8427] IPv6: ADDRCONF(NETDEV_CHANGE): team0: link becomes ready
[   55.373247][ T8427] IPv6: ADDRCONF(NETDEV_CHANGE): hsr_slave_1:
link becomes ready
[   55.376112][ T8419] 8021q: adding VLAN 0 to HW filter on device team0
[   55.381526][ T8418] IPv6: ADDRCONF(NETDEV_CHANGE): hsr0: link becomes ready
[   55.383755][ T4945] IPv6: ADDRCONF(NETDEV_CHANGE): veth0_to_bridge:
link becomes ready
[   55.385310][ T4945] IPv6: ADDRCONF(NETDEV_CHANGE): bridge_slave_0:
link becomes ready
[   55.386752][ T4945] bridge0: port 1(bridge_slave_0) entered blocking state
[   55.387865][ T4945] bridge0: port 1(bridge_slave_0) entered forwarding state
[   55.390813][ T8420] 8021q: adding VLAN 0 to HW filter on device batadv0
[   55.396284][ T8458] IPv6: ADDRCONF(NETDEV_CHANGE): bridge0: link
becomes ready
[   55.397725][ T8458] IPv6: ADDRCONF(NETDEV_CHANGE): veth1_to_bridge:
link becomes ready
[   55.399586][ T8458] IPv6: ADDRCONF(NETDEV_CHANGE): bridge_slave_1:
link becomes ready
[   55.401069][ T8458] bridge0: port 2(bridge_slave_1) entered blocking state
[   55.402284][ T8458] bridge0: port 2(bridge_slave_1) entered forwarding state
[   55.417004][ T8458] IPv6: ADDRCONF(NETDEV_CHANGE): veth0_to_bond:
link becomes ready
[   55.424546][ T3916] IPv6: ADDRCONF(NETDEV_CHANGE): veth0_virt_wifi:
link becomes ready
[   55.426557][ T3916] IPv6: ADDRCONF(NETDEV_CHANGE): veth1_to_bond:
link becomes ready
[   55.435722][ T8462] IPv6: ADDRCONF(NETDEV_CHANGE): veth0_to_team:
link becomes ready
[   55.437382][ T8462] IPv6: ADDRCONF(NETDEV_CHANGE): team_slave_0:
link becomes ready
[   55.438957][ T8462] IPv6: ADDRCONF(NETDEV_CHANGE): veth1_virt_wifi:
link becomes ready
[   55.441726][ T8462] IPv6: ADDRCONF(NETDEV_CHANGE): veth0_virt_wifi:
link becomes ready
[   55.443386][ T8462] IPv6: ADDRCONF(NETDEV_CHANGE): vxcan1: link becomes ready
[   55.444587][ T8462] IPv6: ADDRCONF(NETDEV_CHANGE): vxcan0: link becomes ready
[   55.445831][ T8462] IPv6: ADDRCONF(NETDEV_CHANGE): team0: link becomes ready
[   55.458379][ T8418] 8021q: adding VLAN 0 to HW filter on device batadv0
[   55.464070][ T8462] IPv6: ADDRCONF(NETDEV_CHANGE): veth0_vlan: link
becomes ready
[   55.465632][ T8462] IPv6: ADDRCONF(NETDEV_CHANGE): vlan0: link becomes ready
[   55.467014][ T8462] IPv6: ADDRCONF(NETDEV_CHANGE): vlan1: link becomes ready
[   55.468484][ T8462] IPv6: ADDRCONF(NETDEV_CHANGE): veth1_to_team:
link becomes ready
[   55.471113][ T8462] IPv6: ADDRCONF(NETDEV_CHANGE): team_slave_1:
link becomes ready
[   55.472680][ T8462] IPv6: ADDRCONF(NETDEV_CHANGE): hsr_slave_0:
link becomes ready
[   55.478542][ T8417] device veth0_vlan entered promiscuous mode
[   55.486649][ T8427] IPv6: ADDRCONF(NETDEV_CHANGE): veth1_vlan: link
becomes ready
[   55.488193][ T8427] IPv6: ADDRCONF(NETDEV_CHANGE): veth0_vlan: link
becomes ready
[   55.490207][ T8427] IPv6: ADDRCONF(NETDEV_CHANGE): vlan0: link becomes ready
[   55.491622][ T8427] IPv6: ADDRCONF(NETDEV_CHANGE): vlan1: link becomes ready
[   55.498241][ T8457] IPv6: ADDRCONF(NETDEV_CHANGE): hsr_slave_1:
link becomes ready
[   55.500145][ T8420] device veth0_vlan entered promiscuous mode
[   55.502453][ T8419] IPv6: ADDRCONF(NETDEV_CHANGE): hsr0: link becomes ready
[   55.505635][ T8417] device veth1_vlan entered promiscuous mode
[   55.513802][ T8420] device veth1_vlan entered promiscuous mode
[   55.528752][   T47] IPv6: ADDRCONF(NETDEV_CHANGE): macvlan0: link
becomes ready
[   55.530814][   T47] IPv6: ADDRCONF(NETDEV_CHANGE): macvlan1: link
becomes ready
[   55.532748][   T47] IPv6: ADDRCONF(NETDEV_CHANGE): macvlan0: link
becomes ready
[   55.534307][   T47] IPv6: ADDRCONF(NETDEV_CHANGE): macvlan1: link
becomes ready
[   55.536368][   T47] IPv6: ADDRCONF(NETDEV_CHANGE): vxcan1: link becomes ready
[   55.537604][   T47] IPv6: ADDRCONF(NETDEV_CHANGE): vxcan0: link becomes ready
[   55.543990][ T8460] IPv6: ADDRCONF(NETDEV_CHANGE): veth0_macvtap:
link becomes ready
[   55.545601][ T8460] IPv6: ADDRCONF(NETDEV_CHANGE): veth0_virt_wifi:
link becomes ready
[   55.557011][ T8419] 8021q: adding VLAN 0 to HW filter on device batadv0
[   55.559703][ T8417] device veth0_macvtap entered promiscuous mode
[   55.568438][ T8417] device veth1_macvtap entered promiscuous mode
[   55.576974][   T12] IPv6: ADDRCONF(NETDEV_CHANGE): veth0_vlan: link
becomes ready
[   55.578675][   T12] IPv6: ADDRCONF(NETDEV_CHANGE): vlan0: link becomes ready
[   55.580454][   T12] IPv6: ADDRCONF(NETDEV_CHANGE): vlan1: link becomes ready
[   55.581893][   T12] IPv6: ADDRCONF(NETDEV_CHANGE): macvtap0: link
becomes ready
[   55.585857][ T8462] IPv6: ADDRCONF(NETDEV_CHANGE): veth0_macvtap:
link becomes ready
[   55.590147][ T8418] device veth0_vlan entered promiscuous mode
[   55.593438][ T8420] device veth0_macvtap entered promiscuous mode
[   55.596388][ T8417] batman_adv: batadv0: Interface activated: batadv_slave_0
[   55.599685][ T8427] IPv6: ADDRCONF(NETDEV_CHANGE): macvtap0: link
becomes ready
[   55.601259][ T8427] IPv6: ADDRCONF(NETDEV_CHANGE): batadv_slave_0:
link becomes ready
[   55.602892][ T8427] IPv6: ADDRCONF(NETDEV_CHANGE): veth0_to_batadv:
link becomes ready
[   55.606834][ T8420] device veth1_macvtap entered promiscuous mode
[   55.609803][ T8417] batman_adv: batadv0: Interface activated: batadv_slave_1
[   55.613750][ T8427] IPv6: ADDRCONF(NETDEV_CHANGE): batadv_slave_1:
link becomes ready
[   55.615316][ T8427] IPv6: ADDRCONF(NETDEV_CHANGE): veth1_to_batadv:
link becomes ready
[   55.618276][ T8418] device veth1_vlan entered promiscuous mode
[   55.621546][ T8417] netdevsim netdevsim0 netdevsim0: set [1, 0]
type 2 family 0 port 6081 - 0
[   55.623016][ T8417] netdevsim netdevsim0 netdevsim1: set [1, 0]
type 2 family 0 port 6081 - 0
[   55.624411][ T8417] netdevsim netdevsim0 netdevsim2: set [1, 0]
type 2 family 0 port 6081 - 0
[   55.625764][ T8417] netdevsim netdevsim0 netdevsim3: set [1, 0]
type 2 family 0 port 6081 - 0
[   55.633979][ T8457] IPv6: ADDRCONF(NETDEV_CHANGE): macvlan0: link
becomes ready
[   55.635485][ T8457] IPv6: ADDRCONF(NETDEV_CHANGE): macvlan1: link
becomes ready
[   55.637046][ T8457] IPv6: ADDRCONF(NETDEV_CHANGE): veth0_virt_wifi:
link becomes ready
[   55.647653][ T8420] batman_adv: The newly added mac address
(aa:aa:aa:aa:aa:3d) already exists on: batadv_slave_0
[   55.650656][ T8420] batman_adv: It is strongly recommended to keep
mac addresses unique to avoid problems!
[   55.653585][ T8420] batman_adv: batadv0: Interface activated: batadv_slave_0
[   55.661918][ T8458] IPv6: ADDRCONF(NETDEV_CHANGE): batadv_slave_0:
link becomes ready
[   55.663516][ T8458] IPv6: ADDRCONF(NETDEV_CHANGE): veth0_to_batadv:
link becomes ready
[   55.669589][ T8420] batman_adv: The newly added mac address
(aa:aa:aa:aa:aa:3e) already exists on: batadv_slave_1
[   55.671380][ T8420] batman_adv: It is strongly recommended to keep
mac addresses unique to avoid problems!
[   55.673566][ T8420] batman_adv: batadv0: Interface activated: batadv_slave_1
[   55.676293][   T47] IPv6: ADDRCONF(NETDEV_CHANGE): veth0_vlan: link
becomes ready
[   55.678269][   T47] IPv6: ADDRCONF(NETDEV_CHANGE): batadv_slave_1:
link becomes ready
[   55.681491][   T47] IPv6: ADDRCONF(NETDEV_CHANGE): veth1_to_batadv:
link becomes ready
[   55.683507][   T47] IPv6: ADDRCONF(NETDEV_CHANGE): vlan0: link becomes ready
[   55.685073][   T47] IPv6: ADDRCONF(NETDEV_CHANGE): vlan1: link becomes ready
[   55.693628][ T8419] device veth0_vlan entered promiscuous mode
[   55.695711][ T8420] netdevsim netdevsim3 netdevsim0: set [1, 0]
type 2 family 0 port 6081 - 0
[   55.697187][ T8420] netdevsim netdevsim3 netdevsim1: set [1, 0]
type 2 family 0 port 6081 - 0
[   55.698641][ T8420] netdevsim netdevsim3 netdevsim2: set [1, 0]
type 2 family 0 port 6081 - 0
[   55.701227][ T8420] netdevsim netdevsim3 netdevsim3: set [1, 0]
type 2 family 0 port 6081 - 0
[   55.712126][ T8462] IPv6: ADDRCONF(NETDEV_CHANGE): veth0_macvtap:
link becomes ready
[   55.723666][ T8418] device veth0_macvtap entered promiscuous mode
[   55.732979][ T8418] device veth1_macvtap entered promiscuous mode
[   55.743076][ T8419] device veth1_vlan entered promiscuous mode
[   55.764965][ T3092] wlan0: Created IBSS using preconfigured BSSID
50:50:50:50:50:50
[   55.766588][ T3092] wlan0: Creating new IBSS network, BSSID 50:50:50:50:50:50
[   55.773260][   T12] IPv6: ADDRCONF(NETDEV_CHANGE): macvtap0: link
becomes ready
[   55.775027][   T12] IPv6: ADDRCONF(NETDEV_CHANGE): macvlan0: link
becomes ready
[   55.776594][   T12] IPv6: ADDRCONF(NETDEV_CHANGE): macvlan1: link
becomes ready
[   55.778171][   T12] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
[   55.787908][ T3093] wlan0: Created IBSS using preconfigured BSSID
50:50:50:50:50:50
[   55.787950][ T8418] batman_adv: The newly added mac address
(aa:aa:aa:aa:aa:3d) already exists on: batadv_slave_0
[   55.789768][ T8418] batman_adv: It is strongly recommended to keep
mac addresses unique to avoid problems!
[   55.791403][ T3093] wlan0: Creating new IBSS network, BSSID 50:50:50:50:50:50
[   55.792640][ T8418] batman_adv: The newly added mac address
(aa:aa:aa:aa:aa:3d) already exists on: batadv_slave_0
[   55.795462][ T8418] batman_adv: It is strongly recommended to keep
mac addresses unique to avoid problems!
[   55.797603][ T8418] batman_adv: batadv0: Interface activated: batadv_slave_0
[   55.798845][ T8457] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
[   55.800562][ T8457] IPv6: ADDRCONF(NETDEV_CHANGE): batadv_slave_0:
link becomes ready
[   55.802140][ T8457] IPv6: ADDRCONF(NETDEV_CHANGE): veth0_to_batadv:
link becomes ready
[   55.824228][ T3092] wlan1: Created IBSS using preconfigured BSSID
50:50:50:50:50:50
[   55.824417][ T8418] batman_adv: The newly added mac address
(aa:aa:aa:aa:aa:3e) already exists on: batadv_slave_1
[   55.825590][ T3092] wlan1: Creating new IBSS network, BSSID 50:50:50:50:50:50
[   55.827225][ T8418] batman_adv: It is strongly recommended to keep
mac addresses unique to avoid problems!
[   55.827232][ T8418] batman_adv: The newly added mac address
(aa:aa:aa:aa:aa:3e) already exists on: batadv_slave_1
[   55.832197][ T8418] batman_adv: It is strongly recommended to keep
mac addresses unique to avoid problems!
[   55.834287][ T8418] batman_adv: batadv0: Interface activated: batadv_slave_1
[   55.836978][ T8462] IPv6: ADDRCONF(NETDEV_CHANGE): wlan1: link becomes ready
[   55.838488][ T8462] IPv6: ADDRCONF(NETDEV_CHANGE): batadv_slave_1:
link becomes ready
[   55.848341][ T8462] IPv6: ADDRCONF(NETDEV_CHANGE): veth1_to_batadv:
link becomes ready
[   55.853941][ T3093] wlan1: Created IBSS using preconfigured BSSID
50:50:50:50:50:50
[   55.855398][ T3093] wlan1: Creating new IBSS network, BSSID 50:50:50:50:50:50
[   55.857652][ T8418] netdevsim netdevsim2 netdevsim0: set [1, 0]
type 2 family 0 port 6081 - 0
[   55.859775][ T8418] netdevsim netdevsim2 netdevsim1: set [1, 0]
type 2 family 0 port 6081 - 0
[   55.861661][ T8418] netdevsim netdevsim2 netdevsim2: set [1, 0]
type 2 family 0 port 6081 - 0
[   55.863521][ T8418] netdevsim netdevsim2 netdevsim3: set [1, 0]
type 2 family 0 port 6081 - 0
[   55.866508][ T8457] IPv6: ADDRCONF(NETDEV_CHANGE): wlan1: link becomes ready
[   55.876206][ T8463] IPv6: ADDRCONF(NETDEV_CHANGE): veth0_macvtap:
link becomes ready
[   55.881066][ T8419] device veth0_macvtap entered promiscuous mode
[   55.881542][ T8417] cgroup: cgroup: disabling cgroup2 socket
matching due to net_prio or net_cls activation
[   55.893570][ T8419] device veth1_macvtap entered promiscuous mode
[   55.911291][ T8419] batman_adv: The newly added mac address
(aa:aa:aa:aa:aa:3d) already exists on: batadv_slave_0
[   55.912945][ T8419] batman_adv: It is strongly recommended to keep
mac addresses unique to avoid problems!
[   55.914468][ T8419] batman_adv: The newly added mac address
(aa:aa:aa:aa:aa:3d) already exists on: batadv_slave_0
[   55.916157][ T8419] batman_adv: It is strongly recommended to keep
mac addresses unique to avoid problems!
[   55.917673][ T8419] batman_adv: The newly added mac address
(aa:aa:aa:aa:aa:3d) already exists on: batadv_slave_0
[   55.919741][   T48] Bluetooth: hci0: command 0x0409 tx timeout
[   55.920927][ T8419] batman_adv: It is strongly recommended to keep
mac addresses unique to avoid problems!
[   55.923609][ T8419] batman_adv: batadv0: Interface activated: batadv_slave_0
[   55.929424][ T8457] Bluetooth: hci3: command 0x0409 tx timeout
[   55.930423][ T8457] Bluetooth: hci2: command 0x0409 tx timeout
[   55.931353][ T8458] IPv6: ADDRCONF(NETDEV_CHANGE): veth0_to_batadv:
link becomes ready
[   55.933012][ T8457] Bluetooth: hci1: command 0x0409 tx timeout
[   55.934563][ T8458] IPv6: ADDRCONF(NETDEV_CHANGE): macvtap0: link
becomes ready
[   55.937382][ T8465]
==================================================================
[   55.937545][ T8468] general protection fault, probably for
non-canonical address 0xdffffc000000000e: 0000 [#1] PREEMPT SMP KASAN
[   55.938204][ T8419] batman_adv: The newly added mac address
(aa:aa:aa:aa:aa:3e) already exists on: batadv_slave_1
[   55.938215][ T8419] batman_adv: It is strongly recommended to keep
mac addresses unique to avoid problems!
[   55.938220][ T8419] batman_adv: The newly added mac address
(aa:aa:aa:aa:aa:3e) already exists on: batadv_slave_1
[   55.938227][ T8419] batman_adv: It is strongly recommended to keep
mac addresses unique to avoid problems!
[   55.938232][ T8419] batman_adv: The newly added mac address
(aa:aa:aa:aa:aa:3e) already exists on: batadv_slave_1
[   55.938239][ T8419] batman_adv: It is strongly recommended to keep
mac addresses unique to avoid problems!
[   55.938755][ T8419] batman_adv: batadv0: Interface activated: batadv_slave_1
[   55.938769][ T8465] BUG: KASAN: null-ptr-deref in filp_close+0x22/0x170
[   55.940640][ T8468] KASAN: null-ptr-deref in range
[0x0000000000000070-0x0000000000000077]
[   55.941689][ T8418] ieee80211 phy8: Selected rate control algorithm
'minstrel_ht'
[   55.942228][ T8465] Read of size 8 at addr 0000000000000077 by task
a.out/8465
[   55.943745][ T8468] CPU: 0 PID: 8468 Comm: a.out Not tainted 5.12.0-rc2+ #111
[   55.945341][ T8465]
[   55.945348][ T8465] CPU: 1 PID: 8465 Comm: a.out Not tainted 5.12.0-rc2+ #111
[   55.946919][ T8468] Hardware name: QEMU Standard PC (Q35 + ICH9,
2009), BIOS rel-1.13.0-44-g88ab0c15525c-prebuilt.qemu.org 04/01/2014
[   55.948513][ T8465] Hardware name: QEMU Standard PC (Q35 + ICH9,
2009), BIOS rel-1.13.0-44-g88ab0c15525c-prebuilt.qemu.org 04/01/2014
[   55.950035][ T8468] RIP: 0010:filp_close+0x33/0x170
[   55.951141][ T8465] Call Trace:
[   55.951146][ T8465]  dump_stack+0x141/0x1d7
[   55.952193][ T8468] Code: 89 fd 4c 8d 6d 78 53 e8 6b 8d b5 ff be 08
00 00 00 4c 89 ef e8 8e d8 f6 ff 4c 89 ea 48 b8 00 00 00 00 00 fc ff
df 48 c1 ea 03 <80> 3c 02 005
[   55.953483][ T8465]  ? filp_close+0x22/0x170
[   55.954674][ T8468] RSP: 0018:ffffc900018c7ad8 EFLAGS: 00010203
[   55.955806][ T8465]  kasan_report.cold+0x5f/0xd8
[   55.957002][ T8468]
[   55.957005][ T8468] RAX: dffffc0000000000 RBX: ffffffffffffffff
RCX: ffffffff81bbb852
[   55.957361][ T8465]  ? filp_close+0x22/0x170
[   55.958497][ T8468] RDX: 000000000000000e RSI: 0000000000000008
RDI: 0000000000000077
[   55.960331][ T8465]  kasan_check_range+0x13d/0x180
[   55.962185][ T8468] RBP: ffffffffffffffff R08: 0000000000000000
R09: 000000000000007f
[   55.962943][ T8465]  filp_close+0x22/0x170
[   55.963438][ T8468] R10: ffffed1020c94914 R11: 0000000000000000
R12: ffff8881064a4780
[   55.964083][ T8465]  put_files_struct+0x1d0/0x350
[   55.967078][ T8468] R13: 0000000000000077 R14: ffff8881064a4780
R15: ffff8881064a48a0
[   55.967742][ T8465]  exit_files+0x7e/0xa0
[   55.968652][ T8468] FS:  0000000000000000(0000)
GS:ffff888159e00000(0000) knlGS:0000000000000000
[   55.969361][ T8465]  do_exit+0xba9/0x2a40
[   55.969718][ T8468] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[   55.970913][ T8465]  ? queued_spin_lock_slowpath+0xcc/0x940
[   55.971589][ T8468] CR2: 00000000004a2638 CR3: 0000000117245000
CR4: 0000000000750ef0
[   55.972810][ T8465]  ? find_held_lock+0x2d/0x110
[   55.973564][ T8468] DR0: 0000000000000000 DR1: 0000000000000000
DR2: 0000000000000000
[   55.974777][ T8465]  ? mm_update_next_owner+0x7a0/0x7a0
[   55.975431][ T8468] DR3: 0000000000000000 DR6: 00000000fffe0ff0
DR7: 0000000000000400
[   55.976738][ T8465]  ? get_signal+0x37b/0x2490
[   55.977487][ T8468] PKRU: 55555554
[   55.977492][ T8468] Call Trace:
[   55.978686][ T8465]  ? lock_downgrade+0x6e0/0x6e0
[   55.979316][ T8468]  put_files_struct+0x1d0/0x350
[   55.980664][ T8465]  ? do_raw_spin_lock+0x1d8/0x260
[   55.981302][ T8468]  exit_files+0x7e/0xa0
[   55.982305][ T8465]  do_group_exit+0x125/0x310
[   55.983180][ T8468]  do_exit+0xba9/0x2a40
[   55.984390][ T8465]  get_signal+0x468/0x2490
[   55.985114][ T8468]  ? find_held_lock+0x2d/0x110
[   55.986389][ T8465]  ? futex_exit_release+0x220/0x220
[   55.987213][ T8468]  ? mm_update_next_owner+0x7a0/0x7a0
[   55.988421][ T8465]  arch_do_signal_or_restart+0x2a8/0x1eb0
[   55.989124][ T8468]  ? get_signal+0x37b/0x2490
[   55.989662][ T8465]  ? debug_object_init_on_stack+0x20/0x20
[   55.990163][ T8468]  ? lock_downgrade+0x6e0/0x6e0
[   55.990902][ T8465]  ? clone_private_mount+0x140/0x140
[   55.991645][ T8468]  ? do_raw_spin_lock+0x121/0x260
[   55.992426][ T8465]  ? copy_siginfo_to_user32+0xa0/0xa0
[   55.993058][ T8468]  do_group_exit+0x125/0x310
[   55.993757][ T8465]  ? __do_sys_futex+0x2a2/0x470
[   55.994392][ T8468]  get_signal+0x468/0x2490
[   55.995065][ T8465]  ? __do_sys_futex+0x2ab/0x470
[   55.995793][ T8468]  ? futex_exit_release+0x220/0x220
[   55.996692][ T8465]  ? do_futex+0x1710/0x1710
[   55.997515][ T8468]  arch_do_signal_or_restart+0x2a8/0x1eb0
[   55.998378][ T8465]  exit_to_user_mode_prepare+0x148/0x250
[   55.999079][ T8468]  ? lock_downgrade+0x6e0/0x6e0
[   55.999944][ T8465]  syscall_exit_to_user_mode+0x19/0x50
[   56.000683][ T8468]  ? do_raw_spin_lock+0x121/0x260
[   56.001481][ T8465]  entry_SYSCALL_64_after_hwframe+0x44/0xae
[   56.002245][ T8468]  ? __sanitizer_cov_trace_const_cmp1+0x22/0x80
[   56.003065][ T8465] RIP: 0033:0x4576d9
[   56.003764][ T8468]  ? put_files_struct+0x33/0x350
[   56.004497][ T8465] Code: Unable to access opcode bytes at RIP 0x4576af.
[   56.005169][ T8468]  ? copy_siginfo_to_user32+0xa0/0xa0
[   56.005907][ T8465] RSP: 002b:00007fab4413c1e8 EFLAGS: 00000246
[   56.006817][ T8468]  ? __do_sys_futex+0x2a2/0x470
[   56.007499][ T8465]  ORIG_RAX: 00000000000000ca
[   56.007505][ T8465] RAX: fffffffffffffe00 RBX: 0000000000000000
RCX: 00000000004576d9
[   56.008368][ T8468]  ? __do_sys_futex+0x2ab/0x470
[   56.009225][ T8465] RDX: 0000000000000000 RSI: 0000000000000080
RDI: 00000000004dd3a8
[   56.009962][ T8468]  ? do_futex+0x1710/0x1710
[   56.010791][ T8465] RBP: 00007fab4413c200 R08: 0000000100000001
R09: 0000000100000001
[   56.011557][ T8468]  exit_to_user_mode_prepare+0x148/0x250
[   56.012450][ T8465] R10: 0000000000000000 R11: 0000000000000246
R12: 00007ffe0c4cd91e
[   56.013399][ T8468]  syscall_exit_to_user_mode+0x19/0x50
[   56.013989][ T8465] R13: 00007ffe0c4cd91f R14: 00007fab4413c300
R15: 0000000000022000
[   56.014748][ T8468]  entry_SYSCALL_64_after_hwframe+0x44/0xae
[   56.015786][ T8465]
==================================================================
[   56.016697][ T8468] RIP: 0033:0x4576d9
[   56.023878][ T8465] Kernel panic - not syncing: panic_on_warn set ...
[   56.024082][ T8468] Code: Unable to access opcode bytes at RIP 0x4576af.
[   56.024088][ T8468] RSP: 002b:00007fab4411b1e8 EFLAGS: 00000246
ORIG_RAX: 00000000000000ca
[   56.034295][ T8468] RAX: fffffffffffffe00 RBX: 0000000000000000
RCX: 00000000004576d9
[   56.035533][ T8468] RDX: 0000000000000000 RSI: 0000000000000080
RDI: 00000000004dd3b8
[   56.036797][ T8468] RBP: 00007fab4411b200 R08: 0000000000000000
R09: 0000000000000000
[   56.038006][ T8468] R10: 0000000000000000 R11: 0000000000000246
R12: 00007ffe0c4cd91e
[   56.039221][ T8468] R13: 00007ffe0c4cd91f R14: 00007fab4411b300
R15: 0000000000022000
[   56.040433][ T8468] Modules linked in:
[   56.041067][ T8465] Kernel Offset: disabled
[   56.041718][ T8465] Rebooting in 86400 seconds..

Re: [syzbot] KASAN: null-ptr-deref Read in filp_close (2)

[Christian Brauner]

On Fri, Mar 26, 2021 at 10:34:28AM +0100, Christian Brauner wrote:
> On Fri, Mar 26, 2021, 10:21 Dmitry Vyukov <dvyukov@google.com> wrote:
> 
> > On Fri, Mar 26, 2021 at 10:12 AM Christian Brauner
> > <christian.brauner@ubuntu.com> wrote:
> > >
> > > On Fri, Mar 26, 2021 at 09:02:08AM +0100, Dmitry Vyukov wrote:
> > > > On Fri, Mar 26, 2021 at 8:55 AM syzbot
> > > > <syzbot+283ce5a46486d6acdbaf@syzkaller.appspotmail.com> wrote:
> > > > >
> > > > > Hello,
> > > > >
> > > > > syzbot found the following issue on:
> > > > >
> > > > > HEAD commit:    5ee96fa9 Merge tag 'irq-urgent-2021-03-21' of git://
> > git.ke..
> > > > > git tree:       upstream
> > > > > console output:
> > https://syzkaller.appspot.com/x/log.txt?x=17fb84bed00000
> > > > > kernel config:
> > https://syzkaller.appspot.com/x/.config?x=6abda3336c698a07
> > > > > dashboard link:
> > https://syzkaller.appspot.com/bug?extid=283ce5a46486d6acdbaf
> > > > >
> > > > > Unfortunately, I don't have any reproducer for this issue yet.
> > > > >
> > > > > IMPORTANT: if you fix the issue, please add the following tag to the
> > commit:
> > > > > Reported-by: syzbot+283ce5a46486d6acdbaf@syzkaller.appspotmail.com
> > > >
> > > > I was able to reproduce this with the following C program:
> > > >
> > https://gist.githubusercontent.com/dvyukov/00fb7aae489f22c60b4e64b45ef14d60/raw/cb368ca523d01986c2917f4414add0893b8f4243/gistfile1.txt
> > > >
> > > > +Christian
> > > > The repro also contains close_range as the previous similar crash:
> > > >
> > https://syzkaller.appspot.com/bug?id=1bef50bdd9622a1969608d1090b2b4a588d0c6ac
> > > > I don't know if it's related or not in this case, but looks suspicious.
> > >
> > > Hm, I fail to reproduce this with your repro. Do you need to have it run
> > > for a long time?
> > > One thing that strucky my eye is that binfmt_misc gets setup which made
> > > me go huh and I see commit
> > >
> > > commit e7850f4d844e0acfac7e570af611d89deade3146
> > > Author: Lior Ribak <liorribak@gmail.com>
> > > Date:   Fri Mar 12 21:07:41 2021 -0800
> > >
> > >     binfmt_misc: fix possible deadlock in bm_register_write
> > >
> > > which uses filp_close() after having called open_exec() on the
> > > interpreter which makes me wonder why this doesn't have to use fput()
> > > like in all other codepaths for binfmnt_*.
> > >
> > > Can you revert this commit and see if you can reproduce this issue.
> > > Maybe this is a complete red herring but worth a try.
> >
> >
> > This program reproduces the crash for me almost immediately. Are you
> > sure you used the right commit/config?
> >
> 
> I was trying to reproduce on v5.12-rc3 with all KASAN, KCSAN, KFENCE etc.
> turned on.
> I have an appointment I need to go to but will try to reproduce with commit
> and config you provided when I get home.
> I really hope it's not reproducible with v5.12-rc3 and only later commits
> since that would allow easier bisection.

Ok, I think I know what's going on. This fixes it for me. Can you test
too, please? I tried the #syz test way but syzbot doesn't have the
reproducer you gave me:

Thank you!
Christian

From eeb120d02f40b15a925f54ebcf2b4c747c741ad0 Mon Sep 17 00:00:00 2001
From: Christian Brauner <christian.brauner@ubuntu.com>
Date: Fri, 26 Mar 2021 13:33:03 +0100
Subject: [PATCH] file: fix close_range() for unshare+cloexec

syzbot reported a bug when putting the last reference to a tasks file
descriptor table. Debugging this showed we didn't recalculate the
current maximum fd number for CLOSE_RANGE_UNSHARE | CLOSE_RANGE_CLOEXEC
after we unshared the file descriptors table. So max_fd could exceed the
current fdtable maximum causing us to set excessive bits. As a concrete
example, let's say the user requested everything from fd 4 to ~0UL to be
closed and their current fdtable size is 256 with their highest open fd
being 4.  With CLOSE_RANGE_UNSHARE the caller will end up with a new
fdtable which has room for 64 file descriptors since that is the lowest
fdtable size we accept. But now max_fd will still point to 255 and needs
to be adjusted. Fix this by retrieving the correct maximum fd value in
__range_cloexec().

Reported-by: syzbot+283ce5a46486d6acdbaf@syzkaller.appspotmail.com
Cc: Christoph Hellwig <hch@lst.de>
Cc: Al Viro <viro@zeniv.linux.org.uk>
Cc: linux-fsdevel@vger.kernel.org
Cc: stable@vger.kernel.org
Signed-off-by: Christian Brauner <christian.brauner@ubuntu.com>
---
 fs/file.c | 8 +++++++-
 1 file changed, 7 insertions(+), 1 deletion(-)

diff --git a/fs/file.c b/fs/file.c
index f3a4bac2cbe9..5ef62377d924 100644
--- a/fs/file.c
+++ b/fs/file.c
@@ -632,6 +632,7 @@ EXPORT_SYMBOL(close_fd); /* for ksys_close() */
 static inline void __range_cloexec(struct files_struct *cur_fds,
 				   unsigned int fd, unsigned int max_fd)
 {
+	unsigned int cur_max;
 	struct fdtable *fdt;
 
 	if (fd > max_fd)
@@ -639,7 +640,12 @@ static inline void __range_cloexec(struct files_struct *cur_fds,
 
 	spin_lock(&cur_fds->file_lock);
 	fdt = files_fdtable(cur_fds);
-	bitmap_set(fdt->close_on_exec, fd, max_fd - fd + 1);
+	/* make very sure we're using the correct maximum value */
+	cur_max = fdt->max_fds;
+	cur_max--;
+	cur_max = min(max_fd, cur_max);
+	if (fd <= cur_max)
+		bitmap_set(fdt->close_on_exec, fd, cur_max - fd + 1);
 	spin_unlock(&cur_fds->file_lock);
 }
 
-- 
2.27.0

Re: [syzbot] KASAN: null-ptr-deref Read in filp_close (2)

[Dmitry Vyukov]

On Fri, Mar 26, 2021 at 2:50 PM Christian Brauner
<christian.brauner@ubuntu.com> wrote:
>
> On Fri, Mar 26, 2021 at 10:34:28AM +0100, Christian Brauner wrote:
> > On Fri, Mar 26, 2021, 10:21 Dmitry Vyukov <dvyukov@google.com> wrote:
> >
> > > On Fri, Mar 26, 2021 at 10:12 AM Christian Brauner
> > > <christian.brauner@ubuntu.com> wrote:
> > > >
> > > > On Fri, Mar 26, 2021 at 09:02:08AM +0100, Dmitry Vyukov wrote:
> > > > > On Fri, Mar 26, 2021 at 8:55 AM syzbot
> > > > > <syzbot+283ce5a46486d6acdbaf@syzkaller.appspotmail.com> wrote:
> > > > > >
> > > > > > Hello,
> > > > > >
> > > > > > syzbot found the following issue on:
> > > > > >
> > > > > > HEAD commit:    5ee96fa9 Merge tag 'irq-urgent-2021-03-21' of git://
> > > git.ke..
> > > > > > git tree:       upstream
> > > > > > console output:
> > > https://syzkaller.appspot.com/x/log.txt?x=17fb84bed00000
> > > > > > kernel config:
> > > https://syzkaller.appspot.com/x/.config?x=6abda3336c698a07
> > > > > > dashboard link:
> > > https://syzkaller.appspot.com/bug?extid=283ce5a46486d6acdbaf
> > > > > >
> > > > > > Unfortunately, I don't have any reproducer for this issue yet.
> > > > > >
> > > > > > IMPORTANT: if you fix the issue, please add the following tag to the
> > > commit:
> > > > > > Reported-by: syzbot+283ce5a46486d6acdbaf@syzkaller.appspotmail.com
> > > > >
> > > > > I was able to reproduce this with the following C program:
> > > > >
> > > https://gist.githubusercontent.com/dvyukov/00fb7aae489f22c60b4e64b45ef14d60/raw/cb368ca523d01986c2917f4414add0893b8f4243/gistfile1.txt
> > > > >
> > > > > +Christian
> > > > > The repro also contains close_range as the previous similar crash:
> > > > >
> > > https://syzkaller.appspot.com/bug?id=1bef50bdd9622a1969608d1090b2b4a588d0c6ac
> > > > > I don't know if it's related or not in this case, but looks suspicious.
> > > >
> > > > Hm, I fail to reproduce this with your repro. Do you need to have it run
> > > > for a long time?
> > > > One thing that strucky my eye is that binfmt_misc gets setup which made
> > > > me go huh and I see commit
> > > >
> > > > commit e7850f4d844e0acfac7e570af611d89deade3146
> > > > Author: Lior Ribak <liorribak@gmail.com>
> > > > Date:   Fri Mar 12 21:07:41 2021 -0800
> > > >
> > > >     binfmt_misc: fix possible deadlock in bm_register_write
> > > >
> > > > which uses filp_close() after having called open_exec() on the
> > > > interpreter which makes me wonder why this doesn't have to use fput()
> > > > like in all other codepaths for binfmnt_*.
> > > >
> > > > Can you revert this commit and see if you can reproduce this issue.
> > > > Maybe this is a complete red herring but worth a try.
> > >
> > >
> > > This program reproduces the crash for me almost immediately. Are you
> > > sure you used the right commit/config?
> > >
> >
> > I was trying to reproduce on v5.12-rc3 with all KASAN, KCSAN, KFENCE etc.
> > turned on.
> > I have an appointment I need to go to but will try to reproduce with commit
> > and config you provided when I get home.
> > I really hope it's not reproducible with v5.12-rc3 and only later commits
> > since that would allow easier bisection.
>
> Ok, I think I know what's going on. This fixes it for me. Can you test
> too, please? I tried the #syz test way but syzbot doesn't have the
> reproducer you gave me:


The crash does not happen with this patch.

Tested-by: Dmitry Vyukov <dvyukov@google.com>

Thanks for the quick fix!



> Thank you!
> Christian
>
> From eeb120d02f40b15a925f54ebcf2b4c747c741ad0 Mon Sep 17 00:00:00 2001
> From: Christian Brauner <christian.brauner@ubuntu.com>
> Date: Fri, 26 Mar 2021 13:33:03 +0100
> Subject: [PATCH] file: fix close_range() for unshare+cloexec
>
> syzbot reported a bug when putting the last reference to a tasks file
> descriptor table. Debugging this showed we didn't recalculate the
> current maximum fd number for CLOSE_RANGE_UNSHARE | CLOSE_RANGE_CLOEXEC
> after we unshared the file descriptors table. So max_fd could exceed the
> current fdtable maximum causing us to set excessive bits. As a concrete
> example, let's say the user requested everything from fd 4 to ~0UL to be
> closed and their current fdtable size is 256 with their highest open fd
> being 4.  With CLOSE_RANGE_UNSHARE the caller will end up with a new
> fdtable which has room for 64 file descriptors since that is the lowest
> fdtable size we accept. But now max_fd will still point to 255 and needs
> to be adjusted. Fix this by retrieving the correct maximum fd value in
> __range_cloexec().
>
> Reported-by: syzbot+283ce5a46486d6acdbaf@syzkaller.appspotmail.com
> Cc: Christoph Hellwig <hch@lst.de>
> Cc: Al Viro <viro@zeniv.linux.org.uk>
> Cc: linux-fsdevel@vger.kernel.org
> Cc: stable@vger.kernel.org
> Signed-off-by: Christian Brauner <christian.brauner@ubuntu.com>
> ---
>  fs/file.c | 8 +++++++-
>  1 file changed, 7 insertions(+), 1 deletion(-)
>
> diff --git a/fs/file.c b/fs/file.c
> index f3a4bac2cbe9..5ef62377d924 100644
> --- a/fs/file.c
> +++ b/fs/file.c
> @@ -632,6 +632,7 @@ EXPORT_SYMBOL(close_fd); /* for ksys_close() */
>  static inline void __range_cloexec(struct files_struct *cur_fds,
>                                    unsigned int fd, unsigned int max_fd)
>  {
> +       unsigned int cur_max;
>         struct fdtable *fdt;
>
>         if (fd > max_fd)
> @@ -639,7 +640,12 @@ static inline void __range_cloexec(struct files_struct *cur_fds,
>
>         spin_lock(&cur_fds->file_lock);
>         fdt = files_fdtable(cur_fds);
> -       bitmap_set(fdt->close_on_exec, fd, max_fd - fd + 1);
> +       /* make very sure we're using the correct maximum value */
> +       cur_max = fdt->max_fds;
> +       cur_max--;
> +       cur_max = min(max_fd, cur_max);
> +       if (fd <= cur_max)
> +               bitmap_set(fdt->close_on_exec, fd, cur_max - fd + 1);
>         spin_unlock(&cur_fds->file_lock);
>  }
>
> --
> 2.27.0
>

Re: [syzbot] KASAN: null-ptr-deref Read in filp_close (2)

[Al Viro]

On Fri, Mar 26, 2021 at 02:50:11PM +0100, Christian Brauner wrote:
> @@ -632,6 +632,7 @@ EXPORT_SYMBOL(close_fd); /* for ksys_close() */
>  static inline void __range_cloexec(struct files_struct *cur_fds,
>  				   unsigned int fd, unsigned int max_fd)
>  {
> +	unsigned int cur_max;
>  	struct fdtable *fdt;
>  
>  	if (fd > max_fd)
> @@ -639,7 +640,12 @@ static inline void __range_cloexec(struct files_struct *cur_fds,
>  
>  	spin_lock(&cur_fds->file_lock);
>  	fdt = files_fdtable(cur_fds);
> -	bitmap_set(fdt->close_on_exec, fd, max_fd - fd + 1);
> +	/* make very sure we're using the correct maximum value */
> +	cur_max = fdt->max_fds;
> +	cur_max--;
> +	cur_max = min(max_fd, cur_max);
> +	if (fd <= cur_max)
> +		bitmap_set(fdt->close_on_exec, fd, cur_max - fd + 1);
>  	spin_unlock(&cur_fds->file_lock);
>  }

Umm...  That's harder to follow than it ought to be.  What's the point of
having
        max_fd = min(max_fd, cur_max);
done in the caller, anyway?  Note that in __range_close() you have to
compare with re-fetched ->max_fds (look at pick_file()), so...

BTW, I really wonder if the cost of jerking ->file_lock up and down
in that loop in __range_close() is negligible.  What values do we
typically get from callers and how sparse does descriptor table tend
to be for those?

Re: [syzbot] KASAN: null-ptr-deref Read in filp_close (2)

[Christian Brauner]

On Sat, Mar 27, 2021 at 11:33:37PM +0000, Al Viro wrote:
> On Fri, Mar 26, 2021 at 02:50:11PM +0100, Christian Brauner wrote:
> > @@ -632,6 +632,7 @@ EXPORT_SYMBOL(close_fd); /* for ksys_close() */
> >  static inline void __range_cloexec(struct files_struct *cur_fds,
> >  				   unsigned int fd, unsigned int max_fd)
> >  {
> > +	unsigned int cur_max;
> >  	struct fdtable *fdt;
> >  
> >  	if (fd > max_fd)
> > @@ -639,7 +640,12 @@ static inline void __range_cloexec(struct files_struct *cur_fds,
> >  
> >  	spin_lock(&cur_fds->file_lock);
> >  	fdt = files_fdtable(cur_fds);
> > -	bitmap_set(fdt->close_on_exec, fd, max_fd - fd + 1);
> > +	/* make very sure we're using the correct maximum value */
> > +	cur_max = fdt->max_fds;
> > +	cur_max--;
> > +	cur_max = min(max_fd, cur_max);
> > +	if (fd <= cur_max)
> > +		bitmap_set(fdt->close_on_exec, fd, cur_max - fd + 1);
> >  	spin_unlock(&cur_fds->file_lock);
> >  }
> 
> Umm...  That's harder to follow than it ought to be.  What's the point of
> having
>         max_fd = min(max_fd, cur_max);
> done in the caller, anyway?  Note that in __range_close() you have to
> compare with re-fetched ->max_fds (look at pick_file()), so...

Yeah, I'll massage that patch a bit. I wanted to know whether this fixes
the issue first though.

> 
> BTW, I really wonder if the cost of jerking ->file_lock up and down
> in that loop in __range_close() is negligible.  What values do we

Just for the record, I remember you pointing at that originally. Linus
argued that this likely wasn't going to be a problem and that if people
see performance hits we'll optimize.

> typically get from callers and how sparse does descriptor table tend
> to be for those?

Weirdly, I can actually somewhat answer that question since I tend to
regularly "survey" large userspace projects I know or am involved in
that adopt new APIs we added just to see how they use it.

A few users:
1. crun
   https://github.com/containers/crun/blob/a1c0ef1b886ca30c2fb0906c7c43be04b555c52c/src/libcrun/utils.c#L1490
   ret = syscall_close_range (n, UINT_MAX, CLOSE_RANGE_CLOEXEC);

2. LXD
   https://github.com/lxc/lxd/blob/f12f03a4ba4645892ef6cc167c24da49d1217b02/lxd/main_forkexec.go#L293
   ret = close_range(EXEC_PIPE_FD + 1, UINT_MAX, CLOSE_RANGE_UNSHARE);

3. LXC
   https://github.com/lxc/lxc/blob/1718e6d6018d5d6072a01d92a11d5aafc314f98f/src/lxc/rexec.c#L165
   ret = close_range(STDERR_FILENO + 1, MAX_FILENO, CLOSE_RANGE_CLOEXEC);

Of these three 1. and 3. don't matter because they rely on
CLOSE_RANGE_CLOEXEC and exec.
For 2. I can say that the fdtable is likely going to be sparse.
close_range() here is basically used to prevent accidental fd leaks
across an exec. So 2. should never have more > 4 file. In fact, this
could and should probably be switched to CLOSE_RANGE_CLOEXEC too.

The next two cases might be more interesting:

4. systemd
   - https://github.com/systemd/systemd/blob/fe96c0f86d15e844d74d539c6cff7f971078cf84/src/basic/fd-util.c#L228
     close_range(3, -1, 0)
   - https://github.com/systemd/systemd/blob/fe96c0f86d15e844d74d539c6cff7f971078cf84/src/basic/fd-util.c#L271
     https://github.com/systemd/systemd/blob/fe96c0f86d15e844d74d539c6cff7f971078cf84/src/basic/fd-util.c#L288
     /* Close everything between the start and end fds (both of which shall stay open) */
     if (close_range(start + 1, end - 1, 0) < 0) {
     if (close_range(sorted[n_sorted-1] + 1, -1, 0) >= 0)

5. Python
   https://github.com/python/cpython/blob/9976834f807ea63ca51bc4f89be457d734148682/Python/fileutils.c#L2250

systemd has the regular case that others have too where it simply closes
all fds over 3 and it also has the more complicated case where it has an
ordered array of fds closing up to the lower bound and after the upper
bound up to the maximum. PID 1 can have a large number of fds open
because of socket activation so here close_range() will encounter less
sparse fd tables where it needs to close a lot of fds.

For Python's os.closerange() implementation which depends on our syscall
it's harder to say given that this will be used by a lot of projects but
I would _guess_ that if people use closerange() they do so because they
actually have something to close.

In short, I would think that close_range() without the
CLOSE_RANGE_CLOEXEC feature will usually be used in scenarios where
there's work to be done, i.e. where the caller likely knows that they
might inherit a non-trivial number of file descriptors (usually after a
fork) that they want to close and they want to do it either because they
don't exec or they don't know when they'll exec. All others I'd expect
to switch to CLOSE_RANGE_CLOEXEC on kernels where it's supported.

Christian

Re: [syzbot] KASAN: null-ptr-deref Read in filp_close (2)

[Christian Brauner]

On Mon, Mar 29, 2021 at 11:21:34AM +0200, Christian Brauner wrote:
> On Sat, Mar 27, 2021 at 11:33:37PM +0000, Al Viro wrote:
> > On Fri, Mar 26, 2021 at 02:50:11PM +0100, Christian Brauner wrote:
> > > @@ -632,6 +632,7 @@ EXPORT_SYMBOL(close_fd); /* for ksys_close() */
> > >  static inline void __range_cloexec(struct files_struct *cur_fds,
> > >  				   unsigned int fd, unsigned int max_fd)
> > >  {
> > > +	unsigned int cur_max;
> > >  	struct fdtable *fdt;
> > >  
> > >  	if (fd > max_fd)
> > > @@ -639,7 +640,12 @@ static inline void __range_cloexec(struct files_struct *cur_fds,
> > >  
> > >  	spin_lock(&cur_fds->file_lock);
> > >  	fdt = files_fdtable(cur_fds);
> > > -	bitmap_set(fdt->close_on_exec, fd, max_fd - fd + 1);
> > > +	/* make very sure we're using the correct maximum value */
> > > +	cur_max = fdt->max_fds;
> > > +	cur_max--;
> > > +	cur_max = min(max_fd, cur_max);
> > > +	if (fd <= cur_max)
> > > +		bitmap_set(fdt->close_on_exec, fd, cur_max - fd + 1);
> > >  	spin_unlock(&cur_fds->file_lock);
> > >  }
> > 
> > Umm...  That's harder to follow than it ought to be.  What's the point of
> > having
> >         max_fd = min(max_fd, cur_max);
> > done in the caller, anyway?  Note that in __range_close() you have to
> > compare with re-fetched ->max_fds (look at pick_file()), so...
> 
> Yeah, I'll massage that patch a bit. I wanted to know whether this fixes
> the issue first though.
> 
> > 
> > BTW, I really wonder if the cost of jerking ->file_lock up and down
> > in that loop in __range_close() is negligible.  What values do we
> 
> Just for the record, I remember you pointing at that originally. Linus
> argued that this likely wasn't going to be a problem and that if people
> see performance hits we'll optimize.
> 
> > typically get from callers and how sparse does descriptor table tend
> > to be for those?
> 
> Weirdly, I can actually somewhat answer that question since I tend to
> regularly "survey" large userspace projects I know or am involved in
> that adopt new APIs we added just to see how they use it.
> 
> A few users:
> 1. crun
>    https://github.com/containers/crun/blob/a1c0ef1b886ca30c2fb0906c7c43be04b555c52c/src/libcrun/utils.c#L1490
>    ret = syscall_close_range (n, UINT_MAX, CLOSE_RANGE_CLOEXEC);
> 
> 2. LXD
>    https://github.com/lxc/lxd/blob/f12f03a4ba4645892ef6cc167c24da49d1217b02/lxd/main_forkexec.go#L293
>    ret = close_range(EXEC_PIPE_FD + 1, UINT_MAX, CLOSE_RANGE_UNSHARE);
> 
> 3. LXC
>    https://github.com/lxc/lxc/blob/1718e6d6018d5d6072a01d92a11d5aafc314f98f/src/lxc/rexec.c#L165
>    ret = close_range(STDERR_FILENO + 1, MAX_FILENO, CLOSE_RANGE_CLOEXEC);
> 
> Of these three 1. and 3. don't matter because they rely on
> CLOSE_RANGE_CLOEXEC and exec.
> For 2. I can say that the fdtable is likely going to be sparse.
> close_range() here is basically used to prevent accidental fd leaks
> across an exec. So 2. should never have more > 4 file. In fact, this
> could and should probably be switched to CLOSE_RANGE_CLOEXEC too.
> 
> The next two cases might be more interesting:
> 
> 4. systemd
>    - https://github.com/systemd/systemd/blob/fe96c0f86d15e844d74d539c6cff7f971078cf84/src/basic/fd-util.c#L228
>      close_range(3, -1, 0)
>    - https://github.com/systemd/systemd/blob/fe96c0f86d15e844d74d539c6cff7f971078cf84/src/basic/fd-util.c#L271
>      https://github.com/systemd/systemd/blob/fe96c0f86d15e844d74d539c6cff7f971078cf84/src/basic/fd-util.c#L288
>      /* Close everything between the start and end fds (both of which shall stay open) */
>      if (close_range(start + 1, end - 1, 0) < 0) {
>      if (close_range(sorted[n_sorted-1] + 1, -1, 0) >= 0)
> 
> 5. Python
>    https://github.com/python/cpython/blob/9976834f807ea63ca51bc4f89be457d734148682/Python/fileutils.c#L2250
> 
> systemd has the regular case that others have too where it simply closes
> all fds over 3 and it also has the more complicated case where it has an
> ordered array of fds closing up to the lower bound and after the upper
> bound up to the maximum. PID 1 can have a large number of fds open
> because of socket activation so here close_range() will encounter less
> sparse fd tables where it needs to close a lot of fds.
> 
> For Python's os.closerange() implementation which depends on our syscall
> it's harder to say given that this will be used by a lot of projects but
> I would _guess_ that if people use closerange() they do so because they
> actually have something to close.
> 
> In short, I would think that close_range() without the
> CLOSE_RANGE_CLOEXEC feature will usually be used in scenarios where
> there's work to be done, i.e. where the caller likely knows that they
> might inherit a non-trivial number of file descriptors (usually after a
> fork) that they want to close and they want to do it either because they
> don't exec or they don't know when they'll exec. All others I'd expect
> to switch to CLOSE_RANGE_CLOEXEC on kernels where it's supported.

The patch below is a bit noiser then I'd like but it rips out the double
logic where we check min() twice and should also tweak the worst-case
where we keep taking the spinlock for a few fds that are already past
fdt->max_fds.
Afaict, this should be a very rare (pathological?) case. Even before
this change the logic would've capped max_fds to fdt->max_fds but
wouldn't have bothered to recheck within the pick_file() loop.
I've tweaked it to do that and then to return as soon as we see that
we're past the last fd. If you think that's worth then I'm happy to
write a commit message. I'm not sure if it's worth doing something more
fancy than this tbh but curious to hear what you think (Only compile
tested for now.):

---
 fs/file.c | 72 +++++++++++++++++++++++++++++++++++++------------------
 1 file changed, 49 insertions(+), 23 deletions(-)

diff --git a/fs/file.c b/fs/file.c
index f3a4bac2cbe9..5027cd75ec59 100644
--- a/fs/file.c
+++ b/fs/file.c
@@ -596,18 +596,32 @@ void fd_install(unsigned int fd, struct file *file)
 
 EXPORT_SYMBOL(fd_install);
 
+/**
+ * pick_file - return file associatd with fd
+ * @files: file struct to retrieve file from
+ * @fd: file descriptor to retrieve file for
+ *
+ * If this functions returns an EINVAL error pointer the fd was beyond the
+ * current maximum number of file descriptors for that fdtable.
+ *
+ * Returns: The file associated with @fd, on error returns an error pointer.
+ */
 static struct file *pick_file(struct files_struct *files, unsigned fd)
 {
-	struct file *file = NULL;
+	struct file *file;
 	struct fdtable *fdt;
 
 	spin_lock(&files->file_lock);
 	fdt = files_fdtable(files);
-	if (fd >= fdt->max_fds)
+	if (fd >= fdt->max_fds) {
+		file = ERR_PTR(-EINVAL);
 		goto out_unlock;
+	}
 	file = fdt->fd[fd];
-	if (!file)
+	if (!file) {
+		file = ERR_PTR(-EBADF);
 		goto out_unlock;
+	}
 	rcu_assign_pointer(fdt->fd[fd], NULL);
 	__put_unused_fd(files, fd);
 
@@ -622,24 +636,37 @@ int close_fd(unsigned fd)
 	struct file *file;
 
 	file = pick_file(files, fd);
-	if (!file)
+	if (IS_ERR(file))
 		return -EBADF;
 
 	return filp_close(file, files);
 }
 EXPORT_SYMBOL(close_fd); /* for ksys_close() */
 
+/**
+ * last_fd - return last valid index into fd table
+ * @cur_fds: files struct
+ *
+ * Context: Either rcu read lock or files_lock must be held.
+ *
+ * Returns: Last valid index into fdtable.
+ */
+static inline unsigned last_fd(struct fdtable *fdt)
+{
+	return fdt->max_fds - 1;
+}
+
 static inline void __range_cloexec(struct files_struct *cur_fds,
 				   unsigned int fd, unsigned int max_fd)
 {
 	struct fdtable *fdt;
 
-	if (fd > max_fd)
-		return;
-
+	/* make sure we're using the correct maximum value */
 	spin_lock(&cur_fds->file_lock);
 	fdt = files_fdtable(cur_fds);
-	bitmap_set(fdt->close_on_exec, fd, max_fd - fd + 1);
+	max_fd = min(last_fd(fdt), max_fd);
+	if (fd <= max_fd)
+		bitmap_set(fdt->close_on_exec, fd, max_fd - fd + 1);
 	spin_unlock(&cur_fds->file_lock);
 }
 
@@ -650,11 +677,16 @@ static inline void __range_close(struct files_struct *cur_fds, unsigned int fd,
 		struct file *file;
 
 		file = pick_file(cur_fds, fd++);
-		if (!file)
+		if (!IS_ERR(file)) {
+			/* found a valid file to close */
+			filp_close(file, cur_fds);
+			cond_resched();
 			continue;
+		}
 
-		filp_close(file, cur_fds);
-		cond_resched();
+		/* beyond the last fd in that table */
+		if (PTR_ERR(file) == -EINVAL)
+			return;
 	}
 }
 
@@ -669,7 +701,6 @@ static inline void __range_close(struct files_struct *cur_fds, unsigned int fd,
  */
 int __close_range(unsigned fd, unsigned max_fd, unsigned int flags)
 {
-	unsigned int cur_max;
 	struct task_struct *me = current;
 	struct files_struct *cur_fds = me->files, *fds = NULL;
 
@@ -679,13 +710,6 @@ int __close_range(unsigned fd, unsigned max_fd, unsigned int flags)
 	if (fd > max_fd)
 		return -EINVAL;
 
-	rcu_read_lock();
-	cur_max = files_fdtable(cur_fds)->max_fds;
-	rcu_read_unlock();
-
-	/* cap to last valid index into fdtable */
-	cur_max--;
-
 	if (flags & CLOSE_RANGE_UNSHARE) {
 		int ret;
 		unsigned int max_unshare_fds = NR_OPEN_MAX;
@@ -697,8 +721,12 @@ int __close_range(unsigned fd, unsigned max_fd, unsigned int flags)
 		 * If the caller requested all fds to be made cloexec copy all
 		 * of the file descriptors since they still want to use them.
 		 */
-		if (!(flags & CLOSE_RANGE_CLOEXEC) && (max_fd >= cur_max))
-			max_unshare_fds = fd;
+		if (!(flags & CLOSE_RANGE_CLOEXEC)) {
+			rcu_read_lock();
+			if (max_fd >= last_fd(files_fdtable(cur_fds)))
+				max_unshare_fds = fd;
+			rcu_read_unlock();
+		}
 
 		ret = unshare_fd(CLONE_FILES, max_unshare_fds, &fds);
 		if (ret)
@@ -712,8 +740,6 @@ int __close_range(unsigned fd, unsigned max_fd, unsigned int flags)
 			swap(cur_fds, fds);
 	}
 
-	max_fd = min(max_fd, cur_max);
-
 	if (flags & CLOSE_RANGE_CLOEXEC)
 		__range_cloexec(cur_fds, fd, max_fd);
 	else
-- 
2.27.0

[PATCH 0/3] file: fix and simplify close_range()

[Christian Brauner]

From: Christian Brauner <christian.brauner@ubuntu.com>

Hey,

This fixes the syzbot report that Dmitry took time to give a better
reproducer for. Debugging this showed we didn't recalculate the
current maximum fd number for CLOSE_RANGE_UNSHARE | CLOSE_RANGE_CLOEXEC
after we unshared the file descriptors table. So max_fd could exceed the
current fdtable maximum causing us to set excessive bits. As a concrete
example, let's say the user requested everything from fd 4 to ~0UL to be
closed and their current fdtable size is 256 with their highest open fd
being 4. With CLOSE_RANGE_UNSHARE the caller will end up with a new
fdtable which has room for 64 file descriptors since that is the lowest
fdtable size we accept. But now max_fd will still point to 255 and needs
to be adjusted.
Fix this and simplify the logic in close_range(), getting rid of the
double-checking of max_fd and the convoluted logic around that.
(There some data on how close_range() is currently used in userspace
 which I've mentioned in the original thread. It's interesting as most
 users have switched to CLOSE_RANGE_CLOEXEC pretty quickly apart from
 those where a lot of fds need to be closed and it isn't clear when or
 if exec happens (e.g. systemd and the massive amounts of fds it can
 inherit due to socket activation).)
I've stuffed it in a branch at 
https://git.kernel.org/pub/scm/linux/kernel/git/brauner/linux.git/log/?h=fs/close_range

I just didn't have time to get back to tweak the fix sooner than today.
A version of this has been sitting in linux-next for a while though.
If there's no braino from my side I'd like to get this to Linus rather
sooner than later so the bug is fixed as it's been some time now.

Thanks!
Christian

Christian Brauner (3):
  file: fix close_range() for unshare+cloexec
  file: let pick_file() tell caller it's done
  file: simplify logic in __close_range()

 fs/file.c | 85 +++++++++++++++++++++++++++++++++++++------------------
 1 file changed, 57 insertions(+), 28 deletions(-)


base-commit: 0d02ec6b3136c73c09e7859f0d0e4e2c4c07b49b
-- 
2.27.0

[PATCH 1/3] file: fix close_range() for unshare+cloexec

[Christian Brauner]

From: Christian Brauner <christian.brauner@ubuntu.com>

syzbot reported a bug when putting the last reference to a tasks file
descriptor table. Debugging this showed we didn't recalculate the
current maximum fd number for CLOSE_RANGE_UNSHARE | CLOSE_RANGE_CLOEXEC
after we unshared the file descriptors table. So max_fd could exceed the
current fdtable maximum causing us to set excessive bits. As a concrete
example, let's say the user requested everything from fd 4 to ~0UL to be
closed and their current fdtable size is 256 with their highest open fd
being 4. With CLOSE_RANGE_UNSHARE the caller will end up with a new
fdtable which has room for 64 file descriptors since that is the lowest
fdtable size we accept. But now max_fd will still point to 255 and needs
to be adjusted. Fix this by retrieving the correct maximum fd value in
__range_cloexec().

Reported-by: syzbot+283ce5a46486d6acdbaf@syzkaller.appspotmail.com
Fixes: 582f1fb6b721 ("fs, close_range: add flag CLOSE_RANGE_CLOEXEC")
Fixes: fec8a6a69103 ("close_range: unshare all fds for CLOSE_RANGE_UNSHARE | CLOSE_RANGE_CLOEXEC")
Cc: Christoph Hellwig <hch@lst.de>
Cc: Giuseppe Scrivano <gscrivan@redhat.com>
Cc: Al Viro <viro@zeniv.linux.org.uk>
Cc: linux-fsdevel@vger.kernel.org
Cc: stable@vger.kernel.org
Signed-off-by: Christian Brauner <christian.brauner@ubuntu.com>
---
 fs/file.c | 21 +++++++++++++++++----
 1 file changed, 17 insertions(+), 4 deletions(-)

diff --git a/fs/file.c b/fs/file.c
index f3a4bac2cbe9..f633348029a5 100644
--- a/fs/file.c
+++ b/fs/file.c
@@ -629,17 +629,30 @@ int close_fd(unsigned fd)
 }
 EXPORT_SYMBOL(close_fd); /* for ksys_close() */
 
+/**
+ * last_fd - return last valid index into fd table
+ * @cur_fds: files struct
+ *
+ * Context: Either rcu read lock or files_lock must be held.
+ *
+ * Returns: Last valid index into fdtable.
+ */
+static inline unsigned last_fd(struct fdtable *fdt)
+{
+	return fdt->max_fds - 1;
+}
+
 static inline void __range_cloexec(struct files_struct *cur_fds,
 				   unsigned int fd, unsigned int max_fd)
 {
 	struct fdtable *fdt;
 
-	if (fd > max_fd)
-		return;
-
+	/* make sure we're using the correct maximum value */
 	spin_lock(&cur_fds->file_lock);
 	fdt = files_fdtable(cur_fds);
-	bitmap_set(fdt->close_on_exec, fd, max_fd - fd + 1);
+	max_fd = min(last_fd(fdt), max_fd);
+	if (fd <= max_fd)
+		bitmap_set(fdt->close_on_exec, fd, max_fd - fd + 1);
 	spin_unlock(&cur_fds->file_lock);
 }
 
-- 
2.27.0

[PATCH 2/3] file: let pick_file() tell caller it's done

[Christian Brauner]

From: Christian Brauner <christian.brauner@ubuntu.com>

Let pick_file() report back that the fd it was passed exceeded the
maximum fd in that fdtable. This allows us to simplify the caller of
this helper because it doesn't need to care anymore whether the passed
in max_fd is excessive. It can rely on pick_file() telling it that it's
past the last valid fd.

Cc: Christoph Hellwig <hch@lst.de>
Cc: Giuseppe Scrivano <gscrivan@redhat.com>
Cc: Al Viro <viro@zeniv.linux.org.uk>
Cc: linux-fsdevel@vger.kernel.org
Signed-off-by: Christian Brauner <christian.brauner@ubuntu.com>
---
 fs/file.c | 33 ++++++++++++++++++++++++++-------
 1 file changed, 26 insertions(+), 7 deletions(-)

diff --git a/fs/file.c b/fs/file.c
index f633348029a5..740040346a98 100644
--- a/fs/file.c
+++ b/fs/file.c
@@ -596,18 +596,32 @@ void fd_install(unsigned int fd, struct file *file)
 
 EXPORT_SYMBOL(fd_install);
 
+/**
+ * pick_file - return file associatd with fd
+ * @files: file struct to retrieve file from
+ * @fd: file descriptor to retrieve file for
+ *
+ * If this functions returns an EINVAL error pointer the fd was beyond the
+ * current maximum number of file descriptors for that fdtable.
+ *
+ * Returns: The file associated with @fd, on error returns an error pointer.
+ */
 static struct file *pick_file(struct files_struct *files, unsigned fd)
 {
-	struct file *file = NULL;
+	struct file *file;
 	struct fdtable *fdt;
 
 	spin_lock(&files->file_lock);
 	fdt = files_fdtable(files);
-	if (fd >= fdt->max_fds)
+	if (fd >= fdt->max_fds) {
+		file = ERR_PTR(-EINVAL);
 		goto out_unlock;
+	}
 	file = fdt->fd[fd];
-	if (!file)
+	if (!file) {
+		file = ERR_PTR(-EBADF);
 		goto out_unlock;
+	}
 	rcu_assign_pointer(fdt->fd[fd], NULL);
 	__put_unused_fd(files, fd);
 
@@ -622,7 +636,7 @@ int close_fd(unsigned fd)
 	struct file *file;
 
 	file = pick_file(files, fd);
-	if (!file)
+	if (IS_ERR(file))
 		return -EBADF;
 
 	return filp_close(file, files);
@@ -663,11 +677,16 @@ static inline void __range_close(struct files_struct *cur_fds, unsigned int fd,
 		struct file *file;
 
 		file = pick_file(cur_fds, fd++);
-		if (!file)
+		if (!IS_ERR(file)) {
+			/* found a valid file to close */
+			filp_close(file, cur_fds);
+			cond_resched();
 			continue;
+		}
 
-		filp_close(file, cur_fds);
-		cond_resched();
+		/* beyond the last fd in that table */
+		if (PTR_ERR(file) == -EINVAL)
+			return;
 	}
 }
 
-- 
2.27.0

[PATCH 3/3] file: simplify logic in __close_range()

[Christian Brauner]

From: Christian Brauner <christian.brauner@ubuntu.com>

It never looked too pleasant and it doesn't really buy us anything
anymore now that CLOSE_RANGE_CLOEXEC exists and we need to retake the
current maximum under the lock for it anyway. This also makes the logic
easier to follow.

Cc: Christoph Hellwig <hch@lst.de>
Cc: Giuseppe Scrivano <gscrivan@redhat.com>
Cc: Al Viro <viro@zeniv.linux.org.uk>
Cc: linux-fsdevel@vger.kernel.org
Signed-off-by: Christian Brauner <christian.brauner@ubuntu.com>
---
 fs/file.c | 31 ++++++++++++++-----------------
 1 file changed, 14 insertions(+), 17 deletions(-)

diff --git a/fs/file.c b/fs/file.c
index 740040346a98..ed46cd3ae225 100644
--- a/fs/file.c
+++ b/fs/file.c
@@ -701,7 +701,6 @@ static inline void __range_close(struct files_struct *cur_fds, unsigned int fd,
  */
 int __close_range(unsigned fd, unsigned max_fd, unsigned int flags)
 {
-	unsigned int cur_max;
 	struct task_struct *me = current;
 	struct files_struct *cur_fds = me->files, *fds = NULL;
 
@@ -711,26 +710,26 @@ int __close_range(unsigned fd, unsigned max_fd, unsigned int flags)
 	if (fd > max_fd)
 		return -EINVAL;
 
-	rcu_read_lock();
-	cur_max = files_fdtable(cur_fds)->max_fds;
-	rcu_read_unlock();
-
-	/* cap to last valid index into fdtable */
-	cur_max--;
-
 	if (flags & CLOSE_RANGE_UNSHARE) {
 		int ret;
 		unsigned int max_unshare_fds = NR_OPEN_MAX;
 
 		/*
-		 * If the requested range is greater than the current maximum,
-		 * we're closing everything so only copy all file descriptors
-		 * beneath the lowest file descriptor.
-		 * If the caller requested all fds to be made cloexec copy all
-		 * of the file descriptors since they still want to use them.
+		 * If the caller requested all fds to be made cloexec we always
+		 * copy all of the file descriptors since they still want to
+		 * use them.
 		 */
-		if (!(flags & CLOSE_RANGE_CLOEXEC) && (max_fd >= cur_max))
-			max_unshare_fds = fd;
+		if (!(flags & CLOSE_RANGE_CLOEXEC)) {
+			/*
+			 * If the requested range is greater than the current
+			 * maximum, we're closing everything so only copy all
+			 * file descriptors beneath the lowest file descriptor.
+			 */
+			rcu_read_lock();
+			if (max_fd >= last_fd(files_fdtable(cur_fds)))
+				max_unshare_fds = fd;
+			rcu_read_unlock();
+		}
 
 		ret = unshare_fd(CLONE_FILES, max_unshare_fds, &fds);
 		if (ret)
@@ -744,8 +743,6 @@ int __close_range(unsigned fd, unsigned max_fd, unsigned int flags)
 			swap(cur_fds, fds);
 	}
 
-	max_fd = min(max_fd, cur_max);
-
 	if (flags & CLOSE_RANGE_CLOEXEC)
 		__range_cloexec(cur_fds, fd, max_fd);
 	else
-- 
2.27.0

Re: [PATCH 2/3] file: let pick_file() tell caller it's done

[kernel test robot]

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

Hi Christian,

I love your patch! Perhaps something to improve:

[auto build test WARNING on linus/master]
[also build test WARNING on v5.12-rc5]
[cannot apply to next-20210401]
[If your patch is applied to the wrong git tree, kindly drop us a note.
And when submitting patch, we suggest to use '--base' as documented in
https://git-scm.com/docs/git-format-patch]

url:    https://github.com/0day-ci/linux/commits/Christian-Brauner/file-fix-close_range-for-unshare-cloexec/20210402-203841
base:   https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git 1678e493d530e7977cce34e59a86bb86f3c5631e
config: xtensa-randconfig-s031-20210402 (attached as .config)
compiler: xtensa-linux-gcc (GCC) 9.3.0
reproduce:
        wget https://raw.githubusercontent.com/intel/lkp-tests/master/sbin/make.cross -O ~/bin/make.cross
        chmod +x ~/bin/make.cross
        # apt-get install sparse
        # sparse version: v0.6.3-279-g6d5d9b42-dirty
        # https://github.com/0day-ci/linux/commit/6b3c183f6d109f17c97027f03b18a01c68237733
        git remote add linux-review https://github.com/0day-ci/linux
        git fetch --no-tags linux-review Christian-Brauner/file-fix-close_range-for-unshare-cloexec/20210402-203841
        git checkout 6b3c183f6d109f17c97027f03b18a01c68237733
        # save the attached .config to linux build tree
        COMPILER_INSTALL_PATH=$HOME/0day COMPILER=gcc-9.3.0 make.cross C=1 CF='-fdiagnostic-prefix -D__CHECK_ENDIAN__' ARCH=xtensa 

If you fix the issue, kindly add following tag as appropriate
Reported-by: kernel test robot <lkp@intel.com>


sparse warnings: (new ones prefixed by >>)
   fs/file.c:350:17: sparse: sparse: incorrect type in assignment (different address spaces) @@     expected struct file **old_fds @@     got struct file [noderef] __rcu **fd @@
   fs/file.c:350:17: sparse:     expected struct file **old_fds
   fs/file.c:350:17: sparse:     got struct file [noderef] __rcu **fd
   fs/file.c:351:17: sparse: sparse: incorrect type in assignment (different address spaces) @@     expected struct file **new_fds @@     got struct file [noderef] __rcu **fd @@
   fs/file.c:351:17: sparse:     expected struct file **new_fds
   fs/file.c:351:17: sparse:     got struct file [noderef] __rcu **fd
   fs/file.c:366:17: sparse: sparse: incompatible types in comparison expression (different address spaces):
   fs/file.c:366:17: sparse:    struct file [noderef] __rcu *
   fs/file.c:366:17: sparse:    struct file *
   fs/file.c:401:54: sparse: sparse: incorrect type in initializer (different address spaces) @@     expected struct file *file @@     got struct file [noderef] __rcu * @@
   fs/file.c:441:28: sparse: sparse: incorrect type in initializer (different address spaces) @@     expected struct fdtable [noderef] __rcu *fdt @@     got struct fdtable * @@
>> fs/file.c:620:14: sparse: sparse: incorrect type in assignment (different address spaces) @@     expected struct file *[assigned] file @@     got struct file [noderef] __rcu * @@
   fs/file.c:781:14: sparse: sparse: incorrect type in assignment (different address spaces) @@     expected struct file *file @@     got struct file [noderef] __rcu * @@
   fs/file.c:832:30: sparse: sparse: incorrect type in assignment (different address spaces) @@     expected struct file *file @@     got struct file [noderef] __rcu * @@
   fs/file.c:1057:16: sparse: sparse: incorrect type in assignment (different address spaces) @@     expected struct file *tofree @@     got struct file [noderef] __rcu * @@

vim +620 fs/file.c

0ee8cdfe6af052 Al Viro           2012-08-15  598  
6b3c183f6d109f Christian Brauner 2021-04-02  599  /**
6b3c183f6d109f Christian Brauner 2021-04-02  600   * pick_file - return file associatd with fd
6b3c183f6d109f Christian Brauner 2021-04-02  601   * @files: file struct to retrieve file from
6b3c183f6d109f Christian Brauner 2021-04-02  602   * @fd: file descriptor to retrieve file for
6b3c183f6d109f Christian Brauner 2021-04-02  603   *
6b3c183f6d109f Christian Brauner 2021-04-02  604   * If this functions returns an EINVAL error pointer the fd was beyond the
6b3c183f6d109f Christian Brauner 2021-04-02  605   * current maximum number of file descriptors for that fdtable.
6b3c183f6d109f Christian Brauner 2021-04-02  606   *
6b3c183f6d109f Christian Brauner 2021-04-02  607   * Returns: The file associated with @fd, on error returns an error pointer.
6b3c183f6d109f Christian Brauner 2021-04-02  608   */
278a5fbaed89da Christian Brauner 2019-05-24  609  static struct file *pick_file(struct files_struct *files, unsigned fd)
483ce1d4b8c3b8 Al Viro           2012-08-19  610  {
6b3c183f6d109f Christian Brauner 2021-04-02  611  	struct file *file;
483ce1d4b8c3b8 Al Viro           2012-08-19  612  	struct fdtable *fdt;
483ce1d4b8c3b8 Al Viro           2012-08-19  613  
483ce1d4b8c3b8 Al Viro           2012-08-19  614  	spin_lock(&files->file_lock);
483ce1d4b8c3b8 Al Viro           2012-08-19  615  	fdt = files_fdtable(files);
6b3c183f6d109f Christian Brauner 2021-04-02  616  	if (fd >= fdt->max_fds) {
6b3c183f6d109f Christian Brauner 2021-04-02  617  		file = ERR_PTR(-EINVAL);
483ce1d4b8c3b8 Al Viro           2012-08-19  618  		goto out_unlock;
6b3c183f6d109f Christian Brauner 2021-04-02  619  	}
483ce1d4b8c3b8 Al Viro           2012-08-19 @620  	file = fdt->fd[fd];
6b3c183f6d109f Christian Brauner 2021-04-02  621  	if (!file) {
6b3c183f6d109f Christian Brauner 2021-04-02  622  		file = ERR_PTR(-EBADF);
483ce1d4b8c3b8 Al Viro           2012-08-19  623  		goto out_unlock;
6b3c183f6d109f Christian Brauner 2021-04-02  624  	}
483ce1d4b8c3b8 Al Viro           2012-08-19  625  	rcu_assign_pointer(fdt->fd[fd], NULL);
483ce1d4b8c3b8 Al Viro           2012-08-19  626  	__put_unused_fd(files, fd);
483ce1d4b8c3b8 Al Viro           2012-08-19  627  
483ce1d4b8c3b8 Al Viro           2012-08-19  628  out_unlock:
483ce1d4b8c3b8 Al Viro           2012-08-19  629  	spin_unlock(&files->file_lock);
278a5fbaed89da Christian Brauner 2019-05-24  630  	return file;
278a5fbaed89da Christian Brauner 2019-05-24  631  }
278a5fbaed89da Christian Brauner 2019-05-24  632  

---
0-DAY CI Kernel Test Service, Intel Corporation
https://lists.01.org/hyperkitty/list/kbuild-all(a)lists.01.org

[-- Attachment #2: config.gz --]
[-- Type: application/gzip, Size: 44177 bytes --]

Re: [syzbot] KASAN: null-ptr-deref Read in filp_close (2)

[syzbot]

syzbot has found a reproducer for the following issue on:

HEAD commit:    7fef2edf sd: don't mess with SD_MINORS for CONFIG_DEBUG_BL..
git tree:       upstream
console output: https://syzkaller.appspot.com/x/log.txt?x=178919b0300000
kernel config:  https://syzkaller.appspot.com/x/.config?x=20276914ec6ad813
dashboard link: https://syzkaller.appspot.com/bug?extid=283ce5a46486d6acdbaf
syz repro:      https://syzkaller.appspot.com/x/repro.syz?x=120220f2300000
C reproducer:   https://syzkaller.appspot.com/x/repro.c?x=115f37b4300000

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

==================================================================
BUG: KASAN: use-after-free in instrument_atomic_read include/linux/instrumented.h:71 [inline]
BUG: KASAN: use-after-free in atomic64_read include/asm-generic/atomic-instrumented.h:605 [inline]
BUG: KASAN: use-after-free in atomic_long_read include/asm-generic/atomic-long.h:29 [inline]
BUG: KASAN: use-after-free in filp_close+0x22/0x170 fs/open.c:1306
Read of size 8 at addr ffff888025a40a78 by task syz-executor493/8445

CPU: 1 PID: 8445 Comm: syz-executor493 Not tainted 5.14.0-rc1-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Call Trace:
 __dump_stack lib/dump_stack.c:88 [inline]
 dump_stack_lvl+0xcd/0x134 lib/dump_stack.c:105
 print_address_description.constprop.0.cold+0x6c/0x309 mm/kasan/report.c:233
 __kasan_report mm/kasan/report.c:419 [inline]
 kasan_report.cold+0x83/0xdf mm/kasan/report.c:436
 check_region_inline mm/kasan/generic.c:183 [inline]
 kasan_check_range+0x13d/0x180 mm/kasan/generic.c:189
 instrument_atomic_read include/linux/instrumented.h:71 [inline]
 atomic64_read include/asm-generic/atomic-instrumented.h:605 [inline]
 atomic_long_read include/asm-generic/atomic-long.h:29 [inline]
 filp_close+0x22/0x170 fs/open.c:1306
 close_fd+0x5c/0x80 fs/file.c:628
 __do_sys_close fs/open.c:1331 [inline]
 __se_sys_close fs/open.c:1329 [inline]
 __x64_sys_close+0x2f/0xa0 fs/open.c:1329
 do_syscall_x64 arch/x86/entry/common.c:50 [inline]
 do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
 entry_SYSCALL_64_after_hwframe+0x44/0xae
RIP: 0033:0x4021b3
Code: c7 c2 c0 ff ff ff f7 d8 64 89 02 48 c7 c0 ff ff ff ff eb ba 0f 1f 00 64 8b 04 25 18 00 00 00 85 c0 75 14 b8 03 00 00 00 0f 05 <48> 3d 00 f0 ff ff 77 45 c3 0f 1f 40 00 48 83 ec 18 89 7c 24 0c e8
RSP: 002b:00007ffe62cc73e8 EFLAGS: 00000246 ORIG_RAX: 0000000000000003
RAX: ffffffffffffffda RBX: 0000000000000005 RCX: 00000000004021b3
RDX: 0000000020000000 RSI: 0000000000000005 RDI: 0000000000000004
RBP: 00007ffe62cc73f8 R08: 0000000000000004 R09: 00000000004aa000
R10: 0000000000000000 R11: 0000000000000246 R12: 00007ffe62cc7400
R13: 0000000000000000 R14: 00000000004ad018 R15: 0000000000400488

Allocated by task 8445:
 kasan_save_stack+0x1b/0x40 mm/kasan/common.c:38
 kasan_set_track mm/kasan/common.c:46 [inline]
 set_alloc_info mm/kasan/common.c:434 [inline]
 __kasan_slab_alloc+0x84/0xa0 mm/kasan/common.c:467
 kasan_slab_alloc include/linux/kasan.h:253 [inline]
 slab_post_alloc_hook mm/slab.h:512 [inline]
 slab_alloc_node mm/slub.c:2981 [inline]
 slab_alloc mm/slub.c:2989 [inline]
 kmem_cache_alloc+0x216/0x3a0 mm/slub.c:2994
 kmem_cache_zalloc include/linux/slab.h:711 [inline]
 __alloc_file+0x21/0x280 fs/file_table.c:101
 alloc_empty_file+0x6d/0x170 fs/file_table.c:150
 path_openat+0xde/0x27f0 fs/namei.c:3493
 do_filp_open+0x1aa/0x400 fs/namei.c:3534
 do_sys_openat2+0x16d/0x420 fs/open.c:1204
 do_sys_open fs/open.c:1220 [inline]
 __do_sys_creat fs/open.c:1294 [inline]
 __se_sys_creat fs/open.c:1288 [inline]
 __x64_sys_creat+0xc9/0x120 fs/open.c:1288
 do_syscall_x64 arch/x86/entry/common.c:50 [inline]
 do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
 entry_SYSCALL_64_after_hwframe+0x44/0xae

Freed by task 8445:
 kasan_save_stack+0x1b/0x40 mm/kasan/common.c:38
 kasan_set_track+0x1c/0x30 mm/kasan/common.c:46
 kasan_set_free_info+0x20/0x30 mm/kasan/generic.c:360
 ____kasan_slab_free mm/kasan/common.c:366 [inline]
 ____kasan_slab_free mm/kasan/common.c:328 [inline]
 __kasan_slab_free+0xfb/0x130 mm/kasan/common.c:374
 kasan_slab_free include/linux/kasan.h:229 [inline]
 slab_free_hook mm/slub.c:1650 [inline]
 slab_free_freelist_hook+0xdf/0x240 mm/slub.c:1675
 slab_free mm/slub.c:3235 [inline]
 kfree+0xeb/0x650 mm/slub.c:4295
 put_fs_context+0x3fb/0x650 fs/fs_context.c:454
 fscontext_release+0x4c/0x60 fs/fsopen.c:73
 __fput+0x288/0x920 fs/file_table.c:280
 task_work_run+0xdd/0x1a0 kernel/task_work.c:164
 tracehook_notify_resume include/linux/tracehook.h:189 [inline]
 exit_to_user_mode_loop kernel/entry/common.c:175 [inline]
 exit_to_user_mode_prepare+0x27e/0x290 kernel/entry/common.c:209
 __syscall_exit_to_user_mode_work kernel/entry/common.c:291 [inline]
 syscall_exit_to_user_mode+0x19/0x60 kernel/entry/common.c:302
 do_syscall_64+0x42/0xb0 arch/x86/entry/common.c:86
 entry_SYSCALL_64_after_hwframe+0x44/0xae

Last potentially related work creation:
 kasan_save_stack+0x1b/0x40 mm/kasan/common.c:38
 kasan_record_aux_stack+0xe5/0x110 mm/kasan/generic.c:348
 __call_rcu kernel/rcu/tree.c:3029 [inline]
 call_rcu+0xb1/0x750 kernel/rcu/tree.c:3109
 task_work_run+0xdd/0x1a0 kernel/task_work.c:164
 tracehook_notify_resume include/linux/tracehook.h:189 [inline]
 exit_to_user_mode_loop kernel/entry/common.c:175 [inline]
 exit_to_user_mode_prepare+0x27e/0x290 kernel/entry/common.c:209
 __syscall_exit_to_user_mode_work kernel/entry/common.c:291 [inline]
 syscall_exit_to_user_mode+0x19/0x60 kernel/entry/common.c:302
 do_syscall_64+0x42/0xb0 arch/x86/entry/common.c:86
 entry_SYSCALL_64_after_hwframe+0x44/0xae

Second to last potentially related work creation:
 kasan_save_stack+0x1b/0x40 mm/kasan/common.c:38
 kasan_record_aux_stack+0xe5/0x110 mm/kasan/generic.c:348
 task_work_add+0x3a/0x190 kernel/task_work.c:38
 fput_many.part.0+0xbb/0x170 fs/file_table.c:341
 fput_many fs/file_table.c:336 [inline]
 fput+0x3b/0x50 fs/file_table.c:357
 path_openat+0x19bd/0x27f0 fs/namei.c:3516
 do_filp_open+0x1aa/0x400 fs/namei.c:3534
 do_sys_openat2+0x16d/0x420 fs/open.c:1204
 do_sys_open fs/open.c:1220 [inline]
 __do_sys_open fs/open.c:1228 [inline]
 __se_sys_open fs/open.c:1224 [inline]
 __x64_sys_open+0x119/0x1c0 fs/open.c:1224
 do_syscall_x64 arch/x86/entry/common.c:50 [inline]
 do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
 entry_SYSCALL_64_after_hwframe+0x44/0xae

The buggy address belongs to the object at ffff888025a40a00
 which belongs to the cache filp of size 464
The buggy address is located 120 bytes inside of
 464-byte region [ffff888025a40a00, ffff888025a40bd0)
The buggy address belongs to the page:
page:ffffea0000969000 refcount:1 mapcount:0 mapping:0000000000000000 index:0x0 pfn:0x25a40
head:ffffea0000969000 order:1 compound_mapcount:0
flags: 0xfff00000010200(slab|head|node=0|zone=1|lastcpupid=0x7ff)
raw: 00fff00000010200 0000000000000000 0000000b00000001 ffff8880109c4780
raw: 0000000000000000 00000000800c000c 00000001ffffffff 0000000000000000
page dumped because: kasan: bad access detected
page_owner tracks the page as allocated
page last allocated via order 1, migratetype Unmovable, gfp_mask 0xd20c0(__GFP_IO|__GFP_FS|__GFP_NOWARN|__GFP_NORETRY|__GFP_COMP|__GFP_NOMEMALLOC), pid 4875, ts 15466439710, free_ts 15379402342
 prep_new_page mm/page_alloc.c:2433 [inline]
 get_page_from_freelist+0xa72/0x2f80 mm/page_alloc.c:4166
 __alloc_pages+0x1b2/0x500 mm/page_alloc.c:5374
 alloc_pages+0x18c/0x2a0 mm/mempolicy.c:2244
 alloc_slab_page mm/slub.c:1713 [inline]
 allocate_slab+0x32b/0x4c0 mm/slub.c:1853
 new_slab mm/slub.c:1916 [inline]
 new_slab_objects mm/slub.c:2662 [inline]
 ___slab_alloc+0x4ba/0x820 mm/slub.c:2825
 __slab_alloc.constprop.0+0xa7/0xf0 mm/slub.c:2865
 slab_alloc_node mm/slub.c:2947 [inline]
 slab_alloc mm/slub.c:2989 [inline]
 kmem_cache_alloc+0x372/0x3a0 mm/slub.c:2994
 kmem_cache_zalloc include/linux/slab.h:711 [inline]
 __alloc_file+0x21/0x280 fs/file_table.c:101
 alloc_empty_file+0x6d/0x170 fs/file_table.c:150
 path_openat+0xde/0x27f0 fs/namei.c:3493
 do_filp_open+0x1aa/0x400 fs/namei.c:3534
 do_sys_openat2+0x16d/0x420 fs/open.c:1204
 do_sys_open fs/open.c:1220 [inline]
 __do_sys_open fs/open.c:1228 [inline]
 __se_sys_open fs/open.c:1224 [inline]
 __x64_sys_open+0x119/0x1c0 fs/open.c:1224
 do_syscall_x64 arch/x86/entry/common.c:50 [inline]
 do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
 entry_SYSCALL_64_after_hwframe+0x44/0xae
page last free stack trace:
 reset_page_owner include/linux/page_owner.h:24 [inline]
 free_pages_prepare mm/page_alloc.c:1343 [inline]
 free_pcp_prepare+0x2c5/0x780 mm/page_alloc.c:1394
 free_unref_page_prepare mm/page_alloc.c:3329 [inline]
 free_unref_page+0x19/0x690 mm/page_alloc.c:3408
 qlink_free mm/kasan/quarantine.c:146 [inline]
 qlist_free_all+0x5a/0xc0 mm/kasan/quarantine.c:165
 kasan_quarantine_reduce+0x180/0x200 mm/kasan/quarantine.c:272
 __kasan_slab_alloc+0x8e/0xa0 mm/kasan/common.c:444
 kasan_slab_alloc include/linux/kasan.h:253 [inline]
 slab_post_alloc_hook mm/slab.h:512 [inline]
 slab_alloc_node mm/slub.c:2981 [inline]
 slab_alloc mm/slub.c:2989 [inline]
 __kmalloc+0x1f4/0x330 mm/slub.c:4133
 kmalloc include/linux/slab.h:596 [inline]
 tomoyo_add_entry security/tomoyo/common.c:2031 [inline]
 tomoyo_supervisor+0xce8/0xf00 security/tomoyo/common.c:2103
 tomoyo_audit_path_log security/tomoyo/file.c:168 [inline]
 tomoyo_path_permission security/tomoyo/file.c:587 [inline]
 tomoyo_path_permission+0x270/0x3a0 security/tomoyo/file.c:573
 tomoyo_path_perm+0x2f0/0x400 security/tomoyo/file.c:838
 security_inode_getattr+0xcf/0x140 security/security.c:1332
 vfs_getattr fs/stat.c:139 [inline]
 vfs_statx+0x164/0x390 fs/stat.c:207
 vfs_fstatat fs/stat.c:225 [inline]
 vfs_lstat include/linux/fs.h:3386 [inline]
 __do_sys_newlstat+0x91/0x110 fs/stat.c:380
 do_syscall_x64 arch/x86/entry/common.c:50 [inline]
 do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
 entry_SYSCALL_64_after_hwframe+0x44/0xae

Memory state around the buggy address:
 ffff888025a40900: 00 00 00 00 00 00 00 00 00 00 fc fc fc fc fc fc
 ffff888025a40980: fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc
>ffff888025a40a00: fa fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
                                                                ^
 ffff888025a40a80: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
 ffff888025a40b00: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
==================================================================

Re: [syzbot] KASAN: null-ptr-deref Read in filp_close (2)

[Linus Torvalds]

On Mon, Jul 12, 2021 at 9:12 PM syzbot
<syzbot+283ce5a46486d6acdbaf@syzkaller.appspotmail.com> wrote:
>
> syzbot has found a reproducer for the following issue on:

Hmm.

This issue is reported to have been already fixed:

    Fix commit: 9b5b8722 file: fix close_range() for unshare+cloexec

and that fix is already in the reported HEAD commit:

> HEAD commit:    7fef2edf sd: don't mess with SD_MINORS for CONFIG_DEBUG_BL..

and the oops report clearly is from that:

> CPU: 1 PID: 8445 Comm: syz-executor493 Not tainted 5.14.0-rc1-syzkaller #0

so the alleged fix is already there.

So clearly commit 9b5b872215fe ("file: fix close_range() for
unshare+cloexec") does *NOT* fix the issue.

This was originally bisected to that 582f1fb6b721 ("fs, close_range:
add flag CLOSE_RANGE_CLOEXEC") in

     https://syzkaller.appspot.com/bug?id=1bef50bdd9622a1969608d1090b2b4a588d0c6ac

which is where the "fix" is from.

It would probably be good if sysbot made this kind of "hey, it was
reported fixed, but it's not" very clear.

The KASAN report looks like a use-after-free, and that "use" is
actually the sanity check that the file count is non-zero, so it's
really a "struct file *" that has already been free'd.

That bogus free is a regular close() system call

>  filp_close+0x22/0x170 fs/open.c:1306
>  close_fd+0x5c/0x80 fs/file.c:628
>  __do_sys_close fs/open.c:1331 [inline]
>  __se_sys_close fs/open.c:1329 [inline]

And it was opened by a "creat()" system call:

> Allocated by task 8445:
>  __alloc_file+0x21/0x280 fs/file_table.c:101
>  alloc_empty_file+0x6d/0x170 fs/file_table.c:150
>  path_openat+0xde/0x27f0 fs/namei.c:3493
>  do_filp_open+0x1aa/0x400 fs/namei.c:3534
>  do_sys_openat2+0x16d/0x420 fs/open.c:1204
>  do_sys_open fs/open.c:1220 [inline]
>  __do_sys_creat fs/open.c:1294 [inline]
>  __se_sys_creat fs/open.c:1288 [inline]
>  __x64_sys_creat+0xc9/0x120 fs/open.c:1288
>  do_syscall_x64 arch/x86/entry/common.c:50 [inline]
>  do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
>  entry_SYSCALL_64_after_hwframe+0x44/0xae

But it has apparently already been closed from a workqueue:

> Freed by task 8445:
>  __fput+0x288/0x920 fs/file_table.c:280
>  task_work_run+0xdd/0x1a0 kernel/task_work.c:164

So it's some kind of confusion and re-use of a struct file pointer.

Which is certainly consistent with the "fix" in 9b5b872215fe ("file:
fix close_range() for unshare+cloexec"), but it very much looks like
that fix was incomplete and not the full story.

Some fdtable got re-allocated? The fix that wasn't a fix ends up
re-checking the maximum file number under the file_lock, but there's
clearly something else going on too.

Christian?

                Linus

Re: [syzbot] KASAN: null-ptr-deref Read in filp_close (2)

[Christian Brauner]

On Tue, Jul 13, 2021 at 11:49:14AM -0700, Linus Torvalds wrote:
> On Mon, Jul 12, 2021 at 9:12 PM syzbot
> <syzbot+283ce5a46486d6acdbaf@syzkaller.appspotmail.com> wrote:
> >
> > syzbot has found a reproducer for the following issue on:
> 
> Hmm.
> 
> This issue is reported to have been already fixed:
> 
>     Fix commit: 9b5b8722 file: fix close_range() for unshare+cloexec
> 
> and that fix is already in the reported HEAD commit:
> 
> > HEAD commit:    7fef2edf sd: don't mess with SD_MINORS for CONFIG_DEBUG_BL..
> 
> and the oops report clearly is from that:
> 
> > CPU: 1 PID: 8445 Comm: syz-executor493 Not tainted 5.14.0-rc1-syzkaller #0
> 
> so the alleged fix is already there.
> 
> So clearly commit 9b5b872215fe ("file: fix close_range() for
> unshare+cloexec") does *NOT* fix the issue.
> 
> This was originally bisected to that 582f1fb6b721 ("fs, close_range:
> add flag CLOSE_RANGE_CLOEXEC") in
> 
>      https://syzkaller.appspot.com/bug?id=1bef50bdd9622a1969608d1090b2b4a588d0c6ac
> 
> which is where the "fix" is from.
> 
> It would probably be good if sysbot made this kind of "hey, it was
> reported fixed, but it's not" very clear.
> 
> The KASAN report looks like a use-after-free, and that "use" is
> actually the sanity check that the file count is non-zero, so it's
> really a "struct file *" that has already been free'd.
> 
> That bogus free is a regular close() system call
> 
> >  filp_close+0x22/0x170 fs/open.c:1306
> >  close_fd+0x5c/0x80 fs/file.c:628
> >  __do_sys_close fs/open.c:1331 [inline]
> >  __se_sys_close fs/open.c:1329 [inline]
> 
> And it was opened by a "creat()" system call:
> 
> > Allocated by task 8445:
> >  __alloc_file+0x21/0x280 fs/file_table.c:101
> >  alloc_empty_file+0x6d/0x170 fs/file_table.c:150
> >  path_openat+0xde/0x27f0 fs/namei.c:3493
> >  do_filp_open+0x1aa/0x400 fs/namei.c:3534
> >  do_sys_openat2+0x16d/0x420 fs/open.c:1204
> >  do_sys_open fs/open.c:1220 [inline]
> >  __do_sys_creat fs/open.c:1294 [inline]
> >  __se_sys_creat fs/open.c:1288 [inline]
> >  __x64_sys_creat+0xc9/0x120 fs/open.c:1288
> >  do_syscall_x64 arch/x86/entry/common.c:50 [inline]
> >  do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
> >  entry_SYSCALL_64_after_hwframe+0x44/0xae
> 
> But it has apparently already been closed from a workqueue:
> 
> > Freed by task 8445:
> >  __fput+0x288/0x920 fs/file_table.c:280
> >  task_work_run+0xdd/0x1a0 kernel/task_work.c:164
> 
> So it's some kind of confusion and re-use of a struct file pointer.
> 
> Which is certainly consistent with the "fix" in 9b5b872215fe ("file:
> fix close_range() for unshare+cloexec"), but it very much looks like
> that fix was incomplete and not the full story.
> 
> Some fdtable got re-allocated? The fix that wasn't a fix ends up
> re-checking the maximum file number under the file_lock, but there's
> clearly something else going on too.
> 
> Christian?

Looking into this now.

I have to say I'm very confused by the syzkaller report here.

If I go to

https://syzkaller.appspot.com/bug?extid=283ce5a46486d6acdbaf

which is the original link in the report it shows me

android-54	KASAN: use-after-free Read in filp_close	C			2	183d	183d	0/1	upstream: reported C repro on 2021/01/11 12:38

which seems to indicate that this happened on an Android specific 5.4
kernel?

But ok, so I click on the link "upstream: reported C repro on 2021/01/11 12:38"
which takes me to a google group

https://groups.google.com/g/syzkaller-android-bugs/c/FQj0qcRSy_M/m/wrY70QFzBAAJ

which again strongly indicates that this is an Android specific kernel?

HEAD commit: c9951e5d Merge 5.4.88 into android12-5.4
git tree: android12-5.4

but then I can click on the dashboard link for that crash report and it
takes me to:

https://syzkaller.appspot.com/bug?extid=53897bcb31b82c7a08fe

which seems to be the upstream report?

So I'm a bit confused whether I'm even looking at the correct bug report
but I'll just give the repro a try and see what's going on.

Christian

Re: [syzbot] KASAN: null-ptr-deref Read in filp_close (2)

[Christian Brauner]

On Wed, Jul 14, 2021 at 09:59:25AM +0200, Christian Brauner wrote:
> On Tue, Jul 13, 2021 at 11:49:14AM -0700, Linus Torvalds wrote:
> > On Mon, Jul 12, 2021 at 9:12 PM syzbot
> > <syzbot+283ce5a46486d6acdbaf@syzkaller.appspotmail.com> wrote:
> > >
> > > syzbot has found a reproducer for the following issue on:
> > 
> > Hmm.
> > 
> > This issue is reported to have been already fixed:
> > 
> >     Fix commit: 9b5b8722 file: fix close_range() for unshare+cloexec
> > 
> > and that fix is already in the reported HEAD commit:
> > 
> > > HEAD commit:    7fef2edf sd: don't mess with SD_MINORS for CONFIG_DEBUG_BL..
> > 
> > and the oops report clearly is from that:
> > 
> > > CPU: 1 PID: 8445 Comm: syz-executor493 Not tainted 5.14.0-rc1-syzkaller #0
> > 
> > so the alleged fix is already there.
> > 
> > So clearly commit 9b5b872215fe ("file: fix close_range() for
> > unshare+cloexec") does *NOT* fix the issue.
> > 
> > This was originally bisected to that 582f1fb6b721 ("fs, close_range:
> > add flag CLOSE_RANGE_CLOEXEC") in
> > 
> >      https://syzkaller.appspot.com/bug?id=1bef50bdd9622a1969608d1090b2b4a588d0c6ac
> > 
> > which is where the "fix" is from.
> > 
> > It would probably be good if sysbot made this kind of "hey, it was
> > reported fixed, but it's not" very clear.
> > 
> > The KASAN report looks like a use-after-free, and that "use" is
> > actually the sanity check that the file count is non-zero, so it's
> > really a "struct file *" that has already been free'd.
> > 
> > That bogus free is a regular close() system call
> > 
> > >  filp_close+0x22/0x170 fs/open.c:1306
> > >  close_fd+0x5c/0x80 fs/file.c:628
> > >  __do_sys_close fs/open.c:1331 [inline]
> > >  __se_sys_close fs/open.c:1329 [inline]
> > 
> > And it was opened by a "creat()" system call:
> > 
> > > Allocated by task 8445:
> > >  __alloc_file+0x21/0x280 fs/file_table.c:101
> > >  alloc_empty_file+0x6d/0x170 fs/file_table.c:150
> > >  path_openat+0xde/0x27f0 fs/namei.c:3493
> > >  do_filp_open+0x1aa/0x400 fs/namei.c:3534
> > >  do_sys_openat2+0x16d/0x420 fs/open.c:1204
> > >  do_sys_open fs/open.c:1220 [inline]
> > >  __do_sys_creat fs/open.c:1294 [inline]
> > >  __se_sys_creat fs/open.c:1288 [inline]
> > >  __x64_sys_creat+0xc9/0x120 fs/open.c:1288
> > >  do_syscall_x64 arch/x86/entry/common.c:50 [inline]
> > >  do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
> > >  entry_SYSCALL_64_after_hwframe+0x44/0xae
> > 
> > But it has apparently already been closed from a workqueue:
> > 
> > > Freed by task 8445:
> > >  __fput+0x288/0x920 fs/file_table.c:280
> > >  task_work_run+0xdd/0x1a0 kernel/task_work.c:164
> > 
> > So it's some kind of confusion and re-use of a struct file pointer.
> > 
> > Which is certainly consistent with the "fix" in 9b5b872215fe ("file:
> > fix close_range() for unshare+cloexec"), but it very much looks like
> > that fix was incomplete and not the full story.
> > 
> > Some fdtable got re-allocated? The fix that wasn't a fix ends up
> > re-checking the maximum file number under the file_lock, but there's
> > clearly something else going on too.
> > 
> > Christian?
> 
> Looking into this now.
> 
> I have to say I'm very confused by the syzkaller report here.
> 
> If I go to
> 
> https://syzkaller.appspot.com/bug?extid=283ce5a46486d6acdbaf
> 
> which is the original link in the report it shows me
> 
> android-54	KASAN: use-after-free Read in filp_close	C			2	183d	183d	0/1	upstream: reported C repro on 2021/01/11 12:38
> 
> which seems to indicate that this happened on an Android specific 5.4
> kernel?
> 
> But ok, so I click on the link "upstream: reported C repro on 2021/01/11 12:38"
> which takes me to a google group
> 
> https://groups.google.com/g/syzkaller-android-bugs/c/FQj0qcRSy_M/m/wrY70QFzBAAJ
> 
> which again strongly indicates that this is an Android specific kernel?
> 
> HEAD commit: c9951e5d Merge 5.4.88 into android12-5.4
> git tree: android12-5.4
> 
> but then I can click on the dashboard link for that crash report and it
> takes me to:
> 
> https://syzkaller.appspot.com/bug?extid=53897bcb31b82c7a08fe
> 
> which seems to be the upstream report?
> 
> So I'm a bit confused whether I'm even looking at the correct bug report
> but I'll just give the repro a try and see what's going on.

Ok, reproduced and I think I found the issue. It's not related to
close_fd((), I think it's caused by a UAF when FSCONFIG_SET_FD is with
the key "source" and a valid fd passed through "aux".

Briefly, fs_parameter is a union:

struct fs_parameter {
	const char		*key;		/* Parameter name */
	enum fs_value_type	type:8;		/* The type of value here */
	union {
		char		*string;
		void		*blob;
		struct filename	*name;
		struct file	*file;
	};
	size_t	size;
	int	dirfd;
};

and cgroup1_parse_param is copying out param->string when the param's
key is "source" without verifying that param->type is actually
fs_value_is_string.

I'll explain in detail in the commit once I've confirmed and tested that
my suspicion is correct.

Christian

Re: [syzbot] KASAN: null-ptr-deref Read in filp_close (2)

[Dmitry Vyukov]

On Wed, 14 Jul 2021 at 09:59, Christian Brauner
<christian.brauner@ubuntu.com> wrote:
>
> On Tue, Jul 13, 2021 at 11:49:14AM -0700, Linus Torvalds wrote:
> > On Mon, Jul 12, 2021 at 9:12 PM syzbot
> > <syzbot+283ce5a46486d6acdbaf@syzkaller.appspotmail.com> wrote:
> > >
> > > syzbot has found a reproducer for the following issue on:
> >
> > Hmm.
> >
> > This issue is reported to have been already fixed:
> >
> >     Fix commit: 9b5b8722 file: fix close_range() for unshare+cloexec
> >
> > and that fix is already in the reported HEAD commit:
> >
> > > HEAD commit:    7fef2edf sd: don't mess with SD_MINORS for CONFIG_DEBUG_BL..
> >
> > and the oops report clearly is from that:
> >
> > > CPU: 1 PID: 8445 Comm: syz-executor493 Not tainted 5.14.0-rc1-syzkaller #0
> >
> > so the alleged fix is already there.
> >
> > So clearly commit 9b5b872215fe ("file: fix close_range() for
> > unshare+cloexec") does *NOT* fix the issue.
> >
> > This was originally bisected to that 582f1fb6b721 ("fs, close_range:
> > add flag CLOSE_RANGE_CLOEXEC") in
> >
> >      https://syzkaller.appspot.com/bug?id=1bef50bdd9622a1969608d1090b2b4a588d0c6ac
> >
> > which is where the "fix" is from.
> >
> > It would probably be good if sysbot made this kind of "hey, it was
> > reported fixed, but it's not" very clear.
> >
> > The KASAN report looks like a use-after-free, and that "use" is
> > actually the sanity check that the file count is non-zero, so it's
> > really a "struct file *" that has already been free'd.
> >
> > That bogus free is a regular close() system call
> >
> > >  filp_close+0x22/0x170 fs/open.c:1306
> > >  close_fd+0x5c/0x80 fs/file.c:628
> > >  __do_sys_close fs/open.c:1331 [inline]
> > >  __se_sys_close fs/open.c:1329 [inline]
> >
> > And it was opened by a "creat()" system call:
> >
> > > Allocated by task 8445:
> > >  __alloc_file+0x21/0x280 fs/file_table.c:101
> > >  alloc_empty_file+0x6d/0x170 fs/file_table.c:150
> > >  path_openat+0xde/0x27f0 fs/namei.c:3493
> > >  do_filp_open+0x1aa/0x400 fs/namei.c:3534
> > >  do_sys_openat2+0x16d/0x420 fs/open.c:1204
> > >  do_sys_open fs/open.c:1220 [inline]
> > >  __do_sys_creat fs/open.c:1294 [inline]
> > >  __se_sys_creat fs/open.c:1288 [inline]
> > >  __x64_sys_creat+0xc9/0x120 fs/open.c:1288
> > >  do_syscall_x64 arch/x86/entry/common.c:50 [inline]
> > >  do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
> > >  entry_SYSCALL_64_after_hwframe+0x44/0xae
> >
> > But it has apparently already been closed from a workqueue:
> >
> > > Freed by task 8445:
> > >  __fput+0x288/0x920 fs/file_table.c:280
> > >  task_work_run+0xdd/0x1a0 kernel/task_work.c:164
> >
> > So it's some kind of confusion and re-use of a struct file pointer.
> >
> > Which is certainly consistent with the "fix" in 9b5b872215fe ("file:
> > fix close_range() for unshare+cloexec"), but it very much looks like
> > that fix was incomplete and not the full story.
> >
> > Some fdtable got re-allocated? The fix that wasn't a fix ends up
> > re-checking the maximum file number under the file_lock, but there's
> > clearly something else going on too.
> >
> > Christian?
>
> Looking into this now.
>
> I have to say I'm very confused by the syzkaller report here.
>
> If I go to
>
> https://syzkaller.appspot.com/bug?extid=283ce5a46486d6acdbaf
>
> which is the original link in the report it shows me
>
> android-54      KASAN: use-after-free Read in filp_close        C                       2       183d    183d    0/1     upstream: reported C repro on 2021/01/11 12:38
>
> which seems to indicate that this happened on an Android specific 5.4
> kernel?

Hi Christian,

That's "similar bugs" section. In this section syzbot shows previous
similar bugs and similar bugs on other kernels (lts, android).

"KASAN: use-after-free Read in filp_close" also happened on Android
tree, if you click on the link, you can see crashes and reproducers on
the android tree:
https://syzkaller.appspot.com/bug?id=255edc9d4f00a881d3bf68b87d09a8b7843409e7

If you are interested only in upstream crashes/reproducers, then
ignore the "similar bugs" section.


> But ok, so I click on the link "upstream: reported C repro on 2021/01/11 12:38"
> which takes me to a google group
>
> https://groups.google.com/g/syzkaller-android-bugs/c/FQj0qcRSy_M/m/wrY70QFzBAAJ
>
> which again strongly indicates that this is an Android specific kernel?
>
> HEAD commit: c9951e5d Merge 5.4.88 into android12-5.4
> git tree: android12-5.4
>
> but then I can click on the dashboard link for that crash report and it
> takes me to:
>
> https://syzkaller.appspot.com/bug?extid=53897bcb31b82c7a08fe
>
> which seems to be the upstream report?
>
> So I'm a bit confused whether I'm even looking at the correct bug report
> but I'll just give the repro a try and see what's going on.
>
> Christian
>
> --
> You received this message because you are subscribed to the Google Groups "syzkaller-bugs" group.
> To unsubscribe from this group and stop receiving emails from it, send an email to syzkaller-bugs+unsubscribe@googlegroups.com.
> To view this discussion on the web visit https://groups.google.com/d/msgid/syzkaller-bugs/20210714075925.jtlfrhhuj4bzff3m%40wittgenstein.

Re: [syzbot] KASAN: null-ptr-deref Read in filp_close (2)

[Christian Brauner]

On Mon, Jul 12, 2021 at 09:12:20PM -0700, syzbot wrote:
> syzbot has found a reproducer for the following issue on:
> 
> HEAD commit:    7fef2edf sd: don't mess with SD_MINORS for CONFIG_DEBUG_BL..
> git tree:       upstream
> console output: https://syzkaller.appspot.com/x/log.txt?x=178919b0300000
> kernel config:  https://syzkaller.appspot.com/x/.config?x=20276914ec6ad813
> dashboard link: https://syzkaller.appspot.com/bug?extid=283ce5a46486d6acdbaf
> syz repro:      https://syzkaller.appspot.com/x/repro.syz?x=120220f2300000
> C reproducer:   https://syzkaller.appspot.com/x/repro.c?x=115f37b4300000
> 
> IMPORTANT: if you fix the issue, please add the following tag to the commit:
> Reported-by: syzbot+283ce5a46486d6acdbaf@syzkaller.appspotmail.com
> 
> ==================================================================
> BUG: KASAN: use-after-free in instrument_atomic_read include/linux/instrumented.h:71 [inline]
> BUG: KASAN: use-after-free in atomic64_read include/asm-generic/atomic-instrumented.h:605 [inline]
> BUG: KASAN: use-after-free in atomic_long_read include/asm-generic/atomic-long.h:29 [inline]
> BUG: KASAN: use-after-free in filp_close+0x22/0x170 fs/open.c:1306
> Read of size 8 at addr ffff888025a40a78 by task syz-executor493/8445

#syz test: https://git.kernel.org/pub/scm/linux/kernel/git/brauner/linux.git/ 595fac5cecba71935450ec431eb8dfa963cf45fe 

Re: [syzbot] KASAN: null-ptr-deref Read in filp_close (2)

[Christian Brauner]

On Mon, Jul 12, 2021 at 09:12:20PM -0700, syzbot wrote:
> syzbot has found a reproducer for the following issue on:
> 
> HEAD commit:    7fef2edf sd: don't mess with SD_MINORS for CONFIG_DEBUG_BL..
> git tree:       upstream
> console output: https://syzkaller.appspot.com/x/log.txt?x=178919b0300000
> kernel config:  https://syzkaller.appspot.com/x/.config?x=20276914ec6ad813
> dashboard link: https://syzkaller.appspot.com/bug?extid=283ce5a46486d6acdbaf
> syz repro:      https://syzkaller.appspot.com/x/repro.syz?x=120220f2300000
> C reproducer:   https://syzkaller.appspot.com/x/repro.c?x=115f37b4300000
> 
> IMPORTANT: if you fix the issue, please add the following tag to the commit:
> Reported-by: syzbot+283ce5a46486d6acdbaf@syzkaller.appspotmail.com

#syz test: https://git.kernel.org/pub/scm/linux/kernel/git/brauner/linux.git/ syzbot+283ce5a46486d6acdbaf 

Re: [syzbot] KASAN: null-ptr-deref Read in filp_close (2)

[syzbot]

> On Mon, Jul 12, 2021 at 09:12:20PM -0700, syzbot wrote:
>> syzbot has found a reproducer for the following issue on:
>> 
>> HEAD commit:    7fef2edf sd: don't mess with SD_MINORS for CONFIG_DEBUG_BL..
>> git tree:       upstream
>> console output: https://syzkaller.appspot.com/x/log.txt?x=178919b0300000
>> kernel config:  https://syzkaller.appspot.com/x/.config?x=20276914ec6ad813
>> dashboard link: https://syzkaller.appspot.com/bug?extid=283ce5a46486d6acdbaf
>> syz repro:      https://syzkaller.appspot.com/x/repro.syz?x=120220f2300000
>> C reproducer:   https://syzkaller.appspot.com/x/repro.c?x=115f37b4300000
>> 
>> IMPORTANT: if you fix the issue, please add the following tag to the commit:
>> Reported-by: syzbot+283ce5a46486d6acdbaf@syzkaller.appspotmail.com
>
> #syz test: https://git.kernel.org/pub/scm/linux/kernel/git/brauner/linux.git/ syzbot+283ce5a46486d6acdbaf 

"syzbot+283ce5a46486d6acdbaf" does not look like a valid git branch or commit.

Re: [syzbot] KASAN: null-ptr-deref Read in filp_close (2)

[syzbot]

Hello,

syzbot tried to test the proposed patch but the build/boot failed:

failed to checkout kernel repo https://git.kernel.org/pub/scm/linux/kernel/git/brauner/linux.git/ on commit 595fac5cecba71935450ec431eb8dfa963cf45fe: failed to run ["git" "checkout" "595fac5cecba71935450ec431eb8dfa963cf45fe"]: exit status 128
fatal: reference is not a tree: 595fac5cecba71935450ec431eb8dfa963cf45fe



Tested on:

commit:         [unknown 
git tree:       https://git.kernel.org/pub/scm/linux/kernel/git/brauner/linux.git/ 595fac5cecba71935450ec431eb8dfa963cf45fe
dashboard link: https://syzkaller.appspot.com/bug?extid=283ce5a46486d6acdbaf
compiler:       

Re: [syzbot] KASAN: null-ptr-deref Read in filp_close (2)

[Christian Brauner]

On Wed, Jul 14, 2021 at 03:51:57PM +0200, Christian Brauner wrote:
> On Mon, Jul 12, 2021 at 09:12:20PM -0700, syzbot wrote:
> > syzbot has found a reproducer for the following issue on:
> > 
> > HEAD commit:    7fef2edf sd: don't mess with SD_MINORS for CONFIG_DEBUG_BL..
> > git tree:       upstream
> > console output: https://syzkaller.appspot.com/x/log.txt?x=178919b0300000
> > kernel config:  https://syzkaller.appspot.com/x/.config?x=20276914ec6ad813
> > dashboard link: https://syzkaller.appspot.com/bug?extid=283ce5a46486d6acdbaf
> > syz repro:      https://syzkaller.appspot.com/x/repro.syz?x=120220f2300000
> > C reproducer:   https://syzkaller.appspot.com/x/repro.c?x=115f37b4300000
> > 
> > IMPORTANT: if you fix the issue, please add the following tag to the commit:
> > Reported-by: syzbot+283ce5a46486d6acdbaf@syzkaller.appspotmail.com
> > 
> > ==================================================================
> > BUG: KASAN: use-after-free in instrument_atomic_read include/linux/instrumented.h:71 [inline]
> > BUG: KASAN: use-after-free in atomic64_read include/asm-generic/atomic-instrumented.h:605 [inline]
> > BUG: KASAN: use-after-free in atomic_long_read include/asm-generic/atomic-long.h:29 [inline]
> > BUG: KASAN: use-after-free in filp_close+0x22/0x170 fs/open.c:1306
> > Read of size 8 at addr ffff888025a40a78 by task syz-executor493/8445
> 
> #syz test: https://git.kernel.org/pub/scm/linux/kernel/git/brauner/linux.git/ 595fac5cecba71935450ec431eb8dfa963cf45fe 

Hm, git.kernel.org doesn't seem to have caught up. Let's try:

#syz test: https://gitlab.com/brauner/linux.git 595fac5cecba71935450ec431eb8dfa963cf45fe 

Re: [syzbot] KASAN: null-ptr-deref Read in filp_close (2)

[syzbot]

Hello,

syzbot has tested the proposed patch and the reproducer did not trigger any issue:

Reported-and-tested-by: syzbot+283ce5a46486d6acdbaf@syzkaller.appspotmail.com

Tested on:

commit:         595fac5c cgroup: verify that source is a string
git tree:       https://gitlab.com/brauner/linux.git
kernel config:  https://syzkaller.appspot.com/x/.config?x=20276914ec6ad813
dashboard link: https://syzkaller.appspot.com/bug?extid=283ce5a46486d6acdbaf
compiler:       

Note: testing is done by a robot and is best-effort only.