From: Fredrik Andersson Subject: Re: Fwd: Ext4 bug with fallocate Date: Mon, 26 Oct 2009 11:43:07 +0100 Message-ID: References: <4ADB3AEC.8040901@redhat.com> <1256084662.4316.4.camel@mingming-laptop> Mime-Version: 1.0 Content-Type: text/plain; charset=ISO-8859-1 To: linux-ext4@vger.kernel.org Return-path: Received: from mail-ew0-f208.google.com ([209.85.219.208]:64564 "EHLO mail-ew0-f208.google.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1755519AbZJZKnD (ORCPT ); Mon, 26 Oct 2009 06:43:03 -0400 Received: by ewy4 with SMTP id 4so3448251ewy.37 for ; Mon, 26 Oct 2009 03:43:07 -0700 (PDT) In-Reply-To: Sender: linux-ext4-owner@vger.kernel.org List-ID: I had the same error again, on another machine. I'm posting the calls stacks of these hung processes too. Hope someone can figure this out.. 6515054.873144] INFO: task pdflush:269 blocked for more than 120 seconds. [6515054.873148] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [6515054.873151] pdflush D ffff8801f4cf0ad4 0 269 2 [6515054.873156] ffff88021e551960 0000000000000046 ffff88021e63d6e0 ffff88007ddd1540 [6515054.873161] 0000000000010e80 000000000000c748 ffff88021fa2c020 ffff88021f843900 [6515054.873166] ffff88021fa2c390 0000000100000008 00000002844bfcb2 0080001000800013 [6515054.873170] Call Trace: [6515054.873180] [] schedule+0x9/0x20 [6515054.873184] [] __down_read+0x85/0xb7 [6515054.873187] [] down_read+0x25/0x30 [6515054.873192] [] ext4_get_blocks_wrap+0x52/0x290 [6515054.873196] [] mpage_da_map_blocks+0xd1/0x7a0 [6515054.873202] [] ? write_cache_pages+0x2fc/0x470 [6515054.873205] [] ? __mpage_da_writepage+0x0/0x180 [6515054.873209] [] ext4_da_writepages+0x30b/0x590 [6515054.873213] [] ? finish_task_switch+0x5b/0xd0 [6515054.873217] [] do_writepages+0x28/0x50 [6515054.873222] [] __writeback_single_inode+0x9b/0x3e0 [6515054.873226] [] ? process_timeout+0x0/0x10 [6515054.873230] [] ? io_schedule_timeout+0x37/0x50 [6515054.873234] [] generic_sync_sb_inodes+0x36c/0x440 [6515054.873237] [] writeback_inodes+0x5e/0x100 [6515054.873241] [] wb_kupdate+0xbc/0x140 [6515054.873244] [] pdflush+0x118/0x220 [6515054.873248] [] ? wb_kupdate+0x0/0x140 [6515054.873251] [] ? pdflush+0x0/0x220 [6515054.873255] [] kthread+0x56/0x90 [6515054.873259] [] child_rip+0xa/0x20 [6515054.873263] [] ? restore_args+0x0/0x30 [6515054.873266] [] ? kthread+0x0/0x90 [6515054.873270] [] ? child_rip+0x0/0x20 [6515054.873275] INFO: task kjournald2:1334 blocked for more than 120 seconds. [6515054.873277] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [6515054.873279] kjournald2 D ffff88021e731e28 0 1334 2 [6515054.873283] ffff88021e731d10 0000000000000046 ffff88021e731ca0 ffffffff813a9b3b [6515054.873288] 0000000000010e80 000000000000c748 ffff88021f9c5580 ffff88021f843900 [6515054.873292] ffff88021f9c58f0 0000000100000282 00000002844c0480 0000000000000282 [6515054.873296] Call Trace: [6515054.873300] [] ? __wait_on_bit+0x7b/0x90 [6515054.873303] [] schedule+0x9/0x20 [6515054.873308] [] jbd2_journal_commit_transaction+0x1be/0x1810 [6515054.873312] [] ? dequeue_task_fair+0x256/0x260 [6515054.873315] [] ? finish_task_switch+0x5b/0xd0 [6515054.873320] [] ? autoremove_wake_function+0x0/0x40 [6515054.873324] [] kjournald2+0x11a/0x370 [6515054.873327] [] ? autoremove_wake_function+0x0/0x40 [6515054.873330] [] ? kjournald2+0x0/0x370 [6515054.873333] [] ? kjournald2+0x0/0x370 [6515054.873337] [] kthread+0x56/0x90 [6515054.873340] [] child_rip+0xa/0x20 [6515054.873344] [] ? restore_args+0x0/0x30 [6515054.873347] [] ? kthread+0x0/0x90 [6515054.873351] [] ? child_rip+0x0/0x20 [6515054.873361] INFO: task drdbmake:3919 blocked for more than 120 seconds. [6515054.873363] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [6515054.873365] drdbmake D ffff88021e56f000 0 3919 27107 [6515054.873369] ffff88021eb4da88 0000000000000082 ffff8801f4cf0ae8 ffff880008ba03f0 [6515054.873374] 0000000000010e80 000000000000c748 ffff8801049063c0 ffff88021f843900 [6515054.873378] ffff880104906730 00000001f4cf0ae8 00000002844c0480 0000000000000282 [6515054.873382] Call Trace: [6515054.873386] [] schedule+0x9/0x20 [6515054.873390] [] start_this_handle+0x365/0x5d0 [6515054.873394] [] ? autoremove_wake_function+0x0/0x40 [6515054.873397] [] jbd2_journal_restart+0xbe/0x150 [6515054.873402] [] ext4_ext_truncate+0x6dd/0xa20 [6515054.873406] [] ? find_get_pages+0x3b/0xf0 [6515054.873409] [] ext4_truncate+0x198/0x680 [6515054.873414] [] ? unmap_mapping_range+0x74/0x280 [6515054.873418] [] ? jbd2_journal_stop+0x1e0/0x360 [6515054.873422] [] vmtruncate+0xa5/0x110 [6515054.873426] [] inode_setattr+0x30/0x180 [6515054.873430] [] ext4_setattr+0x173/0x310 [6515054.873433] [] notify_change+0x119/0x330 [6515054.873438] [] do_truncate+0x63/0x90 [6515054.873441] [] ? get_write_access+0x23/0x60 [6515054.873445] [] sys_truncate+0x17b/0x180 [6515054.873448] [] system_call_fastpath+0x16/0x1b [6515174.873066] INFO: task pdflush:269 blocked for more than 120 seconds. [6515174.873070] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [6515174.873074] pdflush D ffff8801f4cf0ad4 0 269 2 [6515174.873079] ffff88021e551960 0000000000000046 ffff88021e63d6e0 ffff88007ddd1540 [6515174.873085] 0000000000010e80 000000000000c748 ffff88021fa2c020 ffff88021f843900 [6515174.873090] ffff88021fa2c390 0000000100000008 00000002844bfcb2 0080001000800013 [6515174.873096] Call Trace: [6515174.873106] [] schedule+0x9/0x20 [6515174.873110] [] __down_read+0x85/0xb7 [6515174.873115] [] down_read+0x25/0x30 [6515174.873120] [] ext4_get_blocks_wrap+0x52/0x290 [6515174.873124] [] mpage_da_map_blocks+0xd1/0x7a0 [6515174.873138] [] ? write_cache_pages+0x2fc/0x470 [6515174.873146] [] ? __mpage_da_writepage+0x0/0x180 [6515174.873155] [] ext4_da_writepages+0x30b/0x590 [6515174.873164] [] ? finish_task_switch+0x5b/0xd0 [6515174.873172] [] do_writepages+0x28/0x50 [6515174.873181] [] __writeback_single_inode+0x9b/0x3e0 [6515174.873190] [] ? process_timeout+0x0/0x10 [6515174.873197] [] ? io_schedule_timeout+0x37/0x50 [6515174.873206] [] generic_sync_sb_inodes+0x36c/0x440 [6515174.873214] [] writeback_inodes+0x5e/0x100 [6515174.873222] [] wb_kupdate+0xbc/0x140 [6515174.873230] [] pdflush+0x118/0x220 [6515174.873238] [] ? wb_kupdate+0x0/0x140 [6515174.873245] [] ? pdflush+0x0/0x220 [6515174.873253] [] kthread+0x56/0x90 [6515174.873261] [] child_rip+0xa/0x20 [6515174.873269] [] ? restore_args+0x0/0x30 [6515174.873277] [] ? kthread+0x0/0x90 [6515174.873284] [] ? child_rip+0x0/0x20 [6515174.873303] INFO: task kjournald2:1334 blocked for more than 120 seconds. [6515174.873308] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [6515174.873314] kjournald2 D ffff88021e731e28 0 1334 2 [6515174.873322] ffff88021e731d10 0000000000000046 ffff88021e731ca0 ffffffff813a9b3b [6515174.873333] 0000000000010e80 000000000000c748 ffff88021f9c5580 ffff88021f843900 [6515174.873344] ffff88021f9c58f0 0000000100000282 00000002844c0480 0000000000000282 [6515174.873355] Call Trace: [6515174.873360] [] ? __wait_on_bit+0x7b/0x90 [6515174.873367] [] schedule+0x9/0x20 [6515174.873375] [] jbd2_journal_commit_transaction+0x1be/0x1810 [6515174.873382] [] ? dequeue_task_fair+0x256/0x260 [6515174.873389] [] ? finish_task_switch+0x5b/0xd0 [6515174.873396] [] ? autoremove_wake_function+0x0/0x40 [6515174.873404] [] kjournald2+0x11a/0x370 [6515174.873411] [] ? autoremove_wake_function+0x0/0x40 [6515174.873418] [] ? kjournald2+0x0/0x370 [6515174.873424] [] ? kjournald2+0x0/0x370 [6515174.873431] [] kthread+0x56/0x90 [6515174.873437] [] child_rip+0xa/0x20 [6515174.873444] [] ? restore_args+0x0/0x30 [6515174.873450] [] ? kthread+0x0/0x90 [6515174.873457] [] ? child_rip+0x0/0x20 [6515174.873470] INFO: task drdbmake:3919 blocked for more than 120 seconds. [6515174.873475] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [6515174.873480] drdbmake D ffff88021e56f000 0 3919 27107 [6515174.873489] ffff88021eb4da88 0000000000000082 ffff8801f4cf0ae8 ffff880008ba03f0 [6515174.873499] 0000000000010e80 000000000000c748 ffff8801049063c0 ffff88021f843900 [6515174.873510] ffff880104906730 00000001f4cf0ae8 00000002844c0480 0000000000000282 [6515174.873521] Call Trace: [6515174.873526] [] schedule+0x9/0x20 [6515174.873534] [] start_this_handle+0x365/0x5d0 [6515174.873541] [] ? autoremove_wake_function+0x0/0x40 [6515174.873548] [] jbd2_journal_restart+0xbe/0x150 [6515174.873556] [] ext4_ext_truncate+0x6dd/0xa20 [6515174.873563] [] ? find_get_pages+0x3b/0xf0 [6515174.873569] [] ext4_truncate+0x198/0x680 [6515174.873578] [] ? unmap_mapping_range+0x74/0x280 [6515174.873585] [] ? jbd2_journal_stop+0x1e0/0x360 [6515174.873592] [] vmtruncate+0xa5/0x110 [6515174.873600] [] inode_setattr+0x30/0x180 [6515174.873607] [] ext4_setattr+0x173/0x310 [6515174.873614] [] notify_change+0x119/0x330 [6515174.873621] [] do_truncate+0x63/0x90 [6515174.873628] [] ? get_write_access+0x23/0x60 [6515174.873635] [] sys_truncate+0x17b/0x180 [6515174.873642] [] system_call_fastpath+0x16/0x1b [6515294.873034] INFO: task pdflush:269 blocked for more than 120 seconds. [6515294.873038] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [6515294.873041] pdflush D ffff8801f4cf0ad4 0 269 2 [6515294.873046] ffff88021e551960 0000000000000046 ffff88021e63d6e0 ffff88007ddd1540 [6515294.873053] 0000000000010e80 000000000000c748 ffff88021fa2c020 ffff88021f843900 [6515294.873058] ffff88021fa2c390 0000000100000008 00000002844bfcb2 0080001000800013 [6515294.873063] Call Trace: [6515294.873073] [] schedule+0x9/0x20 [6515294.873078] [] __down_read+0x85/0xb7 [6515294.873082] [] down_read+0x25/0x30 [6515294.873088] [] ext4_get_blocks_wrap+0x52/0x290 [6515294.873092] [] mpage_da_map_blocks+0xd1/0x7a0 [6515294.873099] [] ? write_cache_pages+0x2fc/0x470 [6515294.873103] [] ? __mpage_da_writepage+0x0/0x180 [6515294.873107] [] ext4_da_writepages+0x30b/0x590 [6515294.873112] [] ? finish_task_switch+0x5b/0xd0 [6515294.873117] [] do_writepages+0x28/0x50 [6515294.873123] [] __writeback_single_inode+0x9b/0x3e0 [6515294.873136] [] ? process_timeout+0x0/0x10 [6515294.873144] [] ? io_schedule_timeout+0x37/0x50 [6515294.873153] [] generic_sync_sb_inodes+0x36c/0x440 [6515294.873161] [] writeback_inodes+0x5e/0x100 [6515294.873169] [] wb_kupdate+0xbc/0x140 [6515294.873177] [] pdflush+0x118/0x220 [6515294.873185] [] ? wb_kupdate+0x0/0x140 [6515294.873192] [] ? pdflush+0x0/0x220 [6515294.873200] [] kthread+0x56/0x90 [6515294.873209] [] child_rip+0xa/0x20 [6515294.873217] [] ? restore_args+0x0/0x30 [6515294.873224] [] ? kthread+0x0/0x90 [6515294.873232] [] ? child_rip+0x0/0x20 [6515294.873241] INFO: task kjournald2:1334 blocked for more than 120 seconds. [6515294.873247] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [6515294.873253] kjournald2 D ffff88021e731e28 0 1334 2 [6515294.873273] ffff88021e731d10 0000000000000046 ffff88021e731ca0 ffffffff813a9b3b [6515294.873284] 0000000000010e80 000000000000c748 ffff88021f9c5580 ffff88021f843900 [6515294.873294] ffff88021f9c58f0 0000000100000282 00000002844c0480 0000000000000282 [6515294.873305] Call Trace: [6515294.873311] [] ? __wait_on_bit+0x7b/0x90 [6515294.873318] [] schedule+0x9/0x20 [6515294.873326] [] jbd2_journal_commit_transaction+0x1be/0x1810 [6515294.873334] [] ? dequeue_task_fair+0x256/0x260 [6515294.873341] [] ? finish_task_switch+0x5b/0xd0 [6515294.873349] [] ? autoremove_wake_function+0x0/0x40 [6515294.873356] [] kjournald2+0x11a/0x370 [6515294.873363] [] ? autoremove_wake_function+0x0/0x40 [6515294.873369] [] ? kjournald2+0x0/0x370 [6515294.873375] [] ? kjournald2+0x0/0x370 [6515294.873382] [] kthread+0x56/0x90 [6515294.873389] [] child_rip+0xa/0x20 [6515294.873395] [] ? restore_args+0x0/0x30 [6515294.873402] [] ? kthread+0x0/0x90 [6515294.873408] [] ? child_rip+0x0/0x20 [6515294.873418] INFO: task receptd:5709 blocked for more than 120 seconds. [6515294.873423] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [6515294.873428] receptd D 000000000000002a 0 5709 2046 [6515294.873436] ffff88009cce3c78 0000000000000086 ffff88009cce3be8 ffffffff81152dd3 [6515294.873447] 0000000000010e80 000000000000c748 ffff880104901c80 ffffffff81526360 [6515294.873457] ffff880104901ff0 00000000810db183 00000002844fcb53 0000000000000286 [6515294.873468] Call Trace: [6515294.873473] [] ? dx_release+0x23/0x50 [6515294.873480] [] schedule+0x9/0x20 [6515294.873488] [] start_this_handle+0x365/0x5d0 [6515294.873495] [] ? autoremove_wake_function+0x0/0x40 [6515294.873502] [] jbd2_journal_start+0xa6/0xf0 [6515294.873510] [] ext4_journal_start_sb+0x55/0x90 [6515294.873517] [] ext4_create+0x81/0x130 [6515294.873524] [] vfs_create+0x9a/0xb0 [6515294.873531] [] do_filp_open+0x85e/0x990 [6515294.873538] [] ? getname+0x36/0x200 [6515294.873545] [] ? alloc_fd+0x4a/0x140 [6515294.873552] [] do_sys_open+0x7b/0x110 [6515294.873558] [] sys_open+0x1b/0x20 [6515294.873565] [] system_call_fastpath+0x16/0x1b [6515294.873575] INFO: task drdbmake:3919 blocked for more than 120 seconds. [6515294.873580] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [6515294.873586] drdbmake D ffff88021e56f000 0 3919 27107 [6515294.873594] ffff88021eb4da88 0000000000000082 ffff8801f4cf0ae8 ffff880008ba03f0 [6515294.873605] 0000000000010e80 000000000000c748 ffff8801049063c0 ffff88021f843900 [6515294.873616] ffff880104906730 00000001f4cf0ae8 00000002844c0480 0000000000000282 [6515294.873627] Call Trace: [6515294.873633] [] schedule+0x9/0x20 [6515294.873640] [] start_this_handle+0x365/0x5d0 [6515294.873647] [] ? autoremove_wake_function+0x0/0x40 [6515294.873654] [] jbd2_journal_restart+0xbe/0x150 [6515294.873662] [] ext4_ext_truncate+0x6dd/0xa20 [6515294.873669] [] ? find_get_pages+0x3b/0xf0 [6515294.873676] [] ext4_truncate+0x198/0x680 [6515294.873685] [] ? unmap_mapping_range+0x74/0x280 [6515294.873692] [] ? jbd2_journal_stop+0x1e0/0x360 [6515294.873700] [] vmtruncate+0xa5/0x110 [6515294.873707] [] inode_setattr+0x30/0x180 [6515294.873714] [] ext4_setattr+0x173/0x310 [6515294.873721] [] notify_change+0x119/0x330 [6515294.873728] [] do_truncate+0x63/0x90 [6515294.873734] [] ? get_write_access+0x23/0x60 [6515294.873741] [] sys_truncate+0x17b/0x180 [6515294.873747] [] system_call_fastpath+0x16/0x1b