Subject: Re: [PATCH net,v3] net: ppp: Fix deadlock caused by unsafe-irq lock in ap_get()

From: Jeongjun Park <[email-masked]>
Date: Mon, 22 Apr 2024 16:18:58 +0900

========================================================
WARNING: possible irq lock inversion dependency detected
6.8.0-rc3-syzkaller-00041-g547ab8fc4cb0 #0 Not tainted
--------------------------------------------------------
kworker/u4:7/1097 just changed the state of lock:
ffffffff8ec04eb8 (disc_data_lock#2){.?..}-{2:2}, at: ap_get drivers/net/ppp/ppp_async.c:136 [inline]
ffffffff8ec04eb8 (disc_data_lock#2){.?..}-{2:2}, at: ppp_asynctty_receive+0x40/0x2000 drivers/net/ppp/ppp_async.c:335
but this lock was taken by another, HARDIRQ-safe lock in the past:
 (&port_lock_key){-.-.}-{2:2}

and interrupts could create inverse lock ordering between them.

other info that might help us debug this:
 Possible interrupt unsafe locking scenario:

       CPU0                    CPU1
       ----                    ----
  lock(disc_data_lock#2);
                               local_irq_disable();
                               lock(&port_lock_key);
                               lock(disc_data_lock#2);
  <Interrupt>
    lock(&port_lock_key);

 *** DEADLOCK ***

4 locks held by kworker/u4:7/1097:
 #0: ffff888014c8d938 ((wq_completion)events_unbound){+.+.}-{0:0}, at: process_one_work kernel/workqueue.c:2608 [inline]
 #0: ffff888014c8d938 ((wq_completion)events_unbound){+.+.}-{0:0}, at: process_scheduled_works+0x825/0x1420 kernel/workqueue.c:2706
 #1: ffffc90004e97d20 ((work_completion)(&buf->work)){+.+.}-{0:0}, at: process_one_work kernel/workqueue.c:2608 [inline]
 #1: ffffc90004e97d20 ((work_completion)(&buf->work)){+.+.}-{0:0}, at: process_scheduled_works+0x825/0x1420 kernel/workqueue.c:2706
 #2: ffff88803d92b0b8 (&buf->lock){+.+.}-{3:3}, at: flush_to_ldisc+0x38/0x860 drivers/tty/tty_buffer.c:466
 #3: ffff8880751ac0a0 (&tty->ldisc_sem){++++}-{0:0}, at: tty_ldisc_ref+0x1c/0x80 drivers/tty/tty_ldisc.c:263

the shortest dependencies between 2nd lock and 1st lock:
 -> (&port_lock_key){-.-.}-{2:2} {
    IN-HARDIRQ-W at:
                      lock_acquire+0x1e3/0x530 kernel/locking/lockdep.c:5754
                      __raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:110 [inline]
                      _raw_spin_lock_irqsave+0xd5/0x120 kernel/locking/spinlock.c:162
                      uart_port_lock_irqsave include/linux/serial_core.h:616 [inline]
                      serial8250_handle_irq+0x81/0x710 drivers/tty/serial/8250/8250_port.c:1913
                      serial8250_default_handle_irq+0xd1/0x1f0 drivers/tty/serial/8250/8250_port.c:1962
                      serial8250_interrupt+0xa9/0x1f0 drivers/tty/serial/8250/8250_core.c:127
                      __handle_irq_event_percpu+0x289/0xa30 kernel/irq/handle.c:158
                      handle_irq_event_percpu kernel/irq/handle.c:193 [inline]
                      handle_irq_event+0x89/0x1f0 kernel/irq/handle.c:210
                      handle_edge_irq+0x25f/0xc20 kernel/irq/chip.c:831
                      generic_handle_irq_desc include/linux/irqdesc.h:161 [inline]
                      handle_irq arch/x86/kernel/irq.c:238 [inline]
                      __common_interrupt+0x138/0x230 arch/x86/kernel/irq.c:257
                      common_interrupt+0xa5/0xd0 arch/x86/kernel/irq.c:247
                      asm_common_interrupt+0x26/0x40 arch/x86/include/asm/idtentry.h:640
                      __raw_spin_unlock_irqrestore include/linux/spinlock_api_smp.h:152 [inline]
                      _raw_spin_unlock_irqrestore+0xd8/0x140 kernel/locking/spinlock.c:194
                      spin_unlock_irqrestore include/linux/spinlock.h:406 [inline]
                      uart_port_unlock_irqrestore include/linux/serial_core.h:667 [inline]
                      serial_port_runtime_resume+0x204/0x2b0 drivers/tty/serial/serial_port.c:41
                      __rpm_callback+0x2df/0x790 drivers/base/power/runtime.c:393
                      rpm_callback drivers/base/power/runtime.c:447 [inline]
                      rpm_resume+0x10b1/0x1af0 drivers/base/power/runtime.c:913
                      pm_runtime_work+0x147/0x210 drivers/base/power/runtime.c:978
                      process_one_work kernel/workqueue.c:2633 [inline]
                      process_scheduled_works+0x913/0x1420 kernel/workqueue.c:2706
                      worker_thread+0xa5f/0x1000 kernel/workqueue.c:2787
                      kthread+0x2ef/0x390 kernel/kthread.c:388
                      ret_from_fork+0x4b/0x80 arch/x86/kernel/process.c:147
                      ret_from_fork_asm+0x1b/0x30 arch/x86/entry/entry_64.S:242
    IN-SOFTIRQ-W at:
                      lock_acquire+0x1e3/0x530 kernel/locking/lockdep.c:5754
                      __raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:110 [inline]
                      _raw_spin_lock_irqsave+0xd5/0x120 kernel/locking/spinlock.c:162
                      uart_port_lock_irqsave include/linux/serial_core.h:616 [inline]
                      serial8250_console_write+0x1a8/0x1840 drivers/tty/serial/8250/8250_port.c:3403
                      console_emit_next_record kernel/printk/printk.c:2901 [inline]
                      console_flush_all+0x808/0xec0 kernel/printk/printk.c:2967
                      console_unlock+0x13b/0x4d0 kernel/printk/printk.c:3036
                      vprintk_emit+0x508/0x720 kernel/printk/printk.c:2303
                      dev_vprintk_emit+0x2ae/0x330 drivers/base/core.c:4850
                      dev_printk_emit+0xdd/0x120 drivers/base/core.c:4861
                      _dev_err+0x122/0x170 drivers/base/core.c:4916
                      __usb_hcd_giveback_urb+0x373/0x530 drivers/usb/core/hcd.c:1650
                      dummy_timer+0x8aa/0x3220 drivers/usb/gadget/udc/dummy_hcd.c:1987
                      call_timer_fn+0x17e/0x600 kernel/time/timer.c:1700
                      expire_timers kernel/time/timer.c:1751 [inline]
                      __run_timers+0x621/0x830 kernel/time/timer.c:2038
                      run_timer_softirq+0x67/0xf0 kernel/time/timer.c:2051
                      __do_softirq+0x2bb/0x942 kernel/softirq.c:553
                      invoke_softirq kernel/softirq.c:427 [inline]
                      __irq_exit_rcu+0xf1/0x1c0 kernel/softirq.c:632
                      irq_exit_rcu+0x9/0x30 kernel/softirq.c:644
                      sysvec_apic_timer_interrupt+0x97/0xb0 arch/x86/kernel/apic/apic.c:1076
                      asm_sysvec_apic_timer_interrupt+0x1a/0x20 arch/x86/include/asm/idtentry.h:649
                      xt_obj_to_user+0xeb/0x130 net/netfilter/x_tables.c:301
                      xt_compat_target_to_user+0x17e/0x3a0 net/netfilter/x_tables.c:1166
                      compat_copy_entry_to_user net/ipv6/netfilter/ip6_tables.c:1258 [inline]
                      compat_copy_entries_to_user+0x34b/0x680 net/ipv6/netfilter/ip6_tables.c:1569
                      compat_get_entries net/ipv6/netfilter/ip6_tables.c:1605 [inline]
                      do_ip6t_get_ctl+0xe46/0x1820 net/ipv6/netfilter/ip6_tables.c:1666
                      nf_getsockopt+0x299/0x2c0 net/netfilter/nf_sockopt.c:116
                      ipv6_getsockopt+0x263/0x380 net/ipv6/ipv6_sockglue.c:1488
                      tcp_getsockopt+0x163/0x1c0 net/ipv4/tcp.c:4372
                      do_sock_getsockopt+0x373/0x850 net/socket.c:2373
                      __sys_getsockopt+0x270/0x330 net/socket.c:2402
                      __do_compat_sys_socketcall net/compat.c:494 [inline]
                      __se_compat_sys_socketcall+0x348/0x1430 net/compat.c:423
                      do_syscall_32_irqs_on arch/x86/entry/common.c:165 [inline]
                      __do_fast_syscall_32+0xbd/0x120 arch/x86/entry/common.c:321
                      do_fast_syscall_32+0x33/0x70 arch/x86/entry/common.c:346
                      entry_SYSENTER_compat_after_hwframe+0x7c/0x86
    INITIAL USE at:
                     lock_acquire+0x1e3/0x530 kernel/locking/lockdep.c:5754
                     __raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:110 [inline]
                     _raw_spin_lock_irqsave+0xd5/0x120 kernel/locking/spinlock.c:162
                     uart_port_lock_irqsave include/linux/serial_core.h:616 [inline]
                     serial8250_do_set_termios+0x531/0x17e0 drivers/tty/serial/8250/8250_port.c:2793
                     uart_set_options+0x3eb/0x730 drivers/tty/serial/serial_core.c:2320
                     serial8250_console_setup+0x3db/0x670 drivers/tty/serial/8250/8250_port.c:3507
                     univ8250_console_setup+0x3ac/0x470 drivers/tty/serial/8250/8250_core.c:632
                     try_enable_preferred_console+0x40d/0x560 kernel/printk/printk.c:3302
                     register_console+0x261/0xcd0 kernel/printk/printk.c:3479
                     univ8250_console_init+0x49/0x50 drivers/tty/serial/8250/8250_core.c:717
                     console_init+0x198/0x680 kernel/printk/printk.c:3688
                     start_kernel+0x2d2/0x500 init/main.c:1008
                     x86_64_start_reservations+0x2a/0x30 arch/x86/kernel/head64.c:555
                     x86_64_start_kernel+0x99/0xa0 arch/x86/kernel/head64.c:536
                     secondary_startup_64_no_verify+0x171/0x17b
  }
  ... key      at: [<ffffffff947ae860>] port_lock_key+0x0/0x20
  ... acquired at:
   lock_acquire+0x1e3/0x530 kernel/locking/lockdep.c:5754
   __raw_read_lock include/linux/rwlock_api_smp.h:150 [inline]
   _raw_read_lock+0x36/0x50 kernel/locking/spinlock.c:228
   ap_get drivers/net/ppp/ppp_async.c:136 [inline]
   ppp_asynctty_wakeup+0x20/0x210 drivers/net/ppp/ppp_async.c:352
   tty_wakeup+0xbb/0x100 drivers/tty/tty_io.c:523
   tty_port_default_wakeup+0xa6/0xf0 drivers/tty/tty_port.c:69
   serial8250_tx_chars+0x6ad/0x8a0 drivers/tty/serial/8250/8250_port.c:1835
   __start_tx+0x32e/0x470 drivers/tty/serial/8250/8250_port.c:1544
   serial_port_runtime_resume+0x1f0/0x2b0 drivers/tty/serial/serial_port.c:40
   __rpm_callback+0x2df/0x790 drivers/base/power/runtime.c:393
   rpm_callback drivers/base/power/runtime.c:447 [inline]
   rpm_resume+0x10b1/0x1af0 drivers/base/power/runtime.c:913
   pm_runtime_work+0x147/0x210 drivers/base/power/runtime.c:978
   process_one_work kernel/workqueue.c:2633 [inline]
   process_scheduled_works+0x913/0x1420 kernel/workqueue.c:2706
   worker_thread+0xa5f/0x1000 kernel/workqueue.c:2787
   kthread+0x2ef/0x390 kernel/kthread.c:388
   ret_from_fork+0x4b/0x80 arch/x86/kernel/process.c:147
   ret_from_fork_asm+0x1b/0x30 arch/x86/entry/entry_64.S:242

-> (disc_data_lock#2){.?..}-{2:2} {
   IN-HARDIRQ-R at:
                    lock_acquire+0x1e3/0x530 kernel/locking/lockdep.c:5754
                    __raw_read_lock include/linux/rwlock_api_smp.h:150 [inline]
                    _raw_read_lock+0x36/0x50 kernel/locking/spinlock.c:228
                    ap_get drivers/net/ppp/ppp_async.c:136 [inline]
                    ppp_asynctty_wakeup+0x20/0x210 drivers/net/ppp/ppp_async.c:352
                    tty_wakeup+0xbb/0x100 drivers/tty/tty_io.c:523
                    tty_port_default_wakeup+0xa6/0xf0 drivers/tty/tty_port.c:69
                    serial8250_tx_chars+0x6ad/0x8a0 drivers/tty/serial/8250/8250_port.c:1835
                    serial8250_handle_irq+0x558/0x710 drivers/tty/serial/8250/8250_port.c:1942
                    serial8250_default_handle_irq+0xd1/0x1f0 drivers/tty/serial/8250/8250_port.c:1962
                    serial8250_interrupt+0xa9/0x1f0 drivers/tty/serial/8250/8250_core.c:127
                    __handle_irq_event_percpu+0x289/0xa30 kernel/irq/handle.c:158
                    handle_irq_event_percpu kernel/irq/handle.c:193 [inline]
                    handle_irq_event+0x89/0x1f0 kernel/irq/handle.c:210
                    handle_edge_irq+0x25f/0xc20 kernel/irq/chip.c:831
                    generic_handle_irq_desc include/linux/irqdesc.h:161 [inline]
                    handle_irq arch/x86/kernel/irq.c:238 [inline]
                    __common_interrupt+0x138/0x230 arch/x86/kernel/irq.c:257
                    common_interrupt+0xa5/0xd0 arch/x86/kernel/irq.c:247
                    asm_common_interrupt+0x26/0x40 arch/x86/include/asm/idtentry.h:640
                    obj_cgroup_charge+0x34e/0x630
                    __memcg_slab_pre_alloc_hook+0x28d/0x2b0 mm/slub.c:1929
                    memcg_slab_pre_alloc_hook mm/slub.c:1950 [inline]
                    slab_pre_alloc_hook mm/slub.c:3766 [inline]
                    slab_alloc_node mm/slub.c:3842 [inline]
                    kmem_cache_alloc+0x202/0x340 mm/slub.c:3867
                    vm_area_dup+0x27/0x290 kernel/fork.c:480
                    dup_mmap kernel/fork.c:695 [inline]
                    dup_mm kernel/fork.c:1685 [inline]
                    copy_mm+0xd94/0x21b0 kernel/fork.c:1734
                    copy_process+0x1d73/0x3fc0 kernel/fork.c:2497
                    kernel_clone+0x21d/0x8d0 kernel/fork.c:2902
                    __do_compat_sys_ia32_clone arch/x86/kernel/sys_ia32.c:254 [inline]
                    __se_compat_sys_ia32_clone arch/x86/kernel/sys_ia32.c:240 [inline]
                    __ia32_compat_sys_ia32_clone+0x255/0x2a0 arch/x86/kernel/sys_ia32.c:240
                    do_syscall_32_irqs_on arch/x86/entry/common.c:165 [inline]
                    __do_fast_syscall_32+0xbd/0x120 arch/x86/entry/common.c:321
                    do_fast_syscall_32+0x33/0x70 arch/x86/entry/common.c:346
                    entry_SYSENTER_compat_after_hwframe+0x7c/0x86
   HARDIRQ-ON-R at:
                    lock_acquire+0x1e3/0x530 kernel/locking/lockdep.c:5754
                    __raw_read_lock include/linux/rwlock_api_smp.h:150 [inline]
                    _raw_read_lock+0x36/0x50 kernel/locking/spinlock.c:228
                    ap_get drivers/net/ppp/ppp_async.c:136 [inline]
                    ppp_asynctty_receive+0x40/0x2000 drivers/net/ppp/ppp_async.c:335
                    tty_ldisc_receive_buf+0x11f/0x170 drivers/tty/tty_buffer.c:390
                    tty_port_default_receive_buf+0x6d/0xa0 drivers/tty/tty_port.c:37
                    receive_buf drivers/tty/tty_buffer.c:444 [inline]
                    flush_to_ldisc+0x328/0x860 drivers/tty/tty_buffer.c:494
                    process_one_work kernel/workqueue.c:2633 [inline]
                    process_scheduled_works+0x913/0x1420 kernel/workqueue.c:2706
                    worker_thread+0xa5f/0x1000 kernel/workqueue.c:2787
                    kthread+0x2ef/0x390 kernel/kthread.c:388
                    ret_from_fork+0x4b/0x80 arch/x86/kernel/process.c:147
                    ret_from_fork_asm+0x1b/0x30 arch/x86/entry/entry_64.S:242
   INITIAL USE at:
                   lock_acquire+0x1e3/0x530 kernel/locking/lockdep.c:5754
                   __raw_write_lock_irq include/linux/rwlock_api_smp.h:195 [inline]
                   _raw_write_lock_irq+0xd3/0x120 kernel/locking/spinlock.c:326
                   ppp_asynctty_close+0x29/0x190 drivers/net/ppp/ppp_async.c:219
                   tty_ldisc_kill+0xa3/0x1a0 drivers/tty/tty_ldisc.c:607
                   tty_ldisc_release+0x1a1/0x200 drivers/tty/tty_ldisc.c:775
                   tty_release_struct+0x2b/0xe0 drivers/tty/tty_io.c:1696
                   tty_release+0xd0c/0x12c0 drivers/tty/tty_io.c:1867
                   __fput+0x429/0x8a0 fs/file_table.c:376
                   __do_sys_close fs/open.c:1554 [inline]
                   __se_sys_close fs/open.c:1539 [inline]
                   __ia32_sys_close+0x7e/0x110 fs/open.c:1539
                   do_syscall_32_irqs_on arch/x86/entry/common.c:165 [inline]
                   __do_fast_syscall_32+0xbd/0x120 arch/x86/entry/common.c:321
                   do_fast_syscall_32+0x33/0x70 arch/x86/entry/common.c:346
                   entry_SYSENTER_compat_after_hwframe+0x7c/0x86
   INITIAL READ USE at:
                        lock_acquire+0x1e3/0x530 kernel/locking/lockdep.c:5754
                        __raw_read_lock include/linux/rwlock_api_smp.h:150 [inline]
                        _raw_read_lock+0x36/0x50 kernel/locking/spinlock.c:228
                        ap_get drivers/net/ppp/ppp_async.c:136 [inline]
                        ppp_asynctty_wakeup+0x20/0x210 drivers/net/ppp/ppp_async.c:352
                        tty_wakeup+0xbb/0x100 drivers/tty/tty_io.c:523
                        tty_port_default_wakeup+0xa6/0xf0 drivers/tty/tty_port.c:69
                        serial8250_tx_chars+0x6ad/0x8a0 drivers/tty/serial/8250/8250_port.c:1835
                        __start_tx+0x32e/0x470 drivers/tty/serial/8250/8250_port.c:1544
                        serial_port_runtime_resume+0x1f0/0x2b0 drivers/tty/serial/serial_port.c:40
                        __rpm_callback+0x2df/0x790 drivers/base/power/runtime.c:393
                        rpm_callback drivers/base/power/runtime.c:447 [inline]
                        rpm_resume+0x10b1/0x1af0 drivers/base/power/runtime.c:913
                        pm_runtime_work+0x147/0x210 drivers/base/power/runtime.c:978
                        process_one_work kernel/workqueue.c:2633 [inline]
                        process_scheduled_works+0x913/0x1420 kernel/workqueue.c:2706
                        worker_thread+0xa5f/0x1000 kernel/workqueue.c:2787
                        kthread+0x2ef/0x390 kernel/kthread.c:388
                        ret_from_fork+0x4b/0x80 arch/x86/kernel/process.c:147
                        ret_from_fork_asm+0x1b/0x30 arch/x86/entry/entry_64.S:242
 }
 ... key      at: [<ffffffff8ec04eb8>] disc_data_lock+0x18/0x60
 ... acquired at:
   mark_lock+0x223/0x350 kernel/locking/lockdep.c:4678
   mark_usage kernel/locking/lockdep.c:4579 [inline]
   __lock_acquire+0x10e0/0x1fd0 kernel/locking/lockdep.c:5091
   lock_acquire+0x1e3/0x530 kernel/locking/lockdep.c:5754
   __raw_read_lock include/linux/rwlock_api_smp.h:150 [inline]
   _raw_read_lock+0x36/0x50 kernel/locking/spinlock.c:228
   ap_get drivers/net/ppp/ppp_async.c:136 [inline]
   ppp_asynctty_receive+0x40/0x2000 drivers/net/ppp/ppp_async.c:335
   tty_ldisc_receive_buf+0x11f/0x170 drivers/tty/tty_buffer.c:390
   tty_port_default_receive_buf+0x6d/0xa0 drivers/tty/tty_port.c:37
   receive_buf drivers/tty/tty_buffer.c:444 [inline]
   flush_to_ldisc+0x328/0x860 drivers/tty/tty_buffer.c:494
   process_one_work kernel/workqueue.c:2633 [inline]
   process_scheduled_works+0x913/0x1420 kernel/workqueue.c:2706
   worker_thread+0xa5f/0x1000 kernel/workqueue.c:2787
   kthread+0x2ef/0x390 kernel/kthread.c:388
   ret_from_fork+0x4b/0x80 arch/x86/kernel/process.c:147
   ret_from_fork_asm+0x1b/0x30 arch/x86/entry/entry_64.S:242

stack backtrace:
CPU: 1 PID: 1097 Comm: kworker/u4:7 Not tainted 6.8.0-rc3-syzkaller-00041-g547ab8fc4cb0 #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/25/2024
Workqueue: events_unbound flush_to_ldisc
Call Trace:
 <TASK>
 __dump_stack lib/dump_stack.c:88 [inline]
 dump_stack_lvl+0x1e7/0x2e0 lib/dump_stack.c:106
 mark_lock_irq+0x867/0xc20 kernel/locking/lockdep.c:4236
 mark_lock+0x223/0x350 kernel/locking/lockdep.c:4678
 mark_usage kernel/locking/lockdep.c:4579 [inline]
 __lock_acquire+0x10e0/0x1fd0 kernel/locking/lockdep.c:5091
 lock_acquire+0x1e3/0x530 kernel/locking/lockdep.c:5754
 __raw_read_lock include/linux/rwlock_api_smp.h:150 [inline]
 _raw_read_lock+0x36/0x50 kernel/locking/spinlock.c:228
 ap_get drivers/net/ppp/ppp_async.c:136 [inline]
 ppp_asynctty_receive+0x40/0x2000 drivers/net/ppp/ppp_async.c:335
 tty_ldisc_receive_buf+0x11f/0x170 drivers/tty/tty_buffer.c:390
 tty_port_default_receive_buf+0x6d/0xa0 drivers/tty/tty_port.c:37
 receive_buf drivers/tty/tty_buffer.c:444 [inline]
 flush_to_ldisc+0x328/0x860 drivers/tty/tty_buffer.c:494
 process_one_work kernel/workqueue.c:2633 [inline]
 process_scheduled_works+0x913/0x1420 kernel/workqueue.c:2706
 worker_thread+0xa5f/0x1000 kernel/workqueue.c:2787
 kthread+0x2ef/0x390 kernel/kthread.c:388
 ret_from_fork+0x4b/0x80 arch/x86/kernel/process.c:147
 ret_from_fork_asm+0x1b/0x30 arch/x86/entry/entry_64.S:242
 </TASK>

This is the stack trace for the issue causing the deadlock reported 
by syzbot. I think there is definitely a problem with ap_get() and 
this needs to be fixed.

Thanks.