warning: checkpointing journal with EXT4_IOC_CHECKPOINT_FLAG_ZEROOUT can be slow
======================================================
WARNING: possible circular locking dependency detected
6.0.0-rc1-next-20220816 #1 Not tainted
------------------------------------------------------
syz-executor.0/8996 is trying to acquire lock:
ffff88800c960400 (&sb->s_type->i_mutex_key#6){++++}-{3:3}, at: ext4_bmap+0x4e/0x470
but task is already holding lock:
ffff88801001a3f8 (&journal->j_checkpoint_mutex){+.+.}-{3:3}, at: jbd2_journal_flush+0x48b/0xc00
which lock already depends on the new lock.
the existing dependency chain (in reverse order) is:
-> #3 (&journal->j_checkpoint_mutex){+.+.}-{3:3}:
mutex_lock_io_nested+0x148/0x1310
jbd2_journal_flush+0x19a/0xc00
__ext4_ioctl+0x9e9/0x4090
__x64_sys_ioctl+0x19a/0x210
do_syscall_64+0x3b/0x90
entry_SYSCALL_64_after_hwframe+0x63/0xcd
-> #2 (&journal->j_barrier){+.+.}-{3:3}:
__mutex_lock+0x136/0x14d0
jbd2_journal_lock_updates+0x15e/0x310
ext4_change_inode_journal_flag+0x17f/0x530
ext4_fileattr_set+0x140d/0x18a0
vfs_fileattr_set+0x77c/0xb80
do_vfs_ioctl+0xfc2/0x1610
__x64_sys_ioctl+0x10c/0x210
do_syscall_64+0x3b/0x90
entry_SYSCALL_64_after_hwframe+0x63/0xcd
-> #1 (&sbi->s_writepages_rwsem){++++}-{0:0}:
ext4_writepages+0x1d2/0x3690
do_writepages+0x1b0/0x6a0
filemap_fdatawrite_wbc+0x147/0x1b0
__filemap_fdatawrite_range+0xb6/0x100
filemap_write_and_wait_range+0x89/0x110
__iomap_dio_rw+0x5ed/0x1bd0
iomap_dio_rw+0x3c/0xa0
ext4_file_read_iter+0x268/0x400
do_iter_readv_writev+0x2f0/0x3c0
do_iter_read+0x2fb/0x750
vfs_readv+0xe5/0x160
do_preadv+0x1ba/0x270
__x64_sys_preadv2+0xeb/0x150
do_syscall_64+0x3b/0x90
entry_SYSCALL_64_after_hwframe+0x63/0xcd
-> #0 (&sb->s_type->i_mutex_key#6){++++}-{3:3}:
__lock_acquire+0x2a02/0x5e70
lock_acquire+0x1a2/0x530
down_read+0x98/0x450
ext4_bmap+0x4e/0x470
bmap+0xac/0x120
jbd2_journal_bmap+0xa8/0x180
jbd2_journal_flush+0x853/0xc00
__ext4_ioctl+0x9e9/0x4090
__x64_sys_ioctl+0x19a/0x210
do_syscall_64+0x3b/0x90
entry_SYSCALL_64_after_hwframe+0x63/0xcd
other info that might help us debug this:
Chain exists of:
&sb->s_type->i_mutex_key#6 --> &journal->j_barrier --> &journal->j_checkpoint_mutex
Possible unsafe locking scenario:
CPU0 CPU1
---- ----
lock(&journal->j_checkpoint_mutex);
lock(&journal->j_barrier);
lock(&journal->j_checkpoint_mutex);
lock(&sb->s_type->i_mutex_key#6);
*** DEADLOCK ***
2 locks held by syz-executor.0/8996:
#0: ffff88801001a170 (&journal->j_barrier){+.+.}-{3:3}, at: jbd2_journal_lock_updates+0x15e/0x310
#1: ffff88801001a3f8 (&journal->j_checkpoint_mutex){+.+.}-{3:3}, at: jbd2_journal_flush+0x48b/0xc00
stack backtrace:
CPU: 1 PID: 8996 Comm: syz-executor.0 Not tainted 6.0.0-rc1-next-20220816 #1
Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS rel-1.14.0-0-g155821a1990b-prebuilt.qemu.org 04/01/2014
Call Trace:
dump_stack_lvl+0x8b/0xb3
check_noncircular+0x263/0x2e0
__lock_acquire+0x2a02/0x5e70
lock_acquire+0x1a2/0x530
down_read+0x98/0x450
ext4_bmap+0x4e/0x470
bmap+0xac/0x120
jbd2_journal_bmap+0xa8/0x180
jbd2_journal_flush+0x853/0xc00
__ext4_ioctl+0x9e9/0x4090
__x64_sys_ioctl+0x19a/0x210
do_syscall_64+0x3b/0x90
entry_SYSCALL_64_after_hwframe+0x63/0xcd
RIP: 0033:0x7f2af5a62b19
Code: ff ff c3 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 40 00 48 89 f8 48 89 f7 48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 c7 c1 bc ff ff ff f7 d8 64 89 01 48
RSP: 002b:00007f2af2fd8188 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: ffffffffffffffda RBX: 00007f2af5b75f60 RCX: 00007f2af5a62b19
RDX: 0000000020000340 RSI: 000000004004662b RDI: 0000000000000004
RBP: 00007f2af5abcf6d R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000
R13: 00007ffe0725656f R14: 00007f2af2fd8300 R15: 0000000000022000
warning: checkpointing journal with EXT4_IOC_CHECKPOINT_FLAG_ZEROOUT can be slow
audit: type=1326 audit(1660649628.480:35): auid=0 uid=0 gid=0 ses=4 subj=system_u:system_r:kernel_t:s0 pid=8982 comm="syz-executor.6" exe="/syz-executor.6" sig=31 arch=c000003e syscall=202 compat=0 ip=0x7f73a140db19 code=0x0
warning: checkpointing journal with EXT4_IOC_CHECKPOINT_FLAG_ZEROOUT can be slow
audit: type=1326 audit(1660649628.974:36): auid=0 uid=0 gid=0 ses=4 subj=system_u:system_r:kernel_t:s0 pid=9039 comm="syz-executor.6" exe="/syz-executor.6" sig=31 arch=c000003e syscall=202 compat=0 ip=0x7f73a140db19 code=0x0
warning: checkpointing journal with EXT4_IOC_CHECKPOINT_FLAG_ZEROOUT can be slow
audit: type=1326 audit(1660649629.277:37): auid=0 uid=0 gid=0 ses=4 subj=system_u:system_r:kernel_t:s0 pid=9044 comm="syz-executor.2" exe="/syz-executor.2" sig=31 arch=c000003e syscall=202 compat=0 ip=0x7fedc7c06b19 code=0x0
warning: checkpointing journal with EXT4_IOC_CHECKPOINT_FLAG_ZEROOUT can be slow
warning: checkpointing journal with EXT4_IOC_CHECKPOINT_FLAG_ZEROOUT can be slow
warning: checkpointing journal with EXT4_IOC_CHECKPOINT_FLAG_ZEROOUT can be slow
Bluetooth: hci7: HCI_REQ-0x0406
Bluetooth: hci6: HCI_REQ-0x0406
Bluetooth: hci5: HCI_REQ-0x0406
Bluetooth: hci4: HCI_REQ-0x0406
Bluetooth: hci3: HCI_REQ-0x0406
------------[ cut here ]------------
WARNING: CPU: 1 PID: 317 at net/bluetooth/hci_conn.c:646 hci_conn_timeout+0x242/0x330
Bluetooth: hci0: HCI_REQ-0x0406
Modules linked in:
Bluetooth: hci2: HCI_REQ-0x0406
CPU: 1 PID: 317 Comm: kworker/u5:6 Not tainted 6.0.0-rc1-next-20220816 #1
Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS rel-1.14.0-0-g155821a1990b-prebuilt.qemu.org 04/01/2014
Workqueue: hci1 hci_conn_timeout
RIP: 0010:hci_conn_timeout+0x242/0x330
Code: ff e8 e2 a6 98 fd 4c 89 e7 e8 3a 55 0b 00 0f b6 e8 e8 d2 a6 98 fd 89 ee 4c 89 e7 e8 38 a3 0d 00 e9 1a ff ff ff e8 be a6 98 fd <0f> 0b e9 36 fe ff ff 84 c0 74 93 4c 89 ef e8 8b 61 cb fd eb 89 48
RSP: 0018:ffff8880437c7ce8 EFLAGS: 00010293
RAX: 0000000000000000 RBX: ffff888043850250 RCX: 0000000000000000
RDX: ffff8880437a5100 RSI: ffffffff83ad0b72 RDI: 0000000000000005
RBP: 00000000ffffffff R08: 0000000000000005 R09: 0000000000000000
R10: 00000000ffffffff R11: 0000000000000001 R12: ffff8880437c7db0
R13: ffff888043aca258 R14: ffff888015c5b000 R15: ffff88801d155a00
FS: 0000000000000000(0000) GS:ffff88806cf00000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 0000001b2dd37000 CR3: 00000000103c4000 CR4: 0000000000350ee0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000ffff4ff0 DR7: 0000000000000400
Call Trace:
process_one_work+0xa0f/0x1690
worker_thread+0x637/0x1260
kthread+0x2ed/0x3a0
ret_from_fork+0x22/0x30
irq event stamp: 6038
hardirqs last enabled at (6037): [] _raw_spin_unlock_irq+0x1f/0x50
hardirqs last disabled at (6038): [] __schedule+0x11d7/0x2490
softirqs last enabled at (5950): [] __irq_exit_rcu+0x11b/0x180
softirqs last disabled at (5941): [] __irq_exit_rcu+0x11b/0x180
---[ end trace 0000000000000000 ]---
audit: type=1326 audit(1660649630.736:38): auid=0 uid=0 gid=0 ses=4 subj=system_u:system_r:kernel_t:s0 pid=9070 comm="syz-executor.6" exe="/syz-executor.6" sig=31 arch=c000003e syscall=202 compat=0 ip=0x7f73a140db19 code=0x0
audit: type=1326 audit(1660649630.869:39): auid=0 uid=0 gid=0 ses=4 subj=system_u:system_r:kernel_t:s0 pid=9083 comm="syz-executor.2" exe="/syz-executor.2" sig=31 arch=c000003e syscall=202 compat=0 ip=0x7fedc7c06b19 code=0x0
audit: type=1326 audit(1660649631.811:40): auid=0 uid=0 gid=0 ses=4 subj=system_u:system_r:kernel_t:s0 pid=9092 comm="syz-executor.6" exe="/syz-executor.6" sig=31 arch=c000003e syscall=202 compat=0 ip=0x7f73a140db19 code=0x0
audit: type=1326 audit(1660649631.841:41): auid=0 uid=0 gid=0 ses=4 subj=system_u:system_r:kernel_t:s0 pid=9106 comm="syz-executor.2" exe="/syz-executor.2" sig=31 arch=c000003e syscall=202 compat=0 ip=0x7fedc7c06b19 code=0x0
Bluetooth: hci2: command 0x0406 tx timeout
Bluetooth: hci0: command 0x0406 tx timeout
Bluetooth: hci3: command 0x0406 tx timeout
Bluetooth: hci4: command 0x0406 tx timeout
Bluetooth: hci5: command 0x0406 tx timeout
Bluetooth: hci6: command 0x0406 tx timeout
Bluetooth: hci7: command 0x0406 tx timeout
netlink: 12 bytes leftover after parsing attributes in process `syz-executor.3'.
netlink: 12 bytes leftover after parsing attributes in process `syz-executor.3'.
netlink: 12 bytes leftover after parsing attributes in process `syz-executor.3'.
netlink: 12 bytes leftover after parsing attributes in process `syz-executor.3'.
Invalid ELF header magic: != ELF
Invalid ELF header magic: != ELF
Invalid ELF header magic: != ELF