mm: cma: add some debug information for CMA

Add trace events for cma_alloc() and cma_release().

Signed-off-by Stefan Strogin <[email protected]>

---
 include/trace/events/cma.h | 57 ++++++++++++++++++++++++++++++++++++++++++++++
 mm/cma.c                   |  5 ++++
 2 files changed, 62 insertions(+)
 create mode 100644 include/trace/events/cma.h

include/trace/events/cma.h new file +57 -0

new file mode 100644
index 0000000..d88881b
@@ -0,0 +1,57 @@
+#undef TRACE_SYSTEM
+#define TRACE_SYSTEM cma
+
+#if !defined(_TRACE_CMA_H) || defined(TRACE_HEADER_MULTI_READ)
+#define _TRACE_CMA_H
+
+#include <linux/types.h>
+#include <linux/tracepoint.h>
+
+TRACE_EVENT(cma_alloc,
+
+	TP_PROTO(struct cma *cma, struct page *page, int count),
+
+	TP_ARGS(cma, page, count),
+
+	TP_STRUCT__entry(
+		__field(struct page *, page)
+		__field(unsigned long, count)
+	),
+
+	TP_fast_assign(
+		__entry->page = page;
+		__entry->count = count;
+	),
+
+	TP_printk("page=%p pfn=%lu count=%lu",
+		  __entry->page,
+		  __entry->page ? page_to_pfn(__entry->page) : 0,
+		  __entry->count)
+);
+
+TRACE_EVENT(cma_release,
+
+	TP_PROTO(struct cma *cma, unsigned long pfn, int count),
+
+	TP_ARGS(cma, pfn, count),
+
+	TP_STRUCT__entry(
+		__field(unsigned long, pfn)
+		__field(unsigned long, count)
+	),
+
+	TP_fast_assign(
+		__entry->pfn = pfn;
+		__entry->count = count;
+	),
+
+	TP_printk("pfn=%lu page=%p count=%lu",
+		  __entry->pfn,
+		  pfn_to_page(__entry->pfn),
+		  __entry->count)
+);
+
+#endif /* _TRACE_CMA_H */
+
+/* This part must be outside protection */
+#include <trace/define_trace.h>

mm/cma.c +4 -0

index 47203fa..63dfc0e 100644
@@ -23,6 +23,7 @@
 #  define DEBUG
 #endif
 #endif
+#define CREATE_TRACE_POINTS
 
 #include <linux/memblock.h>
 #include <linux/err.h>

@@ -34,6 +35,7 @@
 #include <linux/cma.h>
 #include <linux/highmem.h>
 #include <linux/io.h>
+#include <trace/events/cma.h>
 
 #include "cma.h"
 

@@ -414,6 +416,8 @@ struct page *cma_alloc(struct cma *cma, unsigned int count, unsigned int align)
 		start = bitmap_no + mask + 1;
 	}
 
+	trace_cma_alloc(cma, page, count);
+
 	pr_debug("%s(): returned %p\n", __func__, page);
 	return page;
 }

Oops... forgot to cc tracing maintainers. Sorry!

Quoted 35 lines

Add trace events for cma_alloc() and cma_release().

Signed-off-by Stefan Strogin <[email protected]>

---
 include/trace/events/cma.h | 57 ++++++++++++++++++++++++++++++++++++++++++++++
 mm/cma.c                   |  5 ++++
 2 files changed, 62 insertions(+)
 create mode 100644 include/trace/events/cma.h

include/trace/events/cma.h new file +20 -0

new file mode 100644
index 0000000..d88881b
@@ -0,0 +1,57 @@
+#undef TRACE_SYSTEM
+#define TRACE_SYSTEM cma
+
+#if !defined(_TRACE_CMA_H) || defined(TRACE_HEADER_MULTI_READ)
+#define _TRACE_CMA_H
+
+#include <linux/types.h>
+#include <linux/tracepoint.h>
+
+TRACE_EVENT(cma_alloc,
+
+	TP_PROTO(struct cma *cma, struct page *page, int count),
+
+	TP_ARGS(cma, page, count),
+
+	TP_STRUCT__entry(
+		__field(struct page *, page)
+		__field(unsigned long, count)
+	),
+

include/trace/events/cma.h line 28

Quoted 8 lines

include/trace/events/cma.h new file +8 -0

+	TP_fast_assign(
+		__entry->page = page;
+		__entry->count = count;
+	),
+
+	TP_printk("page=%p pfn=%lu count=%lu",
+		  __entry->page,
+		  __entry->page ? page_to_pfn(__entry->page) : 0,

Quoted 14 lines

include/trace/events/cma.h new file +14 -0

+		  __entry->count)
+);
+
+TRACE_EVENT(cma_release,
+
+	TP_PROTO(struct cma *cma, unsigned long pfn, int count),
+
+	TP_ARGS(cma, pfn, count),
+
+	TP_STRUCT__entry(
+		__field(unsigned long, pfn)
+		__field(unsigned long, count)
+	),
+

include/trace/events/cma.h line 50

Quoted 8 lines

include/trace/events/cma.h new file +8 -0

+	TP_fast_assign(
+		__entry->pfn = pfn;
+		__entry->count = count;
+	),
+
+	TP_printk("pfn=%lu page=%p count=%lu",
+		  __entry->pfn,
+		  pfn_to_page(__entry->pfn),

Quoted 38 lines

include/trace/events/cma.h new file +7 -0

+		  __entry->count)
+);
+
+#endif /* _TRACE_CMA_H */
+
+/* This part must be outside protection */
+#include <trace/define_trace.h>

mm/cma.c +4 -0

index 47203fa..63dfc0e 100644
@@ -23,6 +23,7 @@
 #  define DEBUG
 #endif
 #endif
+#define CREATE_TRACE_POINTS
 
 #include <linux/memblock.h>
 #include <linux/err.h>

@@ -34,6 +35,7 @@
 #include <linux/cma.h>
 #include <linux/highmem.h>
 #include <linux/io.h>
+#include <trace/events/cma.h>
 
 #include "cma.h"
 

@@ -414,6 +416,8 @@ struct page *cma_alloc(struct cma *cma, unsigned int count, unsigned int align)
 		start = bitmap_no + mask + 1;
 	}
 
+	trace_cma_alloc(cma, page, count);
+
 	pr_debug("%s(): returned %p\n", __func__, page);
 	return page;
 }

@@ -446,6 +450,7 @@ bool cma_release(struct cma *cma, const struct page *pages, unsigned int count)
 

mm/cma.c bool cma_release(struct cma *cma, const struct page *pages, unsigned int count) · line 456

Quoted 7 lines

mm/cma.c +1 -0

 	free_contig_range(pfn, count);
 	cma_clear_bitmap(cma, pfn, count);
+	trace_cma_release(cma, pfn, count);
 
 	return true;
 }

Quoted 11 lines

Quoted 11 lines

include/trace/events/cma.h new file +11 -0

+TRACE_EVENT(cma_alloc,
+
+	TP_PROTO(struct cma *cma, struct page *page, int count),
+
+	TP_ARGS(cma, page, count),
+
+	TP_STRUCT__entry(
+		__field(struct page *, page)
+		__field(unsigned long, count)
+	),
+

Quoted 8 lines

include/trace/events/cma.h line 28

Quoted 8 lines

include/trace/events/cma.h new file +8 -0

+	TP_fast_assign(
+		__entry->page = page;
+		__entry->count = count;
+	),
+
+	TP_printk("page=%p pfn=%lu count=%lu",
+		  __entry->page,
+		  __entry->page ? page_to_pfn(__entry->page) : 0,

Can page_to_pfn(value) ever be different throughout the life of the boot? That is, can it return a different result given the same value (vmalloc area comes to mind).

Quoted 3 lines

include/trace/events/cma.h line 50

Quoted 3 lines

include/trace/events/cma.h new file +3 -0

+	TP_printk("pfn=%lu page=%p count=%lu",
+		  __entry->pfn,
+		  pfn_to_page(__entry->pfn),

Same here. Can pfn_to_page(value) ever return a different result with the same value in a single boot?

Thank you for the reply, Steven.
I supposed that page_to_pfn() cannot change after mem_map initialization, can it? I'm not sure about such things as memory hotplug though...
Also cma_alloc() calls alloc_contig_range() which returns pfn, then it's converted to struct page * and cma_alloc() returns struct page *, and vice versa in cma_release() (receives struct page * and passes pfn to free_contig_rage()).
Do you mean that printing pfn (or struct page *) in trace event is redundant?

Quoted 10 lines · On Thu, 19 Mar 2015 23:18:18 +0300 Stefan Strogin…

Thank you for the reply, Steven.
I supposed that page_to_pfn() cannot change after mem_map initialization, can it? I'm not sure about such things as memory hotplug though...
Also cma_alloc() calls alloc_contig_range() which returns pfn, then it's converted to struct page * and cma_alloc() returns struct page *, and vice versa in cma_release() (receives struct page * and passes pfn to free_contig_rage()).
Do you mean that printing pfn (or struct page *) in trace event is redundant?

I'm concerned about the time TP_printk() is executed and when TP_fast_assign() is. That is, when the tracepoint is called, TP_fast_assign() is executed, but TP_printk() is called when someone reads the trace files, which can happen seconds, hours, days, weeks, months later.

As long as the result of page_to_pfn() and pfn_to_page() stay the same throughout the life of the boot, things will be fine. But if they could ever change, due to hotplug memory or whatever. The data in the trace buffer will become stale, and report the wrong information.

-- Steve

Ah, thanks, I see. So will this solve the described issue?

include/trace/events/cma.h new file +3 -0

+	TP_fast_assign(
+		__entry->page = page;
+		__entry->pfn = page_to_pfn(__entry->page) : 0;

/* or -1 as Ingo suggested */

include/trace/events/cma.h new file +7 -0

+		__entry->count = count;
+	),
+
+	TP_printk("page=%p pfn=%lu count=%u",
+		  __entry->page,
+		  __entry->pfn,
+		  __entry->count)

Should we do the same in trace/events/kmem.h then?

But really I'm not sure why page_to_pfn()/pfn_to_page() can return different results... I thought that there can appear new 'struct page' entries arrays throughout one boot due to memory hotplug or smth. But how can existing 'struct page' entries associated with the same physical pages change their physical addresses? Or how can one physical address correspond to different physical page throughout one boot?

Quoted 12 lines

include/trace/events/cma.h new file +12 -0

+TRACE_EVENT(cma_alloc,
+
+	TP_PROTO(struct cma *cma, struct page *page, int count),
+
+	TP_ARGS(cma, page, count),
+
+	TP_STRUCT__entry(
+		__field(struct page *, page)
+		__field(unsigned long, count)
+	),
+
+	TP_fast_assign(

include/trace/events/cma.h line 29

Quoted 8 lines

include/trace/events/cma.h new file +8 -0

+		__entry->page = page;
+		__entry->count = count;
+	),
+
+	TP_printk("page=%p pfn=%lu count=%lu",
+		  __entry->page,
+		  __entry->page ? page_to_pfn(__entry->page) : 0,
+		  __entry->count)

include/trace/events/cma.h line 28

Quoted 2 lines

include/trace/events/cma.h new file +2 -0

+		__entry->page = page;
+		  __entry->page ? page_to_pfn(__entry->page) : 0,

include/trace/events/cma.h line 28

Quoted 1 line

include/trace/events/cma.h new file +1 -0

+		  __entry->page ? page_to_pfn(__entry->page) : 0,

Review

Quoted 2 lines

(quoted diff) +2 -0

+	TP_STRUCT__entry(
+		__field(unsigned long, pfn)

Review

Quoted 1 line

(quoted diff) +1 -0

+		__field(unsigned long, count)

include/trace/events/cma.h line 51

Quoted 11 lines

include/trace/events/cma.h new file +11 -0

+	),
+
+	TP_fast_assign(
+		__entry->pfn = pfn;
+		__entry->count = count;
+	),
+
+	TP_printk("pfn=%lu page=%p count=%lu",
+		  __entry->pfn,
+		  pfn_to_page(__entry->pfn),
+		  __entry->count)

Quoted 12 lines · Stefan Strogin

Quoted 12 lines

include/trace/events/cma.h new file +12 -0

+TRACE_EVENT(cma_alloc,
+
+	TP_PROTO(struct cma *cma, struct page *page, int count),
+
+	TP_ARGS(cma, page, count),
+
+	TP_STRUCT__entry(
+		__field(struct page *, page)
+		__field(unsigned long, count)
+	),
+
+	TP_fast_assign(

Quoted 8 lines

include/trace/events/cma.h line 29

Quoted 8 lines

include/trace/events/cma.h new file +8 -0

+		__entry->page = page;
+		__entry->count = count;
+	),
+
+	TP_printk("page=%p pfn=%lu count=%lu",
+		  __entry->page,
+		  __entry->page ? page_to_pfn(__entry->page) : 0,
+		  __entry->count)

So I'm wondering, the fast-assign side is not equivalent to the TP_printk() side:

Quoted 2 lines

include/trace/events/cma.h line 28

Quoted 2 lines

include/trace/events/cma.h new file +2 -0

+		__entry->page = page;
+		  __entry->page ? page_to_pfn(__entry->page) : 0,

to me it seems it would be useful if MM tracing standardized on pfn printing. Just like you did for trace_cma_release().

Also:

Quoted 1 line

include/trace/events/cma.h line 28

Quoted 1 line

include/trace/events/cma.h new file +1 -0

+		  __entry->page ? page_to_pfn(__entry->page) : 0,

pfn 0 should probably be reserved for the true 0th pfn - those exist in some machines. Returning -1ll could be the 'no such pfn' condition?

Quoted 2 lines

Review

Quoted 2 lines

(quoted diff) +2 -0

+	TP_STRUCT__entry(
+		__field(unsigned long, pfn)

Btw., does pfn always fit into 32 bits on 32-bit platforms?

Quoted 1 line

Review

Quoted 1 line

(quoted diff) +1 -0

+		__field(unsigned long, count)

Does this have to be 64-bit on 64-bit platforms?

Quoted 6 lines

Quoted 6 lines

include/trace/events/cma.h new file +6 -0

+	),
+
+	TP_fast_assign(
+		__entry->pfn = pfn;
+		__entry->count = count;
+	),

Quoted 5 lines

include/trace/events/cma.h line 51

Quoted 5 lines

include/trace/events/cma.h new file +5 -0

+
+	TP_printk("pfn=%lu page=%p count=%lu",
+		  __entry->pfn,
+		  pfn_to_page(__entry->pfn),
+		  __entry->count)

So here you print more in the TP_printk() line than in the fast-assign side.

Again I'd double check the various boundary conditions.

Quoted 27 lines · Ingo Molnar

Quoted 12 lines · Stefan Strogin

Quoted 12 lines

include/trace/events/cma.h new file +12 -0

+TRACE_EVENT(cma_alloc,
+
+	TP_PROTO(struct cma *cma, struct page *page, int count),
+
+	TP_ARGS(cma, page, count),
+
+	TP_STRUCT__entry(
+		__field(struct page *, page)
+		__field(unsigned long, count)
+	),
+
+	TP_fast_assign(

Quoted 8 lines

include/trace/events/cma.h line 29

Quoted 8 lines

include/trace/events/cma.h new file +8 -0

+		__entry->page = page;
+		__entry->count = count;
+	),
+
+	TP_printk("page=%p pfn=%lu count=%lu",
+		  __entry->page,
+		  __entry->page ? page_to_pfn(__entry->page) : 0,
+		  __entry->count)

So I'm wondering, the fast-assign side is not equivalent to the TP_printk() side:

Quoted 6 lines

Quoted 2 lines

include/trace/events/cma.h line 28

Quoted 2 lines

include/trace/events/cma.h new file +2 -0

+		__entry->page = page;
+		  __entry->page ? page_to_pfn(__entry->page) : 0,

to me it seems it would be useful if MM tracing standardized on pfn printing. Just like you did for trace_cma_release().

Hello Ingo, thank you for the reply.
I afraid there is no special sense in printing both struct page * and pfn. But cma_alloc() returns struct page *, cma_release receives struct page *, and pr_debugs in these functions print struct page *. Maybe it would be better to print the same here too?

Quoted 2 lines

Again I'd double check the various boundary conditions.

Sorry, I don't quite understand. Boundary conditions are already [should be] checked in cma_alloc()/cma_release, we should only pass to a trace event the information we want to be known, isn't it so?

Add a function seq_print_stack_trace() which prints stacktraces to seq_files.

Signed-off-by Stefan Strogin <[email protected]>

Reviewed-by SeongJae Park <[email protected]>

---
 include/linux/stacktrace.h |  4 ++++
 kernel/stacktrace.c        | 17 +++++++++++++++++
 2 files changed, 21 insertions(+)

include/linux/stacktrace.h +4 -0

index 0a34489..d80f2e9 100644
@@ -2,6 +2,7 @@
 #define __LINUX_STACKTRACE_H
 
 #include <linux/types.h>
+#include <linux/seq_file.h>
 
 struct task_struct;
 struct pt_regs;

@@ -22,6 +23,8 @@ extern void save_stack_trace_tsk(struct task_struct *tsk,
 extern void print_stack_trace(struct stack_trace *trace, int spaces);
 extern int snprint_stack_trace(char *buf, size_t size,
 			struct stack_trace *trace, int spaces);
+extern void seq_print_stack_trace(struct seq_file *m,
+			struct stack_trace *trace, int spaces);
 
 #ifdef CONFIG_USER_STACKTRACE_SUPPORT
 extern void save_stack_trace_user(struct stack_trace *trace);

@@ -35,6 +38,7 @@ extern void save_stack_trace_user(struct stack_trace *trace);
 # define save_stack_trace_user(trace)			do { } while (0)
 # define print_stack_trace(trace, spaces)		do { } while (0)
 # define snprint_stack_trace(buf, size, trace, spaces)	do { } while (0)
+# define seq_print_stack_trace(m, trace, spaces)	do { } while (0)
 #endif
 
 #endif

kernel/stacktrace.c +17 -0

index b6e4c16..66ef6f4 100644
@@ -57,6 +57,23 @@ int snprint_stack_trace(char *buf, size_t size,
 }
 EXPORT_SYMBOL_GPL(snprint_stack_trace);
 
+void seq_print_stack_trace(struct seq_file *m, struct stack_trace *trace,
+			int spaces)
+{
+	int i;
+
+	if (WARN_ON(!trace->entries))
+		return;
+
+	for (i = 0; i < trace->nr_entries; i++) {
+		unsigned long ip = trace->entries[i];
+
+		seq_printf(m, "%*c[<%p>] %pS\n", 1 + spaces, ' ',
+				(void *) ip, (void *) ip);
+	}
+}
+EXPORT_SYMBOL_GPL(seq_print_stack_trace);
+
 /*
  * Architectures that do not implement save_stack_trace_tsk or
  * save_stack_trace_regs get this weak alias and a once-per-bootup warning

Signature · 1 line

2.1.0

When CONFIG_CMA_BUFFER_LIST is configured a file is added to debugfs:
/sys/kernel/debug/cma/cma-<N>/buffers contains a list of currently allocated CMA buffers for each CMA region (N stands for number of CMA region).

Format is:
<base_phys_addr> - <end_phys_addr> (<size> kB), allocated by <PID> (<comm>)

When CONFIG_CMA_ALLOC_STACKTRACE is configured then stack traces are saved when the allocations are made. The stack traces are added to cma/cma-<N>/buffers for each buffer list entry.

Example:

root@debian:/sys/kernel/debug/cma# cat cma-0/buffers
0x2f400000 - 0x2f417000 (92 kB), allocated by pid 1 (swapper/0)
 [<c1142c4b>] cma_alloc+0x1bb/0x200
 [<c143d28a>] dma_alloc_from_contiguous+0x3a/0x40
 [<c10079d9>] dma_generic_alloc_coherent+0x89/0x160
 [<c14456ce>] dmam_alloc_coherent+0xbe/0x100
 [<c1487312>] ahci_port_start+0xe2/0x210
 [<c146e0e0>] ata_host_start.part.28+0xc0/0x1a0
 [<c1473650>] ata_host_activate+0xd0/0x110
 [<c14881bf>] ahci_host_activate+0x3f/0x170
 [<c14854e4>] ahci_init_one+0x764/0xab0
 [<c12e415f>] pci_device_probe+0x6f/0xd0
 [<c14378a8>] driver_probe_device+0x68/0x210
 [<c1437b09>] __driver_attach+0x79/0x80
 [<c1435eef>] bus_for_each_dev+0x4f/0x80
 [<c143749e>] driver_attach+0x1e/0x20
 [<c1437197>] bus_add_driver+0x157/0x200
 [<c14381bd>] driver_register+0x5d/0xf0
<...>

Signed-off-by Stefan Strogin <[email protected]>

mm/cma_debug.c +4 -0

@@ -127,6 +240,93 @@ static int cma_alloc_write(void *data, u64 val)
 
 DEFINE_SIMPLE_ATTRIBUTE(cma_alloc_fops, NULL, cma_alloc_write, "%llu\n");
 
+#ifdef CONFIG_CMA_BUFFER_LIST
+static void *s_start(struct seq_file *seq, loff_t *ppos)
+{
+	struct cma *cma = seq->private;

(quoted diff) +1 -0

+}

Hi all.

Here is the fourth version of a patch set that adds some debugging facility for CMA.

This patch set is based on next-20150316. It is also available on git:
git://github.com/stefanstrogin/linux -b cmainfo-v4

We want an interface to see a list of currently allocated CMA buffers and some useful information about them (like /proc/vmallocinfo but for physically contiguous buffers allocated with CMA).

For example. We want a big (megabytes) CMA buffer to be allocated in runtime in default CMA region. If someone already uses CMA then the big allocation could fail. If it happened then with such an interface we could find who used CMA at the moment of failure, who caused fragmentation and so on. Ftrace also would be helpful here, but with ftrace we can see the whole history of allocations and releases, whereas with this patch set we can see a snapshot of CMA region with actual information about its allocations.

Quoted 13 lines · Stefan Strogin

Quoted 13 lines

Hi all.

Here is the fourth version of a patch set that adds some debugging facility for CMA.

This patch set is based on next-20150316. It is also available on git:
git://github.com/stefanstrogin/linux -b cmainfo-v4

We want an interface to see a list of currently allocated CMA buffers and some useful information about them (like /proc/vmallocinfo but for physically contiguous buffers allocated with CMA).

Quoted 7 lines

Quoted 7 lines

For example. We want a big (megabytes) CMA buffer to be allocated in runtime in default CMA region. If someone already uses CMA then the big allocation could fail. If it happened then with such an interface we could find who used CMA at the moment of failure, who caused fragmentation and so on. Ftrace also would be helpful here, but with ftrace we can see the whole history of allocations and releases, whereas with this patch set we can see a snapshot of CMA region with actual information about its allocations.

Hello,

Hmm... I still don't think that this is really helpful to find root cause of fragmentation. Think about following example.

Assume 1024 MB CMA region.

128 MB allocation * 4
1 MB allocation
128 MB allocation
128 MB release * 4 (first 4)
try 512 MB allocation

With above sequences, fragmentation happens and 512 MB allocation would be failed. We can get information about 1 MB allocation and 128 MB one from the buffer list as you suggested, but, fragmentation are related to whole sequence of allocation/free history, not snapshot of allocation.

Quoted 34 lines · Joonsoo Kim

Quoted 13 lines · Stefan Strogin

Quoted 13 lines

Hi all.

Here is the fourth version of a patch set that adds some debugging facility for CMA.

This patch set is based on next-20150316. It is also available on git:
git://github.com/stefanstrogin/linux -b cmainfo-v4

We want an interface to see a list of currently allocated CMA buffers and some useful information about them (like /proc/vmallocinfo but for physically contiguous buffers allocated with CMA).

Quoted 7 lines

Quoted 7 lines

For example. We want a big (megabytes) CMA buffer to be allocated in runtime in default CMA region. If someone already uses CMA then the big allocation could fail. If it happened then with such an interface we could find who used CMA at the moment of failure, who caused fragmentation and so on. Ftrace also would be helpful here, but with ftrace we can see the whole history of allocations and releases, whereas with this patch set we can see a snapshot of CMA region with actual information about its allocations.

Hello,

Hmm... I still don't think that this is really helpful to find root cause of fragmentation. Think about following example.

Assume 1024 MB CMA region.

128 MB allocation * 4
1 MB allocation
128 MB allocation
128 MB release * 4 (first 4)
try 512 MB allocation

Quoted 4 lines

With above sequences, fragmentation happens and 512 MB allocation would be failed. We can get information about 1 MB allocation and 128 MB one from the buffer list as you suggested, but, fragmentation are related to whole sequence of allocation/free history, not snapshot of allocation.

This is solvable by dumping task->comm in the tracepoint patch (1/5), right?