Groups | Search | Server Info | Keyboard shortcuts | Login | Register [http] [https] [nntp] [nntps]

Groups > linux.kernel > #1501383 > unrolled thread

Re: [RFC] scripts: Include postprocessing script for memory allocation tracing

Back to article view | Back to linux.kernel

This discussion starts older than the indexed window; earlier articles aren't shown. The article labeled Started by below is the oldest one visible, not the original post.

Contents

  Re: [RFC] scripts: Include postprocessing script for memory allocation tracing Janani Ravichandran <janani.rvchndrn@gmail.com> - 2016-10-16 01:40 +0200
    Re: [RFC] scripts: Include postprocessing script for memory  allocation tracing Michal Hocko <mhocko@kernel.org> - 2016-10-16 09:40 +0200
      Re: [RFC] scripts: Include postprocessing script for memory  allocation tracing Michal Hocko <mhocko@kernel.org> - 2016-10-18 15:20 +0200
        Re: [RFC] scripts: Include postprocessing script for memory allocation tracing Janani Ravichandran <janani.rvchndrn@gmail.com> - 2016-10-21 01:20 +0200
          Re: [RFC] scripts: Include postprocessing script for memory  allocation tracing Michal Hocko <mhocko@kernel.org> - 2016-10-21 09:10 +0200

#1501383 — Re: [RFC] scripts: Include postprocessing script for memory allocation tracing

> On Oct 11, 2016, at 10:43 AM, Janani Ravichandran <janani.rvchndrn@gmail.com> wrote:
> 
> Alright. I’ll add a starting tracepoint, change the script accordingly and 
> send a v2. Thanks!
> 
I looked at it again and I think that the context information we need 
can be obtained from the tracepoint trace_mm_page_alloc in 
alloc_pages_nodemask().

I’ll include that tracepoint in the script and send it along with the other
changes you suggested, if you’re fine with it.

Thanks!
Janani.
>> 
> 

[toc] | [next] | [standalone]

#1501412 — Re: [RFC] scripts: Include postprocessing script for memory allocation tracing

On Sat 15-10-16 19:31:22, Janani Ravichandran wrote:
> 
> > On Oct 11, 2016, at 10:43 AM, Janani Ravichandran <janani.rvchndrn@gmail.com> wrote:
> > 
> > Alright. I’ll add a starting tracepoint, change the script accordingly and 
> > send a v2. Thanks!
> > 
> I looked at it again and I think that the context information we need 
> can be obtained from the tracepoint trace_mm_page_alloc in 
> alloc_pages_nodemask().

trace_mm_page_alloc will tell you details about the allocation, like
gfp mask, order but it doesn't tell you how long the allocation took at
its current form. So either you have to note jiffies at the allocation
start and then add the end-start in the trace point or we really need
another trace point to note the start. The later has an advantage that
we do not add unnecessary load for jiffies when the tracepoint is
disabled.
-- 
Michal Hocko
SUSE Labs

[toc] | [prev] | [next] | [standalone]

#1502988 — Re: [RFC] scripts: Include postprocessing script for memory allocation tracing

On Mon 17-10-16 13:31:57, Janani Ravichandran wrote:
> 
> > On Oct 17, 2016, at 1:24 PM, Janani Ravichandran <janani.rvchndrn@gmail.com> wrote:
> > 
> > 
> > On Sun, Oct 16, 2016 at 3:33 AM, Michal Hocko <mhocko@kernel.org <mailto:mhocko@kernel.org>> wrote:
> > 
> > trace_mm_page_alloc will tell you details about the allocation, like
> > gfp mask, order but it doesn't tell you how long the allocation took at
> > its current form. So either you have to note jiffies at the allocation
> > start and then add the end-start in the trace point or we really need
> > another trace point to note the start. The later has an advantage that
> > we do not add unnecessary load for jiffies when the tracepoint is
> > disabled.
> 
> The function graph tracer can tell us how long alloc_pages_nodemask() took.
> Can’t that, combined with the context information given by trace_mm_page_alloc
> give us what we want? Correct me if I am wrong.

yes, function_graph tracer will give you _some_ information but it will
not have the context you are looking for, right? See the following
example

 ------------------------------------------
 0) x-www-b-22756  =>  x-termi-4083 
 ------------------------------------------

 0)               |  __alloc_pages_nodemask() {
 0)               |  /* mm_page_alloc: page=ffffea000411b380 pfn=1066702 order=0 migratetype=0 gfp_flags=GFP_KERNEL */
 0)   3.328 us    |  }
 3)               |  __alloc_pages_nodemask() {
 3)               |  /* mm_page_alloc: page=ffffea0008f1f6c0 pfn=2344923 order=0 migratetype=0 gfp_flags=GFP_KERNEL */
 3)   1.011 us    |  }
 0)               |  __alloc_pages_nodemask() {
 0)               |  /* mm_page_alloc: page=ffffea000411b380 pfn=1066702 order=0 migratetype=0 gfp_flags=GFP_KERNEL */
 0)   0.587 us    |  }
 3)               |  __alloc_pages_nodemask() {
 3)               |  /* mm_page_alloc: page=ffffea0008f1f6c0 pfn=2344923 order=0 migratetype=0 gfp_flags=GFP_KERNEL */
 3)   1.125 us    |  }

How do I know which process has performed those allocations? I know that
CPU0 should be running x-termi-4083 but what is running on other CPUs?

Let me explain my usecase I am very interested in. Say I that a usespace
application is not performing well. I would like to see some statistics
about memory allocations performed for that app - are there few outliers
or the allocation stalls increase gradually? Where do we spend time during
that allocation? Reclaim LRU pages? Compaction or the slab shrinkers?

To answer those questions I need to track particular events (alocation,
reclaim, compaction) to the process and know how long each step
took. Maybe we can reconstruct something from the above output but it is
a major PITA.  If we either hard start/stop pairs for each step (which
we already do have for reclaim, compaction AFAIR) then this is an easy
scripting. Another option would be to have only a single tracepoint for
each step with a timing information.

See my point?
-- 
Michal Hocko
SUSE Labs

[toc] | [prev] | [next] | [standalone]

#1505323

Michal,

> On Oct 18, 2016, at 8:13 AM, Michal Hocko <mhocko@kernel.org> wrote:
> 
>> 
> 
> yes, function_graph tracer will give you _some_ information but it will
> not have the context you are looking for, right? See the following
> example
> 
> ------------------------------------------
> 0) x-www-b-22756  =>  x-termi-4083 
> ------------------------------------------
> 
> 0)               |  __alloc_pages_nodemask() {
> 0)               |  /* mm_page_alloc: page=ffffea000411b380 pfn=1066702 order=0 migratetype=0 gfp_flags=GFP_KERNEL */
> 0)   3.328 us    |  }
> 3)               |  __alloc_pages_nodemask() {
> 3)               |  /* mm_page_alloc: page=ffffea0008f1f6c0 pfn=2344923 order=0 migratetype=0 gfp_flags=GFP_KERNEL */
> 3)   1.011 us    |  }
> 0)               |  __alloc_pages_nodemask() {
> 0)               |  /* mm_page_alloc: page=ffffea000411b380 pfn=1066702 order=0 migratetype=0 gfp_flags=GFP_KERNEL */
> 0)   0.587 us    |  }
> 3)               |  __alloc_pages_nodemask() {
> 3)               |  /* mm_page_alloc: page=ffffea0008f1f6c0 pfn=2344923 order=0 migratetype=0 gfp_flags=GFP_KERNEL */
> 3)   1.125 us    |  }
> 
> How do I know which process has performed those allocations? I know that
> CPU0 should be running x-termi-4083 but what is running on other CPUs?
> 
> Let me explain my usecase I am very interested in. Say I that a usespace
> application is not performing well. I would like to see some statistics
> about memory allocations performed for that app - are there few outliers
> or the allocation stalls increase gradually? Where do we spend time during
> that allocation? Reclaim LRU pages? Compaction or the slab shrinkers?
> 
> To answer those questions I need to track particular events (alocation,
> reclaim, compaction) to the process and know how long each step
> took. Maybe we can reconstruct something from the above output but it is
> a major PITA.  If we either hard start/stop pairs for each step (which
> we already do have for reclaim, compaction AFAIR) then this is an easy
> scripting. Another option would be to have only a single tracepoint for
> each step with a timing information.
> 
> See my point?

Yes, if we want to know what processes are running on what CPUs,
echo funcgraph-proc > trace_options in the tracing directory should give us
what we want.

The bash script which is part of this patch does this kind of setup for you.
As a result, the output you get is something like what you see here:

https://github.com/Jananiravichandran/Analyzing-tracepoints/blob/master/no_tp_no_threshold.txt

Does this answer your question? Let me know if otherwise.

Janani.

> -- 
> Michal Hocko
> SUSE Labs

[toc] | [prev] | [next] | [standalone]

#1505516 — Re: [RFC] scripts: Include postprocessing script for memory allocation tracing

On Thu 20-10-16 18:10:37, Janani Ravichandran wrote:
> Michal,
> 
> > On Oct 18, 2016, at 8:13 AM, Michal Hocko <mhocko@kernel.org> wrote:
> > 
> >> 
> > 
> > yes, function_graph tracer will give you _some_ information but it will
> > not have the context you are looking for, right? See the following
> > example
> > 
> > ------------------------------------------
> > 0) x-www-b-22756  =>  x-termi-4083 
> > ------------------------------------------
> > 
> > 0)               |  __alloc_pages_nodemask() {
> > 0)               |  /* mm_page_alloc: page=ffffea000411b380 pfn=1066702 order=0 migratetype=0 gfp_flags=GFP_KERNEL */
> > 0)   3.328 us    |  }
> > 3)               |  __alloc_pages_nodemask() {
> > 3)               |  /* mm_page_alloc: page=ffffea0008f1f6c0 pfn=2344923 order=0 migratetype=0 gfp_flags=GFP_KERNEL */
> > 3)   1.011 us    |  }
> > 0)               |  __alloc_pages_nodemask() {
> > 0)               |  /* mm_page_alloc: page=ffffea000411b380 pfn=1066702 order=0 migratetype=0 gfp_flags=GFP_KERNEL */
> > 0)   0.587 us    |  }
> > 3)               |  __alloc_pages_nodemask() {
> > 3)               |  /* mm_page_alloc: page=ffffea0008f1f6c0 pfn=2344923 order=0 migratetype=0 gfp_flags=GFP_KERNEL */
> > 3)   1.125 us    |  }
> > 
> > How do I know which process has performed those allocations? I know that
> > CPU0 should be running x-termi-4083 but what is running on other CPUs?
> > 
> > Let me explain my usecase I am very interested in. Say I that a usespace
> > application is not performing well. I would like to see some statistics
> > about memory allocations performed for that app - are there few outliers
> > or the allocation stalls increase gradually? Where do we spend time during
> > that allocation? Reclaim LRU pages? Compaction or the slab shrinkers?
> > 
> > To answer those questions I need to track particular events (alocation,
> > reclaim, compaction) to the process and know how long each step
> > took. Maybe we can reconstruct something from the above output but it is
> > a major PITA.  If we either hard start/stop pairs for each step (which
> > we already do have for reclaim, compaction AFAIR) then this is an easy
> > scripting. Another option would be to have only a single tracepoint for
> > each step with a timing information.
> > 
> > See my point?
> 
> Yes, if we want to know what processes are running on what CPUs,
> echo funcgraph-proc > trace_options in the tracing directory should give us
> what we want.

Interesting.
$ cat /debug/tracing/available_tracers 
function_graph preemptirqsoff preemptoff irqsoff function nop

Do I have to configure anything specially? And if I do why isn't it any
better to simply add a start tracepoint and make this available also to
older kernels?
-- 
Michal Hocko
SUSE Labs

[toc] | [prev] | [standalone]

Back to top | Article view | linux.kernel

csiph-web