Re: net: hang in ip_finish_output

From: Craig Gallek
Date: Fri Jan 15 2016 - 19:21:07 EST

Next message: Kamal Mostafa: "[PATCH 4.2.y-ckt 259/305] KVM: MTRR: treat memory as writeback if MTRR is disabled in guest CPUID"
Previous message: Kamal Mostafa: "[PATCH 4.2.y-ckt 260/305] [PATCH] arm: fix handling of F_OFD_... in oabi_fcntl64()"
In reply to: Dmitry Vyukov: "net: hang in ip_finish_output"
Messages sorted by: [ date ] [ thread ] [ subject ] [ author ]

On Fri, Jan 15, 2016 at 12:57 PM, Dmitry Vyukov <dvyukov@xxxxxxxxxx> wrote:
> Hello,
>
> The following program hangs kernel in ip_finish_output (if run in a
> parallel loop):
>
> // autogenerated by syzkaller (http://github.com/google/syzkaller)
> #include <unistd.h>
> #include <sys/syscall.h>
> #include <string.h>
> #include <stdint.h>
> #include <pthread.h>
>
> long r[21];
>
> void *thr(void *arg)
> {
> switch ((long)arg) {
> case 0:
> r[0] = syscall(SYS_mmap, 0x20000000ul, 0x1d000ul,
> 0x3ul, 0x32ul, 0xfffffffffffffffful, 0x0ul);
> break;
> case 1:
> r[1] = syscall(SYS_socket, 0x2ul, 0x2ul, 0x0ul, 0, 0, 0);
> break;
> case 2:
> *(uint32_t*)0x20016000 = (uint32_t)0xe4c;
> r[3] = syscall(SYS_setsockopt, r[1], 0x1ul, 0xful,
> 0x20016000ul, 0x4ul, 0);
> break;
> case 3:
> memcpy((void*)0x20009000,
> "\x11\x8d\x57\x62\x7e\xc3\xd8\xb9\xe3\xd8\x63\x4d\x56\x77\x7b\xf1\x3c\x7e\x0c\x91\x62\xca\xc6\x26\xb1\xb9\x11\x34\x6a\xae",
> 30);
> r[5] = syscall(SYS_pwrite64, r[1], 0x20009000ul,
> 0x1eul, 0x0ul, 0, 0);
> break;
> case 4:
> memcpy((void*)0x20006f80,
> "\x02\x00\x33\xd9\x7f\x00\x00\x01\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00",
> 128);
> r[7] = syscall(SYS_bind, r[1], 0x20006f80ul, 0x80ul, 0, 0, 0);
> break;
> case 5:
> memcpy((void*)0x20016f80,
> "\x02\x00\x33\xd9\x7f\x00\x00\x01\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00",
> 128);
> r[9] = syscall(SYS_connect, r[1], 0x20016f80ul,
> 0x80ul, 0, 0, 0);
> break;
> case 6:
> *(uint32_t*)0x20011b08 = (uint32_t)0x18;
> *(uint32_t*)0x20011b0c = (uint32_t)0x2;
> *(uint64_t*)0x20011b10 = (uint64_t)0x0;
> *(uint32_t*)0x20011b18 = (uint32_t)0xfffffffffffffffc;
> r[14] = syscall(SYS_write, r[1], 0x20011b08ul, 0x18ul, 0, 0, 0);
> break;
> case 7:
> r[15] = syscall(SYS_getsockopt, r[1], 0x0ul, 0x3ul,
> 0x2000b000ul, 0x2000bffful, 0);
> break;
> case 8:
> memcpy((void*)0x20013c04,
> "\xdb\x4c\xcc\xa8\x07\xbd\xaa\x58\x7c\x57\x37\x63\xa1\x4d\xdb\x5b\x85\x4e\x37\x3b\x20\xb3\x12\xef\x9b\x75\xf0\x88\x28\xa5\x43\x8e\x56\x59\x3c\x16\xfd\xa0\x01\x4f\x90\x83\x4c\x1b\x22\x3e\xd4\xea\x36\x6f\xb5\x43\x96\x02\x8e\x82\xa1\xc6\x47\xd7\xeb\x08\x56\x6f\x40\xb6\x00\x3f\x52\x38\x99\x2f\x57\x63\x9b\xe4\x0e\xb2\x59\xb2\x59\xbc\x9d\x46\xd0\x52\xd4\x91\xe8\xee\x7f\xcf\x81\xa0\xd5\x10\xc4\x77\xf6\xa1\xa1\x35\xb3\xeb\xb5\x46\xfe\xbc\x83\x74\x9f\x78\xa4\xf1\x0b\xf2\x3a\x41\xc3\x2d\x78\x32\x3b\x88\xe9\xb7\x9f\x56",
> 128);
> r[17] = syscall(SYS_write, r[1], 0x20013c04ul, 0x80ul, 0, 0, 0);
> break;
> case 9:
> r[18] = syscall(SYS_read, r[1], 0x2001afabul, 0x55ul, 0, 0, 0);
> break;
> case 10:
> memcpy((void*)0x200173b8,
> "\x04\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00",
> 128);
> r[20] = syscall(SYS_recvfrom, r[1], 0x20017000ul,
> 0xc7ul, 0x0ul, 0x200173b8ul, 0x80ul);
> break;
> }
> return 0;
> }
>
> int main()
> {
> long i;
> pthread_t th[11];
>
> memset(r, -1, sizeof(r));
> for (i = 0; i < 11; i++) {
> pthread_create(&th[i], 0, thr, (void*)i);
> usleep(10000);
> }
> for (i = 0; i < 11; i++) {
> pthread_create(&th[i], 0, thr, (void*)i);
> if (i%2==0)
> usleep(10000);
> }
> usleep(100000);
> return 0;
> }
>
>
> INFO: rcu_sched self-detected stall on CPU
> 1-...: (1 GPs behind) idle=a8b/140000000000001/0 softirq=83363/83364 fqs=6
> (t=26000 jiffies g=29224 c=29223 q=50)
> rcu_sched kthread starved for 25980 jiffies! g29224 c29223 f0x0
> RCU_GP_WAIT_FQS(3) ->state=0x1
> rcu_sched S ffff88003d827a98 29272 8 2 0x00000000
> ffff88003d827a98 ffff88003ec16d40 ffff88003d80e718 00ffed0007b04f6f
> ffff88003ec20a70 ffff88003ec20a48 ffff88003ec200d8 ffff88003d80df08
> ffff88003ec200c0 ffff880034c517c0 ffff88003d80df00 ffff88003d820000
> Call Trace:
> [<ffffffff8625cf27>] schedule+0x97/0x1c0 kernel/sched/core.c:3311
> [<ffffffff86268feb>] schedule_timeout+0x36b/0x920 kernel/time/timer.c:1531
> [<ffffffff814af122>] rcu_gp_kthread+0xad2/0x1b60 kernel/rcu/tree.c:2125
> [<ffffffff813b3b2f>] kthread+0x23f/0x2d0 drivers/block/aoe/aoecmd.c:1303
> [<ffffffff8626c7ef>] ret_from_fork+0x3f/0x70 arch/x86/entry/entry_64.S:468
> Task dump for CPU 1:
> syz-executor R running task 27912 26692 11656 0x0000000a
> ffff880036ebed30 ffff88003ed07230 ffffffff813e7289 0000000000000005
> ffff88003ed200c0 0000000000000001 1ffffffff0ebbab0 ffffffff875dd548
> dffffc0000000000 ffff88003ed07250 ffffffff813ef951 ffffffff875dd500
> Call Trace:
> <IRQ> [<ffffffff813e7289>] sched_show_task+0x269/0x3b0
> kernel/sched/core.c:5036
> [<ffffffff813ef951>] dump_cpu_task+0x71/0x90 kernel/sched/core.c:8717
> [<ffffffff814a4c71>] rcu_dump_cpu_stacks+0x181/0x270 kernel/rcu/tree.c:1247
> [< inline >] print_cpu_stall kernel/rcu/tree.c:1354
> [< inline >] check_cpu_stall kernel/rcu/tree.c:1418
> [< inline >] __rcu_pending kernel/rcu/tree.c:3906
> [< inline >] rcu_pending kernel/rcu/tree.c:3970
> [<ffffffff814b1b90>] rcu_check_callbacks+0xd40/0x1e10 kernel/rcu/tree.c:2795
> [<ffffffff814c23aa>] update_process_times+0x3a/0x70 kernel/time/timer.c:1420
> [<ffffffff814eb8df>] tick_sched_handle.isra.20+0xaf/0xe0
> kernel/time/tick-sched.c:151
> [<ffffffff814ec005>] tick_sched_timer+0x75/0x100 kernel/time/tick-sched.c:1086
> [< inline >] __run_hrtimer kernel/time/hrtimer.c:1229
> [<ffffffff814c4173>] __hrtimer_run_queues+0x363/0xc10
> kernel/time/hrtimer.c:1293
> [<ffffffff814c6172>] hrtimer_interrupt+0x182/0x430 kernel/time/hrtimer.c:1327
> [<ffffffff8124f052>] local_apic_timer_interrupt+0x72/0xe0
> arch/x86/kernel/apic/apic.c:907
> [<ffffffff81252579>] smp_apic_timer_interrupt+0x79/0xa0
> arch/x86/kernel/apic/apic.c:931
> [<ffffffff8626d22c>] apic_timer_interrupt+0x8c/0xa0
> arch/x86/entry/entry_64.S:520
> [<ffffffff814a1244>] rcu_read_lock_held+0xa4/0xc0 kernel/rcu/update.c:293
> [<ffffffff851bdc78>] reuseport_select_sock+0x4a8/0x10c0
> net/core/sock_reuseport.c:211
> [<ffffffff85529032>] udp4_lib_lookup2+0x362/0x7a0 net/ipv4/udp.c:518
> [<ffffffff8552a09d>] __udp4_lib_lookup+0x26d/0xd20 net/ipv4/udp.c:576
> [< inline >] __udp4_lib_lookup_skb net/ipv4/udp.c:651
> [<ffffffff85530785>] __udp4_lib_rcv+0x1135/0x23e0 net/ipv4/udp.c:1891
> [<ffffffff85532f91>] udp_rcv+0x21/0x30 net/ipv4/udp.c:2108
> [<ffffffff8545dd03>] ip_local_deliver_finish+0x2b3/0xa50
> net/ipv4/ip_input.c:216
> [< inline >] NF_HOOK_THRESH include/linux/netfilter.h:226
> [< inline >] NF_HOOK include/linux/netfilter.h:249
> [<ffffffff8545eba4>] ip_local_deliver+0x1c4/0x2f0 net/ipv4/ip_input.c:257
> [< inline >] dst_input include/net/dst.h:498
> [<ffffffff8545c90c>] ip_rcv_finish+0x5ec/0x1730 net/ipv4/ip_input.c:365
> [< inline >] NF_HOOK_THRESH include/linux/netfilter.h:226
> [< inline >] NF_HOOK include/linux/netfilter.h:249
> [<ffffffff8545f633>] ip_rcv+0x963/0x1080 net/ipv4/ip_input.c:455
> [<ffffffff85165850>] __netif_receive_skb_core+0x1620/0x2f80 net/core/dev.c:4149
> [<ffffffff851671da>] __netif_receive_skb+0x2a/0x160 net/core/dev.c:4184
> [<ffffffff851675be>] process_backlog+0x2ae/0x820 net/core/dev.c:4765
> [< inline >] napi_poll net/core/dev.c:5069
> [<ffffffff8516cc9b>] net_rx_action+0x7eb/0xdf0 net/core/dev.c:5134
> [<ffffffff813615ca>] __do_softirq+0x26a/0x920 kernel/softirq.c:273
> [<ffffffff8626e35c>] do_softirq_own_stack+0x1c/0x30
> arch/x86/entry/entry_64.S:875
> <EOI> [<ffffffff8135fbb4>] do_softirq.part.22+0x104/0x130 kernel/softirq.c:317
> [< inline >] do_softirq kernel/softirq.c:165
> [<ffffffff8135fe62>] __local_bh_enable_ip+0x142/0x190 kernel/softirq.c:170
> [< inline >] local_bh_enable include/linux/bottom_half.h:31
> [< inline >] rcu_read_unlock_bh include/linux/rcupdate.h:970
> [<ffffffff854702c3>] ip_finish_output2+0x703/0x11a0 net/ipv4/ip_output.c:211
> [<ffffffff8547405d>] ip_finish_output+0x7bd/0xd00 net/ipv4/ip_output.c:283
> [< inline >] NF_HOOK_COND include/linux/netfilter.h:240
> [<ffffffff85477778>] ip_output+0x218/0x460 net/ipv4/ip_output.c:357
> [< inline >] dst_output include/net/dst.h:492
> [<ffffffff85474a3b>] ip_local_out+0xdb/0x1c0 net/ipv4/ip_output.c:115
> [<ffffffff8547a21c>] ip_send_skb+0x3c/0xc0 net/ipv4/ip_output.c:1439
> [<ffffffff85521506>] udp_send_skb+0x326/0xbf0 net/ipv4/udp.c:914
> [<ffffffff8552b43e>] udp_sendmsg+0x87e/0x1e70 net/ipv4/udp.c:1139
> [<ffffffff855590f7>] inet_sendmsg+0x2f7/0x4c0 net/ipv4/af_inet.c:736
> [< inline >] sock_sendmsg_nosec net/socket.c:611
> [<ffffffff8510417a>] sock_sendmsg+0xca/0x110 net/socket.c:621
> [<ffffffff851043d6>] sock_write_iter+0x216/0x3a0 net/socket.c:820
> [< inline >] new_sync_write fs/read_write.c:517
> [<ffffffff8178d122>] __vfs_write+0x302/0x480 fs/read_write.c:530
> [<ffffffff8178e9c7>] vfs_write+0x167/0x4a0 fs/read_write.c:577
> [< inline >] SYSC_write fs/read_write.c:624
> [<ffffffff81791cb1>] SyS_write+0x111/0x220 fs/read_write.c:616
> [<ffffffff8626c436>] entry_SYSCALL_64_fastpath+0x16/0x7a
> arch/x86/entry/entry_64.S:185
>
> On commit 67990608c8b95d2b8ccc29932376ae73d5818727 (Jan 12).

I wasn't able to reproduce this exact stack trace, but I was able to
cause soft lockup messages with a fork bomb of your test program. It
is certainly related to my recent SO_REUSEPORT change (reverting it
seems to fix the problem). I haven't completely figured out the exact
cause yet, though. Could you please post your configuration and
exactly how you are running this 'parallel loop'?

Craig

Next message: Kamal Mostafa: "[PATCH 4.2.y-ckt 259/305] KVM: MTRR: treat memory as writeback if MTRR is disabled in guest CPUID"
Previous message: Kamal Mostafa: "[PATCH 4.2.y-ckt 260/305] [PATCH] arm: fix handling of F_OFD_... in oabi_fcntl64()"
In reply to: Dmitry Vyukov: "net: hang in ip_finish_output"
Messages sorted by: [ date ] [ thread ] [ subject ] [ author ]