ci starts bisection 2023-04-03 07:04:11.502638754 +0000 UTC m=+5001.825381267
bisecting fixing commit since 6e764bcd1cf72a2846c0e53d3975a09b242c04c9
building syzkaller on b599f2fcc734e2183016a340d4f6fc2891d8e41f
ensuring issue is reproducible on original commit 6e764bcd1cf72a2846c0e53d3975a09b242c04c9
testing commit 6e764bcd1cf72a2846c0e53d3975a09b242c04c9 gcc
compiler: gcc (Debian 10.2.1-6) 10.2.1 20210110, GNU ld (GNU Binutils for Debian) 2.35.2
kernel signature: 4b13c99e4588d7697076ea73ea5619c15fccaf6251611bc480256e36d37efef5
all runs: crashed: INFO: task hung in pn533_finalize_setup
testing current HEAD 7e364e56293bb98cae1b55fd835f5991c4e96e7d
testing commit 7e364e56293bb98cae1b55fd835f5991c4e96e7d gcc
compiler: gcc (Debian 10.2.1-6) 10.2.1 20210110, GNU ld (GNU Binutils for Debian) 2.35.2
kernel signature: c1e87726da2bf97e56dc7dafa8de0a91142a7d074d764765ca2e10cd505f3638
run #0: basic kernel testing failed: BUG: program execution failed: executor NUM: EOF
run #1: crashed: INFO: task hung in pn533_usb_send_frame
run #2: crashed: INFO: task hung in pn533_usb_send_frame
run #3: crashed: INFO: task hung in pn533_usb_send_frame
run #4: crashed: INFO: task hung in pn533_usb_send_frame
run #5: crashed: INFO: task hung in pn533_usb_send_frame
run #6: crashed: INFO: task hung in pn533_usb_send_frame
run #7: crashed: INFO: task hung in pn533_usb_send_frame
run #8: crashed: INFO: task hung in pn533_usb_send_frame
run #9: crashed: INFO: task hung in pn533_usb_send_frame
revisions tested: 2, total time: 27m57.339091778s (build: 15m24.040078254s, test: 11m18.858872205s)
the crash still happens on HEAD
commit msg: Linux 6.3-rc5
crash: INFO: task hung in pn533_usb_send_frame
INFO: task kworker/0:5:5074 blocked for more than 143 seconds.
Not tainted 6.3.0-rc5-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:kworker/0:5 state:D stack:25040 pid:5074 ppid:2 flags:0x00004000
Workqueue: usb_hub_wq hub_event
Call Trace:
context_switch kernel/sched/core.c:5307 [inline]
__schedule+0xa67/0x2e80 kernel/sched/core.c:6625
schedule+0xde/0x1a0 kernel/sched/core.c:6701
schedule_timeout+0x22d/0x270 kernel/time/timer.c:2143
do_wait_for_common kernel/sched/completion.c:85 [inline]
__wait_for_common+0x1ce/0x5c0 kernel/sched/completion.c:106
pn533_usb_send_frame+0x2b5/0x540 drivers/nfc/pn533/usb.c:187
__pn533_send_async+0x1ea/0x550 drivers/nfc/pn533/pn533.c:462
pn533_send_cmd_async drivers/nfc/pn533/pn533.c:501 [inline]
pn533_send_cmd_sync drivers/nfc/pn533/pn533.c:624 [inline]
pn533_get_firmware_version drivers/nfc/pn533/pn533.c:2523 [inline]
pn533_finalize_setup+0xe2/0x590 drivers/nfc/pn533/pn533.c:2720
pn533_usb_probe+0x9a0/0xf80 drivers/nfc/pn533/usb.c:583
usb_probe_interface+0x26c/0x820 drivers/usb/core/driver.c:396
call_driver_probe drivers/base/dd.c:552 [inline]
really_probe+0x1c7/0xb20 drivers/base/dd.c:631
__driver_probe_device+0x186/0x460 drivers/base/dd.c:768
driver_probe_device+0x44/0x110 drivers/base/dd.c:798
__device_attach_driver+0x14e/0x270 drivers/base/dd.c:926
bus_for_each_drv+0x102/0x190 drivers/base/bus.c:457
__device_attach+0x19e/0x3d0 drivers/base/dd.c:998
bus_probe_device+0x12b/0x170 drivers/base/bus.c:532
device_add+0xee4/0x1930 drivers/base/core.c:3589
usb_set_configuration+0xabc/0x1a20 drivers/usb/core/message.c:2171
usb_generic_driver_probe+0x88/0xd0 drivers/usb/core/generic.c:238
usb_probe_device+0x98/0x240 drivers/usb/core/driver.c:293
call_driver_probe drivers/base/dd.c:552 [inline]
really_probe+0x1c7/0xb20 drivers/base/dd.c:631
__driver_probe_device+0x186/0x460 drivers/base/dd.c:768
driver_probe_device+0x44/0x110 drivers/base/dd.c:798
__device_attach_driver+0x14e/0x270 drivers/base/dd.c:926
bus_for_each_drv+0x102/0x190 drivers/base/bus.c:457
__device_attach+0x19e/0x3d0 drivers/base/dd.c:998
bus_probe_device+0x12b/0x170 drivers/base/bus.c:532
device_add+0xee4/0x1930 drivers/base/core.c:3589
usb_new_device+0xc6e/0x1930 drivers/usb/core/hub.c:2575
hub_port_connect drivers/usb/core/hub.c:5407 [inline]
hub_port_connect_change drivers/usb/core/hub.c:5551 [inline]
port_event drivers/usb/core/hub.c:5711 [inline]
hub_event+0x24cc/0x4240 drivers/usb/core/hub.c:5793
process_one_work+0x865/0x1400 kernel/workqueue.c:2390
worker_thread+0x59c/0xec0 kernel/workqueue.c:2537
kthread+0x298/0x340 kernel/kthread.c:376
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:308
Showing all locks held in the system:
1 lock held by rcu_tasks_kthre/12:
#0: ffffffff8b1834f0 (rcu_tasks.tasks_gp_mutex){+.+.}-{3:3}, at: rcu_tasks_one_gp+0x31/0xd80 kernel/rcu/tasks.h:510
1 lock held by rcu_tasks_trace/13:
#0: ffffffff8b1831f0 (rcu_tasks_trace.tasks_gp_mutex){+.+.}-{3:3}, at: rcu_tasks_one_gp+0x31/0xd80 kernel/rcu/tasks.h:510
1 lock held by khungtaskd/28:
#0: ffffffff8b184040 (rcu_read_lock){....}-{1:2}, at: debug_show_all_locks+0x55/0x340 kernel/locking/lockdep.c:6495
2 locks held by kworker/u4:2/41:
2 locks held by kworker/u4:5/1021:
#0: ffff8880b9d3c1d8 (&rq->__lock){-.-.}-{2:2}, at: raw_spin_rq_lock_nested kernel/sched/core.c:539 [inline]
#0: ffff8880b9d3c1d8 (&rq->__lock){-.-.}-{2:2}, at: raw_spin_rq_lock kernel/sched/sched.h:1366 [inline]
#0: ffff8880b9d3c1d8 (&rq->__lock){-.-.}-{2:2}, at: rq_lock kernel/sched/sched.h:1653 [inline]
#0: ffff8880b9d3c1d8 (&rq->__lock){-.-.}-{2:2}, at: __schedule+0x263/0x2e80 kernel/sched/core.c:6542
#1: ffff8880b9d28808 (&per_cpu_ptr(group->pcpu, cpu)->seq){-.-.}-{0:0}, at: psi_task_switch+0x2d8/0x940 kernel/sched/psi.c:976
2 locks held by getty/4736:
#0: ffff888025975098 (&tty->ldisc_sem){++++}-{0:0}, at: tty_ldisc_ref_wait+0x23/0x80 drivers/tty/tty_ldisc.c:244
#1: ffffc900015902f0 (&ldata->atomic_read_lock){+.+.}-{3:3}, at: n_tty_read+0xb73/0x1040 drivers/tty/n_tty.c:2177
6 locks held by kworker/0:5/5074:
#0: ffff88801478ad38 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
#0: ffff88801478ad38 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: arch_atomic_long_set include/linux/atomic/atomic-long.h:41 [inline]
#0: ffff88801478ad38 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: atomic_long_set include/linux/atomic/atomic-instrumented.h:1280 [inline]
#0: ffff88801478ad38 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: set_work_data kernel/workqueue.c:639 [inline]
#0: ffff88801478ad38 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: set_work_pool_and_clear_pending kernel/workqueue.c:666 [inline]
#0: ffff88801478ad38 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: process_one_work+0x78a/0x1400 kernel/workqueue.c:2361
#1: ffffc90003a4fdb8 ((work_completion)(&hub->events)){+.+.}-{0:0}, at: process_one_work+0x7b7/0x1400 kernel/workqueue.c:2365
#2: ffff88801f225190 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:832 [inline]
#2: ffff88801f225190 (&dev->mutex){....}-{3:3}, at: hub_event+0x126/0x4240 drivers/usb/core/hub.c:5739
#3: ffff888020109190 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:832 [inline]
#3: ffff888020109190 (&dev->mutex){....}-{3:3}, at: __device_attach+0x71/0x3d0 drivers/base/dd.c:973
#4: ffff88807e797118 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:832 [inline]
#4: ffff88807e797118 (&dev->mutex){....}-{3:3}, at: __device_attach+0x71/0x3d0 drivers/base/dd.c:973
#5: ffff888024000438 (&priv->cmd_lock){+.+.}-{3:3}, at: __pn533_send_async+0x143/0x550 drivers/nfc/pn533/pn533.c:458
=============================================
NMI backtrace for cpu 1
CPU: 1 PID: 28 Comm: khungtaskd Not tainted 6.3.0-rc5-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 03/02/2023
Call Trace:
__dump_stack lib/dump_stack.c:88 [inline]
dump_stack_lvl+0x64/0xb0 lib/dump_stack.c:106
nmi_cpu_backtrace+0x175/0x200 lib/nmi_backtrace.c:113
nmi_trigger_cpumask_backtrace+0x1bc/0x200 lib/nmi_backtrace.c:62
trigger_all_cpu_backtrace include/linux/nmi.h:148 [inline]
check_hung_uninterruptible_tasks kernel/hung_task.c:222 [inline]
watchdog+0x9f9/0xcf0 kernel/hung_task.c:379
kthread+0x298/0x340 kernel/kthread.c:376
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:308
Sending NMI from CPU 1 to CPUs 0:
NMI backtrace for cpu 0
CPU: 0 PID: 4415 Comm: klogd Not tainted 6.3.0-rc5-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 03/02/2023
RIP: 0010:rcu_dynticks_curr_cpu_in_eqs include/linux/context_tracking.h:122 [inline]
RIP: 0010:rcu_is_watching+0x3d/0xb0 kernel/rcu/tree.c:694
Code: c7 c3 e8 6b 03 00 83 f8 07 89 c5 77 7a 48 8d 3c ed 80 49 aa 8a 48 b8 00 00 00 00 00 fc ff df 48 89 fa 48 c1 ea 03 80 3c 02 00 <75> 54 48 03 1c ed 80 49 aa 8a 48 b8 00 00 00 00 00 fc ff df 48 89
RSP: 0018:ffffc90002d4fac0 EFLAGS: 00000246
RAX: dffffc0000000000 RBX: 0000000000036be8 RCX: ffffffff8156fcb1
RDX: 1ffffffff1554930 RSI: ffffffff89635940 RDI: ffffffff8aaa4980
RBP: 0000000000000000 R08: 0000000000000000 R09: ffffffff8cf33fd7
R10: fffffbfff19e67fa R11: 0000000000000000 R12: 0000000000000000
R13: dffffc0000000000 R14: 0000000000000023 R15: 0000000000000351
FS: 00007fdef1c98800(0000) GS:ffff8880b9c00000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 0000000002933708 CR3: 0000000027228000 CR4: 00000000003506f0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
trace_contention_begin include/trace/events/lock.h:95 [inline]
trace_contention_begin+0xd8/0x100 include/trace/events/lock.h:95
__mutex_lock_common kernel/locking/mutex.c:605 [inline]
__mutex_lock+0x13c/0x1350 kernel/locking/mutex.c:747
syslog_print+0x2db/0x420 kernel/printk/printk.c:1640
do_syslog.part.0+0x1ba/0x470 kernel/printk/printk.c:1741
do_syslog kernel/printk/printk.c:1726 [inline]
__do_sys_syslog kernel/printk/printk.c:1833 [inline]
__se_sys_syslog kernel/printk/printk.c:1831 [inline]
__x64_sys_syslog+0x84/0xa0 kernel/printk/printk.c:1831
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x39/0x80 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x63/0xcd
RIP: 0033:0x7fdef1e338b7
Code: 73 01 c3 48 8b 0d c1 05 0c 00 f7 d8 64 89 01 48 83 c8 ff c3 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 44 00 00 b8 67 00 00 00 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d 91 05 0c 00 f7 d8 64 89 01 48
RSP: 002b:00007ffdddd46d28 EFLAGS: 00000206 ORIG_RAX: 0000000000000067
RAX: ffffffffffffffda RBX: 00007fdef1fc0490 RCX: 00007fdef1e338b7
RDX: 00000000000003ff RSI: 00007fdef1fc0490 RDI: 0000000000000002
RBP: 0000000000000000 R08: 0000000000000007 R09: 0000555c3783c1d0
R10: 0000000000004000 R11: 0000000000000206 R12: 00007fdef1fc0490
R13: 00007fdef1fc04f3 R14: 00007fdef1fc04f3 R15: 0000000000000000