From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1758049Ab0EVTkq (ORCPT ); Sat, 22 May 2010 15:40:46 -0400 Received: from mamba.nagafix.co.uk ([194.145.196.68]:48728 "EHLO mail.nagafix.co.uk" rhost-flags-OK-OK-OK-FAIL) by vger.kernel.org with ESMTP id S1755773Ab0EVTko (ORCPT ); Sat, 22 May 2010 15:40:44 -0400 Message-ID: <4BF83336.2050307@nagafix.co.uk> Date: Sun, 23 May 2010 02:40:38 +0700 From: Antoine Martin User-Agent: Mozilla/5.0 (X11; U; Linux x86_64; en-US; rv:1.9.1.9) Gecko/20100430 Fedora/3.0.4-2.fc12 Thunderbird/3.0.4 MIME-Version: 1.0 To: linux-kernel@vger.kernel.org, Christoph Hellwig , hugh.dickins@tiscali.co.uk Subject: Re: large IO over loop mount can cause one CPU to block in wait state (was: KVM repeatable hang...) References: <4BF7A9BD.6070806@nagafix.co.uk> In-Reply-To: <4BF7A9BD.6070806@nagafix.co.uk> Content-Type: text/plain; charset=ISO-8859-1; format=flowed Content-Transfer-Encoding: 7bit Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org FW: Jim Paris said on KVM ML: This sounds like: https://bugzilla.kernel.org/show_bug.cgi?id=15906 https://bugzilla.redhat.com/show_bug.cgi?id=588930 -jim And indeed it does. Surprising to see that these bug entries are so recent because I have been experiencing this particular bug for quite some time: http://www.mail-archive.com/kvm@vger.kernel.org/msg27586.html (Post from Jan 2010) Probably since around 2.6.31, which matches the info the bug reports above. Is no-one else using loop mounts any more? Please queue for -stable Cheers Antoine On 05/22/2010 04:54 PM, Antoine Martin wrote: > This may be related to > "Re: PROBLEM: oom killer and swap weirdness on 2.6.3* kernels" > http://lkml.org/lkml/2010/5/21/387 > > And also: > " Re: Gentoo guest with smp: emerge freeze while recompile world" > http://www.mail-archive.com/kvm@vger.kernel.org/msg34629.html > > As both the symptom and the way to trigger the problem are similar. > I originally posted this to KVM ML as the problem was only occurring > on virtual machines at the time (IMO because they have less RAM). > > Cheers > Antoine > > > -------- Original Message -------- > Subject: Re: repeatable hang with loop mount and heavy IO in guest > (now in host - not KVM then..) > Date: Fri, 21 May 2010 16:38:41 +0700 > From: Antoine Martin > To: Michael Tokarev > CC: kvm@vger.kernel.org > > > > On 02/27/2010 12:38 AM, Antoine Martin wrote: >>>> 1 0 0 98 0 1| 0 0 | 66B 354B| 0 0 | >>>> 30 11 >>>> 1 1 0 98 0 0| 0 0 | 66B 354B| 0 0 | >>>> 29 11 >>>> From that point onwards, nothing will happen. >>>> The host has disk IO to spare... So what is it waiting for?? >>> Moved to an AMD64 host. No effect. >>> Disabled swap before running the test. No effect. >>> Moved the guest to a fully up-to-date FC12 server >>> (2.6.31.6-145.fc12.x86_64), no effect. > [snip] > > Well, well. I've just hit the exact same bug on another *host* (not a > guest this time), running stock Fedora 12. > So this isn't a kvm bug after all. Definitely a loop+ext(4?) bug. > Looks like you need a pretty big loop mounted partition to trigger it. > (bigger than available ram?) > > This is what triggered it on a quad amd system with 8Gb of ram, software > raid-1 partition: > mount -o loop 2GB.dd source > dd if=/dev/zero of=8GB.dd bs=1048576 count=8192 > mkfs.ext4 -f 8GB.dd > mount -o loop 8GB.dd dest > rsync -rplogtD source/* dest/ > umount source > umount dest > ^ this is where it hangs (for over 10 minutes), I then tried to issue > a 'sync' from another > terminal, which also hung. > It took more than 10 minutes to settle itself, during that time one CPU > was stuck in wait state. Apart from that the box is mostly idle. > dstat reported almost no IO at the time (<1MB/s) > I assume dstat reports page write back like any other disk IO? > That raid partition does ~60MB/s, so writing back 8GB shouldn't take > much more than a couple of minutes. (that's even assuming it would > have to write back the whole 8GB at umount time - which should not be > the case) > > Cheers > Antoine > > Here's the hung trace: > INFO: task umount:526 blocked for more than 120 seconds. > "echo 0> /proc/sys/kernel/hung_task_timeout_secs" disables this message. > umount D 0000000000000002 0 526 32488 0x00000000 > ffff880140f9fc88 0000000000000086 ffff880008e3c228 ffffffff810d5fd9 > ffff880140f9fc28 ffff880140f9fcd8 ffff880140f9ffd8 ffff880140f9ffd8 > ffff88021b5e03d8 000000000000f980 0000000000015740 ffff88021b5e03d8 > Call Trace: > [] ? sync_page+0x0/0x4a > [] ? __enqueue_entity+0x7b/0x7d > [] ? bdi_sched_wait+0x0/0x12 > [] bdi_sched_wait+0xe/0x12 > [] __wait_on_bit+0x48/0x7b > [] ? native_smp_send_reschedule+0x5c/0x5e > [] out_of_line_wait_on_bit+0x6e/0x79 > [] ? bdi_sched_wait+0x0/0x12 > [] ? wake_bit_function+0x0/0x33 > [] wait_on_bit.clone.1+0x1e/0x20 > [] bdi_sync_writeback+0x64/0x6b > [] sync_inodes_sb+0x22/0xec > [] __sync_filesystem+0x4e/0x77 > [] sync_filesystem+0x4b/0x4f > [] generic_shutdown_super+0x27/0xc9 > [] kill_block_super+0x27/0x3f > [] deactivate_super+0x56/0x6b > [] mntput_no_expire+0xb4/0xec > [] sys_umount+0x2d5/0x304 > [] ? do_page_fault+0x270/0x2a0 > [] system_call_fastpath+0x16/0x1b > INFO: task umount:526 blocked for more than 120 seconds. > "echo 0> /proc/sys/kernel/hung_task_timeout_secs" disables this message. > umount D 0000000000000002 0 526 32488 0x00000000 > ffff880140f9fc88 0000000000000086 ffff880008e3c228 ffffffff810d5fd9 > ffff880140f9fc28 ffff880140f9fcd8 ffff880140f9ffd8 ffff880140f9ffd8 > ffff88021b5e03d8 000000000000f980 0000000000015740 ffff88021b5e03d8 > Call Trace: > [] ? sync_page+0x0/0x4a > [] ? __enqueue_entity+0x7b/0x7d > [] ? bdi_sched_wait+0x0/0x12 > [] bdi_sched_wait+0xe/0x12 > [] __wait_on_bit+0x48/0x7b > [] ? native_smp_send_reschedule+0x5c/0x5e > [] out_of_line_wait_on_bit+0x6e/0x79 > [] ? bdi_sched_wait+0x0/0x12 > [] ? wake_bit_function+0x0/0x33 > [] wait_on_bit.clone.1+0x1e/0x20 > [] bdi_sync_writeback+0x64/0x6b > [] sync_inodes_sb+0x22/0xec > [] __sync_filesystem+0x4e/0x77 > [] sync_filesystem+0x4b/0x4f > [] generic_shutdown_super+0x27/0xc9 > [] kill_block_super+0x27/0x3f > [] deactivate_super+0x56/0x6b > [] mntput_no_expire+0xb4/0xec > [] sys_umount+0x2d5/0x304 > [] ? do_page_fault+0x270/0x2a0 > [] system_call_fastpath+0x16/0x1b > INFO: task umount:526 blocked for more than 120 seconds. > "echo 0> /proc/sys/kernel/hung_task_timeout_secs" disables this message. > umount D 0000000000000002 0 526 32488 0x00000000 > ffff880140f9fc88 0000000000000086 ffff880008e3c228 ffffffff810d5fd9 > ffff880140f9fc28 ffff880140f9fcd8 ffff880140f9ffd8 ffff880140f9ffd8 > ffff88021b5e03d8 000000000000f980 0000000000015740 ffff88021b5e03d8 > Call Trace: > [] ? sync_page+0x0/0x4a > [] ? __enqueue_entity+0x7b/0x7d > [] ? bdi_sched_wait+0x0/0x12 > [] bdi_sched_wait+0xe/0x12 > [] __wait_on_bit+0x48/0x7b > [] ? native_smp_send_reschedule+0x5c/0x5e > [] out_of_line_wait_on_bit+0x6e/0x79 > [] ? bdi_sched_wait+0x0/0x12 > [] ? wake_bit_function+0x0/0x33 > [] wait_on_bit.clone.1+0x1e/0x20 > [] bdi_sync_writeback+0x64/0x6b > [] sync_inodes_sb+0x22/0xec > [] __sync_filesystem+0x4e/0x77 > [] sync_filesystem+0x4b/0x4f > [] generic_shutdown_super+0x27/0xc9 > [] kill_block_super+0x27/0x3f > [] deactivate_super+0x56/0x6b > [] mntput_no_expire+0xb4/0xec > [] sys_umount+0x2d5/0x304 > [] ? do_page_fault+0x270/0x2a0 > [] system_call_fastpath+0x16/0x1b > INFO: task umount:526 blocked for more than 120 seconds. > "echo 0> /proc/sys/kernel/hung_task_timeout_secs" disables this message. > umount D 0000000000000002 0 526 32488 0x00000000 > ffff880140f9fc88 0000000000000086 ffff880008e3c228 ffffffff810d5fd9 > ffff880140f9fc28 ffff880140f9fcd8 ffff880140f9ffd8 ffff880140f9ffd8 > ffff88021b5e03d8 000000000000f980 0000000000015740 ffff88021b5e03d8 > Call Trace: > [] ? sync_page+0x0/0x4a > [] ? __enqueue_entity+0x7b/0x7d > [] ? bdi_sched_wait+0x0/0x12 > [] bdi_sched_wait+0xe/0x12 > [] __wait_on_bit+0x48/0x7b > [] ? native_smp_send_reschedule+0x5c/0x5e > [] out_of_line_wait_on_bit+0x6e/0x79 > [] ? bdi_sched_wait+0x0/0x12 > [] ? wake_bit_function+0x0/0x33 > [] wait_on_bit.clone.1+0x1e/0x20 > [] bdi_sync_writeback+0x64/0x6b > [] sync_inodes_sb+0x22/0xec > [] __sync_filesystem+0x4e/0x77 > [] sync_filesystem+0x4b/0x4f > [] generic_shutdown_super+0x27/0xc9 > [] kill_block_super+0x27/0x3f > [] deactivate_super+0x56/0x6b > [] mntput_no_expire+0xb4/0xec > [] sys_umount+0x2d5/0x304 > [] ? do_page_fault+0x270/0x2a0 > [] system_call_fastpath+0x16/0x1b > INFO: task sync:741 blocked for more than 120 seconds. > "echo 0> /proc/sys/kernel/hung_task_timeout_secs" disables this message. > sync D 0000000000000000 0 741 552 0x00000000 > ffff88003c31fed8 0000000000000086 0000000000000000 ffff8801b7472ec0 > ffff88003c31fe38 0000000000000246 ffff88003c31ffd8 ffff88003c31ffd8 > ffff8801b7473298 000000000000f980 0000000000015740 ffff8801b7473298 > Call Trace: > [] __down_read+0x92/0xaa > [] down_read+0x31/0x35 > [] sync_filesystems+0x86/0xf6 > [] sys_sync+0x17/0x33 > [] system_call_fastpath+0x16/0x1b > >