./strace-static-x86_64 -e \!wait4,clock_nanosleep,nanosleep -s 100 -x -f ./syz-executor1310598091

<...>
Warning: Permanently added '10.128.0.76' (ED25519) to the list of known hosts.
execve("./syz-executor1310598091", ["./syz-executor1310598091"], 0x7fffb6b28560 /* 10 vars */) = 0
brk(NULL)                               = 0x5555884f8000
brk(0x5555884f8d00)                     = 0x5555884f8d00
arch_prctl(ARCH_SET_FS, 0x5555884f8380) = 0
set_tid_address(0x5555884f8650)         = 5828
set_robust_list(0x5555884f8660, 24)     = 0
rseq(0x5555884f8ca0, 0x20, 0, 0x53053053) = 0
prlimit64(0, RLIMIT_STACK, NULL, {rlim_cur=8192*1024, rlim_max=RLIM64_INFINITY}) = 0
readlink("/proc/self/exe", "/root/syz-executor1310598091", 4096) = 28
getrandom("\x23\xb0\x45\x6f\x2a\x2a\x5f\x8b", 8, GRND_NONBLOCK) = 8
brk(NULL)                               = 0x5555884f8d00
brk(0x555588519d00)                     = 0x555588519d00
brk(0x55558851a000)                     = 0x55558851a000
mprotect(0x7fe46dd8b000, 16384, PROT_READ) = 0
mmap(0x1ffff000, 4096, PROT_NONE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x1ffff000
mmap(0x20000000, 16777216, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x20000000
mmap(0x21000000, 4096, PROT_NONE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x21000000
unshare(CLONE_NEWPID)                   = 0
clone(child_stack=NULL, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD./strace-static-x86_64: Process 5829 attached
 <unfinished ...>
[pid  5829] set_robust_list(0x5555884f8660, 24 <unfinished ...>
[pid  5828] <... clone resumed>, child_tidptr=0x5555884f8650) = 5829
[pid  5829] <... set_robust_list resumed>) = 0
[pid  5829] prctl(PR_SET_PDEATHSIG, SIGKILL) = 0
[pid  5829] getppid()                   = 0
[pid  5829] prlimit64(0, RLIMIT_AS, {rlim_cur=204800*1024, rlim_max=204800*1024}, NULL) = 0
[pid  5829] prlimit64(0, RLIMIT_MEMLOCK, {rlim_cur=32768*1024, rlim_max=32768*1024}, NULL) = 0
[pid  5829] prlimit64(0, RLIMIT_FSIZE, {rlim_cur=139264*1024, rlim_max=139264*1024}, NULL) = 0
[pid  5829] prlimit64(0, RLIMIT_STACK, {rlim_cur=1024*1024, rlim_max=1024*1024}, NULL) = 0
[pid  5829] prlimit64(0, RLIMIT_CORE, {rlim_cur=131072*1024, rlim_max=131072*1024}, NULL) = 0
[pid  5829] prlimit64(0, RLIMIT_NOFILE, {rlim_cur=256, rlim_max=256}, NULL) = 0
[pid  5829] unshare(CLONE_NEWNS)        = 0
[pid  5829] mount(NULL, "/", NULL, MS_REC|MS_PRIVATE, NULL) = 0
[pid  5829] unshare(CLONE_NEWIPC)       = 0
[pid  5829] unshare(CLONE_NEWCGROUP)    = 0
[pid  5829] unshare(CLONE_NEWUTS)       = 0
[pid  5829] unshare(CLONE_SYSVSEM)      = 0
[pid  5829] openat(AT_FDCWD, "/proc/sys/kernel/shmmax", O_WRONLY|O_CLOEXEC) = 3
[pid  5829] write(3, "16777216", 8)     = 8
[pid  5829] close(3)                    = 0
[pid  5829] openat(AT_FDCWD, "/proc/sys/kernel/shmall", O_WRONLY|O_CLOEXEC) = 3
[pid  5829] write(3, "536870912", 9)    = 9
[pid  5829] close(3)                    = 0
[pid  5829] openat(AT_FDCWD, "/proc/sys/kernel/shmmni", O_WRONLY|O_CLOEXEC) = 3
[pid  5829] write(3, "1024", 4)         = 4
[pid  5829] close(3)                    = 0
[pid  5829] openat(AT_FDCWD, "/proc/sys/kernel/msgmax", O_WRONLY|O_CLOEXEC) = 3
[pid  5829] write(3, "8192", 4)         = 4
[pid  5829] close(3)                    = 0
[pid  5829] openat(AT_FDCWD, "/proc/sys/kernel/msgmni", O_WRONLY|O_CLOEXEC) = 3
[pid  5829] write(3, "1024", 4)         = 4
[pid  5829] close(3)                    = 0
[pid  5829] openat(AT_FDCWD, "/proc/sys/kernel/msgmnb", O_WRONLY|O_CLOEXEC) = 3
[pid  5829] write(3, "1024", 4)         = 4
[pid  5829] close(3)                    = 0
[pid  5829] openat(AT_FDCWD, "/proc/sys/kernel/sem", O_WRONLY|O_CLOEXEC) = 3
[pid  5829] write(3, "1024 1048576 500 1024", 21) = 21
[pid  5829] close(3)                    = 0
[pid  5829] getpid()                    = 1
[pid  5829] capget({version=_LINUX_CAPABILITY_VERSION_3, pid=1}, {effective=1<<CAP_CHOWN|1<<CAP_DAC_OVERRIDE|1<<CAP_DAC_READ_SEARCH|1<<CAP_FOWNER|1<<CAP_FSETID|1<<CAP_KILL|1<<CAP_SETGID|1<<CAP_SETUID|1<<CAP_SETPCAP|1<<CAP_LINUX_IMMUTABLE|1<<CAP_NET_BIND_SERVICE|1<<CAP_NET_BROADCAST|1<<CAP_NET_ADMIN|1<<CAP_NET_RAW|1<<CAP_IPC_LOCK|1<<CAP_IPC_OWNER|1<<CAP_SYS_MODULE|1<<CAP_SYS_RAWIO|1<<CAP_SYS_CHROOT|1<<CAP_SYS_PTRACE|1<<CAP_SYS_PACCT|1<<CAP_SYS_ADMIN|1<<CAP_SYS_BOOT|1<<CAP_SYS_NICE|1<<CAP_SYS_RESOURCE|1<<CAP_SYS_TIME|1<<CAP_SYS_TTY_CONFIG|1<<CAP_MKNOD|1<<CAP_LEASE|1<<CAP_AUDIT_WRITE|1<<CAP_AUDIT_CONTROL|1<<CAP_SETFCAP|1<<CAP_MAC_OVERRIDE|1<<CAP_MAC_ADMIN|1<<CAP_SYSLOG|1<<CAP_WAKE_ALARM|1<<CAP_BLOCK_SUSPEND|1<<CAP_AUDIT_READ|1<<CAP_PERFMON|1<<CAP_BPF|1<<CAP_CHECKPOINT_RESTORE, permitted=1<<CAP_CHOWN|1<<CAP_DAC_OVERRIDE|1<<CAP_DAC_READ_SEARCH|1<<CAP_FOWNER|1<<CAP_FSETID|1<<CAP_KILL|1<<CAP_SETGID|1<<CAP_SETUID|1<<CAP_SETPCAP|1<<CAP_LINUX_IMMUTABLE|1<<CAP_NET_BIND_SERVICE|1<<CAP_NET_BROADCAST|1<<CAP_NET_ADMIN|1<<CAP_NET_RAW|1<<CAP_IPC_LOCK|1<<CAP_IPC_OWNER|1<<CAP_SYS_MODULE|1<<CAP_SYS_RAWIO|1<<CAP_SYS_CHROOT|1<<CAP_SYS_PTRACE|1<<CAP_SYS_PACCT|1<<CAP_SYS_ADMIN|1<<CAP_SYS_BOOT|1<<CAP_SYS_NICE|1<<CAP_SYS_RESOURCE|1<<CAP_SYS_TIME|1<<CAP_SYS_TTY_CONFIG|1<<CAP_MKNOD|1<<CAP_LEASE|1<<CAP_AUDIT_WRITE|1<<CAP_AUDIT_CONTROL|1<<CAP_SETFCAP|1<<CAP_MAC_OVERRIDE|1<<CAP_MAC_ADMIN|1<<CAP_SYSLOG|1<<CAP_WAKE_ALARM|1<<CAP_BLOCK_SUSPEND|1<<CAP_AUDIT_READ|1<<CAP_PERFMON|1<<CAP_BPF|1<<CAP_CHECKPOINT_RESTORE, inheritable=0}) = 0
[pid  5829] capset({version=_LINUX_CAPABILITY_VERSION_3, pid=1}, {effective=1<<CAP_CHOWN|1<<CAP_DAC_OVERRIDE|1<<CAP_DAC_READ_SEARCH|1<<CAP_FOWNER|1<<CAP_FSETID|1<<CAP_KILL|1<<CAP_SETGID|1<<CAP_SETUID|1<<CAP_SETPCAP|1<<CAP_LINUX_IMMUTABLE|1<<CAP_NET_BIND_SERVICE|1<<CAP_NET_BROADCAST|1<<CAP_NET_ADMIN|1<<CAP_NET_RAW|1<<CAP_IPC_LOCK|1<<CAP_IPC_OWNER|1<<CAP_SYS_MODULE|1<<CAP_SYS_RAWIO|1<<CAP_SYS_CHROOT|1<<CAP_SYS_PACCT|1<<CAP_SYS_ADMIN|1<<CAP_SYS_BOOT|1<<CAP_SYS_RESOURCE|1<<CAP_SYS_TIME|1<<CAP_SYS_TTY_CONFIG|1<<CAP_MKNOD|1<<CAP_LEASE|1<<CAP_AUDIT_WRITE|1<<CAP_AUDIT_CONTROL|1<<CAP_SETFCAP|1<<CAP_MAC_OVERRIDE|1<<CAP_MAC_ADMIN|1<<CAP_SYSLOG|1<<CAP_WAKE_ALARM|1<<CAP_BLOCK_SUSPEND|1<<CAP_AUDIT_READ|1<<CAP_PERFMON|1<<CAP_BPF|1<<CAP_CHECKPOINT_RESTORE, permitted=1<<CAP_CHOWN|1<<CAP_DAC_OVERRIDE|1<<CAP_DAC_READ_SEARCH|1<<CAP_FOWNER|1<<CAP_FSETID|1<<CAP_KILL|1<<CAP_SETGID|1<<CAP_SETUID|1<<CAP_SETPCAP|1<<CAP_LINUX_IMMUTABLE|1<<CAP_NET_BIND_SERVICE|1<<CAP_NET_BROADCAST|1<<CAP_NET_ADMIN|1<<CAP_NET_RAW|1<<CAP_IPC_LOCK|1<<CAP_IPC_OWNER|1<<CAP_SYS_MODULE|1<<CAP_SYS_RAWIO|1<<CAP_SYS_CHROOT|1<<CAP_SYS_PACCT|1<<CAP_SYS_ADMIN|1<<CAP_SYS_BOOT|1<<CAP_SYS_RESOURCE|1<<CAP_SYS_TIME|1<<CAP_SYS_TTY_CONFIG|1<<CAP_MKNOD|1<<CAP_LEASE|1<<CAP_AUDIT_WRITE|1<<CAP_AUDIT_CONTROL|1<<CAP_SETFCAP|1<<CAP_MAC_OVERRIDE|1<<CAP_MAC_ADMIN|1<<CAP_SYSLOG|1<<CAP_WAKE_ALARM|1<<CAP_BLOCK_SUSPEND|1<<CAP_AUDIT_READ|1<<CAP_PERFMON|1<<CAP_BPF|1<<CAP_CHECKPOINT_RESTORE, inheritable=0}) = 0
[pid  5829] unshare(CLONE_NEWNET)       = 0
[pid  5829] openat(AT_FDCWD, "/proc/sys/net/ipv4/ping_group_range", O_WRONLY|O_CLOEXEC) = 3
[pid  5829] write(3, "0 65535", 7)      = 7
[pid  5829] close(3)                    = 0
[pid  5829] openat(AT_FDCWD, "/proc/sys/fs/mount-max", O_WRONLY|O_CLOEXEC) = 3
[pid  5829] write(3, "100000", 6)       = 6
[pid  5829] close(3)                    = 0
[pid  5829] mkdir("./syz-tmp", 0777)    = 0
[pid  5829] mount("", "./syz-tmp", "tmpfs", 0, NULL) = 0
[pid  5829] mkdir("./syz-tmp/newroot", 0777) = 0
[pid  5829] mkdir("./syz-tmp/newroot/dev", 0700) = 0
[pid  5829] mount("/dev", "./syz-tmp/newroot/dev", NULL, MS_BIND|MS_REC|MS_PRIVATE, NULL) = 0
[pid  5829] mkdir("./syz-tmp/newroot/proc", 0700) = 0
[pid  5829] mount("syz-proc", "./syz-tmp/newroot/proc", "proc", 0, NULL) = 0
[pid  5829] mkdir("./syz-tmp/newroot/selinux", 0700) = 0
[pid  5829] mount("/selinux", "./syz-tmp/newroot/selinux", NULL, MS_BIND|MS_REC|MS_PRIVATE, NULL) = -1 ENOENT (No such file or directory)
[pid  5829] mount("/sys/fs/selinux", "./syz-tmp/newroot/selinux", NULL, MS_BIND|MS_REC|MS_PRIVATE, NULL) = -1 ENOENT (No such file or directory)
[pid  5829] mkdir("./syz-tmp/newroot/sys", 0700) = 0
[pid  5829] mount("/sys", "./syz-tmp/newroot/sys", NULL, MS_BIND|MS_REC|MS_PRIVATE, NULL) = 0
[pid  5829] mount("/sys/kernel/debug", "./syz-tmp/newroot/sys/kernel/debug", NULL, MS_BIND|MS_REC|MS_PRIVATE, NULL) = 0
[pid  5829] mount("/sys/fs/smackfs", "./syz-tmp/newroot/sys/fs/smackfs", NULL, MS_BIND|MS_REC|MS_PRIVATE, NULL) = -1 ENOENT (No such file or directory)
[pid  5829] mount("/proc/sys/fs/binfmt_misc", "./syz-tmp/newroot/proc/sys/fs/binfmt_misc", NULL, MS_BIND|MS_REC|MS_PRIVATE, NULL) = 0
[pid  5829] mkdir("./syz-tmp/pivot", 0777) = 0
[pid  5829] pivot_root("./syz-tmp", "./syz-tmp/pivot") = 0
[pid  5829] chdir("/")                  = 0
[pid  5829] umount2("./pivot", MNT_DETACH) = 0
[pid  5829] chroot("./newroot")         = 0
[pid  5829] chdir("/")                  = 0
[pid  5829] mkdir("/dev/binderfs", 0777) = 0
[pid  5829] mount("binder", "/dev/binderfs", "binder", 0, NULL) = 0
[pid  5829] symlink("/dev/binderfs", "./binderfs") = 0
[pid  5829] mount(NULL, "/sys/fs/fuse/connections", "fusectl", 0, NULL) = -1 EBUSY (Device or resource busy)
[pid  5829] openat(AT_FDCWD, "/dev/loop0", O_RDWR) = 3
[pid  5829] ioctl(3, LOOP_CLR_FD)       = -1 ENXIO (No such device or address)
[pid  5829] close(3)                    = 0
[pid  5829] clone(child_stack=NULL, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD./strace-static-x86_64: Process 5832 attached
, child_tidptr=0x5555884f8650) = 2
[pid  5832] set_robust_list(0x5555884f8660, 24) = 0
[pid  5832] prctl(PR_SET_PDEATHSIG, SIGKILL) = 0
[pid  5832] setpgid(0, 0)               = 0
[pid  5832] openat(AT_FDCWD, "/proc/self/oom_score_adj", O_WRONLY|O_CLOEXEC) = 3
[pid  5832] write(3, "1000", 4)         = 4
[pid  5832] close(3)                    = 0
executing program
[pid  5832] write(1, "executing program\n", 18) = 18
[pid  5832] memfd_create("syzkaller", 0) = 3
[pid  5832] mmap(NULL, 138412032, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fe465800000
[pid  5832] write(3, "\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00"..., 16777216) = 16777216
[pid  5832] munmap(0x7fe465800000, 138412032) = 0
[pid  5832] openat(AT_FDCWD, "/dev/loop0", O_RDWR) = 4
[pid  5832] ioctl(4, LOOP_SET_FD, 3)    = 0
[pid  5832] close(3)                    = 0
[pid  5832] close(4)                    = 0
[pid  5832] mkdir("./file0", 0777)      = 0
[   58.577555][ T5832] loop0: detected capacity change from 0 to 32768
[   58.649898][ T5832] bcachefs (loop0): starting version 1.7: mi_btree_bitmap opts=metadata_checksum=none,data_checksum=none,compression=lz4,usrquota,grpquota,fsck,fix_errors=yes,nojournal_transaction_names,no_data_io
[   58.670127][ T5832] invalid bkey u64s 11 type btree_ptr_v2 SPOS_MAX len 0 ver 0: seq 28f61e078e70b95c written 16 min_key POS_MIN durability: 1 ptr: 0:28:0 gen 0
[   58.670146][ T5832]   nonzero snapshot: delete?, fixing
[   58.690185][ T5832] bcachefs (loop0): recovering from clean shutdown, journal seq 10
[   58.698274][ T5832] bcachefs (loop0): Version upgrade required:
[   58.698274][ T5832] Version upgrade from 0.128: (unknown version) to 1.7: mi_btree_bitmap incomplete
[   58.698274][ T5832] Doing incompatible version upgrade from 0.128: (unknown version) to 1.13: inode_has_child_snapshots
[   58.698274][ T5832]   running recovery passes: check_allocations,check_snapshots,check_subvols,check_inodes,check_dirents,set_fs_needs_rebalance
[   58.743625][ T5832] invalid bkey u64s 17 type inode_v3 0:4097:U32_MAX len 0 ver 0: (unpack error)
[   58.743652][ T5832]   invalid variable length fields: delete?, fixing
[   58.762262][ T5832] bcachefs (loop0): error validating btree node at btree alloc level 0/0
[   58.762275][ T5832]   u64s 11 type btree_ptr_v2 SPOS_MAX len 0 ver 0: seq ac62141f8dc7e261 written 24 min_key POS_MIN durability: 1 ptr: 0:26:0 gen 0  
[   58.762283][ T5832]   node offset 8/24 bset u64s 375 bset byte offset 184: keys out of order: u64s 11 type alloc_v4 0:32:0 len 0 ver 0 > u64s 11 type alloc_v4 0:2:0 len 0 ver 0, fixing
[   58.801940][ T5832] invalid bkey u64s 12 type alloc_v4 0:28:0 len 0 ver 0: 
[   58.801952][ T5832]   gen 0 oldest_gen 0 data_type btree
[   58.801958][ T5832]   journal_seq       6
[   58.801963][ T5832]   need_discard      1
[   58.801968][ T5832]   need_inc_gen      1
[   58.801974][ T5832]   dirty_sectors     0
[   58.801979][ T5832]   stripe_sectors    0
[   58.801984][ T5832]   cached_sectors    0
[   58.801989][ T5832]   stripe            0
[   58.801994][ T5832]   stripe_redundancy 0
[   58.801999][ T5832]   io_time[READ]     1
[   58.802004][ T5832]   io_time[WRITE]    768
[   58.802009][ T5832]   fragmentation     0
[   58.802014][ T5832]   bp_start          8
[   58.802019][ T5832] 
[   58.802024][ T5832]   invalid data type (got 3 should be 9): delete?, fixing
[   58.874438][ T5832] bcachefs (loop0): btree_node_read_work: rewriting btree node at due to error
[   58.874438][ T5832]   btree=alloc level=0 u64s 11 type btree_ptr_v2 SPOS_MAX len 0 ver 0: seq ac62141f8dc7e261 written 24 min_key POS_MIN durability: 1 ptr: 0:26:0 gen 0
[   58.900210][ T5832] bcachefs (loop0): error validating btree node on loop0 at btree snapshots level 0/0
[   58.900227][ T5832]   u64s 11 type btree_ptr_v2 SPOS_MAX len 0 ver 0: seq ebb8d5a9e3463bdb written 16 min_key POS_MIN durability: 1 ptr: 0:32:0 gen 0  
[   58.900235][ T5832]   node offset 0/16: got wrong btree node: got
[   58.900240][ T5832]   btree=snapshots level=0 seq 50817571109851x
[   58.900246][ T5832]   min: POS_MIN
[   58.900251][ T5832]   max: SPOS_MAX
[   58.943695][ T5832] bcachefs (loop0): flagging btree snapshots lost data
[   58.950665][ T5832] bcachefs (loop0): running explicit recovery pass scan_for_btree_nodes (1), currently at recovery_pass_empty (0)
[   58.965243][ T5832] error reading btree root btree=snapshots level=0: btree_node_read_error, fixing
[   58.978698][ T5832] bcachefs (loop0): scan_for_btree_nodes...
[   58.997943][ T5832] bch2_scan_for_btree_nodes: nodes found after overwrites:
[   58.997962][ T5832]   btree=extents level=0 seq=1 journal_seq=5 cookie=c6c25c03258c59c5 POS_MIN-SPOS_MAX ptr: 0:27:0 gen 0
[   58.997970][ T5832]   btree=inodes level=0 seq=1 journal_seq=5 cookie=7589ab5e0c11cc7a POS_MIN-SPOS_MAX ptr: 0:38:0 gen 0
[   58.997976][ T5832]   btree=dirents level=0 seq=1 journal_seq=4 cookie=9aa2895aefce4bdf POS_MIN-SPOS_MAX ptr: 0:41:0 gen 0
[   58.997982][ T5832]   btree=xattrs level=0 seq=1 journal_seq=4 cookie=2285c34bed0abe32 POS_MIN-SPOS_MAX ptr: 0:31:0 gen 0
[   58.997989][ T5832]   btree=subvolumes level=0 seq=1 journal_seq=1 cookie=c0bef60d07ceb940 POS_MIN-SPOS_MAX ptr: 0:35:0 gen 0
[   58.997995][ T5832]   btree=snapshots level=0 seq=1 journal_seq=0 cookie=2e37e3463bdb POS_MIN-SPOS_MAX ptr: 0:32:0 gen 0
[   58.998002][ T5832]   btree=deleted_inodes level=0 seq=1 journal_seq=0 cookie=1db8f60c84bb244c POS_MIN-SPOS_MAX ptr: 0:42:0 gen 0
[   58.998008][ T5832] 
[   59.092724][ T5832]  done
[   59.096360][ T5832] bcachefs (loop0): check_topology...
[   59.096573][ T5832] bcachefs (loop0): btree root extentsinodesdirentsxattrsallocquotasstripesreflinksubvolumessnapshots unreadable, must recover from scan
[   59.116168][ T5832] bcachefs (loop0): bch2_get_scanned_nodes(): recovery btree=snapshots level=0 POS_MIN - SPOS_MAX
[   59.126907][ T5832] bcachefs (loop0): bch2_get_scanned_nodes(): recovering u64s 11 type btree_ptr_v2 SPOS_MAX len 0 ver 0: seq 2e37e3463bdb written 8 min_key POS_MIN durability: 1 ptr: 0:32:0 gen 0
[   59.147552][ T5832]  done
[   59.151107][ T5832] bcachefs (loop0): accounting_read... done
[   59.158118][ T5832] bcachefs (loop0): alloc_read... done
[   59.163681][ T5832] bcachefs (loop0): stripes_read... done
[   59.169351][ T5832] bcachefs (loop0): snapshots_read...
[   59.170283][ T5832] bcachefs (loop0): running explicit recovery pass reconstruct_snapshots (21), currently at snapshots_read (7)
[   59.187508][ T5832]  done
[   59.190279][ T5832] bcachefs (loop0): check_allocations...
[   59.193803][ T5832] bucket 0:26 data type btree ptr gen 0 missing in alloc btree
[   59.193820][ T5832] while marking u64s 11 type btree_ptr_v2 SPOS_MAX len 0 ver 0: seq ac62141f8dc7e261 written 24 min_key POS_MIN durability: 1 ptr: 0:26:0 gen 0, fixing
[   59.224242][ T5832] bucket 0:38 data type btree ptr gen 0 missing in alloc btree
[   59.224256][ T5832] while marking u64s 11 type btree_ptr_v2 SPOS_MAX len 0 ver 0: seq 7589ab5e0c11cc7a written 24 min_key POS_MIN durability: 1 ptr: 0:38:0 gen 0, fixing
[   59.248418][ T5832] bucket 0:41 data type btree ptr gen 0 missing in alloc btree
[   59.248431][ T5832] while marking u64s 11 type btree_ptr_v2 SPOS_MAX len 0 ver 0: seq 9aa2895aefce4bdf written 24 min_key POS_MIN durability: 1 ptr: 0:41:0 gen 0, fixing
[   59.272942][ T5832] bucket 0:35 data type btree ptr gen 0 missing in alloc btree
[   59.272954][ T5832] while marking u64s 11 type btree_ptr_v2 SPOS_MAX len 0 ver 0: seq c0bef60d07ceb940 written 16 min_key POS_MIN durability: 1 ptr: 0:35:0 gen 0, fixing
[   59.298621][ T5832] bucket 0:29 data type btree ptr gen 0 missing in alloc btree
[   59.298634][ T5832] while marking u64s 11 type btree_ptr_v2 SPOS_MAX len 0 ver 0: seq e81e1ed936acf3df written 32 min_key POS_MIN durability: 1 ptr: 0:29:0 gen 0, fixing
[   59.322364][ T5832] bucket 0:1 gen 0 has wrong data_type: got free, should be sb, fixing
[   59.330953][ T5832] bucket 0:1 gen 0 data type sb has wrong dirty_sectors: got 0, should be 256, fixing
[   59.341683][ T5832] bucket 0:2 gen 0 has wrong data_type: got free, should be sb, fixing
[   59.350128][ T5832] bucket 0:2 gen 0 data type sb has wrong dirty_sectors: got 0, should be 256, fixing
[   59.359894][ T5832] bucket 0:3 gen 0 has wrong data_type: got free, should be sb, fixing
[   59.368242][ T5832] bucket 0:3 gen 0 data type sb has wrong dirty_sectors: got 0, should be 256, fixing
[   59.378315][ T5832] bucket 0:4 gen 0 has wrong data_type: got free, should be sb, fixing
[   59.386678][ T5832] bucket 0:4 gen 0 data type sb has wrong dirty_sectors: got 0, should be 256, fixing
[   59.396392][ T5832] bucket 0:5 gen 0 has wrong data_type: got free, should be sb, fixing
[   59.404750][ T5832] bucket 0:5 gen 0 data type sb has wrong dirty_sectors: got 0, should be 256, fixing
[   59.414458][ T5832] bucket 0:6 gen 0 has wrong data_type: got free, should be sb, fixing
[   59.422742][ T5832] bucket 0:6 gen 0 data type sb has wrong dirty_sectors: got 0, should be 256, fixing
[   59.432548][ T5832] bucket 0:7 gen 0 has wrong data_type: got free, should be sb, fixing
[   59.440874][ T5832] bucket 0:7 gen 0 data type sb has wrong dirty_sectors: got 0, should be 256, fixing
[   59.450657][ T5832] bucket 0:8 gen 0 has wrong data_type: got free, should be sb, fixing
[   59.458971][ T5832] bucket 0:8 gen 0 data type sb has wrong dirty_sectors: got 0, should be 8, fixing
[   59.468573][ T5832] bucket 0:9 gen 0 has wrong data_type: got free, should be journal, fixing
[   59.477324][ T5832] bucket 0:9 gen 0 data type journal has wrong dirty_sectors: got 0, should be 256, fixing
[   59.487556][ T5832] bucket 0:10 gen 0 has wrong data_type: got free, should be journal, fixing
[   59.496425][ T5832] bucket 0:10 gen 0 data type journal has wrong dirty_sectors: got 0, should be 256, fixing
[   59.506755][ T5832] bucket 0:11 gen 0 has wrong data_type: got free, should be journal, fixing
[   59.515585][ T5832] bcachefs (loop0): Ratelimiting new instances of previous error
[   59.523407][ T5832] bucket 0:11 gen 0 data type journal has wrong dirty_sectors: got 0, should be 256, fixing
[   59.533593][ T5832] bcachefs (loop0): Ratelimiting new instances of previous error
[   59.547064][ T5832]  done
[   59.551408][ T5832] bcachefs (loop0): going read-write
[   59.558452][ T5832] bcachefs (loop0): journal_replay...
[   59.562978][ T5832] u64s 13 type alloc_v4 0:21:0 len 0 ver 0: 
[   59.562996][ T5832]   gen 0 oldest_gen 0 data_type sb
[   59.563002][ T5832]   journal_seq       0
[   59.563007][ T5832]   need_discard      0
[   59.563013][ T5832]   need_inc_gen      0
[   59.563018][ T5832]   dirty_sectors     256
[   59.563024][ T5832]   stripe_sectors    0
[   59.563029][ T5832]   cached_sectors    0
[   59.563035][ T5832]   stripe            0
[   59.563040][ T5832]   stripe_redundancy 0
[   59.563046][ T5832]   io_time[READ]     0
[   59.563051][ T5832]   io_time[WRITE]    0
[   59.563057][ T5832]   fragmentation     0
[   59.563062][ T5832]   bp_start          8
[   59.563067][ T5832] 
[   59.563073][ T5832]   incorrectly set at freespace:0:21:0 (free 0, genbits 0 should be 0), fixing
[   59.645527][ T5832] 
[   59.647863][ T5832] ============================================
[   59.653990][ T5832] WARNING: possible recursive locking detected
[   59.660125][ T5832] 6.12.0-next-20241120-syzkaller #0 Not tainted
[   59.666338][ T5832] --------------------------------------------
[   59.672465][ T5832] syz-executor131/5832 is trying to acquire lock:
[   59.678854][ T5832] ffff888079f9dc38 (&wp->lock){+.+.}-{4:4}, at: bch2_alloc_sectors_start_trans+0x956/0x2030
[   59.688924][ T5832] 
[   59.688924][ T5832] but task is already holding lock:
[   59.696265][ T5832] ffff888079f9dc38 (&wp->lock){+.+.}-{4:4}, at: bch2_alloc_sectors_start_trans+0x2e8/0x2030
[   59.706346][ T5832] 
[   59.706346][ T5832] other info that might help us debug this:
[   59.714381][ T5832]  Possible unsafe locking scenario:
[   59.714381][ T5832] 
[   59.721819][ T5832]        CPU0
[   59.725080][ T5832]        ----
[   59.728340][ T5832]   lock(&wp->lock);
[   59.732228][ T5832]   lock(&wp->lock);
[   59.736115][ T5832] 
[   59.736115][ T5832]  *** DEADLOCK ***
[   59.736115][ T5832] 
[   59.744242][ T5832]  May be due to missing lock nesting notation
[   59.744242][ T5832] 
[   59.752544][ T5832] 5 locks held by syz-executor131/5832:
[   59.758071][ T5832]  #0: ffff888079f80278 (&c->state_lock){+.+.}-{4:4}, at: bch2_fs_start+0x45/0x610
[   59.767381][ T5832]  #1: ffff888079f843a8 (&c->btree_trans_barrier){.+.+}-{0:0}, at: bch2_trans_srcu_lock+0x9a/0x1a0
[   59.778078][ T5832]  #2: ffff888079fa6710 (&c->gc_lock){++++}-{4:4}, at: bch2_btree_update_start+0x682/0x14e0
[   59.788160][ T5832]  #3: ffff888079f9dc38 (&wp->lock){+.+.}-{4:4}, at: bch2_alloc_sectors_start_trans+0x2e8/0x2030
[   59.798684][ T5832]  #4: ffff888079fa6710 (&c->gc_lock){++++}-{4:4}, at: bch2_btree_update_start+0x682/0x14e0
[   59.808766][ T5832] 
[   59.808766][ T5832] stack backtrace:
[   59.814651][ T5832] CPU: 0 UID: 0 PID: 5832 Comm: syz-executor131 Not tainted 6.12.0-next-20241120-syzkaller #0
[   59.824879][ T5832] Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 10/30/2024
[   59.834924][ T5832] Call Trace:
[   59.838190][ T5832]  <TASK>
[   59.841116][ T5832]  dump_stack_lvl+0x241/0x360
[   59.845792][ T5832]  ? __pfx_dump_stack_lvl+0x10/0x10
[   59.850979][ T5832]  ? __pfx__printk+0x10/0x10
[   59.855556][ T5832]  ? lockdep_unlock+0x16a/0x300
[   59.860395][ T5832]  print_deadlock_bug+0x483/0x620
[   59.865420][ T5832]  validate_chain+0x15e2/0x5920
[   59.870259][ T5832]  ? hlock_conflict+0x59/0x1e0
[   59.875014][ T5832]  ? __pfx___bfs+0x10/0x10
[   59.879423][ T5832]  ? __pfx_validate_chain+0x10/0x10
[   59.884612][ T5832]  ? check_path+0x21/0x40
[   59.888948][ T5832]  ? check_noncircular+0x259/0x4a0
[   59.894059][ T5832]  ? __pfx_validate_chain+0x10/0x10
[   59.899260][ T5832]  ? __pfx_check_noncircular+0x10/0x10
[   59.904720][ T5832]  ? lockdep_unlock+0x16a/0x300
[   59.909561][ T5832]  ? __pfx_lockdep_unlock+0x10/0x10
[   59.914760][ T5832]  ? validate_chain+0x15c0/0x5920
[   59.919781][ T5832]  ? mark_lock+0x9a/0x360
[   59.924102][ T5832]  __lock_acquire+0x1397/0x2100
[   59.928946][ T5832]  lock_acquire+0x1ed/0x550
[   59.933466][ T5832]  ? bch2_alloc_sectors_start_trans+0x956/0x2030
[   59.939799][ T5832]  ? __pfx_lock_acquire+0x10/0x10
[   59.944819][ T5832]  ? __pfx___might_resched+0x10/0x10
[   59.950114][ T5832]  ? __pfx_reacquire_held_locks+0x10/0x10
[   59.955837][ T5832]  ? lock_release+0xbf/0xa30
[   59.960428][ T5832]  __mutex_lock+0x1ac/0xee0
[   59.964935][ T5832]  ? bch2_alloc_sectors_start_trans+0x956/0x2030
[   59.971268][ T5832]  ? bch2_trans_unlock+0x346/0x470
[   59.976369][ T5832]  ? __pfx_lock_release+0x10/0x10
[   59.981382][ T5832]  ? bch2_alloc_sectors_start_trans+0x956/0x2030
[   59.987708][ T5832]  ? __pfx___mutex_lock+0x10/0x10
[   59.992721][ T5832]  ? bch2_trans_unlock+0x3a6/0x470
[   59.997824][ T5832]  bch2_alloc_sectors_start_trans+0x956/0x2030
[   60.003995][ T5832]  ? __pfx_lock_release+0x10/0x10
[   60.009006][ T5832]  ? trace_contention_end+0x3c/0x120
[   60.014281][ T5832]  ? __pfx_bch2_alloc_sectors_start_trans+0x10/0x10
[   60.020863][ T5832]  ? __mutex_unlock_slowpath+0x21e/0x790
[   60.026488][ T5832]  ? __pfx___mutex_lock+0x10/0x10
[   60.031504][ T5832]  bch2_btree_reserve_get+0x612/0x1890
[   60.036964][ T5832]  ? __pfx_bch2_btree_reserve_get+0x10/0x10
[   60.042846][ T5832]  ? percpu_up_read+0xdc/0x1b0
[   60.047602][ T5832]  ? __pfx___bch2_disk_reservation_add+0x10/0x10
[   60.053919][ T5832]  ? bch2_btree_update_start+0x682/0x14e0
[   60.059630][ T5832]  bch2_btree_update_start+0xe56/0x14e0
[   60.065174][ T5832]  ? bch2_btree_split_leaf+0x121/0x880
[   60.070621][ T5832]  ? __pfx_bch2_btree_update_start+0x10/0x10
[   60.076594][ T5832]  ? bch2_path_put+0x1d3/0x2290
[   60.081437][ T5832]  ? __build_rw_aux_tree+0x6ce/0x880
[   60.086717][ T5832]  bch2_btree_split_leaf+0x121/0x880
[   60.091992][ T5832]  bch2_trans_commit_error+0x212/0x1390
[   60.097526][ T5832]  ? bch2_check_discard_freespace_key+0xba7/0x1120
[   60.104018][ T5832]  ? six_unlock_ip+0x2ce/0x3e0
[   60.108769][ T5832]  ? bch2_trans_unlock_write+0x892/0xce0
[   60.114391][ T5832]  ? __pfx_bch2_trans_commit_error+0x10/0x10
[   60.120360][ T5832]  ? bch2_trans_unlock_write+0xc2d/0xce0
[   60.125980][ T5832]  ? bch2_btree_path_verify_locks+0x633/0x720
[   60.132038][ T5832]  ? bch2_trans_verify_locks+0x339/0x3c0
[   60.137666][ T5832]  __bch2_trans_commit+0x7f95/0x9520
[   60.142944][ T5832]  ? __pfx___bch2_fsck_err+0x10/0x10
[   60.148223][ T5832]  ? __pfx___bch2_trans_commit+0x10/0x10
[   60.153844][ T5832]  ? __asan_memcpy+0x40/0x70
[   60.158425][ T5832]  bch2_check_discard_freespace_key+0xba7/0x1120
[   60.164750][ T5832]  ? __pfx_bch2_check_discard_freespace_key+0x10/0x10
[   60.171501][ T5832]  ? bch2_path_get+0xf03/0x15d0
[   60.176353][ T5832]  ? bch2_check_discard_freespace_key+0x2b2/0x1120
[   60.182842][ T5832]  ? __bch2_path_free+0x6ef/0x820
[   60.187877][ T5832]  ? bch2_bucket_alloc_trans+0xefd/0x2fd0
[   60.193590][ T5832]  bch2_bucket_alloc_trans+0x1584/0x2fd0
[   60.199213][ T5832]  ? __pfx_validate_chain+0x10/0x10
[   60.204416][ T5832]  ? bch2_bucket_alloc_trans+0xc04/0x2fd0
[   60.210150][ T5832]  ? __pfx_bch2_bucket_alloc_trans+0x10/0x10
[   60.216145][ T5832]  ? bch2_bucket_alloc_trans+0xc04/0x2fd0
[   60.221865][ T5832]  ? __pfx_lock_release+0x10/0x10
[   60.226889][ T5832]  bch2_bucket_alloc_set_trans+0x517/0xd30
[   60.232692][ T5832]  ? bch2_bucket_alloc_set_trans+0x26f/0xd30
[   60.238669][ T5832]  ? __pfx___bfs+0x10/0x10
[   60.243074][ T5832]  ? __pfx_bch2_bucket_alloc_set_trans+0x10/0x10
[   60.249394][ T5832]  ? hlock_conflict+0x59/0x1e0
[   60.254148][ T5832]  ? __bfs+0x368/0x6f0
[   60.258207][ T5832]  ? mark_lock+0x9a/0x360
[   60.262524][ T5832]  ? __lock_acquire+0x1397/0x2100
[   60.267547][ T5832]  ? lockdep_unlock+0x16a/0x300
[   60.272382][ T5832]  ? __pfx_lockdep_unlock+0x10/0x10
[   60.277574][ T5832]  __open_bucket_add_buckets+0x13d0/0x1ec0
[   60.283391][ T5832]  ? __pfx_validate_chain+0x10/0x10
[   60.288579][ T5832]  ? __pfx___open_bucket_add_buckets+0x10/0x10
[   60.294727][ T5832]  ? __pfx_validate_chain+0x10/0x10
[   60.299914][ T5832]  ? mark_lock+0x9a/0x360
[   60.304241][ T5832]  ? __lock_acquire+0x1397/0x2100
[   60.309256][ T5832]  ? bch2_btree_path_verify_locks+0x279/0x720
[   60.315324][ T5832]  ? __bch2_trans_relock+0x44d/0x5f0
[   60.320601][ T5832]  open_bucket_add_buckets+0x33a/0x410
[   60.326063][ T5832]  bch2_alloc_sectors_start_trans+0xce9/0x2030
[   60.332214][ T5832]  ? __pfx_lock_release+0x10/0x10
[   60.337229][ T5832]  ? trace_contention_end+0x3c/0x120
[   60.342506][ T5832]  ? __pfx_bch2_alloc_sectors_start_trans+0x10/0x10
[   60.349085][ T5832]  ? __mutex_unlock_slowpath+0x21e/0x790
[   60.354713][ T5832]  ? __pfx___mutex_lock+0x10/0x10
[   60.359726][ T5832]  bch2_btree_reserve_get+0x612/0x1890
[   60.365188][ T5832]  ? __pfx_bch2_btree_reserve_get+0x10/0x10
[   60.371078][ T5832]  ? __pfx___closure_sync_timeout+0x10/0x10
[   60.376962][ T5832]  ? __bch2_wait_on_allocator+0x1f1/0x250
[   60.382677][ T5832]  bch2_btree_update_start+0x1160/0x14e0
[   60.388301][ T5832]  ? bch2_btree_split_leaf+0x121/0x880
[   60.393754][ T5832]  ? __pfx_bch2_btree_update_start+0x10/0x10
[   60.399738][ T5832]  ? __pfx_bch2_trans_update+0x10/0x10
[   60.405206][ T5832]  ? __pfx_closure_sync_fn+0x10/0x10
[   60.410487][ T5832]  ? __do_six_trylock+0x832/0x9f0
[   60.415508][ T5832]  bch2_btree_split_leaf+0x121/0x880
[   60.420795][ T5832]  bch2_trans_commit_error+0x212/0x1390
[   60.426337][ T5832]  ? bch2_journal_replay+0x1a18/0x2a70
[   60.431791][ T5832]  ? six_unlock_ip+0x2ce/0x3e0
[   60.436547][ T5832]  ? bch2_trans_unlock_write+0x892/0xce0
[   60.442168][ T5832]  ? __pfx_bch2_trans_commit_error+0x10/0x10
[   60.448135][ T5832]  ? bch2_trans_unlock_write+0xc2d/0xce0
[   60.453775][ T5832]  ? bch2_btree_path_verify_locks+0x633/0x720
[   60.459857][ T5832]  ? bch2_trans_verify_locks+0x339/0x3c0
[   60.465500][ T5832]  __bch2_trans_commit+0x7f95/0x9520
[   60.470786][ T5832]  ? bch2_journal_replay_key+0x24d/0xeb0
[   60.476416][ T5832]  ? __pfx___bch2_trans_commit+0x10/0x10
[   60.482040][ T5832]  bch2_journal_replay+0x1a18/0x2a70
[   60.487317][ T5832]  ? tick_nohz_tick_stopped+0x82/0xb0
[   60.492686][ T5832]  ? __pfx_bch2_journal_replay+0x10/0x10
[   60.498307][ T5832]  ? vprintk_emit+0x7ed/0xa10
[   60.502977][ T5832]  ? __pfx_vprintk_emit+0x10/0x10
[   60.508014][ T5832]  ? __pfx_lock_release+0x10/0x10
[   60.513029][ T5832]  ? __bch2_print+0x17a/0x220
[   60.517694][ T5832]  ? bch2_run_recovery_pass+0x6d/0x1e0
[   60.523147][ T5832]  ? __pfx___bch2_print+0x10/0x10
[   60.528159][ T5832]  ? lockdep_hardirqs_on_prepare+0x43d/0x780
[   60.534128][ T5832]  ? __pfx_lockdep_hardirqs_on_prepare+0x10/0x10
[   60.540440][ T5832]  ? _raw_spin_lock_irq+0xdf/0x120
[   60.545545][ T5832]  bch2_run_recovery_pass+0xf0/0x1e0
[   60.550822][ T5832]  bch2_run_recovery_passes+0x290/0x9f0
[   60.556364][ T5832]  bch2_fs_recovery+0x2666/0x3a90
[   60.561394][ T5832]  ? __pfx_bch2_fs_recovery+0x10/0x10
[   60.566763][ T5832]  ? __pfx_lock_release+0x10/0x10
[   60.571772][ T5832]  ? bch2_get_next_online_dev+0x2b/0x4f0
[   60.577396][ T5832]  ? __pfx_lock_release+0x10/0x10
[   60.582410][ T5832]  ? bch2_get_next_online_dev+0x2b/0x4f0
[   60.588036][ T5832]  ? bch2_get_next_online_dev+0x4b9/0x4f0
[   60.593747][ T5832]  ? bch2_get_next_online_dev+0x2b/0x4f0
[   60.599371][ T5832]  ? llist_reverse_order+0x72/0x90
[   60.604475][ T5832]  bch2_fs_start+0x37c/0x610
[   60.609056][ T5832]  bch2_fs_get_tree+0xd8d/0x1740
[   60.613990][ T5832]  ? __pfx_bch2_fs_get_tree+0x10/0x10
[   60.619354][ T5832]  ? generic_parse_monolithic+0x387/0x400
[   60.625070][ T5832]  ? apparmor_capable+0x13b/0x1b0
[   60.630104][ T5832]  vfs_get_tree+0x90/0x2b0
[   60.634511][ T5832]  do_new_mount+0x2be/0xb40
[   60.639010][ T5832]  ? __pfx_do_new_mount+0x10/0x10
[   60.644027][ T5832]  __se_sys_mount+0x2d6/0x3c0
[   60.648695][ T5832]  ? __pfx___se_sys_mount+0x10/0x10
[   60.653883][ T5832]  ? do_syscall_64+0x100/0x230
[   60.658638][ T5832]  ? __x64_sys_mount+0x20/0xc0
[   60.663393][ T5832]  do_syscall_64+0xf3/0x230
[   60.667881][ T5832]  ? clear_bhb_loop+0x35/0x90
[   60.672546][ T5832]  entry_SYSCALL_64_after_hwframe+0x77/0x7f
[   60.678445][ T5832] RIP: 0033:0x7fe46dd1340a
[   60.682854][ T5832] Code: d8 64 89 02 48 c7 c0 ff ff ff ff eb a6 e8 8e 04 00 00 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 40 00 49 89 ca b8 a5 00 00 00 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 c7 c1 b8 ff ff ff f7 d8 64 89 01 48
[   60.702445][ T5832] RSP: 002b:00007ffcf1924ad8 EFLAGS: 00000282 ORIG_RAX: 00000000000000a5
[   60.710849][ T5832] RAX: ffffffffffffffda RBX: 00007ffcf1924af0 RCX: 00007fe46dd1340a
[   60.718809][ T5832] RDX: 00000000200058c0 RSI: 0000000020000040 RDI: 00007ffcf1924af0
[   60.726767][ T5832] RBP: 0000000000000004 R08: 00007ffcf1924b30 R09: 00000000000058df
[   60.734727][ T5832] R10: 0000000008000000 R11: 0000000000000282 R12: 0000000008000000
[   60.742685][ T5832] R13: 00007ffcf1924b30 R14: 0000000000000003 R15: 0000000001000000
[   60.750649][ T5832]  </TASK>
[pid  5832] mount("/dev/loop0", "./file0", "bcachefs", MS_NOREMOTELOCK, "inodes_use_key_cache,grpquota,dirnd_compression=lz4,usrquota,fix_errors=yes,no_data_io,fsck,hash," <unfinished ...>
[pid  5829] kill(-2, SIGKILL)           = 0
[pid  5829] kill(2, SIGKILL)            = 0
[pid  5829] openat(AT_FDCWD, "/sys/fs/fuse/connections", O_RDONLY|O_NONBLOCK|O_CLOEXEC|O_DIRECTORY) = 3
[pid  5829] newfstatat(3, "", {st_mode=S_IFDIR|0755, st_size=0, ...}, AT_EMPTY_PATH) = 0
[pid  5829] getdents64(3, 0x5555884f96f0 /* 2 entries */, 32768) = 48
[pid  5829] getdents64(3, 0x5555884f96f0 /* 0 entries */, 32768) = 0
[pid  5829] close(3)                    = 0