[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+283ce5...@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 syzk...@googlegroups.com.

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

[Dmitry Vyukov]

On Fri, Mar 26, 2021 at 8:55 AM syzbot
<syzbot+283ce5...@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+283ce5...@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.

> --
> 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-bug...@googlegroups.com.
> To view this discussion on the web visit https://groups.google.com/d/msgid/syzkaller-bugs/00000000000069c40405be6bdad4%40google.com.

[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+283ce5...@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+283ce5...@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 <lior...@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

[Dmitry Vyukov]

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..

[Christian Brauner]

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.

Christian

[Christian Brauner]

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 <christia...@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+283ce5...@syzkaller.appspotmail.com
Cc: Christoph Hellwig <h...@lst.de>
Cc: Al Viro <vi...@zeniv.linux.org.uk>
Cc: linux-...@vger.kernel.org
Cc: sta...@vger.kernel.org
Signed-off-by: Christian Brauner <christia...@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

[Dmitry Vyukov]

On Fri, Mar 26, 2021 at 2:50 PM Christian Brauner

The crash does not happen with this patch.

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

Thanks for the quick fix!

[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?

[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

[Christian Brauner]

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

[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+283ce5...@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
==================================================================

[Hillf Danton]

On Mon, 12 Jul 2021 21:12:20 -0700

A couple of weird things, 1) get file from fd table with invalid count.

2) After put file will get no chance for landing in fdtable.

Then where is wrong if it is not count leak somewhere else?

[Linus Torvalds]

On Mon, Jul 12, 2021 at 9:12 PM syzbot
<syzbot+283ce5...@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

[Christian Brauner]

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

[Christian Brauner]

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

[Dmitry Vyukov]

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-bug...@googlegroups.com.

> To view this discussion on the web visit https://groups.google.com/d/msgid/syzkaller-bugs/20210714075925.jtlfrhhuj4bzff3m%40wittgenstein.

[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+283ce5...@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

[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+283ce5...@syzkaller.appspotmail.com

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

[syzbot]

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

[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:

[Christian Brauner]

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

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

[syzbot]

Hello,

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

Reported-and-tested-by: syzbot+283ce5...@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.