REISERFS (device loop3): found reiserfs format "3.6" with non-standard journal REISERFS (device loop3): using ordered data mode audit: type=1800 audit(1677719668.383:23): pid=9730 uid=0 auid=4294967295 ses=4294967295 op="collect_data" cause="failed(directio)" comm="syz-executor.3" name="file0" dev="loop3" ino=5 res=0 reiserfs: using flush barriers ================================ WARNING: inconsistent lock state 4.14.307-syzkaller #0 Not tainted -------------------------------- inconsistent {SOFTIRQ-ON-W} -> {IN-SOFTIRQ-W} usage. syz-executor.2/9790 [HC0[0]:SC1[1]:HE1:SE0] takes: (&(&local->client_conns_lock)->rlock){+.?.}, at: [] spin_lock include/linux/spinlock.h:317 [inline] (&(&local->client_conns_lock)->rlock){+.?.}, at: [] rxrpc_put_one_client_conn net/rxrpc/conn_client.c:905 [inline] (&(&local->client_conns_lock)->rlock){+.?.}, at: [] rxrpc_put_client_conn+0x661/0xac0 net/rxrpc/conn_client.c:957 {SOFTIRQ-ON-W} state was registered at: lock_acquire+0x170/0x3f0 kernel/locking/lockdep.c:3998 __raw_spin_lock include/linux/spinlock_api_smp.h:142 [inline] _raw_spin_lock+0x2a/0x40 kernel/locking/spinlock.c:152 spin_lock include/linux/spinlock.h:317 [inline] rxrpc_get_client_conn net/rxrpc/conn_client.c:306 [inline] rxrpc_connect_call+0x2bb/0x3e10 net/rxrpc/conn_client.c:692 rxrpc_new_client_call+0x8f4/0x1a10 net/rxrpc/call_object.c:276 rxrpc_new_client_call_for_sendmsg net/rxrpc/sendmsg.c:531 [inline] rxrpc_do_sendmsg+0x8dc/0xfb0 net/rxrpc/sendmsg.c:583 rxrpc_sendmsg+0x3cf/0x5f0 net/rxrpc/af_rxrpc.c:543 sock_sendmsg_nosec net/socket.c:646 [inline] sock_sendmsg+0xb5/0x100 net/socket.c:656 ___sys_sendmsg+0x6c8/0x800 net/socket.c:2062 audit: type=1804 audit(1677719668.423:24): pid=9730 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.3" name="/root/syzkaller-testdir540972435/syzkaller.MJgzIG/13/file1/file0" dev="loop3" ino=5 res=1 __sys_sendmsg+0xa3/0x120 net/socket.c:2096 SYSC_sendmsg net/socket.c:2107 [inline] SyS_sendmsg+0x27/0x40 net/socket.c:2103 do_syscall_64+0x1d5/0x640 arch/x86/entry/common.c:292 entry_SYSCALL_64_after_hwframe+0x5e/0xd3 irq event stamp: 19668 hardirqs last enabled at (19668): [] __raw_spin_unlock_irqrestore include/linux/spinlock_api_smp.h:160 [inline] hardirqs last enabled at (19668): [] _raw_spin_unlock_irqrestore+0x79/0xe0 kernel/locking/spinlock.c:192 hardirqs last disabled at (19667): [] __raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:108 [inline] hardirqs last disabled at (19667): [] _raw_spin_lock_irqsave+0x66/0xc0 kernel/locking/spinlock.c:160 softirqs last enabled at (14582): [] __do_softirq+0x68b/0x9ff kernel/softirq.c:314 softirqs last disabled at (19583): [] invoke_softirq kernel/softirq.c:368 [inline] softirqs last disabled at (19583): [] irq_exit+0x193/0x240 kernel/softirq.c:409 other info that might help us debug this: Possible unsafe locking scenario: CPU0 ---- lock(&(&local->client_conns_lock)->rlock); lock(&(&local->client_conns_lock)->rlock); *** DEADLOCK *** 2 locks held by syz-executor.2/9790: #0: (&type->s_umount_key#22/1){+.+.}, at: [] alloc_super fs/super.c:251 [inline] #0: (&type->s_umount_key#22/1){+.+.}, at: [] sget_userns+0x556/0xc10 fs/super.c:516 #1: (rcu_callback){....}, at: [] __rcu_reclaim kernel/rcu/rcu.h:185 [inline] #1: (rcu_callback){....}, at: [] rcu_do_batch kernel/rcu/tree.c:2699 [inline] #1: (rcu_callback){....}, at: [] invoke_rcu_callbacks kernel/rcu/tree.c:2962 [inline] #1: (rcu_callback){....}, at: [] __rcu_process_callbacks kernel/rcu/tree.c:2929 [inline] #1: (rcu_callback){....}, at: [] rcu_process_callbacks+0x84e/0x1180 kernel/rcu/tree.c:2946 audit: type=1804 audit(1677719668.533:25): pid=9774 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.3" name="/root/syzkaller-testdir540972435/syzkaller.MJgzIG/13/file1/bus" dev="loop3" ino=4 res=1 stack backtrace: CPU: 0 PID: 9790 Comm: syz-executor.2 Not tainted 4.14.307-syzkaller #0 Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 02/16/2023 Call Trace: __dump_stack lib/dump_stack.c:17 [inline] dump_stack+0x1b2/0x281 lib/dump_stack.c:58 print_usage_bug.cold+0x42e/0x570 kernel/locking/lockdep.c:2589 valid_state kernel/locking/lockdep.c:2602 [inline] mark_lock_irq kernel/locking/lockdep.c:2796 [inline] mark_lock+0xb4d/0x1050 kernel/locking/lockdep.c:3194 mark_irqflags kernel/locking/lockdep.c:3072 [inline] __lock_acquire+0xc81/0x3f20 kernel/locking/lockdep.c:3448 REISERFS (device loop4): found reiserfs format "3.6" with non-standard journal lock_acquire+0x170/0x3f0 kernel/locking/lockdep.c:3998 REISERFS (device loop4): using ordered data mode __raw_spin_lock include/linux/spinlock_api_smp.h:142 [inline] _raw_spin_lock+0x2a/0x40 kernel/locking/spinlock.c:152 spin_lock include/linux/spinlock.h:317 [inline] rxrpc_put_one_client_conn net/rxrpc/conn_client.c:905 [inline] rxrpc_put_client_conn+0x661/0xac0 net/rxrpc/conn_client.c:957 reiserfs: using flush barriers rxrpc_put_connection net/rxrpc/ar-internal.h:862 [inline] rxrpc_rcu_destroy_call+0x83/0x190 net/rxrpc/call_object.c:653 __rcu_reclaim kernel/rcu/rcu.h:195 [inline] rcu_do_batch kernel/rcu/tree.c:2699 [inline] invoke_rcu_callbacks kernel/rcu/tree.c:2962 [inline] __rcu_process_callbacks kernel/rcu/tree.c:2929 [inline] rcu_process_callbacks+0x780/0x1180 kernel/rcu/tree.c:2946 __do_softirq+0x24d/0x9ff kernel/softirq.c:288 invoke_softirq kernel/softirq.c:368 [inline] irq_exit+0x193/0x240 kernel/softirq.c:409 exiting_irq arch/x86/include/asm/apic.h:638 [inline] smp_apic_timer_interrupt+0x141/0x5e0 arch/x86/kernel/apic/apic.c:1106 apic_timer_interrupt+0x93/0xa0 arch/x86/entry/entry_64.S:796 REISERFS (device loop4): journal params: device loop4, size 512, journal first block 18, max trans len 256, max batch 225, max commit age 30, max trans age 30 RIP: 0010:__raw_spin_unlock_irq include/linux/spinlock_api_smp.h:169 [inline] RIP: 0010:_raw_spin_unlock_irq+0x50/0x80 kernel/locking/spinlock.c:200 RSP: 0018:ffff88805dc97308 EFLAGS: 00000282 ORIG_RAX: ffffffffffffff10 RAX: 1ffffffff11e13db RBX: ffff88805dda2680 RCX: 1ffff1100bbb45e5 RDX: dffffc0000000000 RSI: ffff88805dda2f08 RDI: ffff88805dda2f04 RBP: ffff8880ba434400 R08: ffffffff8b9e3470 R09: 0000000000000000 R10: 0000000000000000 R11: 0000000000000000 R12: ffff8880ba434400 R13: ffff88805dc5a4c0 R14: ffff8880b3746000 R15: ffff8880ba434d50 finish_lock_switch kernel/sched/sched.h:1346 [inline] finish_task_switch+0x178/0x610 kernel/sched/core.c:2678 REISERFS (device loop4): checking transaction log (loop4) context_switch kernel/sched/core.c:2814 [inline] __schedule+0x893/0x1de0 kernel/sched/core.c:3386 preempt_schedule_common+0x45/0xc0 kernel/sched/core.c:3510 ___preempt_schedule+0x16/0x18 audit: type=1804 audit(1677719668.603:26): pid=9777 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="ToMToU" comm="syz-executor.3" name="/root/syzkaller-testdir540972435/syzkaller.MJgzIG/13/file1/bus" dev="loop3" ino=4 res=1 rcu_read_unlock_sched include/linux/rcupdate.h:768 [inline] percpu_ref_put_many include/linux/percpu-refcount.h:280 [inline] percpu_ref_put include/linux/percpu-refcount.h:294 [inline] blk_queue_exit+0x165/0x1d0 block/blk-core.c:810 generic_make_request block/blk-core.c:2231 [inline] generic_make_request+0x202/0x850 block/blk-core.c:2173 submit_bio+0x234/0x390 block/blk-core.c:2303 submit_bh_wbc+0x526/0x6f0 fs/buffer.c:3147 submit_bh fs/buffer.c:3153 [inline] ll_rw_block+0x151/0x190 fs/buffer.c:3203 reiserfs_breada+0x17a/0x330 fs/reiserfs/journal.c:2352 journal_read fs/reiserfs/journal.c:2455 [inline] journal_init+0x2166/0x5e30 fs/reiserfs/journal.c:2904 reiserfs_fill_super+0xa08/0x2990 fs/reiserfs/super.c:2029 mount_bdev+0x2b3/0x360 fs/super.c:1134 mount_fs+0x92/0x2a0 fs/super.c:1237 vfs_kern_mount.part.0+0x5b/0x470 fs/namespace.c:1046 vfs_kern_mount fs/namespace.c:1036 [inline] do_new_mount fs/namespace.c:2572 [inline] do_mount+0xe65/0x2a30 fs/namespace.c:2905 REISERFS (device loop4): Using r5 hash to sort names SYSC_mount fs/namespace.c:3121 [inline] SyS_mount+0xa8/0x120 fs/namespace.c:3098 REISERFS (device loop4): Created .reiserfs_priv - reserved for xattr storage. do_syscall_64+0x1d5/0x640 arch/x86/entry/common.c:292 entry_SYSCALL_64_after_hwframe+0x5e/0xd3 RIP: 0033:0x7fbaefc1062a RSP: 002b:00007fbaee180f88 EFLAGS: 00000202 ORIG_RAX: 00000000000000a5 RAX: ffffffffffffffda RBX: 0000000000001101 RCX: 00007fbaefc1062a RDX: 0000000020001100 RSI: 00000000200001c0 RDI: 00007fbaee180fe0 netlink: 40 bytes leftover after parsing attributes in process `syz-executor.1'. RBP: 00007fbaee181020 R08: 00007fbaee181020 R09: 0000000000208088 R10: 0000000000208088 R11: 0000000000000202 R12: 0000000020001100 R13: 00000000200001c0 R14: 00007fbaee180fe0 R15: 0000000020000240 REISERFS (device loop3): journal params: device loop3, size 512, journal first block 18, max trans len 256, max batch 225, max commit age 30, max trans age 30 REISERFS (device loop3): checking transaction log (loop3) REISERFS (device loop3): Using r5 hash to sort names REISERFS (device loop3): Created .reiserfs_priv - reserved for xattr storage. netlink: 40 bytes leftover after parsing attributes in process `syz-executor.1'. netlink: 40 bytes leftover after parsing attributes in process `syz-executor.1'. REISERFS (device loop2): Using r5 hash to sort names REISERFS (device loop2): Created .reiserfs_priv - reserved for xattr storage. REISERFS (device loop4): found reiserfs format "3.6" with non-standard journal REISERFS (device loop4): using ordered data mode reiserfs: using flush barriers REISERFS (device loop4): journal params: device loop4, size 512, journal first block 18, max trans len 256, max batch 225, max commit age 30, max trans age 30 REISERFS (device loop4): checking transaction log (loop4) REISERFS (device loop4): Using r5 hash to sort names REISERFS (device loop4): Created .reiserfs_priv - reserved for xattr storage. netlink: 40 bytes leftover after parsing attributes in process `syz-executor.1'. REISERFS (device loop3): found reiserfs format "3.6" with non-standard journal REISERFS (device loop3): using ordered data mode reiserfs: using flush barriers REISERFS (device loop3): journal params: device loop3, size 512, journal first block 18, max trans len 256, max batch 225, max commit age 30, max trans age 30 netlink: 40 bytes leftover after parsing attributes in process `syz-executor.1'. REISERFS (device loop3): checking transaction log (loop3) netlink: 40 bytes leftover after parsing attributes in process `syz-executor.1'. netlink: 40 bytes leftover after parsing attributes in process `syz-executor.1'. kvm: vcpu 0: requested 128 ns lapic timer period limited to 500000 ns REISERFS (device loop3): Using r5 hash to sort names REISERFS (device loop3): Created .reiserfs_priv - reserved for xattr storage. REISERFS (device loop2): found reiserfs format "3.6" with non-standard journal REISERFS (device loop2): using ordered data mode reiserfs: using flush barriers REISERFS (device loop2): journal params: device loop2, size 512, journal first block 18, max trans len 256, max batch 225, max commit age 30, max trans age 30 REISERFS (device loop2): checking transaction log (loop2) device gretap1 entered promiscuous mode REISERFS (device loop2): Using r5 hash to sort names REISERFS (device loop2): Created .reiserfs_priv - reserved for xattr storage. kvm: vcpu 0: requested 128 ns lapic timer period limited to 500000 ns kvm: vcpu 0: requested 128 ns lapic timer period limited to 500000 ns UDF-fs: INFO Mounting volume 'LinuxUDF', timestamp 2022/11/22 14:59 (1000) UDF-fs: INFO Mounting volume 'LinuxUDF', timestamp 2022/11/22 14:59 (1000) UDF-fs: INFO Mounting volume 'LinuxUDF', timestamp 2022/11/22 14:59 (1000) device gretap1 entered promiscuous mode kvm: vcpu 0: requested 128 ns lapic timer period limited to 500000 ns kvm: vcpu 0: requested 128 ns lapic timer period limited to 500000 ns device gretap1 entered promiscuous mode kvm: vcpu 0: requested 128 ns lapic timer period limited to 500000 ns kvm: vcpu 0: requested 128 ns lapic timer period limited to 500000 ns sctp: [Deprecated]: syz-executor.2 (pid 10117) Use of int in max_burst socket option. Use struct sctp_assoc_value instead sctp: [Deprecated]: syz-executor.2 (pid 10121) Use of int in max_burst socket option. Use struct sctp_assoc_value instead sctp: [Deprecated]: syz-executor.2 (pid 10133) Use of int in max_burst socket option. Use struct sctp_assoc_value instead sctp: [Deprecated]: syz-executor.2 (pid 10137) Use of int in max_burst socket option. Use struct sctp_assoc_value instead batman_adv: Cannot find parent device device gretap1 entered promiscuous mode gfs2: fsid=syz:syz: Trying to join cluster "lock_nolock", "syz:syz" gfs2: fsid=syz:syz: Now mounting FS... gfs2: fsid=syz:syz.0: journal 0 mapped with 8 extents gfs2: fsid=syz:syz.0: jid=0, already locked for use gfs2: fsid=syz:syz.0: jid=0: Looking at journal... gfs2: fsid=syz:syz.0: jid=0: Done gfs2: fsid=syz:syz.0: first mount done, others may mount overlayfs: fs on 'file0' does not support file handles, falling back to index=off. overlayfs: fs on './file0' does not support file handles, falling back to index=off. gfs2: fsid=syz:syz: Trying to join cluster "lock_nolock", "syz:syz" gfs2: fsid=syz:syz: Now mounting FS... gfs2: fsid=syz:syz.0: journal 0 mapped with 8 extents gfs2: fsid=syz:syz.0: jid=0, already locked for use gfs2: fsid=syz:syz.0: jid=0: Looking at journal... gfs2: fsid=syz:syz.0: jid=0: Done gfs2: fsid=syz:syz.0: first mount done, others may mount netlink: 16 bytes leftover after parsing attributes in process `syz-executor.1'. PF_BRIDGE: br_mdb_parse() with invalid attr overlayfs: fs on 'file0' does not support file handles, falling back to index=off. overlayfs: fs on 'file0' does not support file handles, falling back to index=off. overlayfs: fs on './file0' does not support file handles, falling back to index=off. overlayfs: fs on './file0' does not support file handles, falling back to index=off. gfs2: fsid=syz:syz: Trying to join cluster "lock_nolock", "syz:syz" gfs2: fsid=syz:syz: Now mounting FS... gfs2: fsid=syz:syz.0: journal 0 mapped with 8 extents gfs2: fsid=syz:syz.0: jid=0, already locked for use gfs2: fsid=syz:syz.0: jid=0: Looking at journal... gfs2: fsid=syz:syz.0: jid=0: Done gfs2: fsid=syz:syz.0: first mount done, others may mount overlayfs: fs on 'file0' does not support file handles, falling back to index=off. overlayfs: fs on 'file0' does not support file handles, falling back to index=off. netlink: 16 bytes leftover after parsing attributes in process `syz-executor.1'. PF_BRIDGE: br_mdb_parse() with invalid attr overlayfs: fs on 'file0' does not support file handles, falling back to index=off. overlayfs: fs on 'file0' does not support file handles, falling back to index=off. overlayfs: fs on './file0' does not support file handles, falling back to index=off. overlayfs: fs on './file0' does not support file handles, falling back to index=off. overlayfs: fs on './file0' does not support file handles, falling back to index=off. overlayfs: fs on './file0' does not support file handles, falling back to index=off. overlayfs: fs on 'file0' does not support file handles, falling back to index=off. overlayfs: fs on 'file0' does not support file handles, falling back to index=off. overlayfs: fs on 'file0' does not support file handles, falling back to index=off. overlayfs: fs on './file0' does not support file handles, falling back to index=off. overlayfs: fs on 'file0' does not support file handles, falling back to index=off. overlayfs: fs on './file0' does not support file handles, falling back to index=off. gfs2: fsid=syz:syz: Trying to join cluster "lock_nolock", "syz:syz" overlayfs: fs on './file0' does not support file handles, falling back to index=off. overlayfs: fs on './file0' does not support file handles, falling back to index=off. gfs2: fsid=syz:syz: Now mounting FS... gfs2: fsid=syz:syz.0: journal 0 mapped with 8 extents gfs2: fsid=syz:syz.0: jid=0, already locked for use gfs2: fsid=syz:syz.0: jid=0: Looking at journal... netlink: 16 bytes leftover after parsing attributes in process `syz-executor.1'. PF_BRIDGE: br_mdb_parse() with invalid attr gfs2: fsid=syz:syz.0: jid=0: Done gfs2: fsid=syz:syz.0: first mount done, others may mount overlayfs: fs on 'file0' does not support file handles, falling back to index=off. netlink: 16 bytes leftover after parsing attributes in process `syz-executor.0'. PF_BRIDGE: br_mdb_parse() with invalid attr overlayfs: fs on './file0' does not support file handles, falling back to index=off. overlayfs: fs on 'file0' does not support file handles, falling back to index=off. overlayfs: fs on 'file0' does not support file handles, falling back to index=off. overlayfs: fs on './file0' does not support file handles, falling back to index=off. overlayfs: fs on './file0' does not support file handles, falling back to index=off. netlink: 16 bytes leftover after parsing attributes in process `syz-executor.1'. PF_BRIDGE: br_mdb_parse() with invalid attr