From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1751931Ab3GJIGN (ORCPT ); Wed, 10 Jul 2013 04:06:13 -0400 Received: from cantor2.suse.de ([195.135.220.15]:46605 "EHLO mx2.suse.de" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1751196Ab3GJIGI (ORCPT ); Wed, 10 Jul 2013 04:06:08 -0400 Date: Wed, 10 Jul 2013 10:06:05 +0200 From: Michal Hocko To: Dave Chinner Cc: Glauber Costa , Andrew Morton , linux-mm@kvack.org, LKML Subject: Re: linux-next: slab shrinkers: BUG at mm/list_lru.c:92 Message-ID: <20130710080605.GC4437@dhcp22.suse.cz> References: <20130701012558.GB27780@dastard> <20130701075005.GA28765@dhcp22.suse.cz> <20130701081056.GA4072@dastard> <20130702092200.GB16815@dhcp22.suse.cz> <20130702121947.GE14996@dastard> <20130702124427.GG16815@dhcp22.suse.cz> <20130703112403.GP14996@dastard> <20130704163643.GF7833@dhcp22.suse.cz> <20130708125352.GC20149@dhcp22.suse.cz> <20130710023138.GO3438@dastard> MIME-Version: 1.0 Content-Type: text/plain; charset=us-ascii Content-Disposition: inline In-Reply-To: <20130710023138.GO3438@dastard> User-Agent: Mutt/1.5.21 (2010-09-15) Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org On Wed 10-07-13 12:31:39, Dave Chinner wrote: [...] > > 20761 [] xlog_grant_head_wait+0xdd/0x1a0 [xfs] > > [] xlog_grant_head_check+0xc6/0xe0 [xfs] > > [] xfs_log_reserve+0xff/0x240 [xfs] > > [] xfs_trans_reserve+0x234/0x240 [xfs] > > [] xfs_create+0x1a9/0x5c0 [xfs] > > [] xfs_vn_mknod+0x8a/0x1a0 [xfs] > > [] xfs_vn_create+0xe/0x10 [xfs] > > [] vfs_create+0xad/0xd0 > > [] lookup_open+0x1b8/0x1d0 > > [] do_last+0x2de/0x780 > > [] path_openat+0xda/0x400 > > [] do_filp_open+0x43/0xa0 > > [] do_sys_open+0x160/0x1e0 > > [] sys_open+0x1c/0x20 > > [] system_call_fastpath+0x16/0x1b > > [] 0xffffffffffffffff > > That's an XFS log space issue, indicating that it has run out of > space in IO the log and it is waiting for more to come free. That > requires IO completion to occur. > > > [276962.652076] INFO: task xfs-data/sda9:930 blocked for more than 480 seconds. > > [276962.652087] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. > > [276962.652093] xfs-data/sda9 D ffff88001ffb9cc8 0 930 2 0x00000000 > > Oh, that's why. This is the IO completion worker... But that task doesn't seem to be stuck anymore (at least lockup watchdog doesn't report it anymore and I have already rebooted to test with ext3 :/). I am sorry if the these lockups logs were more confusing than helpful, but they happened _long_ time ago and the system obviously recovered from them. I am pasting only the traces for processes in D state here again for reference. 14442 [] sleep_on_page+0x9/0x10 [] wait_on_page_bit+0x6f/0x80 [] shrink_page_list+0x503/0x790 [] shrink_inactive_list+0x1bb/0x570 [] shrink_lruvec+0xf9/0x330 [] mem_cgroup_shrink_node_zone+0xda/0x140 [] mem_cgroup_soft_reclaim+0xb2/0x140 [] mem_cgroup_soft_limit_reclaim+0x9f/0x270 [] shrink_zones+0x108/0x220 [] do_try_to_free_pages+0x8a/0x360 [] try_to_free_pages+0x130/0x180 [] __alloc_pages_slowpath+0x39e/0x790 [] __alloc_pages_nodemask+0x1fa/0x210 [] alloc_pages_vma+0xa0/0x120 [] read_swap_cache_async+0x113/0x160 [] swapin_readahead+0x101/0x190 [] do_swap_page+0xef/0x5e0 [] handle_pte_fault+0x1bd/0x240 [] handle_mm_fault+0x2ef/0x400 [] __do_page_fault+0x237/0x4f0 [] do_page_fault+0x9/0x10 [] page_fault+0x28/0x30 [] 0xffffffffffffffff 14962 [] sleep_on_page+0x9/0x10 [] wait_on_page_bit+0x6f/0x80 [] shrink_page_list+0x503/0x790 [] shrink_inactive_list+0x1bb/0x570 [] shrink_lruvec+0xf9/0x330 [] mem_cgroup_shrink_node_zone+0xda/0x140 [] mem_cgroup_soft_reclaim+0xb2/0x140 [] mem_cgroup_soft_limit_reclaim+0x9f/0x270 [] shrink_zones+0x108/0x220 [] do_try_to_free_pages+0x8a/0x360 [] try_to_free_pages+0x130/0x180 [] __alloc_pages_slowpath+0x39e/0x790 [] __alloc_pages_nodemask+0x1fa/0x210 [] alloc_pages_vma+0xa0/0x120 [] do_anonymous_page+0x16b/0x350 [] handle_pte_fault+0x235/0x240 [] handle_mm_fault+0x2ef/0x400 [] __do_page_fault+0x237/0x4f0 [] do_page_fault+0x9/0x10 [] page_fault+0x28/0x30 [] 0xffffffffffffffff 20757 [] xlog_grant_head_wait+0xdd/0x1a0 [xfs] [] xlog_grant_head_check+0xc6/0xe0 [xfs] [] xfs_log_reserve+0xff/0x240 [xfs] [] xfs_trans_reserve+0x234/0x240 [xfs] [] xfs_free_eofblocks+0x180/0x250 [xfs] [] xfs_release+0x106/0x1d0 [xfs] [] xfs_file_release+0x10/0x20 [xfs] [] __fput+0xbd/0x240 [] ____fput+0x9/0x10 [] task_work_run+0xb1/0xe0 [] do_notify_resume+0x90/0x1d0 [] int_signal+0x12/0x17 [] 0xffffffffffffffff 20758 [] xlog_grant_head_wait+0xdd/0x1a0 [xfs] [] xlog_grant_head_check+0xc6/0xe0 [xfs] [] xfs_log_reserve+0xff/0x240 [xfs] [] xfs_trans_reserve+0x234/0x240 [xfs] [] xfs_create+0x1a9/0x5c0 [xfs] [] xfs_vn_mknod+0x8a/0x1a0 [xfs] [] xfs_vn_create+0xe/0x10 [xfs] [] vfs_create+0xad/0xd0 [] lookup_open+0x1b8/0x1d0 [] do_last+0x2de/0x780 [] path_openat+0xda/0x400 [] do_filp_open+0x43/0xa0 [] do_sys_open+0x160/0x1e0 [] sys_open+0x1c/0x20 [] system_call_fastpath+0x16/0x1b [] 0xffffffffffffffff 20761 [] xlog_grant_head_wait+0xdd/0x1a0 [xfs] [] xlog_grant_head_check+0xc6/0xe0 [xfs] [] xfs_log_reserve+0xff/0x240 [xfs] [] xfs_trans_reserve+0x234/0x240 [xfs] [] xfs_create+0x1a9/0x5c0 [xfs] [] xfs_vn_mknod+0x8a/0x1a0 [xfs] [] xfs_vn_create+0xe/0x10 [xfs] [] vfs_create+0xad/0xd0 [] lookup_open+0x1b8/0x1d0 [] do_last+0x2de/0x780 [] path_openat+0xda/0x400 [] do_filp_open+0x43/0xa0 [] do_sys_open+0x160/0x1e0 [] sys_open+0x1c/0x20 [] system_call_fastpath+0x16/0x1b [] 0xffffffffffffffff We are wating for page under writeback but neither of the 2 paths starts in xfs code. So I do not think waiting for PageWriteback causes a deadlock here. [...] > ... is running IO completion work and trying to commit a transaction > that is blocked in memory allocation which is waiting for IO > completion. It's disappeared up it's own fundamental orifice. > > Ok, this has absolutely nothing to do with the LRU changes - this is > a pre-existing XFS/mm interaction problem from around 3.2. The > question is now this: how the hell do I get memory allocation to not > block waiting on IO completion here? This is already being done in > GFP_NOFS allocation context here.... Just for reference. wait_on_page_writeback is issued only for memcg reclaim because there is no other throttling mechanism to prevent from too many dirty pages on the list, thus pre-mature OOM killer. See e62e384e9d (memcg: prevent OOM with too many dirty pages) for more details. The original patch relied on may_enter_fs but that check disappeared by later changes by c3b94f44fc (memcg: further prevent OOM with too many dirty pages). -- Michal Hocko SUSE Labs From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: from psmtp.com (na3sys010amx141.postini.com [74.125.245.141]) by kanga.kvack.org (Postfix) with SMTP id E008B6B0033 for ; Wed, 10 Jul 2013 04:06:07 -0400 (EDT) Date: Wed, 10 Jul 2013 10:06:05 +0200 From: Michal Hocko Subject: Re: linux-next: slab shrinkers: BUG at mm/list_lru.c:92 Message-ID: <20130710080605.GC4437@dhcp22.suse.cz> References: <20130701012558.GB27780@dastard> <20130701075005.GA28765@dhcp22.suse.cz> <20130701081056.GA4072@dastard> <20130702092200.GB16815@dhcp22.suse.cz> <20130702121947.GE14996@dastard> <20130702124427.GG16815@dhcp22.suse.cz> <20130703112403.GP14996@dastard> <20130704163643.GF7833@dhcp22.suse.cz> <20130708125352.GC20149@dhcp22.suse.cz> <20130710023138.GO3438@dastard> MIME-Version: 1.0 Content-Type: text/plain; charset=us-ascii Content-Disposition: inline In-Reply-To: <20130710023138.GO3438@dastard> Sender: owner-linux-mm@kvack.org List-ID: To: Dave Chinner Cc: Glauber Costa , Andrew Morton , linux-mm@kvack.org, LKML On Wed 10-07-13 12:31:39, Dave Chinner wrote: [...] > > 20761 [] xlog_grant_head_wait+0xdd/0x1a0 [xfs] > > [] xlog_grant_head_check+0xc6/0xe0 [xfs] > > [] xfs_log_reserve+0xff/0x240 [xfs] > > [] xfs_trans_reserve+0x234/0x240 [xfs] > > [] xfs_create+0x1a9/0x5c0 [xfs] > > [] xfs_vn_mknod+0x8a/0x1a0 [xfs] > > [] xfs_vn_create+0xe/0x10 [xfs] > > [] vfs_create+0xad/0xd0 > > [] lookup_open+0x1b8/0x1d0 > > [] do_last+0x2de/0x780 > > [] path_openat+0xda/0x400 > > [] do_filp_open+0x43/0xa0 > > [] do_sys_open+0x160/0x1e0 > > [] sys_open+0x1c/0x20 > > [] system_call_fastpath+0x16/0x1b > > [] 0xffffffffffffffff > > That's an XFS log space issue, indicating that it has run out of > space in IO the log and it is waiting for more to come free. That > requires IO completion to occur. > > > [276962.652076] INFO: task xfs-data/sda9:930 blocked for more than 480 seconds. > > [276962.652087] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. > > [276962.652093] xfs-data/sda9 D ffff88001ffb9cc8 0 930 2 0x00000000 > > Oh, that's why. This is the IO completion worker... But that task doesn't seem to be stuck anymore (at least lockup watchdog doesn't report it anymore and I have already rebooted to test with ext3 :/). I am sorry if the these lockups logs were more confusing than helpful, but they happened _long_ time ago and the system obviously recovered from them. I am pasting only the traces for processes in D state here again for reference. 14442 [] sleep_on_page+0x9/0x10 [] wait_on_page_bit+0x6f/0x80 [] shrink_page_list+0x503/0x790 [] shrink_inactive_list+0x1bb/0x570 [] shrink_lruvec+0xf9/0x330 [] mem_cgroup_shrink_node_zone+0xda/0x140 [] mem_cgroup_soft_reclaim+0xb2/0x140 [] mem_cgroup_soft_limit_reclaim+0x9f/0x270 [] shrink_zones+0x108/0x220 [] do_try_to_free_pages+0x8a/0x360 [] try_to_free_pages+0x130/0x180 [] __alloc_pages_slowpath+0x39e/0x790 [] __alloc_pages_nodemask+0x1fa/0x210 [] alloc_pages_vma+0xa0/0x120 [] read_swap_cache_async+0x113/0x160 [] swapin_readahead+0x101/0x190 [] do_swap_page+0xef/0x5e0 [] handle_pte_fault+0x1bd/0x240 [] handle_mm_fault+0x2ef/0x400 [] __do_page_fault+0x237/0x4f0 [] do_page_fault+0x9/0x10 [] page_fault+0x28/0x30 [] 0xffffffffffffffff 14962 [] sleep_on_page+0x9/0x10 [] wait_on_page_bit+0x6f/0x80 [] shrink_page_list+0x503/0x790 [] shrink_inactive_list+0x1bb/0x570 [] shrink_lruvec+0xf9/0x330 [] mem_cgroup_shrink_node_zone+0xda/0x140 [] mem_cgroup_soft_reclaim+0xb2/0x140 [] mem_cgroup_soft_limit_reclaim+0x9f/0x270 [] shrink_zones+0x108/0x220 [] do_try_to_free_pages+0x8a/0x360 [] try_to_free_pages+0x130/0x180 [] __alloc_pages_slowpath+0x39e/0x790 [] __alloc_pages_nodemask+0x1fa/0x210 [] alloc_pages_vma+0xa0/0x120 [] do_anonymous_page+0x16b/0x350 [] handle_pte_fault+0x235/0x240 [] handle_mm_fault+0x2ef/0x400 [] __do_page_fault+0x237/0x4f0 [] do_page_fault+0x9/0x10 [] page_fault+0x28/0x30 [] 0xffffffffffffffff 20757 [] xlog_grant_head_wait+0xdd/0x1a0 [xfs] [] xlog_grant_head_check+0xc6/0xe0 [xfs] [] xfs_log_reserve+0xff/0x240 [xfs] [] xfs_trans_reserve+0x234/0x240 [xfs] [] xfs_free_eofblocks+0x180/0x250 [xfs] [] xfs_release+0x106/0x1d0 [xfs] [] xfs_file_release+0x10/0x20 [xfs] [] __fput+0xbd/0x240 [] ____fput+0x9/0x10 [] task_work_run+0xb1/0xe0 [] do_notify_resume+0x90/0x1d0 [] int_signal+0x12/0x17 [] 0xffffffffffffffff 20758 [] xlog_grant_head_wait+0xdd/0x1a0 [xfs] [] xlog_grant_head_check+0xc6/0xe0 [xfs] [] xfs_log_reserve+0xff/0x240 [xfs] [] xfs_trans_reserve+0x234/0x240 [xfs] [] xfs_create+0x1a9/0x5c0 [xfs] [] xfs_vn_mknod+0x8a/0x1a0 [xfs] [] xfs_vn_create+0xe/0x10 [xfs] [] vfs_create+0xad/0xd0 [] lookup_open+0x1b8/0x1d0 [] do_last+0x2de/0x780 [] path_openat+0xda/0x400 [] do_filp_open+0x43/0xa0 [] do_sys_open+0x160/0x1e0 [] sys_open+0x1c/0x20 [] system_call_fastpath+0x16/0x1b [] 0xffffffffffffffff 20761 [] xlog_grant_head_wait+0xdd/0x1a0 [xfs] [] xlog_grant_head_check+0xc6/0xe0 [xfs] [] xfs_log_reserve+0xff/0x240 [xfs] [] xfs_trans_reserve+0x234/0x240 [xfs] [] xfs_create+0x1a9/0x5c0 [xfs] [] xfs_vn_mknod+0x8a/0x1a0 [xfs] [] xfs_vn_create+0xe/0x10 [xfs] [] vfs_create+0xad/0xd0 [] lookup_open+0x1b8/0x1d0 [] do_last+0x2de/0x780 [] path_openat+0xda/0x400 [] do_filp_open+0x43/0xa0 [] do_sys_open+0x160/0x1e0 [] sys_open+0x1c/0x20 [] system_call_fastpath+0x16/0x1b [] 0xffffffffffffffff We are wating for page under writeback but neither of the 2 paths starts in xfs code. So I do not think waiting for PageWriteback causes a deadlock here. [...] > ... is running IO completion work and trying to commit a transaction > that is blocked in memory allocation which is waiting for IO > completion. It's disappeared up it's own fundamental orifice. > > Ok, this has absolutely nothing to do with the LRU changes - this is > a pre-existing XFS/mm interaction problem from around 3.2. The > question is now this: how the hell do I get memory allocation to not > block waiting on IO completion here? This is already being done in > GFP_NOFS allocation context here.... Just for reference. wait_on_page_writeback is issued only for memcg reclaim because there is no other throttling mechanism to prevent from too many dirty pages on the list, thus pre-mature OOM killer. See e62e384e9d (memcg: prevent OOM with too many dirty pages) for more details. The original patch relied on may_enter_fs but that check disappeared by later changes by c3b94f44fc (memcg: further prevent OOM with too many dirty pages). -- Michal Hocko SUSE Labs -- To unsubscribe, send a message with 'unsubscribe linux-mm' in the body to majordomo@kvack.org. For more info on Linux MM, see: http://www.linux-mm.org/ . Don't email: email@kvack.org