[ltt-dev] ltt trace doesn't show event mm.page_alloc

[ltt-dev] ltt trace doesn't show event mm.page_alloc

[Dany Madden]

Hi,

Ltt trace doesn't show mm.page_alloc event with the mainline kernel:

- mainline kernel 2.6.32.12
- patch-2.6.32.9-lttng-0.198
- ltt-control-0.79-01022010
- lttv-0.12.30-02102010

mm-trace.ko is loaded.

ltt-armall output shows
....
Connecting /sys/kernel/debug/ltt/markers/mm/wait_on_page_start
Connecting /sys/kernel/debug/ltt/markers/mm/wait_on_page_end
Connecting /sys/kernel/debug/ltt/markers/mm/huge_page_free
Connecting /sys/kernel/debug/ltt/markers/mm/huge_page_alloc
Connecting /sys/kernel/debug/ltt/markers/mm/page_free
Connecting /sys/kernel/debug/ltt/markers/mm/page_alloc
Connecting /sys/kernel/debug/ltt/markers/mm/swap_in
Connecting /sys/kernel/debug/ltt/markers/mm/swap_out
Connecting /sys/kernel/debug/ltt/markers/mm/swap_file_close
Connecting /sys/kernel/debug/ltt/markers/mm/swap_file_open
Connecting /sys/kernel/debug/ltt/markers/mm/add_to_page_cache
Connecting /sys/kernel/debug/ltt/markers/mm/remove_from_page_cache
...

These are the steps to recreate the problem:
% lttctl -C -w /tmp/trace4 trace4
% # ** run a program that does a lot of malloc and free
% lttctl -D trace4

# even mm.page_alloc is **not** showing in the trace
% lttv -m textDump --fatal -e event.name=mm.page_alloc -t /tmp/trace4
Trace set contains 1 traces

End trace set

# even mm.page_free is showing in the trace.
% lttv -m textDump --process_stats -e event.name=mm.page_free -t
/tmp/trace4
Trace set contains 1 traces
...
mm.page_free: 7334.057610863 (/tmp/trace4/mm_1), 6200, 6200, ./ltt_alloc, ,
4962, 0x0, SYSCALL { pfn = 487653, order = 0 }
mm.page_free: 7334.057612915 (/tmp/trace4/mm_1), 6200, 6200, ./ltt_alloc, ,
4962, 0x0, SYSCALL { pfn = 510031, order = 0 }
mm.page_free: 7334.057613190 (/tmp/trace4/mm_1), 6200, 6200, ./ltt_alloc, ,
4962, 0x0, SYSCALL { pfn = 510030, order = 0 }
...

Please help look at this problem.

Thanks!
Dany
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.casi.polymtl.ca/pipermail/lttng-dev/attachments/20100614/ac6d9260/attachment-0003.htm>

[ltt-dev] ltt trace doesn't show event mm.page_alloc

[Josh Boyer]

On Mon, Jun 14, 2010 at 10:16:46AM -0700, Dany Madden wrote:
>Hi,
>
>Ltt trace doesn't show mm.page_alloc event with the mainline kernel:
>
>- mainline kernel 2.6.32.12
>- patch-2.6.32.9-lttng-0.198
>- ltt-control-0.79-01022010
>- lttv-0.12.30-02102010
>
>mm-trace.ko is loaded.
>
>ltt-armall output shows
>....
>Connecting /sys/kernel/debug/ltt/markers/mm/wait_on_page_start
>Connecting /sys/kernel/debug/ltt/markers/mm/wait_on_page_end
>Connecting /sys/kernel/debug/ltt/markers/mm/huge_page_free
>Connecting /sys/kernel/debug/ltt/markers/mm/huge_page_alloc
>Connecting /sys/kernel/debug/ltt/markers/mm/page_free
>Connecting /sys/kernel/debug/ltt/markers/mm/page_alloc
>Connecting /sys/kernel/debug/ltt/markers/mm/swap_in
>Connecting /sys/kernel/debug/ltt/markers/mm/swap_out
>Connecting /sys/kernel/debug/ltt/markers/mm/swap_file_close
>Connecting /sys/kernel/debug/ltt/markers/mm/swap_file_open
>Connecting /sys/kernel/debug/ltt/markers/mm/add_to_page_cache
>Connecting /sys/kernel/debug/ltt/markers/mm/remove_from_page_cache
>...
>
>These are the steps to recreate the problem:
>% lttctl -C -w /tmp/trace4 trace4
>% # ** run a program that does a lot of malloc and free
>% lttctl -D trace4
>
># even mm.page_alloc is **not** showing in the trace
>% lttv -m textDump --fatal -e event.name=mm.page_alloc -t /tmp/trace4
>Trace set contains 1 traces
>
>End trace set
>
># even mm.page_free is showing in the trace.
>% lttv -m textDump --process_stats -e event.name=mm.page_free -t
>/tmp/trace4
>Trace set contains 1 traces
>...
>mm.page_free: 7334.057610863 (/tmp/trace4/mm_1), 6200, 6200, ./ltt_alloc, ,
>4962, 0x0, SYSCALL { pfn = 487653, order = 0 }
>mm.page_free: 7334.057612915 (/tmp/trace4/mm_1), 6200, 6200, ./ltt_alloc, ,
>4962, 0x0, SYSCALL { pfn = 510031, order = 0 }
>mm.page_free: 7334.057613190 (/tmp/trace4/mm_1), 6200, 6200, ./ltt_alloc, ,
>4962, 0x0, SYSCALL { pfn = 510030, order = 0 }
>...
>
>Please help look at this problem.

Dany and I discussed this a bit today.

It seems that the trace_page_alloc tracepoint is only placed in
__alloc_pages_slowpath, which is only called under memory reclaim conditions
from what I can tell.  The placement of trace_page_free seems spread to more
areas in the page free paths, so it gets picked up more broadly and shows up
in the trace.  Should the trace_page_alloc point be moved up to the
__alloc_pages_nodemask function or some other higher level allocation function?

Confusing the issue, or me at least, is that there is a trace_mm_page_alloc
call in the more general __alloc_pages_nodemask.  However, that call doesn't
seem to be an LTTng tracepoint so it doesn't register LTTng events in the
traces we see.  Is that perhaps an FTrace tracepoint?  There are other
functions in the mm/page_alloc.c file like this as well, such as
trace_mm_pagevec_free, and trace_mm_page_free_direct.  None of those generate
anything in the LTTng output either.

All of that is still true with the lttng-0.216 branch from what I can tell.

josh

[ltt-dev] ltt trace doesn't show event mm.page_alloc

[Mathieu Desnoyers]

* Josh Boyer (jwboyer at linux.vnet.ibm.com) wrote:
> On Mon, Jun 14, 2010 at 10:16:46AM -0700, Dany Madden wrote:
> >Hi,
> >
> >Ltt trace doesn't show mm.page_alloc event with the mainline kernel:
> >
> >- mainline kernel 2.6.32.12
> >- patch-2.6.32.9-lttng-0.198
> >- ltt-control-0.79-01022010
> >- lttv-0.12.30-02102010
> >
> >mm-trace.ko is loaded.
> >
> >ltt-armall output shows
> >....
> >Connecting /sys/kernel/debug/ltt/markers/mm/wait_on_page_start
> >Connecting /sys/kernel/debug/ltt/markers/mm/wait_on_page_end
> >Connecting /sys/kernel/debug/ltt/markers/mm/huge_page_free
> >Connecting /sys/kernel/debug/ltt/markers/mm/huge_page_alloc
> >Connecting /sys/kernel/debug/ltt/markers/mm/page_free
> >Connecting /sys/kernel/debug/ltt/markers/mm/page_alloc
> >Connecting /sys/kernel/debug/ltt/markers/mm/swap_in
> >Connecting /sys/kernel/debug/ltt/markers/mm/swap_out
> >Connecting /sys/kernel/debug/ltt/markers/mm/swap_file_close
> >Connecting /sys/kernel/debug/ltt/markers/mm/swap_file_open
> >Connecting /sys/kernel/debug/ltt/markers/mm/add_to_page_cache
> >Connecting /sys/kernel/debug/ltt/markers/mm/remove_from_page_cache
> >...
> >
> >These are the steps to recreate the problem:
> >% lttctl -C -w /tmp/trace4 trace4
> >% # ** run a program that does a lot of malloc and free
> >% lttctl -D trace4
> >
> ># even mm.page_alloc is **not** showing in the trace
> >% lttv -m textDump --fatal -e event.name=mm.page_alloc -t /tmp/trace4
> >Trace set contains 1 traces
> >
> >End trace set
> >
> ># even mm.page_free is showing in the trace.
> >% lttv -m textDump --process_stats -e event.name=mm.page_free -t
> >/tmp/trace4
> >Trace set contains 1 traces
> >...
> >mm.page_free: 7334.057610863 (/tmp/trace4/mm_1), 6200, 6200, ./ltt_alloc, ,
> >4962, 0x0, SYSCALL { pfn = 487653, order = 0 }
> >mm.page_free: 7334.057612915 (/tmp/trace4/mm_1), 6200, 6200, ./ltt_alloc, ,
> >4962, 0x0, SYSCALL { pfn = 510031, order = 0 }
> >mm.page_free: 7334.057613190 (/tmp/trace4/mm_1), 6200, 6200, ./ltt_alloc, ,
> >4962, 0x0, SYSCALL { pfn = 510030, order = 0 }
> >...
> >
> >Please help look at this problem.
> 
> Dany and I discussed this a bit today.
> 
> It seems that the trace_page_alloc tracepoint is only placed in
> __alloc_pages_slowpath, which is only called under memory reclaim conditions
> from what I can tell.  The placement of trace_page_free seems spread to more
> areas in the page free paths, so it gets picked up more broadly and shows up
> in the trace.  Should the trace_page_alloc point be moved up to the
> __alloc_pages_nodemask function or some other higher level allocation function?
> 
> Confusing the issue, or me at least, is that there is a trace_mm_page_alloc
> call in the more general __alloc_pages_nodemask.  However, that call doesn't
> seem to be an LTTng tracepoint so it doesn't register LTTng events in the
> traces we see.  Is that perhaps an FTrace tracepoint?  There are other
> functions in the mm/page_alloc.c file like this as well, such as
> trace_mm_pagevec_free, and trace_mm_page_free_direct.  None of those generate
> anything in the LTTng output either.
> 
> All of that is still true with the lttng-0.216 branch from what I can tell.

The latest LTTng have not been updated to use the mainline tracepoints.
We need to create probes in ltt/probes/ for that. Indeed, for memory
management, it would be good to replace the current LTTng tracepoints
with the more complete mainline set.

Note that the LTTng probes will probably vanish in a few release, being
replaced by probes automatically generated by TRACE_EVENT().

Thanks,

Mathieu

> 
> josh
> 
> _______________________________________________
> ltt-dev mailing list
> ltt-dev at lists.casi.polymtl.ca
> http://lists.casi.polymtl.ca/cgi-bin/mailman/listinfo/ltt-dev
> 

-- 
Mathieu Desnoyers
Operating System Efficiency R&D Consultant
EfficiOS Inc.
http://www.efficios.com