From patchwork Fri Nov 20 15:35:38 2015 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Vladimir Murzin X-Patchwork-Id: 7669271 Return-Path: X-Original-To: patchwork-linux-arm@patchwork.kernel.org Delivered-To: patchwork-parsemail@patchwork1.web.kernel.org Received: from mail.kernel.org (mail.kernel.org [198.145.29.136]) by patchwork1.web.kernel.org (Postfix) with ESMTP id 0E6799F1C2 for ; Fri, 20 Nov 2015 15:50:14 +0000 (UTC) Received: from mail.kernel.org (localhost [127.0.0.1]) by mail.kernel.org (Postfix) with ESMTP id DCB532042A for ; Fri, 20 Nov 2015 15:50:12 +0000 (UTC) Received: from bombadil.infradead.org (bombadil.infradead.org [198.137.202.9]) (using TLSv1.2 with cipher AES128-GCM-SHA256 (128/128 bits)) (No client certificate requested) by mail.kernel.org (Postfix) with ESMTPS id B0A512041E for ; Fri, 20 Nov 2015 15:50:11 +0000 (UTC) Received: from localhost ([127.0.0.1] helo=bombadil.infradead.org) by bombadil.infradead.org with esmtp (Exim 4.80.1 #2 (Red Hat Linux)) id 1Zznw8-0002Vp-7P; Fri, 20 Nov 2015 15:49:20 +0000 Received: from eu-smtp-delivery-143.mimecast.com ([207.82.80.143]) by bombadil.infradead.org with esmtp (Exim 4.80.1 #2 (Red Hat Linux)) id 1ZznjN-0000Am-UQ for linux-arm-kernel@lists.infradead.org; Fri, 20 Nov 2015 15:36:20 +0000 Received: from cam-owa2.Emea.Arm.com (fw-tnat.cambridge.arm.com [217.140.96.140]) by eu-smtp-1.mimecast.com with ESMTP id uk-mta-2-HCMm3pMiSYSp0VpGU9i12Q-1; Fri, 20 Nov 2015 15:35:44 +0000 Received: from [10.1.87.55] ([10.1.2.79]) by cam-owa2.Emea.Arm.com with Microsoft SMTPSVC(6.0.3790.3959); Fri, 20 Nov 2015 15:35:44 +0000 Message-ID: <564F3DCA.1080907@arm.com> Date: Fri, 20 Nov 2015 15:35:38 +0000 From: Vladimir Murzin User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:31.0) Gecko/20100101 Thunderbird/31.2.0 MIME-Version: 1.0 To: linux-kernel@vger.kernel.org Subject: [BISECTED] rcu_sched self-detected stall since 3.17 X-OriginalArrivalTime: 20 Nov 2015 15:35:44.0602 (UTC) FILETIME=[1EF123A0:01D123A9] X-MC-Unique: HCMm3pMiSYSp0VpGU9i12Q-1 X-CRM114-Version: 20100106-BlameMichelson ( TRE 0.8.0 (BSD) ) MR-646709E3 X-CRM114-CacheID: sfid-20151120_073610_647549_DE29248B X-CRM114-Status: UNSURE ( 9.86 ) X-CRM114-Notice: Please train this message. X-Spam-Score: -4.2 (----) X-BeenThere: linux-arm-kernel@lists.infradead.org X-Mailman-Version: 2.1.20 Precedence: list List-Id: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Cc: mark.rutland@arm.com, linux-mm@kvack.org, neilb@suse.de, oleg@redhat.com, peterz@infradead.org, linux-arm-kernel@lists.infradead.org Sender: "linux-arm-kernel" Errors-To: linux-arm-kernel-bounces+patchwork-linux-arm=patchwork.kernel.org@lists.infradead.org X-Spam-Status: No, score=-4.8 required=5.0 tests=BAYES_00, RCVD_IN_DNSWL_MED, RP_MATCHES_RCVD, UNPARSEABLE_RELAY autolearn=unavailable version=3.3.1 X-Spam-Checker-Version: SpamAssassin 3.3.1 (2010-03-16) on mail.kernel.org X-Virus-Scanned: ClamAV using ClamSMTP Hi, I've been getting rcu_sched self-detected stall on one of our test environment with the following (or similar) log: Linux 4.3 > INFO: rcu_sched self-detected stall on CPU > 2: (2099 ticks this GP) idle=a73/140000000000001/0 softirq=277/283 fqs=2092 > (t=2100 jiffies g=-197 c=-198 q=230) > Task dump for CPU 2: > paranoia R running 0 423 1 0x00000003 > [] (unwind_backtrace) from [] (show_stack+0x10/0x14) > [] (show_stack) from [] (rcu_dump_cpu_stacks+0xa4/0xc4) > [] (rcu_dump_cpu_stacks) from [] (rcu_check_callbacks+0x2dc/0x81c) > [] (rcu_check_callbacks) from [] (update_process_times+0x38/0x64) > [] (update_process_times) from [] (tick_periodic+0xa8/0xb8) > [] (tick_periodic) from [] (tick_handle_periodic+0x28/0x88) > [] (tick_handle_periodic) from [] (arch_timer_handler_virt+0x28/0x30) > [] (arch_timer_handler_virt) from [] (handle_percpu_devid_irq+0x6c/0x84) > [] (handle_percpu_devid_irq) from [] (generic_handle_irq+0x24/0x34) > [] (generic_handle_irq) from [] (__handle_domain_irq+0x98/0xac) > [] (__handle_domain_irq) from [] (gic_handle_irq+0x54/0x90) > [] (gic_handle_irq) from [] (__irq_svc+0x54/0x70) > Exception stack(0xdb007c60 to 0xdb007ca8) > 7c60: 00000000 00000000 00000000 00000001 dc3e9a20 00000000 00000000 00000001 > 7c80: dc3e9a20 0000001b 00080000 0000000b ffffffff db007cb0 c00ac8f0 c00aa96c > 7ca0: 600d0113 ffffffff > [] (__irq_svc) from [] (free_pages_prepare+0x18c/0x218) > [] (free_pages_prepare) from [] (free_hot_cold_page+0x34/0x168) > [] (free_hot_cold_page) from [] (handle_mm_fault+0x7b8/0xe60) > [] (handle_mm_fault) from [] (do_page_fault+0x12c/0x378) > [] (do_page_fault) from [] (do_DataAbort+0x38/0xb4) > [] (do_DataAbort) from [] (__dabt_svc+0x40/0x60) > Exception stack(0xdb007e68 to 0xdb007eb0) > 7e60: 0001b2c8 00000d30 00000000 00000055 00000051 dbb04600 > 7e80: 00000000 db007ec8 db8ea700 db8f3080 dba43240 0001b2c8 00000000 db007eb8 > 7ea0: c012c178 c0174ce8 200d0113 ffffffff > [] (__dabt_svc) from [] (__clear_user_std+0x34/0x68) > [] (__clear_user_std) from [] (padzero+0x58/0x74) > [] (padzero) from [] (load_elf_binary+0x730/0x1250) > [] (load_elf_binary) from [] (search_binary_handler+0xa0/0x23c) > [] (search_binary_handler) from [] (do_execveat_common+0x444/0x5d8) > [] (do_execveat_common) from [] (do_execve+0x24/0x2c) > [] (do_execve) from [] (ret_fast_syscall+0x0/0x3c) (I put report for Linux 3.17 under [2]) This rcu_sched self-detected stall is usually reproduced 2 or 3 times out of 10 runs, but sometimes even more runs go without issue. I bisected [1] it to commit commit 743162013d40ca612b4cb53d3a200dff2d9ab26e Author: NeilBrown Date: Mon Jul 7 15:16:04 2014 +1000 sched: Remove proliferation of wait_on_bit() action functions The only change I noticed is from (mm/filemap.c) io_schedule(); fatal_signal_pending(current) to (kernel/sched/wait.c) signal_pending_state(current->state, current) io_schedule(); and if I apply following diff I don't see stalls anymore. Any ideas why it might happen and why diff above helps? [1] Bisect log: I checked 4.[0-3] and 3.1[7-9] manually I have https://lkml.org/lkml/2015/8/26/649 for better report > git bisect start '--no-checkout' > # good: [19583ca584d6f574384e17fe7613dfaeadcdc4a6] Linux 3.16 > git bisect good 19583ca584d6f574384e17fe7613dfaeadcdc4a6 > # bad: [53ee983378ff23e8f3ff95ecf99dea7c6c221900] Merge tag 'staging-3.17-rc1' of git://git.kernel.org/pub/scm/linux/kernel/git/gregkh/staging > git bisect bad 53ee983378ff23e8f3ff95ecf99dea7c6c221900 > # good: [2042088cd67d0064d18c52c13c69af2499907bb1] staging: comedi: ni_labpc: tidy up labpc_ai_scan_mode() > git bisect good 2042088cd67d0064d18c52c13c69af2499907bb1 > # bad: [98959948a7ba33cf8c708626e0d2a1456397e1c6] Merge branch 'sched-core-for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip > git bisect bad 98959948a7ba33cf8c708626e0d2a1456397e1c6 > # good: [c9b88e9581828bb8bba06c5e7ee8ed1761172b6e] Merge tag 'trace-3.17-2' of git://git.kernel.org/pub/scm/linux/kernel/git/rostedt/linux-trace > git bisect good c9b88e9581828bb8bba06c5e7ee8ed1761172b6e > # good: [5bda4f638f36ef4c4e3b1397b02affc3db94356e] Merge branch 'core-rcu-for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip > git bisect good 5bda4f638f36ef4c4e3b1397b02affc3db94356e > # good: [2336ebc32676df5b794acfe0c980583ec6c05f34] Merge tag 'perf-core-for-mingo' of git://git.kernel.org/pub/scm/linux/kernel/git/jolsa/perf into perf/core > git bisect good 2336ebc32676df5b794acfe0c980583ec6c05f34 > # good: [ef35ad26f8ff44d2c93e29952cdb336bda729d9d] Merge branch 'perf-core-for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip > git bisect good ef35ad26f8ff44d2c93e29952cdb336bda729d9d > # good: [1c5d3eb3759013bc7ee4197aa0a9f245bdb6eb90] sched/numa: Simplify task_numa_compare() > git bisect good 1c5d3eb3759013bc7ee4197aa0a9f245bdb6eb90 > # good: [6e76ea8a8209386c3cc7ee5594e6ea5d25525cf2] sched: Remove extra static_key*() function indirection > git bisect good 6e76ea8a8209386c3cc7ee5594e6ea5d25525cf2 > # bad: [c1221321b7c25b53204447cff9949a6d5a7ddddc] sched: Allow wait_on_bit_action() functions to support a timeout > git bisect bad c1221321b7c25b53204447cff9949a6d5a7ddddc > # good: [e720fff6341fe4b95e5a93c939bd3c77fa55ced4] sched/numa: Revert "Use effective_load() to balance NUMA loads" > git bisect good e720fff6341fe4b95e5a93c939bd3c77fa55ced4 > # bad: [743162013d40ca612b4cb53d3a200dff2d9ab26e] sched: Remove proliferation of wait_on_bit() action functions > git bisect bad 743162013d40ca612b4cb53d3a200dff2d9ab26e > # good: [d26fad5b38e1c4667d4f2604936e59c837caa54d] Merge tag 'v3.16-rc5' into sched/core, to refresh the branch before applying bigger tree-wide changes > git bisect good d26fad5b38e1c4667d4f2604936e59c837caa54d [2] rcu_sched self-detected stall under Linux 3.17 > INFO: rcu_sched self-detected stall on CPU { 2} (t=2100 jiffies g=-199 c=-200 q=172) > Task dump for CPU 2: > paranoia R running 0 414 1 0x00000003 > [] (unwind_backtrace) from [] (show_stack+0x10/0x14) > [] (show_stack) from [] (rcu_dump_cpu_stacks+0xa4/0xc4) > [] (rcu_dump_cpu_stacks) from [] (rcu_check_callbacks+0x280/0x6f8) > [] (rcu_check_callbacks) from [] (update_process_times+0x40/0x60) > [] (update_process_times) from [] (tick_periodic+0xa8/0xb8) > [] (tick_periodic) from [] (tick_handle_periodic+0x28/0x88) > [] (tick_handle_periodic) from [] (arch_timer_handler_virt+0x28/0x30) > [] (arch_timer_handler_virt) from [] (handle_percpu_devid_irq+0x6c/0x84) > [] (handle_percpu_devid_irq) from [] (generic_handle_irq+0x2c/0x3c) > [] (generic_handle_irq) from [] (handle_IRQ+0x7c/0x8c) > [] (handle_IRQ) from [] (gic_handle_irq+0x40/0x5c) > [] (gic_handle_irq) from [] (__irq_svc+0x40/0x54) > Exception stack(0xdb063c60 to 0xdb063ca8) > 3c60: 00000000 0001b000 dbbfc000 0000000b dbbfc000 0000000b dbbfc000 0001b000 > 3c80: 0001b000 dbb2d6e0 0000001b db03c380 0000006c db063ca8 c00b935c c00b935c > 3ca0: a00d0113 ffffffff > [] (__irq_svc) from [] (do_cow_fault.isra.97+0x1c/0x198) > [] (do_cow_fault.isra.97) from [] (handle_mm_fault+0x14c/0x900) > [] (handle_mm_fault) from [] (do_page_fault+0x120/0x3d8) > [] (do_page_fault) from [] (do_DataAbort+0x38/0x98) > [] (do_DataAbort) from [] (__dabt_svc+0x38/0x60) > Exception stack(0xdb063e70 to 0xdb063eb8) > 3e60: 0001b2c8 00000d30 00000000 00000000 > 3e80: db902a80 dbadc100 00000000 db063ec8 db062008 dbadc200 0001b2c8 0001b6cc > 3ea0: 00000000 db063eb8 c011689c c015a884 200d0013 ffffffff > [] (__dabt_svc) from [] (__clear_user_std+0x34/0x64) > [] (__clear_user_std) from [] (padzero+0x44/0x58) > [] (padzero) from [] (load_elf_binary+0x778/0x138c) > [] (load_elf_binary) from [] (search_binary_handler+0x98/0x1d8) > [] (search_binary_handler) from [] (do_execve+0x35c/0x4bc) > [] (do_execve) from [] (ret_fast_syscall+0x0/0x30) Thanks Vladimir diff --git a/kernel/sched/wait.c b/kernel/sched/wait.c index a104879..2d68cdb 100644 --- a/kernel/sched/wait.c +++ b/kernel/sched/wait.c @@ -514,9 +514,10 @@ EXPORT_SYMBOL(bit_wait); __sched int bit_wait_io(void *word) { + io_schedule(); + if (signal_pending_state(current->state, current)) return 1; - io_schedule(); return 0; } EXPORT_SYMBOL(bit_wait_io);