tty: stall in n_tty_ioctl/inq_canon

From: Dmitry Vyukov
Date: Thu Jun 23 2016 - 06:16:36 EST

Next message: Thomas Gleixner: "Re: [RESEND PATCH v2 2/2] power/idle: enhance the precision of sleep_length"
Previous message: Thomas Gleixner: "Re: [PATCH V7] irq: Track the interrupt timings"
Messages sorted by: [ date ] [ thread ] [ subject ] [ author ]

Hello,

I've got the following stall while running syzkaller fuzzer on
4.3.5-based kernel:

NMI watchdog: BUG: soft lockup - CPU#0 stuck for 11s! [syz-executor:13407]
Modules linked in:
CPU: 0 PID: 13407 Comm: syz-executor Not tainted 4.3.5-smp-DEV #4
Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Bochs 01/01/2011
task: ffff88003db4d580 ti: ffff88003c0a8000 task.ti: ffff88003c0a8000
RIP: 0010:[<ffffffff8934ff59>]
[< inline >] variable_test_bit ././arch/x86/include/asm/bitops.h:318
[< inline >] inq_canon ./drivers/tty/n_tty.c:2514
[<ffffffff8934ff59>] n_tty_ioctl+0x1b9/0x270 ./drivers/tty/n_tty.c:2534
RSP: 0018:ffff88003c0abb90 EFLAGS: 00000202
RAX: ffffffffffffffe0 RBX: 00000000e011c95d RCX: 0000000000000000
RDX: 0000000000000000 RSI: ffffc9000184b060 RDI: ffffc9000184c268
RBP: ffff88003c0abbd8 R08: 0000000000000000 R09: dffffc0000000000
R10: 0000000000000000 R11: 0000000000000293 R12: 0000000020001fca
R13: ffffc9000184a000 R14: 000000000000095d R15: ffff88006d58a598
FS: 00007f3dfc590700(0000) GS:ffff88003ec00000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 000000008005003b
CR2: 0000000020001000 CR3: 000000003c418000 CR4: 00000000000006f0
Stack:
ffff88006d58a4c0 ffff88006d58a518 ffff88003b8a6ac0 000000000000541b
ffff88006d58a4c0 1ffff10007815780 ffff88003b8a6ac0 000000000000541b
ffff88006850bce0 ffff88003c0abdc8 ffffffff89348eb5 0000000000000000
Call Trace:
[<ffffffff89348eb5>] tty_ioctl+0x845/0x1dd0 ./drivers/tty/tty_io.c:2972
[< inline >] vfs_ioctl ./fs/ioctl.c:43
[<ffffffff88d0f54d>] do_vfs_ioctl+0x53d/0xda0 ./fs/ioctl.c:607
[< inline >] SYSC_ioctl ./fs/ioctl.c:622
[<ffffffff88d0fe29>] SyS_ioctl+0x79/0x90 ./fs/ioctl.c:613
[<ffffffff88880b97>] entry_SYSCALL_64_fastpath+0x12/0x17
./arch/x86/entry/entry_64.S:185
Code: 00 48 39 d9 74 70 48 89 c8 49 8d b5 60 10 00 00 49 b9 00 00 00 00 00 fc ff
df 48 29 d8 49 89 de 41 81 e6 ff 0f 00 00 4c 0f a3 36 <19> d2 85 d2 74 2b 4b 8d
7c 35 5e 48 89 fa 49 89 f8 48 c1 ea 03
IP: 0xffffffff8934fed9:
fed8 415c415b 415e415d 49c35d5f 48107d8d 000000b8 fffc0000 fa8948df 03eac148
fef8 00023c80 0103850f 8d490000 002268bd 00b84800 00000000 49dffffc 48104d8b
ff18 c148fa89 3c8003ea 850f0002 000000cb 689d8b49 48000022 7074d939 49c88948
ff38 1060b58d b9490000 00000000 dffffc00 49d82948 8141de89 000fffe6 a30f4c00
ff58 85d21936 4b2b74d2 5e357c8d 49fa8948 c148f889 834103ea 0f4207e0 440a14b6
ff78 047fc238 4c75d284 357c8043 8348015e 834800d8 394801c3 89b875d9 fef8e9c3
ff98 51e8ffff e9ff93c3 fffffe99 e7e9db31 e8fffffe ff93c390 fffe41e9 ef894cff
ffb8 93c383e8 fea3e9ff 79e8ffff e9ff93c3 fffffebf b84d894c c0458948 c8758948
ffd8 d04d8948 93c26fe8 4d8b4cff 458b48b8 758b48c0 4d8b48c8 488debd0 e8d04d89

SI: 0xffffc9000184afe0:
afe0 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
b000 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
b020 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
b040 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
b060 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
b080 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
b0a0 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
b0c0 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000

DI: 0xffffc9000184c1e8:
c1e8 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
c208 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
c228 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
c248 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
c268 00000020 00000000 00000000 00000000 00000000 00000000 00000000 00000000
c288 00000001 00000000 0184c290 ffffc900 0184c290 ffffc900 00000000 00000000
c2a8 00000000 00000000 00000001 00000000 0184c2b8 ffffc900 0184c2b8 ffffc900
c2c8 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000

BP: 0xffff88003c0abb58:
bb58 0184c268 ffffc900 ffffff10 ffffffff 8934ff59 ffffffff 00000010 00000000
bb78 00000202 00000000 3c0abb90 ffff8800 00000018 00000000 6d58a4c0 ffff8800
bb98 6d58a518 ffff8800 3b8a6ac0 ffff8800 0000541b 00000000 6d58a4c0 ffff8800
bbb8 07815780 1ffff100 3b8a6ac0 ffff8800 0000541b 00000000 6850bce0 ffff8800
bbd8 3c0abdc8 ffff8800 89348eb5 ffffffff 00000000 00000000 00000016 00000000
bbf8 20001fca 00000000 41b58ab3 00000000 8a2d8970 ffffffff 89348670 ffffffff
bc18 00000000 dffffc00 3db4d5e0 ffff8800 07b69ac6 ffffed00 3c0abc90 ffff8800
bc38 88937949 ffffffff 07945fd6 1ffff100 3c0abc68 ffff8800 88c8b7ee ffffffff

R13: 0xffffc90001849f80:
9f80 ******** ******** ******** ******** ******** ******** ******** ********
9fa0 ******** ******** ******** ******** ******** ******** ******** ********
9fc0 ******** ******** ******** ******** ******** ******** ******** ********
9fe0 ******** ******** ******** ******** ******** ******** ******** ********
a000 00000050 00000000 00000050 00000000 00000000 00000000 00000000 00000000
a020 00000000 00000000 00000000 00000000 00080648 00000000 00000000 00000000
a040 08000000 01400000 00080000 00000000 fffc9c6f 00000000 00000002 205b1000
a060 35362020 3839302e 5d353137 205b5020 35362020 3030312e 5d313939 205b7420

R15: 0xffff88006d58a518:
a518 6850bce0 ffff8800 00000001 00000000 6d58a528 ffff8800 6d58a528 ffff8800
a538 00000000 00000000 00000000 00000000 00000001 00000000 6d58a550 ffff8800
a558 6d58a550 ffff8800 00000000 00000000 00000000 00000000 00000001 00000000
a578 6d58a578 ffff8800 6d58a578 ffff8800 00000000 00000000 00000000 00000000
a598 00000001 ffffffff 6d58a5a0 ffff8800 6d58a5a0 ffff8800 00000000 00000000
a5b8 3db4d580 ffff8800 00000001 00000000 6d58a5c8 ffff8800 6d58a5c8 ffff8800
a5d8 00000000 00000000 00000000 00000000 00000000 00000000 00000001 00000006
a5f8 0000eff0 ffffffff 09030000 4aefd39b 00000008 b65a13b8 00000006 00000000

SP: 0xffff88003c0abb10:
bb10 e011c95d 00000000 00000293 00000000 00000000 00000000 00000000 dffffc00
bb30 00000000 00000000 ffffffe0 ffffffff 00000000 00000000 00000000 00000000
bb50 0184b060 ffffc900 0184c268 ffffc900 ffffff10 ffffffff 8934ff59 ffffffff
bb70 00000010 00000000 00000202 00000000 3c0abb90 ffff8800 00000018 00000000
bb90 6d58a4c0 ffff8800 6d58a518 ffff8800 3b8a6ac0 ffff8800 0000541b 00000000
bbb0 6d58a4c0 ffff8800 07815780 1ffff100 3b8a6ac0 ffff8800 0000541b 00000000
bbd0 6850bce0 ffff8800 3c0abdc8 ffff8800 89348eb5 ffffffff 00000000 00000000
bbf0 00000016 00000000 20001fca 00000000 41b58ab3 00000000 8a2d8970 ffffffff

INFO: rcu_sched self-detected stall on CPU
0: (20929 ticks this GP) idle=571/140000000000001/0 softirq=24903/24903 fqs=6974
(t=21001 jiffies g=13260 c=13259 q=497)
Task dump for CPU 0:
syz-executor R running task on cpu 0 0 13407 3160 0x0000000c
dffffc0000000000 ffff88003ec07c10 ffffffff8890367b ffffffff8a55d104
0000000000000000 ffff88003ec1e2c0 0000000000000000 1ffffffff14aba20
ffffffff8a55d100 ffff88003ec07c30 ffffffff88932998 0000000000000000
Call Trace:
<IRQ> [<ffffffff8890367b>] _sched_show_task+0x20b/0x3a0
./kernel/sched/core.c:7114
[< inline >] sched_show_task ./kernel/sched/core.c:7123
[<ffffffff88932998>] dump_cpu_task+0x78/0x90 ./kernel/sched/core.c:10872
[<ffffffff889b1d6f>] rcu_dump_cpu_stacks+0x18f/0x2d0 ./kernel/rcu/tree.c:1211
[< inline >] print_cpu_stall ./kernel/rcu/tree.c:1318
[< inline >] check_cpu_stall ./kernel/rcu/tree.c:1382
[< inline >] __rcu_pending ./kernel/rcu/tree.c:3633
[< inline >] rcu_pending ./kernel/rcu/tree.c:3697
[<ffffffff889bca6c>] rcu_check_callbacks+0xb6c/0x1bb0 ./kernel/rcu/tree.c:2793
[<ffffffff889cf819>] update_process_times+0x39/0x60 ./kernel/time/timer.c:1420
[<ffffffff889f3729>] tick_sched_handle.isra.14+0x49/0xe0
./kernel/time/tick-sched.c:151
[<ffffffff889f4d80>] tick_sched_timer+0x70/0x110
./kernel/time/tick-sched.c:1070
[< inline >] __run_hrtimer ./kernel/time/hrtimer.c:1229
[<ffffffff889d1314>] __hrtimer_run_queues+0x344/0x7e0
./kernel/time/hrtimer.c:1293
[<ffffffff889d2ba9>] hrtimer_interrupt+0x169/0x410 ./kernel/time/hrtimer.c:1327
[<ffffffff888128d4>] local_apic_timer_interrupt+0x74/0xe0
./arch/x86/kernel/apic/apic.c:901
[<ffffffff8860ba55>] smp_apic_timer_interrupt+0xc5/0x100
./arch/x86/kernel/apic/apic.c:925
[<ffffffff8888190f>] apic_timer_interrupt+0x7f/0x90
./arch/x86/entry/entry_64.S:696
[<ffffffff89348eb5>] tty_ioctl+0x845/0x1dd0 ./drivers/tty/tty_io.c:2972
[< inline >] vfs_ioctl ./fs/ioctl.c:43
[<ffffffff88d0f54d>] do_vfs_ioctl+0x53d/0xda0 ./fs/ioctl.c:607
[< inline >] SYSC_ioctl ./fs/ioctl.c:622
[<ffffffff88d0fe29>] SyS_ioctl+0x79/0x90 ./fs/ioctl.c:613
[<ffffffff88880b97>] entry_SYSCALL_64_fastpath+0x12/0x17
./arch/x86/entry/entry_64.S:185

Here is disassembly of n_tty_ioctl:

inq_canon loop:
/* Skip EOF-chars.. */
while (head != tail) {
if (test_bit(tail & (N_TTY_BUF_SIZE - 1), ldata->read_flags) &&
read_buf(ldata, tail) == __DISABLED_CHAR)
nr--;
tail++;
}

ffffffff81d4ff4b: 49 89 de mov %rbx,%r14
ffffffff81d4ff4e: 41 81 e6 ff 0f 00 00 and $0xfff,%r14d
ffffffff81d4ff55: 4c 0f a3 36 bt %r14,(%rsi)
ffffffff81d4ff59: 19 d2 sbb %edx,%edx <========= RIP
ffffffff81d4ff5b: 85 d2 test %edx,%edx
ffffffff81d4ff5d: 74 2b je ffffffff81d4ff8a
<n_tty_ioctl+0x1ea>
ffffffff81d4ff5f: 4b 8d 7c 35 5e lea 0x5e(%r13,%r14,1),%rdi
ffffffff81d4ff64: 48 89 fa mov %rdi,%rdx
ffffffff81d4ff67: 49 89 f8 mov %rdi,%r8
ffffffff81d4ff6a: 48 c1 ea 03 shr $0x3,%rdx
ffffffff81d4ff6e: 41 83 e0 07 and $0x7,%r8d
ffffffff81d4ff72: 42 0f b6 14 0a movzbl (%rdx,%r9,1),%edx
ffffffff81d4ff77: 44 38 c2 cmp %r8b,%dl
ffffffff81d4ff7a: 7f 04 jg ffffffff81d4ff80
<n_tty_ioctl+0x1e0>
ffffffff81d4ff7c: 84 d2 test %dl,%dl
ffffffff81d4ff7e: 75 4c jne ffffffff81d4ffcc
<n_tty_ioctl+0x22c>
ffffffff81d4ff80: 43 80 7c 35 5e 01 cmpb $0x1,0x5e(%r13,%r14,1)
ffffffff81d4ff86: 48 83 d8 00 sbb $0x0,%rax
ffffffff81d4ff8a: 48 83 c3 01 add $0x1,%rbx
ffffffff81d4ff8e: 48 39 d9 cmp %rbx,%rcx
ffffffff81d4ff91: 75 b8 jne ffffffff81d4ff4b
<n_tty_ioctl+0x1ab>

Full disassembly:
https://gist.githubusercontent.com/dvyukov/e57602f031f78043f168104c3c2a9077/raw/1a5319ab131342622c5e6cc0edb336a6d1270799/gistfile1.txt

tail seems to be in %rbx = 00000000e011c95d
and head in %rcx = 0000000000000000

Somehow tail ended up being > head, so now it is in process of
overflowing uint64.

Any ideas how it could happen? The program could
read/write/reset/switch to/from canon concurrently.

Thanks

Next message: Thomas Gleixner: "Re: [RESEND PATCH v2 2/2] power/idle: enhance the precision of sleep_length"
Previous message: Thomas Gleixner: "Re: [PATCH V7] irq: Track the interrupt timings"
Messages sorted by: [ date ] [ thread ] [ subject ] [ author ]