INFO: rcu detected stall in disk_check_events

[Haichi Wang]

Dear Linux maintainers and reviewers:

We would like to report a linux kernel bug, found by a modified version of syzkaller.

May affected file: fs/jbd2/transaction.c

Kernel Version: 7e57714cd0ad2d5bb90e50b5096a0e671dec1ef3 (v5.17-rc6)

Kernel Config: see attach, linux.config

Syzkaller Version: 3666edfeb55080ebe138d77417fa96fe2555d6bb

reproducing program: see attach, reproducing.txt.

 

To use the reproducing program, please follow https://github.com/google/syzkaller/blob/master/docs/reproducing_crashes.md for more details.

Feel free to  email us if any other infomations are needed. Hope the provided materials will help finding and fixing the bug.

The full log crash log are as follows:(also in the attach, crash.report)

---------

rcu: INFO: rcu_preempt self-detected stall on CPU
rcu: 	0-...!: (23 ticks this GP) idle=0e5/1/0x4000000000000000 softirq=323415/323417 fqs=1 
	(t=29452 jiffies g=531885 q=18)
NMI backtrace for cpu 0
CPU: 0 PID: 5 Comm: kworker/0:0 Not tainted 5.17.0-rc6 #7
Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.13.0-1ubuntu1.1 04/01/2014
Workqueue: events_freezable_power_ disk_events_workfn
Call Trace:
 <IRQ>
 __dump_stack lib/dump_stack.c:88 [inline]
 dump_stack_lvl+0x4d/0x66 lib/dump_stack.c:106
 nmi_cpu_backtrace.cold+0xd0/0xd5 lib/nmi_backtrace.c:111
 nmi_trigger_cpumask_backtrace+0x1a9/0x1e0 lib/nmi_backtrace.c:62
 trigger_single_cpu_backtrace include/linux/nmi.h:164 [inline]
 rcu_dump_cpu_stacks+0x204/0x2e0 kernel/rcu/tree_stall.h:343
 print_cpu_stall kernel/rcu/tree_stall.h:604 [inline]
 check_cpu_stall kernel/rcu/tree_stall.h:688 [inline]
 rcu_pending kernel/rcu/tree.c:3919 [inline]
 rcu_sched_clock_irq.cold+0x7f/0x5ed kernel/rcu/tree.c:2617
 update_process_times+0x14d/0x1d0 kernel/time/timer.c:1785
 tick_sched_handle.isra.0+0x105/0x150 kernel/time/tick-sched.c:226
 tick_sched_timer+0xd6/0x100 kernel/time/tick-sched.c:1428
 __run_hrtimer kernel/time/hrtimer.c:1685 [inline]
 __hrtimer_run_queues+0x2e0/0x6f0 kernel/time/hrtimer.c:1749
 hrtimer_interrupt+0x2f3/0x700 kernel/time/hrtimer.c:1811
 local_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1086 [inline]
 __sysvec_apic_timer_interrupt+0x111/0x370 arch/x86/kernel/apic/apic.c:1103
 sysvec_apic_timer_interrupt+0x89/0xc0 arch/x86/kernel/apic/apic.c:1097
 </IRQ>
 <TASK>
 asm_sysvec_apic_timer_interrupt+0x12/0x20 arch/x86/include/asm/idtentry.h:638
RIP: 0010:__raw_spin_unlock_irqrestore include/linux/spinlock_api_smp.h:152 [inline]
RIP: 0010:_raw_spin_unlock_irqrestore+0x38/0x70 kernel/locking/spinlock.c:194
Code: 48 89 fa 48 c1 ea 03 0f b6 04 02 48 89 fa 83 e2 07 38 d0 7f 04 84 c0 75 30 c6 07 00 f7 c6 00 02 00 00 74 01 fb bf 01 00 00 00 <e8> a3 53 93 fd 65 8b 05 7c a2 19 63 85 c0 74 05 48 83 c4 10 c3 0f
RSP: 0018:ffff8881001ef6a8 EFLAGS: 00000206
RAX: 0000000000000000 RBX: ffff888103388000 RCX: ffffffff9bdd63c5
RDX: 0000000000000000 RSI: 0000000000000246 RDI: 0000000000000001
RBP: ffff8881037bb3c0 R08: 0000000000000001 R09: ffffed1023646abd
R10: ffff88811b2355e3 R11: ffffed1023646abc R12: 0000000000000000
R13: 0000000000000246 R14: ffff888103388010 R15: ffffffff9e310820
 spin_unlock_irqrestore include/linux/spinlock.h:404 [inline]
 ata_scsi_queuecmd+0xdc/0x160 drivers/ata/libata-scsi.c:4040
 scsi_dispatch_cmd drivers/scsi/scsi_lib.c:1560 [inline]
 scsi_queue_rq+0x13d3/0x28b0 drivers/scsi/scsi_lib.c:1749
 blk_mq_dispatch_rq_list+0x8de/0x20b0 block/blk-mq.c:1855
 __blk_mq_sched_dispatch_requests+0x277/0x4c0 block/blk-mq-sched.c:299
 blk_mq_sched_dispatch_requests+0xd8/0x140 block/blk-mq-sched.c:332
 __blk_mq_run_hw_queue+0x94/0x180 block/blk-mq.c:1972
 __blk_mq_delay_run_hw_queue+0x492/0x590 block/blk-mq.c:2049
 blk_mq_run_hw_queue+0x1f7/0x2b0 block/blk-mq.c:2100
 blk_mq_sched_insert_request+0x25c/0x3b0 block/blk-mq-sched.c:451
 blk_execute_rq+0xc6/0x280 block/blk-mq.c:1235
 __scsi_execute+0x27b/0x580 drivers/scsi/scsi_lib.c:244
 scsi_execute_req include/scsi/scsi_device.h:469 [inline]
 sr_get_events drivers/scsi/sr.c:214 [inline]
 sr_check_events+0x174/0x8d0 drivers/scsi/sr.c:254
 cdrom_update_events drivers/cdrom/cdrom.c:1490 [inline]
 cdrom_check_events+0x61/0x110 drivers/cdrom/cdrom.c:1500
 sr_block_check_events+0x173/0x260 drivers/scsi/sr.c:606
 disk_check_events+0xbe/0x340 block/disk-events.c:193
 process_one_work+0x870/0x1200 kernel/workqueue.c:2307
 worker_thread+0x93/0xed0 kernel/workqueue.c:2454
 kthread+0x285/0x330 kernel/kthread.c:377
 ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:295
 </TASK>
----------------
Code disassembly (best guess):
   0:	48 89 fa             	mov    %rdi,%rdx
   3:	48 c1 ea 03          	shr    $0x3,%rdx
   7:	0f b6 04 02          	movzbl (%rdx,%rax,1),%eax
   b:	48 89 fa             	mov    %rdi,%rdx
   e:	83 e2 07             	and    $0x7,%edx
  11:	38 d0                	cmp    %dl,%al
  13:	7f 04                	jg     0x19
  15:	84 c0                	test   %al,%al
  17:	75 30                	jne    0x49
  19:	c6 07 00             	movb   $0x0,(%rdi)
  1c:	f7 c6 00 02 00 00    	test   $0x200,%esi
  22:	74 01                	je     0x25
  24:	fb                   	sti
  25:	bf 01 00 00 00       	mov    $0x1,%edi
* 2a:	e8 a3 53 93 fd       	callq  0xfd9353d2 <-- trapping instruction
  2f:	65 8b 05 7c a2 19 63 	mov    %gs:0x6319a27c(%rip),%eax        # 0x6319a2b2
  36:	85 c0                	test   %eax,%eax
  38:	74 05                	je     0x3f
  3a:	48 83 c4 10          	add    $0x10,%rsp
  3e:	c3                   	retq
  3f:	0f                   	.byte 0xf

Yours,

Haichi Wang