IPv6: ADDRCONF(NETDEV_CHANGE): wlan1: link becomes ready
binder: 25327:25351 ioctl 4008941a 20000080 returned -22
binder: 25327:25347 ioctl 4008941a 20000080 returned -22
ttyprintk ttyprintk: tty_port_close_start: tty->count = 1 port count = 3
======================================================
WARNING: possible circular locking dependency detected
4.19.163-syzkaller #0 Not tainted
------------------------------------------------------
syz-executor.3/25348 is trying to acquire lock:
00000000b38d0c9c (console_owner){-.-.}, at: console_trylock_spinning kernel/printk/printk.c:1697 [inline]
00000000b38d0c9c (console_owner){-.-.}, at: vprintk_emit+0x3fe/0x740 kernel/printk/printk.c:1964

but task is already holding lock:
00000000dd872082 (&(&port->lock)->rlock){-.-.}, at: tty_port_close_start.part.0+0x28/0x540 drivers/tty/tty_port.c:574

which lock already depends on the new lock.


the existing dependency chain (in reverse order) is:

-> #2 (&(&port->lock)->rlock){-.-.}:
       tty_port_tty_get+0x1d/0x80 drivers/tty/tty_port.c:289
       tty_port_default_wakeup+0x11/0x40 drivers/tty/tty_port.c:47
       serial8250_tx_chars+0x490/0xaf0 drivers/tty/serial/8250/8250_port.c:1806
       serial8250_handle_irq.part.0+0x31f/0x3d0 drivers/tty/serial/8250/8250_port.c:1893
       serial8250_handle_irq drivers/tty/serial/8250/8250_port.c:1866 [inline]
       serial8250_default_handle_irq+0xae/0x220 drivers/tty/serial/8250/8250_port.c:1909
       serial8250_interrupt+0x101/0x240 drivers/tty/serial/8250/8250_core.c:125
       __handle_irq_event_percpu+0x27e/0x8e0 kernel/irq/handle.c:149
       handle_irq_event_percpu kernel/irq/handle.c:189 [inline]
       handle_irq_event+0x102/0x285 kernel/irq/handle.c:206
       handle_edge_irq+0x260/0xcf0 kernel/irq/chip.c:797
       generic_handle_irq_desc include/linux/irqdesc.h:155 [inline]
       handle_irq+0x35/0x50 arch/x86/kernel/irq_64.c:87
       do_IRQ+0x93/0x1c0 arch/x86/kernel/irq.c:246
       ret_from_intr+0x0/0x1e
       arch_local_irq_restore arch/x86/include/asm/paravirt.h:789 [inline]
       __raw_spin_unlock_irqrestore include/linux/spinlock_api_smp.h:160 [inline]
       _raw_spin_unlock_irqrestore+0xa3/0xe0 kernel/locking/spinlock.c:184
       spin_unlock_irqrestore include/linux/spinlock.h:384 [inline]
       uart_write+0x3bb/0x6f0 drivers/tty/serial/serial_core.c:612
       do_output_char+0x5de/0x850 drivers/tty/n_tty.c:445
       process_output drivers/tty/n_tty.c:512 [inline]
       n_tty_write+0x46e/0xff0 drivers/tty/n_tty.c:2343
       do_tty_write drivers/tty/tty_io.c:960 [inline]
       tty_write+0x496/0x810 drivers/tty/tty_io.c:1044
       redirected_tty_write+0xaa/0xb0 drivers/tty/tty_io.c:1065
       do_loop_readv_writev fs/read_write.c:704 [inline]
       do_loop_readv_writev fs/read_write.c:688 [inline]
       do_iter_write+0x461/0x5d0 fs/read_write.c:962
       vfs_writev+0x153/0x2e0 fs/read_write.c:1005
       do_writev+0x136/0x330 fs/read_write.c:1040
       do_syscall_64+0xf9/0x620 arch/x86/entry/common.c:293
       entry_SYSCALL_64_after_hwframe+0x49/0xbe

-> #1 (&port_lock_key){-.-.}:
       serial8250_console_write+0x89b/0xad0 drivers/tty/serial/8250/8250_port.c:3270
       call_console_drivers kernel/printk/printk.c:1764 [inline]
       console_unlock+0xbb6/0x1110 kernel/printk/printk.c:2460
       vprintk_emit+0x2d1/0x740 kernel/printk/printk.c:1965
       vprintk_func+0x79/0x17e kernel/printk/printk_safe.c:397
       printk+0xba/0xed kernel/printk/printk.c:2040
       register_console+0x87f/0xc90 kernel/printk/printk.c:2776
       univ8250_console_init+0x3a/0x46 drivers/tty/serial/8250/8250_core.c:684
       console_init+0x4cb/0x718 kernel/printk/printk.c:2862
       start_kernel+0x686/0x911 init/main.c:659
       secondary_startup_64+0xa4/0xb0 arch/x86/kernel/head_64.S:243

-> #0 (console_owner){-.-.}:
       console_trylock_spinning kernel/printk/printk.c:1718 [inline]
       vprintk_emit+0x43b/0x740 kernel/printk/printk.c:1964
       vprintk_func+0x79/0x17e kernel/printk/printk_safe.c:397
       printk+0xba/0xed kernel/printk/printk.c:2040
       tty_port_close_start.part.0+0x4f3/0x540 drivers/tty/tty_port.c:576
       tty_port_close_start drivers/tty/tty_port.c:648 [inline]
       tty_port_close+0x46/0x160 drivers/tty/tty_port.c:641
       tty_release+0x45e/0x1210 drivers/tty/tty_io.c:1678
       __fput+0x2ce/0x890 fs/file_table.c:278
       task_work_run+0x148/0x1c0 kernel/task_work.c:113
       tracehook_notify_resume include/linux/tracehook.h:193 [inline]
       exit_to_usermode_loop+0x251/0x2a0 arch/x86/entry/common.c:167
       prepare_exit_to_usermode arch/x86/entry/common.c:198 [inline]
       syscall_return_slowpath arch/x86/entry/common.c:271 [inline]
       do_syscall_64+0x538/0x620 arch/x86/entry/common.c:296
       entry_SYSCALL_64_after_hwframe+0x49/0xbe

other info that might help us debug this:

Chain exists of:
  console_owner --> &port_lock_key --> &(&port->lock)->rlock

 Possible unsafe locking scenario:

       CPU0                    CPU1
       ----                    ----
  lock(&(&port->lock)->rlock);
                               lock(&port_lock_key);
                               lock(&(&port->lock)->rlock);
  lock(console_owner);

 *** DEADLOCK ***

2 locks held by syz-executor.3/25348:
 #0: 000000004a2ceeac (&tty->legacy_mutex){+.+.}, at: tty_lock+0x6a/0xa0 drivers/tty/tty_mutex.c:19
 #1: 00000000dd872082 (&(&port->lock)->rlock){-.-.}, at: tty_port_close_start.part.0+0x28/0x540 drivers/tty/tty_port.c:574

stack backtrace:
CPU: 0 PID: 25348 Comm: syz-executor.3 Not tainted 4.19.163-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Call Trace:
 __dump_stack lib/dump_stack.c:77 [inline]
 dump_stack+0x1fc/0x2fe lib/dump_stack.c:118
 print_circular_bug.constprop.0.cold+0x2d7/0x41e kernel/locking/lockdep.c:1221
 check_prev_add kernel/locking/lockdep.c:1865 [inline]
 check_prevs_add kernel/locking/lockdep.c:1978 [inline]
 validate_chain kernel/locking/lockdep.c:2419 [inline]
 __lock_acquire+0x30c9/0x3ff0 kernel/locking/lockdep.c:3415
 lock_acquire+0x170/0x3c0 kernel/locking/lockdep.c:3907
 console_trylock_spinning kernel/printk/printk.c:1718 [inline]
 vprintk_emit+0x43b/0x740 kernel/printk/printk.c:1964
 vprintk_func+0x79/0x17e kernel/printk/printk_safe.c:397
 printk+0xba/0xed kernel/printk/printk.c:2040
 tty_port_close_start.part.0+0x4f3/0x540 drivers/tty/tty_port.c:576
 tty_port_close_start drivers/tty/tty_port.c:648 [inline]
 tty_port_close+0x46/0x160 drivers/tty/tty_port.c:641
 tty_release+0x45e/0x1210 drivers/tty/tty_io.c:1678
 __fput+0x2ce/0x890 fs/file_table.c:278
 task_work_run+0x148/0x1c0 kernel/task_work.c:113
 tracehook_notify_resume include/linux/tracehook.h:193 [inline]
 exit_to_usermode_loop+0x251/0x2a0 arch/x86/entry/common.c:167
 prepare_exit_to_usermode arch/x86/entry/common.c:198 [inline]
 syscall_return_slowpath arch/x86/entry/common.c:271 [inline]
 do_syscall_64+0x538/0x620 arch/x86/entry/common.c:296
 entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x417aa1
Code: 75 14 b8 03 00 00 00 0f 05 48 3d 01 f0 ff ff 0f 83 a4 1a 00 00 c3 48 83 ec 08 e8 0a fc ff ff 48 89 04 24 b8 03 00 00 00 0f 05 <48> 8b 3c 24 48 89 c2 e8 53 fc ff ff 48 89 d0 48 83 c4 08 48 3d 01
RSP: 002b:00007ffeded80180 EFLAGS: 00000293 ORIG_RAX: 0000000000000003
RAX: 0000000000000000 RBX: 0000000000000004 RCX: 0000000000417aa1
RDX: 0000001b30920000 RSI: 0000000080000000 RDI: 0000000000000003
RBP: 0000000000000001 R08: 0000000000000c23 R09: 000000006494ec27
R10: 00007ffeded80260 R11: 0000000000000293 R12: ffffffffffffffff
R13: 0000000000064c38 R14: 00000000000003e8 R15: 000000000119bf8c
ptrace attach of "/root/syz-executor.5"[8146] was attempted by "/root/syz-executor.5"[25344]
overlayfs: fs on './file0' does not support file handles, falling back to index=off,nfs_export=off.
FAT-fs (loop0): Invalid FSINFO signature: 0x00000000, 0x00000000 (sector = 1)
overlayfs: filesystem on './file0' not supported as upperdir
audit: type=1804 audit(1608877464.586:102): pid=25454 uid=0 auid=0 ses=4 subj==unconfined op=invalid_pcr cause=ToMToU comm="syz-executor.3" name="/root/syzkaller-testdir267614179/syzkaller.qYevo2/375/file0/file0" dev="ramfs" ino=113169 res=1
TCP: request_sock_TCPv6: Possible SYN flooding on port 20002. Sending cookies.  Check SNMP counters.
TCP: request_sock_TCPv6: Possible SYN flooding on port 20002. Sending cookies.  Check SNMP counters.
ptrace attach of "/root/syz-executor.3"[8142] was attempted by "/root/syz-executor.3"[25523]
ptrace attach of "/root/syz-executor.3"[8142] was attempted by "/root/syz-executor.3"[25553]
xt_CT: netfilter: NOTRACK target is deprecated, use CT instead or upgrade iptables
ipt_CLUSTERIP: Please specify destination IP
ptrace attach of "/root/syz-executor.3"[8142] was attempted by "/root/syz-executor.3"[25565]
binder: 25547:25555 ioctl 4008941a 20000000 returned -22
ptrace attach of "/root/syz-executor.3"[8142] was attempted by "/root/syz-executor.3"[25583]
binder: 25547:25585 ioctl 4008941a 20000000 returned -22
xt_TPROXY: Can be used only with -p tcp or -p udp
xt_TPROXY: Can be used only with -p tcp or -p udp
ptrace attach of "/root/syz-executor.3"[8142] was attempted by "/root/syz-executor.3"[25625]
EXT4-fs (loop5): mounted filesystem without journal. Opts: (null)
ptrace attach of "/root/syz-executor.3"[8142] was attempted by "/root/syz-executor.3"[25650]
binder: 25619:25627 ioctl 4008941a 20000000 returned -22
ptrace attach of "/root/syz-executor.3"[8142] was attempted by "/root/syz-executor.3"[25666]
EXT4-fs (loop5): mounted filesystem without journal. Opts: (null)
ptrace attach of "/root/syz-executor.3"[8142] was attempted by "/root/syz-executor.3"[25682]
binder: 25667:25673 ioctl 4008941a 20000000 returned -22
EXT4-fs (loop5): mounted filesystem without journal. Opts: (null)
ptrace attach of "/root/syz-executor.3"[8142] was attempted by "/root/syz-executor.3"[25711]
EXT4-fs (loop5): mounted filesystem without journal. Opts: (null)
binder: 25705:25712 ioctl 4008941a 20000000 returned -22
ptrace attach of "/root/syz-executor.3"[8142] was attempted by "/root/syz-executor.3"[25737]
EXT4-fs (loop5): mounted filesystem without journal. Opts: (null)
Bluetooth: hci4: command 0x0406 tx timeout
EXT4-fs (loop5): mounted filesystem without journal. Opts: (null)
EXT4-fs (loop5): bad geometry: block count 64 exceeds size of device (8 blocks)
EXT4-fs (loop5): bad geometry: block count 64 exceeds size of device (8 blocks)
EXT4-fs (loop5): bad geometry: block count 64 exceeds size of device (8 blocks)
netlink: 16 bytes leftover after parsing attributes in process `syz-executor.4'.
netlink: 48 bytes leftover after parsing attributes in process `syz-executor.4'.
print_req_error: I/O error, dev loop5, sector 2
EXT4-fs (loop5): unable to read superblock
print_req_error: I/O error, dev loop5, sector 2
EXT4-fs (loop5): unable to read superblock
print_req_error: I/O error, dev loop5, sector 2
EXT4-fs (loop5): unable to read superblock
EXT4-fs error (device loop5): ext4_fill_super:4448: inode #2: comm syz-executor.5: iget: root inode unallocated
EXT4-fs (loop5): get root inode failed
EXT4-fs (loop5): mount failed
__report_access: 19 callbacks suppressed
ptrace attach of "/root/syz-executor.0"[11040] was attempted by "/root/syz-executor.0"[26148]
ptrace attach of "/root/syz-executor.3"[8142] was attempted by "/root/syz-executor.3"[26151]
EXT4-fs error (device loop5): ext4_fill_super:4448: inode #2: comm syz-executor.5: iget: root inode unallocated
EXT4-fs (loop5): get root inode failed
EXT4-fs (loop5): mount failed
ptrace attach of "/root/syz-executor.3"[8142] was attempted by "/root/syz-executor.3"[26180]
ptrace attach of "/root/syz-executor.0"[11040] was attempted by "/root/syz-executor.0"[26184]
ptrace attach of "/root/syz-executor.3"[8142] was attempted by "/root/syz-executor.3"[26190]
ptrace attach of "/root/syz-executor.2"[14111] was attempted by "/root/syz-executor.2"[26202]
ptrace attach of "/root/syz-executor.3"[8142] was attempted by "/root/syz-executor.3"[26206]
EXT4-fs error (device loop5): ext4_fill_super:4448: inode #2: comm syz-executor.5: iget: root inode unallocated
EXT4-fs (loop5): get root inode failed
EXT4-fs (loop5): mount failed
ptrace attach of "/root/syz-executor.3"[8142] was attempted by "/root/syz-executor.3"[26228]
ptrace attach of "/root/syz-executor.2"[14111] was attempted by "/root/syz-executor.2"[26227]
ptrace attach of "/root/syz-executor.0"[11040] was attempted by "/root/syz-executor.0"[26230]
EXT4-fs error (device loop5): ext4_fill_super:4448: inode #2: comm syz-executor.5: iget: root inode unallocated
EXT4-fs (loop5): get root inode failed
EXT4-fs (loop5): mount failed
EXT4-fs error (device loop5): ext4_fill_super:4448: inode #2: comm syz-executor.5: iget: root inode unallocated
EXT4-fs (loop5): get root inode failed
EXT4-fs (loop5): mount failed
EXT4-fs error (device loop5): ext4_fill_super:4448: inode #2: comm syz-executor.5: iget: root inode unallocated
EXT4-fs (loop5): get root inode failed
EXT4-fs (loop5): mount failed
EXT4-fs error (device loop5): ext4_fill_super:4448: inode #2: comm syz-executor.5: iget: root inode unallocated
EXT4-fs (loop5): get root inode failed
EXT4-fs (loop5): mount failed
EXT4-fs error (device loop5): ext4_fill_super:4448: inode #2: comm syz-executor.5: iget: root inode unallocated
EXT4-fs (loop5): get root inode failed
EXT4-fs (loop5): mount failed
EXT4-fs error (device loop5): ext4_fill_super:4448: inode #2: comm syz-executor.5: iget: root inode unallocated
EXT4-fs (loop5): get root inode failed
EXT4-fs (loop5): mount failed