From: Dave Chinner <david@fromorbit.com> To: Linus Torvalds <torvalds@linux-foundation.org> Cc: Bob Peterson <rpeterso@redhat.com>, "Kirill A. Shutemov" <kirill.shutemov@linux.intel.com>, "Huang, Ying" <ying.huang@intel.com>, Christoph Hellwig <hch@lst.de>, Wu Fengguang <fengguang.wu@intel.com>, LKP <lkp@01.org>, Tejun Heo <tj@kernel.org>, LKML <linux-kernel@vger.kernel.org> Subject: Re: [LKP] [lkp] [xfs] 68a9f5e700: aim7.jobs-per-min -13.6% regression Date: Tue, 16 Aug 2016 10:19:42 +1000 [thread overview] Message-ID: <20160816001942.GF16044@dastard> (raw) In-Reply-To: <CA+55aFzOAorMxCsv3uyyyhS8c5xteVnZVEm+bGyBjkjWVT5Zag@mail.gmail.com> On Mon, Aug 15, 2016 at 04:20:55PM -0700, Linus Torvalds wrote: > On Mon, Aug 15, 2016 at 3:42 PM, Dave Chinner <david@fromorbit.com> wrote: > > > > 31.18% [kernel] [k] __pv_queued_spin_lock_slowpath > > 9.90% [kernel] [k] copy_user_generic_string > > 3.65% [kernel] [k] __raw_callee_save___pv_queued_spin_unlock > > 2.62% [kernel] [k] __block_commit_write.isra.29 > > 2.26% [kernel] [k] _raw_spin_lock_irqsave > > 1.72% [kernel] [k] _raw_spin_lock > > Ok, this is more like it. > > I'd still like to see it on raw hardware, just to see if we may have a > bug in the PV code. Because that code has been buggy before. I > *thought* we fixed it, but ... > > In fact, you don't even need to do it outside of virtualization, but > with paravirt disabled (so that it runs the native non-pv locking in > the virtual machine). > > > 36.60% 0.00% [kernel] [k] kswapd > > - 30.29% kswapd > > - 30.23% shrink_node > > - 30.07% shrink_node_memcg.isra.75 > > - 30.15% shrink_inactive_list > > - 29.49% shrink_page_list > > - 22.79% __remove_mapping > > - 22.27% _raw_spin_lock_irqsave > > __pv_queued_spin_lock_slowpath > > How I dislike the way perf shows the call graph data... Just last week > I was talking to Arnaldo about how to better visualize the cost of > spinlocks, because the normal way "perf" shows costs is so nasty. Do not change it - it's the way call graph profiles have been presented for the past 20 years. I hate it when long standing conventions are changed because one person doesn't like them and everyone else has to relearn skills the haven't had to think about for years.... > What happens is that you see that 36% of CPU time is attributed to > kswapd, and then you can drill down and see where that 36% comes from. > So far so good, and that's what perf does fairly well. > > But then when you find the spinlock, you actually want to go the other > way, and instead ask it to show "who were the callers to this routine > and what were the percentages", so that you can then see whether (for > example) it's just that __remove_mapping() use that contends with > itself, or whether it's contending with the page additions or > whatever.. Um, perf already does that: - 31.55% 31.55% [kernel] [k] __pv_queued_spin_lock_slowpath - 19.83% ret_from_fork - kthread - 18.55% kswapd shrink_node shrink_node_memcg.isra.75 shrink_inactive_list 1.76% worker_thread process_one_work wb_workfn wb_writeback __writeback_inodes_wb writeback_sb_inodes __writeback_single_inode do_writepages xfs_vm_writepages write_cache_pages xfs_do_writepage + 5.95% __libc_pwrite I have that right here because *it's a view of the profile I've already looked at*. I didn't post it because, well, it's shorter to simply say "contention is from in kswapd". > So what I'd like to see (and this is where it becomes *so* much more > useful to be able to recreate it myself so that I can play with the > perf data several different ways) is to see what the profile looks > like in that spinlocked region. Boot your machine with "fake_numa=4", and play till you heart is content. That's all I do with my test VMs to make them exercise NUMA paths. > None of this code is all that new, which is annoying. This must have > gone on forever, Yes, it has been. Just worse than I've notice before, probably because of all the stuff put under the tree lock in the past couple of years. Cheers, Dave. -- Dave Chinner david@fromorbit.com
WARNING: multiple messages have this Message-ID (diff)
From: Dave Chinner <david@fromorbit.com> To: lkp@lists.01.org Subject: Re: [xfs] 68a9f5e700: aim7.jobs-per-min -13.6% regression Date: Tue, 16 Aug 2016 10:19:42 +1000 [thread overview] Message-ID: <20160816001942.GF16044@dastard> (raw) In-Reply-To: <CA+55aFzOAorMxCsv3uyyyhS8c5xteVnZVEm+bGyBjkjWVT5Zag@mail.gmail.com> [-- Attachment #1: Type: text/plain, Size: 3924 bytes --] On Mon, Aug 15, 2016 at 04:20:55PM -0700, Linus Torvalds wrote: > On Mon, Aug 15, 2016 at 3:42 PM, Dave Chinner <david@fromorbit.com> wrote: > > > > 31.18% [kernel] [k] __pv_queued_spin_lock_slowpath > > 9.90% [kernel] [k] copy_user_generic_string > > 3.65% [kernel] [k] __raw_callee_save___pv_queued_spin_unlock > > 2.62% [kernel] [k] __block_commit_write.isra.29 > > 2.26% [kernel] [k] _raw_spin_lock_irqsave > > 1.72% [kernel] [k] _raw_spin_lock > > Ok, this is more like it. > > I'd still like to see it on raw hardware, just to see if we may have a > bug in the PV code. Because that code has been buggy before. I > *thought* we fixed it, but ... > > In fact, you don't even need to do it outside of virtualization, but > with paravirt disabled (so that it runs the native non-pv locking in > the virtual machine). > > > 36.60% 0.00% [kernel] [k] kswapd > > - 30.29% kswapd > > - 30.23% shrink_node > > - 30.07% shrink_node_memcg.isra.75 > > - 30.15% shrink_inactive_list > > - 29.49% shrink_page_list > > - 22.79% __remove_mapping > > - 22.27% _raw_spin_lock_irqsave > > __pv_queued_spin_lock_slowpath > > How I dislike the way perf shows the call graph data... Just last week > I was talking to Arnaldo about how to better visualize the cost of > spinlocks, because the normal way "perf" shows costs is so nasty. Do not change it - it's the way call graph profiles have been presented for the past 20 years. I hate it when long standing conventions are changed because one person doesn't like them and everyone else has to relearn skills the haven't had to think about for years.... > What happens is that you see that 36% of CPU time is attributed to > kswapd, and then you can drill down and see where that 36% comes from. > So far so good, and that's what perf does fairly well. > > But then when you find the spinlock, you actually want to go the other > way, and instead ask it to show "who were the callers to this routine > and what were the percentages", so that you can then see whether (for > example) it's just that __remove_mapping() use that contends with > itself, or whether it's contending with the page additions or > whatever.. Um, perf already does that: - 31.55% 31.55% [kernel] [k] __pv_queued_spin_lock_slowpath - 19.83% ret_from_fork - kthread - 18.55% kswapd shrink_node shrink_node_memcg.isra.75 shrink_inactive_list 1.76% worker_thread process_one_work wb_workfn wb_writeback __writeback_inodes_wb writeback_sb_inodes __writeback_single_inode do_writepages xfs_vm_writepages write_cache_pages xfs_do_writepage + 5.95% __libc_pwrite I have that right here because *it's a view of the profile I've already looked at*. I didn't post it because, well, it's shorter to simply say "contention is from in kswapd". > So what I'd like to see (and this is where it becomes *so* much more > useful to be able to recreate it myself so that I can play with the > perf data several different ways) is to see what the profile looks > like in that spinlocked region. Boot your machine with "fake_numa=4", and play till you heart is content. That's all I do with my test VMs to make them exercise NUMA paths. > None of this code is all that new, which is annoying. This must have > gone on forever, Yes, it has been. Just worse than I've notice before, probably because of all the stuff put under the tree lock in the past couple of years. Cheers, Dave. -- Dave Chinner david(a)fromorbit.com
next prev parent reply other threads:[~2016-08-16 0:38 UTC|newest] Thread overview: 219+ messages / expand[flat|nested] mbox.gz Atom feed top 2016-08-09 14:33 [lkp] [xfs] 68a9f5e700: aim7.jobs-per-min -13.6% regression kernel test robot 2016-08-09 14:33 ` kernel test robot 2016-08-10 18:24 ` [lkp] " Linus Torvalds 2016-08-10 18:24 ` Linus Torvalds 2016-08-10 23:08 ` [lkp] " Dave Chinner 2016-08-10 23:08 ` Dave Chinner 2016-08-10 23:51 ` [lkp] " Linus Torvalds 2016-08-10 23:51 ` Linus Torvalds 2016-08-10 23:58 ` [LKP] [lkp] " Huang, Ying 2016-08-10 23:58 ` Huang, Ying 2016-08-11 0:11 ` [LKP] [lkp] " Huang, Ying 2016-08-11 0:11 ` Huang, Ying 2016-08-11 0:23 ` [LKP] [lkp] " Linus Torvalds 2016-08-11 0:23 ` Linus Torvalds 2016-08-11 0:33 ` [LKP] [lkp] " Huang, Ying 2016-08-11 0:33 ` Huang, Ying 2016-08-11 1:00 ` [LKP] [lkp] " Linus Torvalds 2016-08-11 1:00 ` Linus Torvalds 2016-08-11 4:46 ` [LKP] [lkp] " Dave Chinner 2016-08-11 4:46 ` Dave Chinner 2016-08-15 17:22 ` [LKP] [lkp] " Huang, Ying 2016-08-15 17:22 ` Huang, Ying 2016-08-16 0:08 ` [LKP] [lkp] " Dave Chinner 2016-08-16 0:08 ` Dave Chinner 2016-08-11 15:57 ` [LKP] [lkp] " Christoph Hellwig 2016-08-11 15:57 ` Christoph Hellwig 2016-08-11 16:55 ` [LKP] [lkp] " Linus Torvalds 2016-08-11 16:55 ` Linus Torvalds 2016-08-11 17:51 ` [LKP] [lkp] " Huang, Ying 2016-08-11 17:51 ` Huang, Ying 2016-08-11 19:51 ` [LKP] [lkp] " Linus Torvalds 2016-08-11 19:51 ` Linus Torvalds 2016-08-11 20:00 ` [LKP] [lkp] " Christoph Hellwig 2016-08-11 20:00 ` Christoph Hellwig 2016-08-11 20:35 ` [LKP] [lkp] " Linus Torvalds 2016-08-11 20:35 ` Linus Torvalds 2016-08-11 22:16 ` [LKP] [lkp] " Al Viro 2016-08-11 22:16 ` Al Viro 2016-08-11 22:30 ` [LKP] [lkp] " Linus Torvalds 2016-08-11 22:30 ` Linus Torvalds 2016-08-11 21:16 ` [LKP] [lkp] " Huang, Ying 2016-08-11 21:16 ` Huang, Ying 2016-08-11 21:40 ` [LKP] [lkp] " Linus Torvalds 2016-08-11 21:40 ` Linus Torvalds 2016-08-11 22:08 ` [LKP] [lkp] " Christoph Hellwig 2016-08-11 22:08 ` Christoph Hellwig 2016-08-12 0:54 ` [LKP] [lkp] " Dave Chinner 2016-08-12 0:54 ` Dave Chinner 2016-08-12 2:23 ` [LKP] [lkp] " Dave Chinner 2016-08-12 2:23 ` Dave Chinner 2016-08-12 2:32 ` [LKP] [lkp] " Linus Torvalds 2016-08-12 2:32 ` Linus Torvalds 2016-08-12 2:52 ` [LKP] [lkp] " Christoph Hellwig 2016-08-12 2:52 ` Christoph Hellwig 2016-08-12 3:20 ` [LKP] [lkp] " Linus Torvalds 2016-08-12 3:20 ` Linus Torvalds 2016-08-12 4:16 ` [LKP] [lkp] " Dave Chinner 2016-08-12 4:16 ` Dave Chinner 2016-08-12 5:02 ` [LKP] [lkp] " Linus Torvalds 2016-08-12 5:02 ` Linus Torvalds 2016-08-12 6:04 ` [LKP] [lkp] " Dave Chinner 2016-08-12 6:04 ` Dave Chinner 2016-08-12 6:29 ` [LKP] [lkp] " Ye Xiaolong 2016-08-12 6:29 ` Ye Xiaolong 2016-08-12 8:51 ` [LKP] [lkp] " Ye Xiaolong 2016-08-12 8:51 ` Ye Xiaolong 2016-08-12 10:02 ` [LKP] [lkp] " Dave Chinner 2016-08-12 10:02 ` Dave Chinner 2016-08-12 10:43 ` Fengguang Wu 2016-08-12 10:43 ` Fengguang Wu 2016-08-13 0:30 ` [LKP] [lkp] " Christoph Hellwig 2016-08-13 0:30 ` Christoph Hellwig 2016-08-13 21:48 ` [LKP] [lkp] " Christoph Hellwig 2016-08-13 21:48 ` Christoph Hellwig 2016-08-13 22:07 ` [LKP] [lkp] " Fengguang Wu 2016-08-13 22:07 ` Fengguang Wu 2016-08-13 22:15 ` [LKP] [lkp] " Christoph Hellwig 2016-08-13 22:15 ` Christoph Hellwig 2016-08-13 22:51 ` [LKP] [lkp] " Fengguang Wu 2016-08-13 22:51 ` Fengguang Wu 2016-08-14 14:50 ` [LKP] [lkp] " Fengguang Wu 2016-08-14 14:50 ` Fengguang Wu 2016-08-14 16:17 ` [LKP] [lkp] " Christoph Hellwig 2016-08-14 16:17 ` Christoph Hellwig 2016-08-14 23:46 ` [LKP] [lkp] " Dave Chinner 2016-08-14 23:46 ` Dave Chinner 2016-08-14 23:57 ` [LKP] [lkp] " Fengguang Wu 2016-08-14 23:57 ` Fengguang Wu 2016-08-15 14:14 ` [LKP] [lkp] " Fengguang Wu 2016-08-15 14:14 ` Fengguang Wu 2016-08-15 21:22 ` [LKP] [lkp] " Dave Chinner 2016-08-15 21:22 ` Dave Chinner 2016-08-16 12:20 ` [LKP] [lkp] " Fengguang Wu 2016-08-16 12:20 ` Fengguang Wu 2016-08-15 20:30 ` [LKP] [lkp] " Huang, Ying 2016-08-15 20:30 ` Huang, Ying 2016-08-22 22:09 ` [LKP] [lkp] " Huang, Ying 2016-08-22 22:09 ` Huang, Ying 2016-09-26 6:25 ` [LKP] [lkp] " Huang, Ying 2016-09-26 6:25 ` Huang, Ying 2016-09-26 14:55 ` [LKP] [lkp] " Christoph Hellwig 2016-09-26 14:55 ` Christoph Hellwig 2016-09-27 0:52 ` [LKP] [lkp] " Huang, Ying 2016-09-27 0:52 ` Huang, Ying 2016-08-16 13:25 ` [LKP] [lkp] " Fengguang Wu 2016-08-16 13:25 ` Fengguang Wu 2016-08-13 23:32 ` [LKP] [lkp] " Dave Chinner 2016-08-13 23:32 ` Dave Chinner 2016-08-12 2:27 ` [LKP] [lkp] " Linus Torvalds 2016-08-12 2:27 ` Linus Torvalds 2016-08-12 3:56 ` [LKP] [lkp] " Dave Chinner 2016-08-12 3:56 ` Dave Chinner 2016-08-12 18:03 ` [LKP] [lkp] " Linus Torvalds 2016-08-12 18:03 ` Linus Torvalds 2016-08-13 23:58 ` [LKP] [lkp] " Fengguang Wu 2016-08-13 23:58 ` Fengguang Wu 2016-08-15 0:48 ` [LKP] [lkp] " Dave Chinner 2016-08-15 0:48 ` Dave Chinner 2016-08-15 1:37 ` [LKP] [lkp] " Linus Torvalds 2016-08-15 1:37 ` Linus Torvalds 2016-08-15 2:28 ` [LKP] [lkp] " Dave Chinner 2016-08-15 2:28 ` Dave Chinner 2016-08-15 2:53 ` [LKP] [lkp] " Linus Torvalds 2016-08-15 2:53 ` Linus Torvalds 2016-08-15 5:00 ` [LKP] [lkp] " Dave Chinner 2016-08-15 5:00 ` Dave Chinner [not found] ` <CA+55aFwva2Xffai+Eqv1Jn_NGryk3YJ2i5JoHOQnbQv6qVPAsw@mail.gmail.com> [not found] ` <CA+55aFy14nUnJQ_GdF=j8Fa9xiH70c6fY2G3q5HQ01+8z1z3qQ@mail.gmail.com> 2016-08-15 5:12 ` Linus Torvalds 2016-08-15 22:22 ` [LKP] [lkp] " Dave Chinner 2016-08-15 22:22 ` Dave Chinner 2016-08-15 22:42 ` [LKP] [lkp] " Dave Chinner 2016-08-15 22:42 ` Dave Chinner 2016-08-15 23:20 ` [LKP] [lkp] " Linus Torvalds 2016-08-15 23:20 ` Linus Torvalds 2016-08-15 23:48 ` [LKP] [lkp] " Linus Torvalds 2016-08-15 23:48 ` Linus Torvalds 2016-08-16 0:44 ` [LKP] [lkp] " Dave Chinner 2016-08-16 0:44 ` Dave Chinner 2016-08-16 15:05 ` [LKP] [lkp] " Mel Gorman 2016-08-16 15:05 ` Mel Gorman 2016-08-16 17:47 ` [LKP] [lkp] " Linus Torvalds 2016-08-16 17:47 ` Linus Torvalds 2016-08-17 15:48 ` [LKP] [lkp] " Michal Hocko 2016-08-17 15:48 ` Michal Hocko 2016-08-17 16:42 ` [LKP] [lkp] " Michal Hocko 2016-08-17 16:42 ` Michal Hocko 2016-08-17 15:49 ` [LKP] [lkp] " Mel Gorman 2016-08-17 15:49 ` Mel Gorman 2016-08-18 0:45 ` [LKP] [lkp] " Mel Gorman 2016-08-18 0:45 ` Mel Gorman 2016-08-18 7:11 ` [LKP] [lkp] " Dave Chinner 2016-08-18 7:11 ` Dave Chinner 2016-08-18 13:24 ` [LKP] [lkp] " Mel Gorman 2016-08-18 13:24 ` Mel Gorman 2016-08-18 17:55 ` [LKP] [lkp] " Linus Torvalds 2016-08-18 17:55 ` Linus Torvalds 2016-08-18 21:19 ` [LKP] [lkp] " Dave Chinner 2016-08-18 21:19 ` Dave Chinner 2016-08-18 22:25 ` [LKP] [lkp] " Linus Torvalds 2016-08-18 22:25 ` Linus Torvalds 2016-08-19 9:00 ` [LKP] [lkp] " Michal Hocko 2016-08-19 9:00 ` Michal Hocko 2016-08-19 10:49 ` [LKP] [lkp] " Mel Gorman 2016-08-19 10:49 ` Mel Gorman 2016-08-19 23:48 ` [LKP] [lkp] " Dave Chinner 2016-08-19 23:48 ` Dave Chinner 2016-08-20 1:08 ` [LKP] [lkp] " Linus Torvalds 2016-08-20 1:08 ` Linus Torvalds 2016-08-20 12:16 ` [LKP] [lkp] " Mel Gorman 2016-08-20 12:16 ` Mel Gorman 2016-08-19 15:08 ` [LKP] [lkp] " Mel Gorman 2016-08-19 15:08 ` Mel Gorman 2016-09-01 23:32 ` [LKP] [lkp] " Dave Chinner 2016-09-01 23:32 ` Dave Chinner 2016-09-06 15:37 ` [LKP] [lkp] " Mel Gorman 2016-09-06 15:37 ` Mel Gorman 2016-09-06 15:52 ` [LKP] [lkp] " Huang, Ying 2016-09-06 15:52 ` Huang, Ying 2016-08-24 15:40 ` [LKP] [lkp] " Huang, Ying 2016-08-24 15:40 ` Huang, Ying 2016-08-25 9:37 ` [LKP] [lkp] " Mel Gorman 2016-08-25 9:37 ` Mel Gorman 2016-08-18 2:44 ` [LKP] [lkp] " Dave Chinner 2016-08-18 2:44 ` Dave Chinner 2016-08-16 0:15 ` [LKP] [lkp] " Linus Torvalds 2016-08-16 0:15 ` Linus Torvalds 2016-08-16 0:38 ` [LKP] [lkp] " Dave Chinner 2016-08-16 0:38 ` Dave Chinner 2016-08-16 0:50 ` [LKP] [lkp] " Linus Torvalds 2016-08-16 0:50 ` Linus Torvalds 2016-08-16 0:19 ` Dave Chinner [this message] 2016-08-16 0:19 ` Dave Chinner 2016-08-16 1:51 ` [LKP] [lkp] " Linus Torvalds 2016-08-16 1:51 ` Linus Torvalds 2016-08-16 22:02 ` [LKP] [lkp] " Dave Chinner 2016-08-16 22:02 ` Dave Chinner 2016-08-16 23:23 ` [LKP] [lkp] " Linus Torvalds 2016-08-16 23:23 ` Linus Torvalds 2016-08-15 23:01 ` [LKP] [lkp] " Linus Torvalds 2016-08-15 23:01 ` Linus Torvalds 2016-08-16 0:17 ` [LKP] [lkp] " Dave Chinner 2016-08-16 0:17 ` Dave Chinner 2016-08-16 0:45 ` [LKP] [lkp] " Linus Torvalds 2016-08-16 0:45 ` Linus Torvalds 2016-08-15 5:03 ` [LKP] [lkp] " Ingo Molnar 2016-08-15 5:03 ` Ingo Molnar 2016-08-17 16:24 ` [LKP] [lkp] " Peter Zijlstra 2016-08-17 16:24 ` Peter Zijlstra 2016-08-15 12:58 ` [LKP] [lkp] " Fengguang Wu 2016-08-15 12:58 ` Fengguang Wu 2016-08-11 1:16 ` [LKP] [lkp] " Dave Chinner 2016-08-11 1:16 ` Dave Chinner 2016-08-11 1:32 ` [LKP] [lkp] " Dave Chinner 2016-08-11 1:32 ` Dave Chinner 2016-08-11 2:36 ` [LKP] [lkp] " Ye Xiaolong 2016-08-11 2:36 ` Ye Xiaolong 2016-08-11 3:05 ` [LKP] [lkp] " Dave Chinner 2016-08-11 3:05 ` Dave Chinner 2016-08-12 1:26 ` [LKP] [lkp] " Dave Chinner 2016-08-12 1:26 ` Dave Chinner
Reply instructions: You may reply publicly to this message via plain-text email using any one of the following methods: * Save the following mbox file, import it into your mail client, and reply-to-all from there: mbox Avoid top-posting and favor interleaved quoting: https://en.wikipedia.org/wiki/Posting_style#Interleaved_style * Reply using the --to, --cc, and --in-reply-to switches of git-send-email(1): git send-email \ --in-reply-to=20160816001942.GF16044@dastard \ --to=david@fromorbit.com \ --cc=fengguang.wu@intel.com \ --cc=hch@lst.de \ --cc=kirill.shutemov@linux.intel.com \ --cc=linux-kernel@vger.kernel.org \ --cc=lkp@01.org \ --cc=rpeterso@redhat.com \ --cc=tj@kernel.org \ --cc=torvalds@linux-foundation.org \ --cc=ying.huang@intel.com \ /path/to/YOUR_REPLY https://kernel.org/pub/software/scm/git/docs/git-send-email.html * If your mail client supports setting the In-Reply-To header via mailto: links, try the mailto: linkBe sure your reply has a Subject: header at the top and a blank line before the message body.
This is an external index of several public inboxes, see mirroring instructions on how to clone and mirror all data and code used by this external index.