[Bug] INFO: task hung in lock_sock_nested

[Sam Sun]

Dear developers and maintainers,

We encountered a bug in net core. It is tested on linux kernel
6.8.0-rc7. Kernel config and C repro are attached to this email. Bug
report is listed below.

```
INFO: task syz-executor301:8111 blocked for more than 143 seconds.
      Not tainted 6.7.0-rc7 #1
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor301 state:D stack:27968 pid:8111  tgid:8111
ppid:8110   flags:0x00004006
Call Trace:
 <TASK>
 context_switch kernel/sched/core.c:5376 [inline]
 __schedule+0xcea/0x59e0 kernel/sched/core.c:6688
 __schedule_loop kernel/sched/core.c:6763 [inline]
 schedule+0xe9/0x270 kernel/sched/core.c:6778
 __lock_sock+0x141/0x260 net/core/sock.c:2944
 lock_sock_nested+0xda/0xf0 net/core/sock.c:3524
 lock_sock include/net/sock.h:1720 [inline]
 l2cap_sock_shutdown+0xc6/0x1060 net/bluetooth/l2cap_sock.c:1306
 nbd_mark_nsock_dead+0xae/0x5c0 drivers/block/nbd.c:303
 sock_shutdown+0x17c/0x280 drivers/block/nbd.c:377
 nbd_start_device_ioctl drivers/block/nbd.c:1446 [inline]
 __nbd_ioctl drivers/block/nbd.c:1511 [inline]
 nbd_ioctl+0xc08/0xd70 drivers/block/nbd.c:1551
 blkdev_ioctl+0x2f2/0x750 block/ioctl.c:633
 vfs_ioctl fs/ioctl.c:51 [inline]
 __do_sys_ioctl fs/ioctl.c:871 [inline]
 __se_sys_ioctl fs/ioctl.c:857 [inline]
 __x64_sys_ioctl+0x19d/0x210 fs/ioctl.c:857
 do_syscall_x64 arch/x86/entry/common.c:52 [inline]
 do_syscall_64+0x40/0x110 arch/x86/entry/common.c:83
 entry_SYSCALL_64_after_hwframe+0x63/0x6b
RIP: 0033:0x7f7335e2c18d
RSP: 002b:00007ffd088318f8 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: ffffffffffffffda RBX: 00007ffd08831b58 RCX: 00007f7335e2c18d
RDX: 0000000000000000 RSI: 000000000000ab03 RDI: 0000000000000003
RBP: 0000000000000000 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000001
R13: 431bde82d7b634db R14: 00007f7335ea94f0 R15: 0000000000000001
 </TASK>

Showing all locks held in the system:
1 lock held by khungtaskd/32:
 #0: ffffffff8cfa9a60 (rcu_read_lock){....}-{1:2}, at:
rcu_lock_acquire include/linux/rcupdate.h:301 [inline]
 #0: ffffffff8cfa9a60 (rcu_read_lock){....}-{1:2}, at: rcu_read_lock
include/linux/rcupdate.h:747 [inline]
 #0: ffffffff8cfa9a60 (rcu_read_lock){....}-{1:2}, at:
debug_show_all_locks+0x75/0x340 kernel/locking/lockdep.c:6614
3 locks held by kworker/u9:0/54:
 #0: ffff8881053de538 ((wq_completion)nbd0-recv){+.+.}-{0:0}, at:
process_one_work+0x77b/0x15c0 kernel/workqueue.c:2602
 #1: ffffc90000defd88 ((work_completion)(&args->work)){+.+.}-{0:0},
at: process_one_work+0x7dd/0x15c0 kernel/workqueue.c:2603
 #2: ffff88801c94e130
(sk_lock-AF_BLUETOOTH-BTPROTO_L2CAP){+.+.}-{0:0}, at: lock_sock
include/net/sock.h:1720 [inline]
 #2: ffff88801c94e130
(sk_lock-AF_BLUETOOTH-BTPROTO_L2CAP){+.+.}-{0:0}, at:
bt_sock_recvmsg+0xcb/0x750 net/bluetooth/af_bluetooth.c:312
1 lock held by in:imklog/7716:
 #0: ffff88801babb888 (&f->f_pos_lock){+.+.}-{3:3}, at:
__fdget_pos+0xdb/0x160 fs/file.c:1177
2 locks held by syz-executor301/8111:
 #0: ffff88810cddeb70 (&nsock->tx_lock){+.+.}-{3:3}, at:
sock_shutdown+0x16f/0x280 drivers/block/nbd.c:376
 #1: ffff88801c94e130
(sk_lock-AF_BLUETOOTH-BTPROTO_L2CAP){+.+.}-{0:0}, at: lock_sock
include/net/sock.h:1720 [inline]
 #1: ffff88801c94e130
(sk_lock-AF_BLUETOOTH-BTPROTO_L2CAP){+.+.}-{0:0}, at:
l2cap_sock_shutdown+0xc6/0x1060 net/bluetooth/l2cap_sock.c:1306
```

NMI backtrace seems not relevant to this bug, but will be attached to
this email.

If you have any questions, please contact us.
Reported by: Yue Sun <samsun1006219@xxxxxxxxx>
Reported by: xingwei lee <xrivendell7@xxxxxxxxx>

Best Regards,
Yue

Attachment: config
Description: Binary data

// autogenerated by syzkaller (https://github.com/google/syzkaller)

#define _GNU_SOURCE

#include <dirent.h>
#include <endian.h>
#include <errno.h>
#include <fcntl.h>
#include <signal.h>
#include <stdarg.h>
#include <stdbool.h>
#include <stdint.h>
#include <stdio.h>
#include <stdlib.h>
#include <string.h>
#include <sys/prctl.h>
#include <sys/stat.h>
#include <sys/syscall.h>
#include <sys/types.h>
#include <sys/wait.h>
#include <time.h>
#include <unistd.h>

static void sleep_ms(uint64_t ms)
{
  usleep(ms * 1000);
}

static uint64_t current_time_ms(void)
{
  struct timespec ts;
  if (clock_gettime(CLOCK_MONOTONIC, &ts))
    exit(1);
  return (uint64_t)ts.tv_sec * 1000 + (uint64_t)ts.tv_nsec / 1000000;
}

static bool write_file(const char* file, const char* what, ...)
{
  char buf[1024];
  va_list args;
  va_start(args, what);
  vsnprintf(buf, sizeof(buf), what, args);
  va_end(args);
  buf[sizeof(buf) - 1] = 0;
  int len = strlen(buf);
  int fd = open(file, O_WRONLY | O_CLOEXEC);
  if (fd == -1)
    return false;
  if (write(fd, buf, len) != len) {
    int err = errno;
    close(fd);
    errno = err;
    return false;
  }
  close(fd);
  return true;
}

const int kInitNetNsFd = 201;

static long syz_open_dev(volatile long a0, volatile long a1, volatile long a2)
{
  if (a0 == 0xc || a0 == 0xb) {
    char buf[128];
    sprintf(buf, "/dev/%s/%d:%d", a0 == 0xc ? "char" : "block", (uint8_t)a1,
            (uint8_t)a2);
    return open(buf, O_RDWR, 0);
  } else {
    char buf[1024];
    char* hash;
    strncpy(buf, (char*)a0, sizeof(buf) - 1);
    buf[sizeof(buf) - 1] = 0;
    while ((hash = strchr(buf, '#'))) {
      *hash = '0' + (char)(a1 % 10);
      a1 /= 10;
    }
    return open(buf, a2, 0);
  }
}

static long syz_init_net_socket(volatile long domain, volatile long type,
                                volatile long proto)
{
  return syscall(__NR_socket, domain, type, proto);
}

static void kill_and_wait(int pid, int* status)
{
  kill(-pid, SIGKILL);
  kill(pid, SIGKILL);
  for (int i = 0; i < 100; i++) {
    if (waitpid(-1, status, WNOHANG | __WALL) == pid)
      return;
    usleep(1000);
  }
  DIR* dir = opendir("/sys/fs/fuse/connections");
  if (dir) {
    for (;;) {
      struct dirent* ent = readdir(dir);
      if (!ent)
        break;
      if (strcmp(ent->d_name, ".") == 0 || strcmp(ent->d_name, "..") == 0)
        continue;
      char abort[300];
      snprintf(abort, sizeof(abort), "/sys/fs/fuse/connections/%s/abort",
               ent->d_name);
      int fd = open(abort, O_WRONLY);
      if (fd == -1) {
        continue;
      }
      if (write(fd, abort, 1) < 0) {
      }
      close(fd);
    }
    closedir(dir);
  } else {
  }
  while (waitpid(-1, status, __WALL) != pid) {
  }
}

static void setup_test()
{
  prctl(PR_SET_PDEATHSIG, SIGKILL, 0, 0, 0);
  setpgrp();
  write_file("/proc/self/oom_score_adj", "1000");
}

static void execute_one(void);

#define WAIT_FLAGS __WALL

static void loop(void)
{
  int iter = 0;
  for (;; iter++) {
    int pid = fork();
    if (pid < 0)
      exit(1);
    if (pid == 0) {
      setup_test();
      execute_one();
      exit(0);
    }

    int status = 0;
    uint64_t start = current_time_ms();
    for (;;) {
      if (waitpid(-1, &status, WNOHANG | WAIT_FLAGS) == pid)
        break;
      sleep_ms(1);
      if (current_time_ms() - start < 5000)
        continue;
      kill_and_wait(pid, &status);
      break;
    }
  }
}

uint64_t r[4] = {0xffffffffffffffff, 0xffffffffffffffff, 0xffffffffffffffff,
                 0xffffffffffffffff};

void execute_one(void)
{
  intptr_t res = 0;
  memcpy((void*)0x20000000, "/dev/nbd#\000", 10);
  res = -1;
  res = syz_open_dev(/*dev=*/0x20000000, /*id=*/0, /*flags=*/0);
  if (res != -1)
    r[0] = res;
  res = -1;
  res = syz_init_net_socket(/*fam=*/0x1f, /*type=*/3, /*proto=*/0);
  if (res != -1)
    r[1] = res;
  memcpy((void*)0x20000080,
         "/sys/devices/pnp0/00:05/rtc/rtc0/max_user_freq\000", 47);
  res = syscall(__NR_openat, /*fd=*/0xffffffffffffff9cul, /*file=*/0x20000080ul,
                /*flags=*/2ul, /*mode=*/0ul);
  if (res != -1)
    r[2] = res;
  res = syscall(__NR_dup2, /*oldfd=*/r[1], /*newfd=*/r[2]);
  if (res != -1)
    r[3] = res;
  syscall(__NR_ioctl, /*fd=*/r[0], /*cmd=*/0xab00, /*arg=*/r[3]);
  syscall(__NR_ioctl, /*fd=*/r[0], /*cmd=*/0xab03, 0);
}
int main(void)
{
  syscall(__NR_mmap, /*addr=*/0x1ffff000ul, /*len=*/0x1000ul, /*prot=*/0ul,
          /*flags=*/0x32ul, /*fd=*/-1, /*offset=*/0ul);
  syscall(__NR_mmap, /*addr=*/0x20000000ul, /*len=*/0x1000000ul, /*prot=*/7ul,
          /*flags=*/0x32ul, /*fd=*/-1, /*offset=*/0ul);
  syscall(__NR_mmap, /*addr=*/0x21000000ul, /*len=*/0x1000ul, /*prot=*/0ul,
          /*flags=*/0x32ul, /*fd=*/-1, /*offset=*/0ul);
  loop();
  return 0;
}
NMI backtrace for cpu 0
CPU: 0 PID: 32 Comm: khungtaskd Not tainted 6.7.0-rc7 #1
Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.15.0-1 04/01/2014
Call Trace:
 <TASK>
 __dump_stack lib/dump_stack.c:88 [inline]
 dump_stack_lvl+0xd9/0x150 lib/dump_stack.c:106
 nmi_cpu_backtrace+0x29c/0x350 lib/nmi_backtrace.c:113
 nmi_trigger_cpumask_backtrace+0x299/0x300 lib/nmi_backtrace.c:62
 trigger_all_cpu_backtrace include/linux/nmi.h:160 [inline]
 check_hung_uninterruptible_tasks kernel/hung_task.c:222 [inline]
 watchdog+0xe7a/0x1100 kernel/hung_task.c:379
 kthread+0x2cc/0x3b0 kernel/kthread.c:388
 ret_from_fork+0x45/0x80 arch/x86/kernel/process.c:147
 ret_from_fork_asm+0x11/0x20 arch/x86/entry/entry_64.S:242
 </TASK>
Sending NMI from CPU 0 to CPUs 1:
NMI backtrace for cpu 1
CPU: 1 PID: 4522 Comm: systemd-journal Not tainted 6.7.0-rc7 #1
Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.15.0-1 04/01/2014
RIP: 0010:unwind_next_frame+0x4df/0x2220 arch/x86/kernel/unwind_orc.c:505
Code: 00 00 00 00 fc ff df 4c 89 ea 48 c1 ea 03 0f b6 04 02 4c 89 ea 83 e2 07 38 d0 7f 08 84 c0 0f 85 7d 18 00 00 45 0f b6 7c 24 05 <31> ff 41 83 e7 07 44 89 fe e8 53 b5 4b 00 45 84 ff 0f 84 95 fe ff
RSP: 0000:ffffc900026ff528 EFLAGS: 00000246
RAX: 0000000000000000 RBX: ffffc900026ff5a0 RCX: ffffffff81394c34
RDX: 0000000000000001 RSI: ffffffff81395b2d RDI: 0000000000000006
RBP: 0000000000000001 R08: 0000000000000006 R09: ffffffff81c4b482
R10: ffffffff81c4ad0e R11: 0000000000000000 R12: ffffffff8fb00944
R13: ffffffff8fb00949 R14: ffffc900026ff5d5 R15: 0000000000000002
FS:  00007fb6f2bf3900(0000) GS:ffff888135c00000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007fb6f0e56720 CR3: 00000000194fd000 CR4: 0000000000750ef0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
PKRU: 55555554
Call Trace:
 <NMI>
 </NMI>
 <TASK>
 arch_stack_walk+0xe0/0x160 arch/x86/kernel/stacktrace.c:25
 stack_trace_save+0x90/0xc0 kernel/stacktrace.c:122
 kasan_save_stack+0x22/0x40 mm/kasan/common.c:45
 kasan_set_track+0x25/0x30 mm/kasan/common.c:52
 __kasan_slab_alloc+0x7f/0x90 mm/kasan/common.c:328
 kasan_slab_alloc include/linux/kasan.h:188 [inline]
 slab_post_alloc_hook mm/slab.h:763 [inline]
 slab_alloc_node mm/slab.c:3237 [inline]
 slab_alloc mm/slab.c:3246 [inline]
 __kmem_cache_alloc_lru mm/slab.c:3423 [inline]
 kmem_cache_alloc+0x2aa/0x370 mm/slab.c:3432
 kmem_cache_zalloc include/linux/slab.h:711 [inline]
 jbd2_alloc_handle include/linux/jbd2.h:1595 [inline]
 new_handle fs/jbd2/transaction.c:476 [inline]
 jbd2__journal_start+0x195/0x850 fs/jbd2/transaction.c:503
 __ext4_journal_start_sb+0x342/0x5d0 fs/ext4/ext4_jbd2.c:112
 __ext4_journal_start fs/ext4/ext4_jbd2.h:326 [inline]
 ext4_dirty_inode+0xa5/0x130 fs/ext4/inode.c:5962
 __mark_inode_dirty+0x1e0/0xd80 fs/fs-writeback.c:2452
 generic_update_time+0xcb/0xf0 fs/inode.c:1943
 inode_update_time fs/inode.c:1956 [inline]
 __file_update_time fs/inode.c:2144 [inline]
 file_update_time+0x132/0x160 fs/inode.c:2174
 ext4_page_mkwrite+0x352/0x16b0 fs/ext4/inode.c:6083
 do_page_mkwrite+0x181/0x390 mm/memory.c:2944
 wp_page_shared mm/memory.c:3339 [inline]
 do_wp_page+0x793/0x3580 mm/memory.c:3479
 handle_pte_fault mm/memory.c:5055 [inline]
 __handle_mm_fault+0x15b8/0x3c40 mm/memory.c:5180
 handle_mm_fault+0x3c2/0xa30 mm/memory.c:5345
 do_user_addr_fault+0x2ed/0xff0 arch/x86/mm/fault.c:1364
 handle_page_fault arch/x86/mm/fault.c:1505 [inline]
 exc_page_fault+0x99/0x180 arch/x86/mm/fault.c:1561
 asm_exc_page_fault+0x26/0x30 arch/x86/include/asm/idtentry.h:570
RIP: 0033:0x7fb6f33c5fde
Code: 40 38 00 00 00 00 4c 89 e8 48 f7 f1 48 8b 85 d8 00 00 00 48 c1 e2 04 48 01 d0 49 89 d5 48 8b 50 08 48 85 d2 0f 85 32 03 00 00 <4c> 89 00 48 8b 85 d8 00 00 00 4e 89 44 28 08 48 8b 85 d0 00 00 00
RSP: 002b:00007fffb2f8dc50 EFLAGS: 00010246
RAX: 00007fb6f0e56720 RBX: 000055e64147e320 RCX: 000000000000acf8
RDX: 0000000000000000 RSI: 000055e64147e320 RDI: 00007fb6f0efe8e0
RBP: 000055e6414bd890 R08: 00000000000fe8a0 R09: 00000000000fe8a0
R10: 0000000000000002 R11: 7fffffffffffffff R12: 0000000000000025
R13: 0000000000055130 R14: 0000000000000000 R15: 00007fffb2f8dc70
 </TASK>
INFO: NMI handler (nmi_cpu_backtrace_handler) took too long to run: 3.714 msecs