pagecache tracepoints proposal

From the output, we can know some information like:

Hello,

This is v3 of a patchset to add some tracepoints for pagecache.

I would propose several tracepoints for tracing pagecache behavior and a script for these.
By using both the tracepoints and the script, we can analysis pagecache behavior like usage or hit ratio with high resolution like per process or per file. Example output of the script looks like:

[process list]
o yum-3215
cache find cache hit cache hit
device inode count count ratio
--------------------------------------------------------

         253:0         16      34434      34130     99.12%
         253:0        198       9692       9463     97.64%
         253:0        639        647        628     97.06%
         253:0        778         32         29     90.62%
         253:0       7305      50225      49005     97.57%
         253:0     144217         12         10     83.33%
         253:0     262775         16         13     81.25%

*snip*

-------------------------------------------------------------------------------

[file list]
device cached
(maj:min) inode pages
--------------------------------

         253:0         16     5752
         253:0        198     2233
         253:0        639       51
         253:0        778       86
         253:0       7305    12307
         253:0     144217       11
         253:0     262775       39

*snip*

[process list]
o yum-3215
device cached added removed indirect
(maj:min) inode pages pages pages removed pages
----------------------------------------------------------------

         253:0         16    34130     5752        0             0
         253:0        198     9463     2233        0             0
         253:0        639      628       51        0             0
         253:0        778       29       78        0             0
         253:0       7305    49005    12307        0             0
         253:0     144217       10       11        0             0
         253:0     262775       13       39        0             0

*snip*
----------------------------------------------------------------
total: 102346 26165 1 0

We can now know system-wide pagecache usage by /proc/meminfo. But we have no method to get higher resolution information like per file or per process usage than system-wide one.
A process may share some pagecache or add a pagecache to the memory or remove a pagecache from the memory.
If a pagecache miss hit ratio rises, maybe it leads to extra I/O and affects system performance.

So, by using the tracepoints we can get the following information.
1. how many pagecaches each process has per each file
2. how many pages are cached per each file
3. how many pagecaches each process shares
4. how often each process adds/removes pagecache
5. how long a pagecache stays in the memory
6. pagecache hit rate per file

Especially, the monitoring pagecache usage per each file and pagecache hit ratio would help us tune some applications like database.
And it will also help us tune the kernel parameters like "vm.dirty_*".

Changelog since v2
o add new script to monitor pagecache hit ratio per process.
o use DECLARE_EVENT_CLASS

Changelog since v1
o Add a script based on "perf trace stream scripting support".

Any comments are welcome.

Looks really nice IMO! It also demonstrates nicely the extensibility via Tom's perf trace scripting engine. (which will soon get a Python script engine as well, so Perl and C wont be the only possibility to extend perf with.)

I've Cc:-ed a few parties who might be interested in this. Wu Fengguang has done MM instrumentation in this area before - there might be some common ground instead of scattered functionality in /proc, debugfs, perf and elsewhere?

Note that there's also these older experimental commits in tip:tracing/mm that introduce the notion of 'object collections' and adds the ability to trace them:

3383e37: tracing, page-allocator: Add a postprocessing script for page-allocator-related ftrace events
c33b359: tracing, page-allocator: Add trace event for page traffic related to the buddy lists 0d524fb: tracing, mm: Add trace events for anti-fragmentation falling back to other migratetypes
b9a2817: tracing, page-allocator: Add trace events for page allocation and page freeing 08b6cb8: perf_counter tools: Provide default bfd_demangle() function in case it's not around
eb46710: tracing/mm: rename 'trigger' file to 'dump_range'
1487a7a: tracing/mm: fix mapcount trace record field
dcac8cd: tracing/mm: add page frame snapshot trace

this concept, if refreshed a bit and extended to the page cache, would allow the recording/snapshotting of the MM state of all currently present pages in the page-cache - a possibly nice addition to the dynamic technique you apply in your patches.
there's similar "object collections" work underway for 'perf lock' btw., by Hitoshi Mitake and Frederic.

So there's lots of common ground and lots of interest.

Btw., instead of "perf trace record pagecache-usage", you might want to think about introducing a higher level tool as well: 'perf mm' or 'perf pagecache'
- just like we have 'perf kmem' for SLAB instrumentation, 'perf sched' for scheduler instrumentation and 'perf lock' for locking instrumentation. [with 'perf timer' having been posted too.]

'perf mm' could then still map to Perl scripts, it's just a convenience. It could then harbor other MM related instrumentation bits as well. Just an idea
- this is a possibility, if you are trying to achieve higher organization.

Note that there's also these older experimental commits in tip:tracing/mm that introduce the notion of 'object collections' and adds the ability to trace them:

3383e37: tracing, page-allocator: Add a postprocessing script for page-allocator-related ftrace events
c33b359: tracing, page-allocator: Add trace event for page traffic related to the buddy lists 0d524fb: tracing, mm: Add trace events for anti-fragmentation falling back to other migratetypes
b9a2817: tracing, page-allocator: Add trace events for page allocation and page freeing 08b6cb8: perf_counter tools: Provide default bfd_demangle() function in case it's not around
eb46710: tracing/mm: rename 'trigger' file to 'dump_range'
1487a7a: tracing/mm: fix mapcount trace record field
dcac8cd: tracing/mm: add page frame snapshot trace

this concept, if refreshed a bit and extended to the page cache, would allow the recording/snapshotting of the MM state of all currently present pages in the page-cache - a possibly nice addition to the dynamic technique you apply in your patches.

there's similar "object collections" work underway for 'perf lock' btw., by Hitoshi Mitake and Frederic.

So there's lots of common ground and lots of interest.

Here is a scratch patch to exercise the "object collections" idea :)

Interestingly, the pagecache walk is pretty fast, while copying out the trace data takes more time:

        # time (echo / > walk-fs)
        (; echo / > walk-fs; )  0.01s user 0.11s system 82% cpu 0.145 total

        # time wc /debug/tracing/trace
        4570 45893 551282 /debug/tracing/trace
        wc /debug/tracing/trace  0.75s user 0.55s system 88% cpu 1.470 total

TODO:

correctness
- show file path name
XXX: can trace_seq_path() be called directly inside TRACE_EVENT()?

Quoted 11 lines

Here is a scratch patch to exercise the "object collections" idea :)

Interestingly, the pagecache walk is pretty fast, while copying out the trace data takes more time:

        # time (echo / > walk-fs)
        (; echo / > walk-fs; )  0.01s user 0.11s system 82% cpu 0.145 total

        # time wc /debug/tracing/trace
        4570 45893 551282 /debug/tracing/trace
        wc /debug/tracing/trace  0.75s user 0.55s system 88% cpu 1.470 total

Ah got it: it takes much time to "print" the raw trace data.

Quoted 5 lines

TODO:

correctness
- show file path name
XXX: can trace_seq_path() be called directly inside TRACE_EVENT()?

OK, finished with the file name with d_path(). I choose not to mangle the possible '\n' in file names, and simply show "?" for such files, for the sake of speed.

Thanks,
Fengguang
---
tracing: pagecache object collections

This dumps
- all cached files of a mounted fs (the inode-cache)
- all cached pages of a cached file (the page-cache)

Usage and Sample output:

# echo /dev > /debug/tracing/objects/mm/pages/walk-fs
# tail /debug/tracing/trace
             zsh-2528  [000] 10429.172470: dump_inode: ino=889 size=0 cached=0 age=442 dirty=0 dev=0:18 file=/dev/console
             zsh-2528  [000] 10429.172472: dump_inode: ino=888 size=0 cached=0 age=442 dirty=7 dev=0:18 file=/dev/null
             zsh-2528  [000] 10429.172474: dump_inode: ino=887 size=40 cached=0 age=442 dirty=0 dev=0:18 file=/dev/shm
             zsh-2528  [000] 10429.172477: dump_inode: ino=886 size=40 cached=0 age=442 dirty=0 dev=0:18 file=/dev/pts
             zsh-2528  [000] 10429.172479: dump_inode: ino=885 size=11 cached=0 age=442 dirty=0 dev=0:18 file=/dev/core
             zsh-2528  [000] 10429.172481: dump_inode: ino=884 size=15 cached=0 age=442 dirty=0 dev=0:18 file=/dev/stderr
             zsh-2528  [000] 10429.172483: dump_inode: ino=883 size=15 cached=0 age=442 dirty=0 dev=0:18 file=/dev/stdout
             zsh-2528  [000] 10429.172486: dump_inode: ino=882 size=15 cached=0 age=442 dirty=0 dev=0:18 file=/dev/stdin
             zsh-2528  [000] 10429.172488: dump_inode: ino=881 size=13 cached=0 age=442 dirty=0 dev=0:18 file=/dev/fd
             zsh-2528  [000] 10429.172491: dump_inode: ino=872 size=13360 cached=0 age=442 dirty=0 dev=0:18 file=/dev

Here "age" is either age from inode create time, or from last dirty time.

TODO:

correctness
- reliably prevent ring buffer overflow,
by replacing cond_resched() with some wait function (eg. wait until 2+ pages are free in ring buffer)
- use stable_page_flags() in recent kernel

output style
- use plain tracing output format (no fancy TASK-PID/.../FUNCTION fields)
- clear ring buffer before dumping the objects?
- output format: key=value pairs ==> header + tabbed values?
- add filtering options if necessary

CC Ingo Molnar <[email protected]>

CC Chris Frost <[email protected]>

CC Steven Rostedt <[email protected]>

CC Peter Zijlstra <[email protected]>

CC Frederic Weisbecker <[email protected]>

Signed-off-by Wu Fengguang <[email protected]>

---
 fs/inode.c                |    2 
 include/trace/events/mm.h |   70 ++++++++++++
 kernel/trace/trace_mm.c   |  204 ++++++++++++++++++++++++++++++++++++
 3 files changed, 275 insertions(+), 1 deletion(-)

include/trace/events/mm.h +70 -0

@@ -2,6 +2,7 @@
 #define _TRACE_MM_H
 
 #include <linux/tracepoint.h>
+#include <linux/pagemap.h>
 #include <linux/mm.h>
 
 #undef TRACE_SYSTEM

@@ -42,6 +43,75 @@ TRACE_EVENT(dump_pages,
 		  __entry->mapcount, __entry->index)
 );
 
+TRACE_EVENT(dump_pagecache_range,
+
+	TP_PROTO(struct page *page, unsigned long len),
+
+	TP_ARGS(page, len),
+
+	TP_STRUCT__entry(
+		__field(	unsigned long,	index		)
+		__field(	unsigned long,	len		)
+		__field(	unsigned long,	flags		)
+		__field(	unsigned int,	count		)
+		__field(	unsigned int,	mapcount	)
+	),
+
+	TP_fast_assign(
+		__entry->index		= page->index;
+		__entry->len		= len;
+		__entry->flags		= page->flags;
+		__entry->count		= atomic_read(&page->_count);
+		__entry->mapcount	= page_mapcount(page);
+	),
+
+	TP_printk("index=%lu len=%lu flags=%lx count=%u mapcount=%u",
+		  __entry->index,
+		  __entry->len,
+		  __entry->flags,
+		  __entry->count,
+		  __entry->mapcount)
+);
+
+TRACE_EVENT(dump_inode,
+
+	TP_PROTO(struct inode *inode, char *name, int len),
+
+	TP_ARGS(inode, name, len),
+
+	TP_STRUCT__entry(
+		__field(	unsigned long,	ino		)
+		__field(	loff_t,		size		)
+		__field(	unsigned long,	nrpages		)
+		__field(	unsigned long,	age		)
+		__field(	unsigned long,	state		)
+		__field(	dev_t,		dev		)
+		__dynamic_array(char,		file,	len	)
+	),
+
+	TP_fast_assign(
+		__entry->ino		= inode->i_ino;
+		__entry->size		= i_size_read(inode);
+		__entry->nrpages	= inode->i_mapping->nrpages;
+		__entry->age		= jiffies - inode->dirtied_when;
+		__entry->state		= inode->i_state;
+		__entry->dev		= inode->i_sb->s_dev;
+		memcpy(__get_str(file), name, len);
+	),
+
+	TP_printk("ino=%lu size=%llu cached=%lu age=%lu dirty=%lu "
+		  "dev=%u:%u file=%s",
+		  __entry->ino,
+		  __entry->size,
+		  __entry->nrpages << PAGE_CACHE_SHIFT,
+		  __entry->age / HZ,
+		  __entry->state & I_DIRTY,
+		  MAJOR(__entry->dev),
+		  MINOR(__entry->dev),
+		  strchr(__get_str(file), '\n') ? "?" : __get_str(file))
+);
+
+
 #endif /*  _TRACE_MM_H */
 
 /* This part must be outside protection */

kernel/trace/trace_mm.c +12 -0

@@ -9,6 +9,9 @@
 #include <linux/bootmem.h>
 #include <linux/debugfs.h>
 #include <linux/uaccess.h>
+#include <linux/pagevec.h>
+#include <linux/writeback.h>
+#include <linux/file.h>
 
 #include "trace_output.h"
 

@@ -95,6 +98,201 @@ static const struct file_operations trac
 	.write		= trace_mm_dump_range_write,
 };
 
+static unsigned long page_flags(struct page* page)
+{
+	return page->flags & ((1 << NR_PAGEFLAGS) - 1);
+}
+
+static int pages_similiar(struct page* page0, struct page* page)
+{
+	if (page_count(page0) != page_count(page))
+		return 0;

kernel/trace/trace_mm.c +5 -0

+#define BATCH_LINES	100
+static void dump_pagecache(struct address_space *mapping)
+{
+	int i;
+	int lines = 0;

kernel/trace/trace_mm.c +92 -0

+
+		if (pvec.nr == 0) {
+			if (len)
+				trace_dump_pagecache_range(page0, len);
+			break;
+		}
+
+		if (!page0)
+			page0 = pvec.pages[0];
+
+		for (i = 0; i < pvec.nr; i++) {
+			page = pvec.pages[i];
+
+			if (page->index == start + len &&
+					pages_similiar(page0, page))
+				len++;
+			else {
+				trace_dump_pagecache_range(page0, len);
+				page0 = page;
+				start = page->index;
+				len = 1;
+				if (++lines > BATCH_LINES) {
+					lines = 0;
+					cond_resched();
+				}
+			}
+		}
+	}
+}
+
+static void dump_inode(struct inode *inode,
+		       char *name_buf,
+		       struct vfsmount *mnt)
+{
+	struct path path = {
+		.mnt = mnt,
+		.dentry = d_find_alias(inode)
+	};
+	char *name;
+	int len;
+
+	if (!path.dentry) {
+		trace_dump_inode(inode, "?", 2);
+		return;
+	}
+
+	name = d_path(&path, name_buf, PAGE_SIZE);
+	if (IS_ERR(name)) {
+		name = "?";
+		len = 2;
+	} else
+		len = PAGE_SIZE + name_buf - name;
+
+	trace_dump_inode(inode, name, len);
+
+	if (path.dentry)
+		dput(path.dentry);
+}
+
+static void dump_fs_pagecache(struct super_block *sb, struct vfsmount *mnt)
+{
+	struct inode *inode;
+	struct inode *prev_inode = NULL;
+	char *name_buf;
+
+	name_buf = (char *)__get_free_page(GFP_TEMPORARY);
+	if (!name_buf)
+		return;
+
+	down_read(&sb->s_umount);
+	if (!sb->s_root)
+		goto out;
+
+	spin_lock(&inode_lock);
+	list_for_each_entry(inode, &sb->s_inodes, i_sb_list) {
+		if (inode->i_state & (I_FREEING|I_CLEAR|I_WILL_FREE|I_NEW))
+			continue;
+		__iget(inode);
+		spin_unlock(&inode_lock);
+		dump_inode(inode, name_buf, mnt);
+		if (inode->i_mapping->nrpages)
+			dump_pagecache(inode->i_mapping);
+		iput(prev_inode);
+		prev_inode = inode;
+		cond_resched();
+		spin_lock(&inode_lock);
+	}
+	spin_unlock(&inode_lock);
+	iput(prev_inode);
+out:
+	up_read(&sb->s_umount);
+	free_page((unsigned long)name_buf);

kernel/trace/trace_mm.c +7 -0

+	if (count <= 1)
+		return -EINVAL;
+	if (count > PATH_MAX + 1)
+		return -ENAMETOOLONG;
+
+	name = kmalloc(count+1, GFP_KERNEL);
+	if (!name)

kernel/trace/trace_mm.c +48 -0

+	name[count-1] = '\0';
+
+	file = filp_open(name, O_RDONLY|O_LARGEFILE, 0);
+	if (IS_ERR(file)) {
+		err = PTR_ERR(file);
+		file = NULL;
+		goto out;
+	}
+
+	if (tracing_update_buffers() < 0) {
+		err = -ENOMEM;
+		goto out;
+	}
+	if (trace_set_clr_event("mm", "dump_pagecache_range", 1)) {
+		err = -EINVAL;
+		goto out;
+	}
+	if (trace_set_clr_event("mm", "dump_inode", 1)) {
+		err = -EINVAL;
+		goto out;
+	}
+
+	if (filp->f_path.dentry->d_inode->i_private) {
+		dump_fs_pagecache(file->f_path.dentry->d_sb, file->f_path.mnt);
+	} else {
+		dump_pagecache(file->f_mapping);
+	}
+
+out:
+	if (file)
+		fput(file);
+	kfree(name);
+
+	return err ? err : count;
+}
+
+static const struct file_operations trace_pagecache_fops = {
+	.open		= tracing_open_generic,
+	.read		= trace_mm_dump_range_read,
+	.write		= trace_pagecache_write,
+};
+
 /* move this into trace_objects.c when that file is created */
 static struct dentry *trace_objects_dir(void)
 {

@@ -167,6 +365,12 @@ static __init int trace_objects_mm_init(
 	trace_create_file("dump_range", 0600, d_pages, NULL,
 			  &trace_mm_fops);
 
+	trace_create_file("walk-file", 0600, d_pages, NULL,
+			  &trace_pagecache_fops);
+
+	trace_create_file("walk-fs", 0600, d_pages, (void *)1,
+			  &trace_pagecache_fops);
+
 	return 0;
 }
 fs_initcall(trace_objects_mm_init);

Quoted 48 lines · Wu Fengguang

Quoted 11 lines

Here is a scratch patch to exercise the "object collections" idea :)

Interestingly, the pagecache walk is pretty fast, while copying out the trace data takes more time:

        # time (echo / > walk-fs)
        (; echo / > walk-fs; )  0.01s user 0.11s system 82% cpu 0.145 total

        # time wc /debug/tracing/trace
        4570 45893 551282 /debug/tracing/trace
        wc /debug/tracing/trace  0.75s user 0.55s system 88% cpu 1.470 total

Ah got it: it takes much time to "print" the raw trace data.

Quoted 5 lines

TODO:

correctness
- show file path name
XXX: can trace_seq_path() be called directly inside TRACE_EVENT()?

OK, finished with the file name with d_path(). I choose not to mangle the possible '\n' in file names, and simply show "?" for such files, for the sake of speed.

Thanks,
Fengguang
---
tracing: pagecache object collections

This dumps
- all cached files of a mounted fs (the inode-cache)
- all cached pages of a cached file (the page-cache)

Usage and Sample output:

# echo /dev > /debug/tracing/objects/mm/pages/walk-fs
# tail /debug/tracing/trace
             zsh-2528  [000] 10429.172470: dump_inode: ino=889 size=0 cached=0 age=442 dirty=0 dev=0:18 file=/dev/console
             zsh-2528  [000] 10429.172472: dump_inode: ino=888 size=0 cached=0 age=442 dirty=7 dev=0:18 file=/dev/null
             zsh-2528  [000] 10429.172474: dump_inode: ino=887 size=40 cached=0 age=442 dirty=0 dev=0:18 file=/dev/shm
             zsh-2528  [000] 10429.172477: dump_inode: ino=886 size=40 cached=0 age=442 dirty=0 dev=0:18 file=/dev/pts
             zsh-2528  [000] 10429.172479: dump_inode: ino=885 size=11 cached=0 age=442 dirty=0 dev=0:18 file=/dev/core
             zsh-2528  [000] 10429.172481: dump_inode: ino=884 size=15 cached=0 age=442 dirty=0 dev=0:18 file=/dev/stderr
             zsh-2528  [000] 10429.172483: dump_inode: ino=883 size=15 cached=0 age=442 dirty=0 dev=0:18 file=/dev/stdout
             zsh-2528  [000] 10429.172486: dump_inode: ino=882 size=15 cached=0 age=442 dirty=0 dev=0:18 file=/dev/stdin
             zsh-2528  [000] 10429.172488: dump_inode: ino=881 size=13 cached=0 age=442 dirty=0 dev=0:18 file=/dev/fd
             zsh-2528  [000] 10429.172491: dump_inode: ino=872 size=13360 cached=0 age=442 dirty=0 dev=0:18 file=/dev

Quoted 2 lines

Here "age" is either age from inode create time, or from last dirty time.

It would be nice to see mapped/unmapped information as well.

Quoted 21 lines

tracing: pagecache object collections

This dumps
- all cached files of a mounted fs (the inode-cache)
- all cached pages of a cached file (the page-cache)

Usage and Sample output:

# echo /dev > /debug/tracing/objects/mm/pages/walk-fs
# tail /debug/tracing/trace
             zsh-2528  [000] 10429.172470: dump_inode: ino=889 size=0 cached=0 age=442 dirty=0 dev=0:18 file=/dev/console
             zsh-2528  [000] 10429.172472: dump_inode: ino=888 size=0 cached=0 age=442 dirty=7 dev=0:18 file=/dev/null
             zsh-2528  [000] 10429.172474: dump_inode: ino=887 size=40 cached=0 age=442 dirty=0 dev=0:18 file=/dev/shm
             zsh-2528  [000] 10429.172477: dump_inode: ino=886 size=40 cached=0 age=442 dirty=0 dev=0:18 file=/dev/pts
             zsh-2528  [000] 10429.172479: dump_inode: ino=885 size=11 cached=0 age=442 dirty=0 dev=0:18 file=/dev/core
             zsh-2528  [000] 10429.172481: dump_inode: ino=884 size=15 cached=0 age=442 dirty=0 dev=0:18 file=/dev/stderr
             zsh-2528  [000] 10429.172483: dump_inode: ino=883 size=15 cached=0 age=442 dirty=0 dev=0:18 file=/dev/stdout
             zsh-2528  [000] 10429.172486: dump_inode: ino=882 size=15 cached=0 age=442 dirty=0 dev=0:18 file=/dev/stdin
             zsh-2528  [000] 10429.172488: dump_inode: ino=881 size=13 cached=0 age=442 dirty=0 dev=0:18 file=/dev/fd
             zsh-2528  [000] 10429.172491: dump_inode: ino=872 size=13360 cached=0 age=442 dirty=0 dev=0:18 file=/dev

Quoted 2 lines

Here "age" is either age from inode create time, or from last dirty time.

It would be nice to see mapped/unmapped information as well.

Quoted 9 lines

kernel/trace/trace_mm.c +9 -0

+static int pages_similiar(struct page* page0, struct page* page)
+{
+     if (page_count(page0) != page_count(page))
+             return 0;
+
+     if (page_mapcount(page0) != page_mapcount(page))
+             return 0;
+
+     if (page_flags(page0) != page_flags(page))

kernel/trace/trace_mm.c static const struct file_operations trac · line 119

Quoted 5 lines

kernel/trace/trace_mm.c +5 -0

+             return 0;
+
+     return 1;
+}
+

OK, so pages_similar() is used to identify a range of pages in the cache?

Quoted 10 lines

kernel/trace/trace_mm.c +10 -0

+#define BATCH_LINES  100
+static void dump_pagecache(struct address_space *mapping)
+{
+     int i;
+     int lines = 0;
+     pgoff_t len = 0;
+     struct pagevec pvec;
+     struct page *page;
+     struct page *page0 = NULL;
+     unsigned long start = 0;

kernel/trace/trace_mm.c static const struct file_operations trac · line 134

Quoted 5 lines

kernel/trace/trace_mm.c +5 -0

+
+     for (;;) {
+             pagevec_init(&pvec, 0);
+             pvec.nr = radix_tree_gang_lookup(&mapping->page_tree,
+                             (void **)pvec.pages, start + len, PAGEVEC_SIZE);

Is radix_tree_gang_lookup synchronized somewhere? Don't we need to call it under RCU or a lock (mapping) ?

kernel/trace/trace_mm.c static const struct file_operations trac · line 236

Quoted 8 lines

kernel/trace/trace_mm.c +8 -0

+static ssize_t
+trace_pagecache_write(struct file *filp, const char __user *ubuf, size_t count,
+                   loff_t *ppos)
+{
+     struct file *file = NULL;
+     char *name;
+     int err = 0;
+

Can't we use the trace_parser here?

Quoted 11 lines

kernel/trace/trace_mm.c +11 -0

+     if (count <= 1)
+             return -EINVAL;
+     if (count > PATH_MAX + 1)
+             return -ENAMETOOLONG;
+
+     name = kmalloc(count+1, GFP_KERNEL);
+     if (!name)
+             return -ENOMEM;
+
+     if (copy_from_user(name, ubuf, count)) {
+             err = -EFAULT;

kernel/trace/trace_mm.c static const struct file_operations trac · line 253

Quoted 6 lines

kernel/trace/trace_mm.c +6 -0

+             goto out;
+     }
+
+     /* strip the newline added by `echo` */
+     if (name[count-1] != '\n')
+             return -EINVAL;

Doesn't sound correct, what happens if we use echo -n?

Quoted 4 lines

fs/inode.c 2010-02-08 23:19:22.000000000 +0800 renamed from fs/inode.c 2010-02-08 23:19:12.000000000 +0800 +0 -0

@@ -149,7 +149,7 @@ struct inode *inode_init_always(struct s
      inode->i_bdev = NULL;

fs/inode.c 2010-02-08 23:19:22.000000000 +0800 struct inode *inode_init_always(struct s · line 153

Quoted 5 lines

fs/inode.c 2010-02-08 23:19:22.000000000 +0800 renamed from fs/inode.c 2010-02-08 23:19:12.000000000 +0800 +1 -1

      inode->i_cdev = NULL;
      inode->i_rdev = 0;
-     inode->dirtied_when = 0;
+     inode->dirtied_when = jiffies;
 

Hmmm... Is the inode really dirtied when initialized? I know the change is for tracing, but the code when read is confusing.

Quoted 11 lines

Here is a scratch patch to exercise the "object collections" idea :)

Interestingly, the pagecache walk is pretty fast, while copying out the trace data takes more time:

        # time (echo / > walk-fs)
        (; echo / > walk-fs; )  0.01s user 0.11s system 82% cpu 0.145 total

        # time wc /debug/tracing/trace
        4570 45893 551282 /debug/tracing/trace
        wc /debug/tracing/trace  0.75s user 0.55s system 88% cpu 1.470 total

Ah got it: it takes much time to "print" the raw trace data.

Quoted 2 lines

TODO:

Quoted 3 lines

correctness
- show file path name
XXX: can trace_seq_path() be called directly inside TRACE_EVENT()?

OK, finished with the file name with d_path(). I choose not to mangle the possible '\n' in file names, and simply show "?" for such files, for the sake of speed.

Thanks,
Fengguang
---
tracing: pagecache object collections

This dumps
- all cached files of a mounted fs (the inode-cache)
- all cached pages of a cached file (the page-cache)

Usage and Sample output:

# echo /dev > /debug/tracing/objects/mm/pages/walk-fs
# tail /debug/tracing/trace
             zsh-2528  [000] 10429.172470: dump_inode: ino=889 size=0 cached=0 age=442 dirty=0 dev=0:18 file=/dev/console
             zsh-2528  [000] 10429.172472: dump_inode: ino=888 size=0 cached=0 age=442 dirty=7 dev=0:18 file=/dev/null
             zsh-2528  [000] 10429.172474: dump_inode: ino=887 size=40 cached=0 age=442 dirty=0 dev=0:18 file=/dev/shm
             zsh-2528  [000] 10429.172477: dump_inode: ino=886 size=40 cached=0 age=442 dirty=0 dev=0:18 file=/dev/pts
             zsh-2528  [000] 10429.172479: dump_inode: ino=885 size=11 cached=0 age=442 dirty=0 dev=0:18 file=/dev/core
             zsh-2528  [000] 10429.172481: dump_inode: ino=884 size=15 cached=0 age=442 dirty=0 dev=0:18 file=/dev/stderr
             zsh-2528  [000] 10429.172483: dump_inode: ino=883 size=15 cached=0 age=442 dirty=0 dev=0:18 file=/dev/stdout
             zsh-2528  [000] 10429.172486: dump_inode: ino=882 size=15 cached=0 age=442 dirty=0 dev=0:18 file=/dev/stdin
             zsh-2528  [000] 10429.172488: dump_inode: ino=881 size=13 cached=0 age=442 dirty=0 dev=0:18 file=/dev/fd
             zsh-2528  [000] 10429.172491: dump_inode: ino=872 size=13360 cached=0 age=442 dirty=0 dev=0:18 file=/dev

Here "age" is either age from inode create time, or from last dirty time.

TODO:

correctness
- reliably prevent ring buffer overflow,
by replacing cond_resched() with some wait function (eg. wait until 2+ pages are free in ring buffer)
- use stable_page_flags() in recent kernel

output style
- use plain tracing output format (no fancy TASK-PID/.../FUNCTION fields)
- clear ring buffer before dumping the objects?
- output format: key=value pairs ==> header + tabbed values?
- add filtering options if necessary

CC Ingo Molnar <[email protected]>

CC Chris Frost <[email protected]>

CC Steven Rostedt <[email protected]>

CC Peter Zijlstra <[email protected]>

CC Frederic Weisbecker <[email protected]>

Signed-off-by Wu Fengguang <[email protected]>

---
 fs/inode.c                |    2 
 include/trace/events/mm.h |   70 ++++++++++++
 kernel/trace/trace_mm.c   |  204 ++++++++++++++++++++++++++++++++++++
 3 files changed, 275 insertions(+), 1 deletion(-)

include/trace/events/mm.h +70 -0

@@ -2,6 +2,7 @@
 #define _TRACE_MM_H
 
 #include <linux/tracepoint.h>
+#include <linux/pagemap.h>
 #include <linux/mm.h>
 
 #undef TRACE_SYSTEM

@@ -42,6 +43,75 @@ TRACE_EVENT(dump_pages,
 		  __entry->mapcount, __entry->index)
 );
 
+TRACE_EVENT(dump_pagecache_range,
+
+	TP_PROTO(struct page *page, unsigned long len),
+
+	TP_ARGS(page, len),
+
+	TP_STRUCT__entry(
+		__field(	unsigned long,	index		)
+		__field(	unsigned long,	len		)
+		__field(	unsigned long,	flags		)
+		__field(	unsigned int,	count		)
+		__field(	unsigned int,	mapcount	)
+	),
+
+	TP_fast_assign(
+		__entry->index		= page->index;
+		__entry->len		= len;
+		__entry->flags		= page->flags;
+		__entry->count		= atomic_read(&page->_count);
+		__entry->mapcount	= page_mapcount(page);
+	),
+
+	TP_printk("index=%lu len=%lu flags=%lx count=%u mapcount=%u",
+		  __entry->index,
+		  __entry->len,
+		  __entry->flags,
+		  __entry->count,
+		  __entry->mapcount)
+);
+
+TRACE_EVENT(dump_inode,
+
+	TP_PROTO(struct inode *inode, char *name, int len),
+
+	TP_ARGS(inode, name, len),
+
+	TP_STRUCT__entry(
+		__field(	unsigned long,	ino		)
+		__field(	loff_t,		size		)
+		__field(	unsigned long,	nrpages		)
+		__field(	unsigned long,	age		)
+		__field(	unsigned long,	state		)
+		__field(	dev_t,		dev		)
+		__dynamic_array(char,		file,	len	)
+	),
+
+	TP_fast_assign(
+		__entry->ino		= inode->i_ino;
+		__entry->size		= i_size_read(inode);
+		__entry->nrpages	= inode->i_mapping->nrpages;
+		__entry->age		= jiffies - inode->dirtied_when;
+		__entry->state		= inode->i_state;
+		__entry->dev		= inode->i_sb->s_dev;
+		memcpy(__get_str(file), name, len);
+	),
+
+	TP_printk("ino=%lu size=%llu cached=%lu age=%lu dirty=%lu "
+		  "dev=%u:%u file=%s",
+		  __entry->ino,
+		  __entry->size,
+		  __entry->nrpages << PAGE_CACHE_SHIFT,
+		  __entry->age / HZ,
+		  __entry->state & I_DIRTY,
+		  MAJOR(__entry->dev),
+		  MINOR(__entry->dev),
+		  strchr(__get_str(file), '\n') ? "?" : __get_str(file))
+);
+
+
 #endif /*  _TRACE_MM_H */
 
 /* This part must be outside protection */

kernel/trace/trace_mm.c +204 -0

@@ -9,6 +9,9 @@
 #include <linux/bootmem.h>
 #include <linux/debugfs.h>
 #include <linux/uaccess.h>
+#include <linux/pagevec.h>
+#include <linux/writeback.h>
+#include <linux/file.h>
 
 #include "trace_output.h"
 

@@ -95,6 +98,201 @@ static const struct file_operations trac
 	.write		= trace_mm_dump_range_write,
 };
 
+static unsigned long page_flags(struct page* page)
+{
+	return page->flags & ((1 << NR_PAGEFLAGS) - 1);
+}
+
+static int pages_similiar(struct page* page0, struct page* page)
+{
+	if (page_count(page0) != page_count(page))
+		return 0;
+
+	if (page_mapcount(page0) != page_mapcount(page))
+		return 0;
+
+	if (page_flags(page0) != page_flags(page))
+		return 0;
+
+	return 1;
+}
+
+#define BATCH_LINES	100
+static void dump_pagecache(struct address_space *mapping)
+{
+	int i;
+	int lines = 0;
+	pgoff_t len = 0;
+	struct pagevec pvec;
+	struct page *page;
+	struct page *page0 = NULL;
+	unsigned long start = 0;
+
+	for (;;) {
+		pagevec_init(&pvec, 0);
+		pvec.nr = radix_tree_gang_lookup(&mapping->page_tree,
+				(void **)pvec.pages, start + len, PAGEVEC_SIZE);
+
+		if (pvec.nr == 0) {
+			if (len)
+				trace_dump_pagecache_range(page0, len);
+			break;
+		}
+
+		if (!page0)
+			page0 = pvec.pages[0];
+
+		for (i = 0; i < pvec.nr; i++) {
+			page = pvec.pages[i];
+
+			if (page->index == start + len &&
+					pages_similiar(page0, page))
+				len++;
+			else {
+				trace_dump_pagecache_range(page0, len);
+				page0 = page;
+				start = page->index;
+				len = 1;
+				if (++lines > BATCH_LINES) {
+					lines = 0;
+					cond_resched();
+				}
+			}
+		}
+	}
+}
+
+static void dump_inode(struct inode *inode,
+		       char *name_buf,
+		       struct vfsmount *mnt)
+{
+	struct path path = {
+		.mnt = mnt,
+		.dentry = d_find_alias(inode)
+	};
+	char *name;
+	int len;
+
+	if (!path.dentry) {
+		trace_dump_inode(inode, "?", 2);
+		return;
+	}
+
+	name = d_path(&path, name_buf, PAGE_SIZE);
+	if (IS_ERR(name)) {
+		name = "?";
+		len = 2;
+	} else
+		len = PAGE_SIZE + name_buf - name;
+
+	trace_dump_inode(inode, name, len);
+
+	if (path.dentry)
+		dput(path.dentry);
+}
+
+static void dump_fs_pagecache(struct super_block *sb, struct vfsmount *mnt)
+{
+	struct inode *inode;
+	struct inode *prev_inode = NULL;
+	char *name_buf;
+
+	name_buf = (char *)__get_free_page(GFP_TEMPORARY);
+	if (!name_buf)
+		return;
+
+	down_read(&sb->s_umount);
+	if (!sb->s_root)
+		goto out;
+
+	spin_lock(&inode_lock);
+	list_for_each_entry(inode, &sb->s_inodes, i_sb_list) {
+		if (inode->i_state & (I_FREEING|I_CLEAR|I_WILL_FREE|I_NEW))
+			continue;
+		__iget(inode);
+		spin_unlock(&inode_lock);
+		dump_inode(inode, name_buf, mnt);
+		if (inode->i_mapping->nrpages)
+			dump_pagecache(inode->i_mapping);
+		iput(prev_inode);
+		prev_inode = inode;
+		cond_resched();
+		spin_lock(&inode_lock);
+	}
+	spin_unlock(&inode_lock);
+	iput(prev_inode);
+out:
+	up_read(&sb->s_umount);
+	free_page((unsigned long)name_buf);
+}
+
+static ssize_t
+trace_pagecache_write(struct file *filp, const char __user *ubuf, size_t count,
+		      loff_t *ppos)
+{
+	struct file *file = NULL;
+	char *name;
+	int err = 0;
+
+	if (count <= 1)
+		return -EINVAL;
+	if (count > PATH_MAX + 1)
+		return -ENAMETOOLONG;
+
+	name = kmalloc(count+1, GFP_KERNEL);
+	if (!name)
+		return -ENOMEM;
+
+	if (copy_from_user(name, ubuf, count)) {
+		err = -EFAULT;
+		goto out;
+	}
+
+	/* strip the newline added by `echo` */
+	if (name[count-1] != '\n')
+		return -EINVAL;
+	name[count-1] = '\0';
+
+	file = filp_open(name, O_RDONLY|O_LARGEFILE, 0);
+	if (IS_ERR(file)) {
+		err = PTR_ERR(file);
+		file = NULL;
+		goto out;
+	}
+
+	if (tracing_update_buffers() < 0) {
+		err = -ENOMEM;
+		goto out;
+	}
+	if (trace_set_clr_event("mm", "dump_pagecache_range", 1)) {
+		err = -EINVAL;
+		goto out;
+	}
+	if (trace_set_clr_event("mm", "dump_inode", 1)) {
+		err = -EINVAL;
+		goto out;
+	}
+
+	if (filp->f_path.dentry->d_inode->i_private) {
+		dump_fs_pagecache(file->f_path.dentry->d_sb, file->f_path.mnt);
+	} else {
+		dump_pagecache(file->f_mapping);
+	}
+
+out:
+	if (file)
+		fput(file);
+	kfree(name);
+
+	return err ? err : count;
+}
+
+static const struct file_operations trace_pagecache_fops = {
+	.open		= tracing_open_generic,
+	.read		= trace_mm_dump_range_read,
+	.write		= trace_pagecache_write,
+};
+
 /* move this into trace_objects.c when that file is created */
 static struct dentry *trace_objects_dir(void)
 {

@@ -167,6 +365,12 @@ static __init int trace_objects_mm_init(
 	trace_create_file("dump_range", 0600, d_pages, NULL,
 			  &trace_mm_fops);
 
+	trace_create_file("walk-file", 0600, d_pages, NULL,
+			  &trace_pagecache_fops);
+
+	trace_create_file("walk-fs", 0600, d_pages, (void *)1,
+			  &trace_pagecache_fops);
+
 	return 0;
 }
 fs_initcall(trace_objects_mm_init);

fs/inode.c +1 -2

@@ -149,7 +149,7 @@ struct inode *inode_init_always(struct s
 	inode->i_bdev = NULL;
 	inode->i_cdev = NULL;
 	inode->i_rdev = 0;
-	inode->dirtied_when = 0;
+	inode->dirtied_when = jiffies;
 
 	if (security_inode_alloc(inode))
 		goto out_free_inode;
 
--

To unsubscribe, send a message with 'unsubscribe linux-mm' in the body to [email protected]. For more info on Linux MM,
see: http://www.linux-mm.org/ .
Don't email: <a href=mailto:"[email protected]"> [email protected] </a>

Quoted 20 lines

Quoted 11 lines

Here is a scratch patch to exercise the "object collections" idea :)

Interestingly, the pagecache walk is pretty fast, while copying out the trace data takes more time:

        # time (echo / > walk-fs)
        (; echo / > walk-fs; )  0.01s user 0.11s system 82% cpu 0.145 total

        # time wc /debug/tracing/trace
        4570 45893 551282 /debug/tracing/trace
        wc /debug/tracing/trace  0.75s user 0.55s system 88% cpu 1.470 total

Ah got it: it takes much time to "print" the raw trace data.

Quoted 5 lines

TODO:

correctness
- show file path name
XXX: can trace_seq_path() be called directly inside TRACE_EVENT()?

Quoted 3 lines

OK, finished with the file name with d_path(). I choose not to mangle the possible '\n' in file names, and simply show "?" for such files, for the sake of speed.

This patch is nicer than KII-san's one. I plan to test it on my local test environment awhile.

Hi Ingo,

Quoted 18 lines

Note that there's also these older experimental commits in tip:tracing/mm that introduce the notion of 'object collections' and adds the ability to trace them:

3383e37: tracing, page-allocator: Add a postprocessing script for page-allocator-related ftrace events
c33b359: tracing, page-allocator: Add trace event for page traffic related to the buddy lists 0d524fb: tracing, mm: Add trace events for anti-fragmentation falling back to other migratetypes
b9a2817: tracing, page-allocator: Add trace events for page allocation and page freeing 08b6cb8: perf_counter tools: Provide default bfd_demangle() function in case it's not around
eb46710: tracing/mm: rename 'trigger' file to 'dump_range'
1487a7a: tracing/mm: fix mapcount trace record field
dcac8cd: tracing/mm: add page frame snapshot trace

this concept, if refreshed a bit and extended to the page cache, would allow the recording/snapshotting of the MM state of all currently present pages in the page-cache - a possibly nice addition to the dynamic technique you apply in your patches.

Quoted 4 lines

there's similar "object collections" work underway for 'perf lock' btw., by Hitoshi Mitake and Frederic.

So there's lots of common ground and lots of interest.

Here is a scratch patch to exercise the "object collections" idea :)

Interestingly, the pagecache walk is pretty fast, while copying out the trace data takes more time:

        # time (echo / > walk-fs)
        (; echo / > walk-fs; )  0.01s user 0.11s system 82% cpu 0.145 total

        # time wc /debug/tracing/trace
        4570 45893 551282 /debug/tracing/trace
        wc /debug/tracing/trace  0.75s user 0.55s system 88% cpu 1.470 total

        # time (cat /debug/tracing/trace > /dev/shm/t)
        (; cat /debug/tracing/trace > /dev/shm/t; )  0.04s user 0.49s system 95% cpu 0.548 total

        # time (dd if=/debug/tracing/trace of=/dev/shm/t bs=1M)
        0+138 records in
        0+138 records out
        551282 bytes (551 kB) copied, 0.380454 s, 1.4 MB/s
        (; dd if=/debug/tracing/trace of=/dev/shm/t bs=1M; )  0.09s user 0.48s system 96% cpu 0.600 total

The patch is based on tip/tracing/mm.

Thanks,
Fengguang
---
tracing: pagecache object collections

This dumps
- all cached files of a mounted fs (the inode-cache)
- all cached pages of a cached file (the page-cache)

Usage and Sample output:

# echo / > /debug/tracing/objects/mm/pages/walk-fs
# head /debug/tracing/trace

# tracer: nop
#
# TASK-PID CPU# TIMESTAMP FUNCTION
# | | | | |

             zsh-3078  [000]   526.272587: dump_inode: ino=102223 size=169291 cached=172032 age=9 dirty=6 dev=0:15 file=<TODO>
             zsh-3078  [000]   526.274260: dump_pagecache_range: index=0 len=41 flags=10000000000002c count=1 mapcount=0
             zsh-3078  [000]   526.274340: dump_pagecache_range: index=41 len=1 flags=10000000000006c count=1 mapcount=0
             zsh-3078  [000]   526.274401: dump_inode: ino=8966 size=442 cached=4096 age=49 dirty=0 dev=0:15 file=<TODO>
             zsh-3078  [000]   526.274425: dump_pagecache_range: index=0 len=1 flags=10000000000002c count=1 mapcount=0
             zsh-3078  [000]   526.274440: dump_inode: ino=8964 size=4096 cached=0 age=49 dirty=0 dev=0:15 file=<TODO>

Here "age" is either age from inode create time, or from last dirty time.

TODO:

correctness
- show file path name
XXX: can trace_seq_path() be called directly inside TRACE_EVENT()?
- reliably prevent ring buffer overflow,
by replacing cond_resched() with some wait function (eg. wait until 2+ pages are free in ring buffer)
- use stable_page_flags() in recent kernel

output style
- use plain tracing output format (no fancy TASK-PID/.../FUNCTION fields)
- clear ring buffer before dumping the objects?
- output format: key=value pairs ==> header + tabbed values?
- add filtering options if necessary

CC Ingo Molnar <[email protected]>

CC Chris Frost <[email protected]>

CC Steven Rostedt <[email protected]>

CC Peter Zijlstra <[email protected]>

CC Frederic Weisbecker <[email protected]>

Signed-off-by Wu Fengguang <[email protected]>

---
 fs/inode.c                |    2 
 include/trace/events/mm.h |   67 ++++++++++++++
 kernel/trace/trace_mm.c   |  165 ++++++++++++++++++++++++++++++++++++
 3 files changed, 233 insertions(+), 1 deletion(-)

include/trace/events/mm.h +67 -0

@@ -2,6 +2,7 @@
 #define _TRACE_MM_H
 
 #include <linux/tracepoint.h>
+#include <linux/pagemap.h>
 #include <linux/mm.h>
 
 #undef TRACE_SYSTEM

@@ -42,6 +43,72 @@ TRACE_EVENT(dump_pages,
 		  __entry->mapcount, __entry->index)
 );
 
+TRACE_EVENT(dump_pagecache_range,
+
+	TP_PROTO(struct page *page, unsigned long len),
+
+	TP_ARGS(page, len),
+
+	TP_STRUCT__entry(
+		__field(	unsigned long,	index		)
+		__field(	unsigned long,	len		)
+		__field(	unsigned long,	flags		)
+		__field(	unsigned int,	count		)
+		__field(	unsigned int,	mapcount	)
+	),
+
+	TP_fast_assign(
+		__entry->index		= page->index;
+		__entry->len		= len;
+		__entry->flags		= page->flags;
+		__entry->count		= atomic_read(&page->_count);
+		__entry->mapcount	= page_mapcount(page);
+	),
+
+	TP_printk("index=%lu len=%lu flags=%lx count=%u mapcount=%u",
+		  __entry->index,
+		  __entry->len,
+		  __entry->flags,
+		  __entry->count,
+		  __entry->mapcount)
+);
+
+TRACE_EVENT(dump_inode,
+
+	TP_PROTO(struct inode *inode),
+
+	TP_ARGS(inode),
+
+	TP_STRUCT__entry(
+		__field(	unsigned long,	ino		)
+		__field(	loff_t,		size		)
+		__field(	unsigned long,	nrpages		)
+		__field(	unsigned long,	age		)
+		__field(	unsigned long,	state		)
+		__field(	dev_t,		dev		)
+	),
+
+	TP_fast_assign(
+		__entry->ino		= inode->i_ino;
+		__entry->size		= i_size_read(inode);
+		__entry->nrpages	= inode->i_mapping->nrpages;
+		__entry->age		= jiffies - inode->dirtied_when;
+		__entry->state		= inode->i_state;
+		__entry->dev		= inode->i_sb->s_dev;
+	),
+
+	TP_printk("ino=%lu size=%llu cached=%lu age=%lu dirty=%lu "
+		  "dev=%u:%u file=<TODO>",
+		  __entry->ino,
+		  __entry->size,
+		  __entry->nrpages << PAGE_CACHE_SHIFT,
+		  __entry->age / HZ,
+		  __entry->state & I_DIRTY,
+		  MAJOR(__entry->dev),
+		  MINOR(__entry->dev))
+);
+
+
 #endif /*  _TRACE_MM_H */
 
 /* This part must be outside protection */

kernel/trace/trace_mm.c +165 -0

@@ -9,6 +9,9 @@
 #include <linux/bootmem.h>
 #include <linux/debugfs.h>
 #include <linux/uaccess.h>
+#include <linux/pagevec.h>
+#include <linux/writeback.h>
+#include <linux/file.h>
 
 #include "trace_output.h"
 

@@ -95,6 +98,162 @@ static const struct file_operations trac
 	.write		= trace_mm_dump_range_write,
 };
 
+static unsigned long page_flags(struct page* page)
+{
+	return page->flags & ((1 << NR_PAGEFLAGS) - 1);
+}
+
+static int pages_similiar(struct page* page0, struct page* page)
+{
+	if (page_count(page0) != page_count(page))
+		return 0;
+
+	if (page_mapcount(page0) != page_mapcount(page))
+		return 0;
+
+	if (page_flags(page0) != page_flags(page))
+		return 0;
+
+	return 1;
+}
+
+#define BATCH_LINES	100
+static void dump_pagecache(struct address_space *mapping)
+{
+	int i;
+	int lines = 0;
+	pgoff_t len = 0;
+	struct pagevec pvec;
+	struct page *page;
+	struct page *page0 = NULL;
+	unsigned long start = 0;
+
+	for (;;) {
+		pagevec_init(&pvec, 0);
+		pvec.nr = radix_tree_gang_lookup(&mapping->page_tree,
+				(void **)pvec.pages, start + len, PAGEVEC_SIZE);
+
+		if (pvec.nr == 0) {
+			if (len)
+				trace_dump_pagecache_range(page0, len);
+			break;
+		}
+
+		if (!page0)
+			page0 = pvec.pages[0];
+
+		for (i = 0; i < pvec.nr; i++) {
+			page = pvec.pages[i];
+
+			if (page->index == start + len &&
+					pages_similiar(page0, page))
+				len++;
+			else {
+				trace_dump_pagecache_range(page0, len);
+				page0 = page;
+				start = page->index;
+				len = 1;
+				if (++lines > BATCH_LINES) {
+					lines = 0;
+					cond_resched();
+				}
+			}
+		}
+	}
+}
+
+static void dump_fs_pagecache(struct super_block *sb)
+{
+	struct inode *inode;
+	struct inode *prev_inode = NULL;
+
+	down_read(&sb->s_umount);
+	if (!sb->s_root)
+		goto out;
+	spin_lock(&inode_lock);
+	list_for_each_entry(inode, &sb->s_inodes, i_sb_list) {
+		if (inode->i_state & (I_FREEING|I_CLEAR|I_WILL_FREE|I_NEW))
+			continue;
+		__iget(inode);
+		spin_unlock(&inode_lock);
+		trace_dump_inode(inode);
+		if (inode->i_mapping->nrpages)
+			dump_pagecache(inode->i_mapping);
+		iput(prev_inode);
+		prev_inode = inode;
+		cond_resched();
+		spin_lock(&inode_lock);
+	}
+	spin_unlock(&inode_lock);
+	iput(prev_inode);
+out:
+	up_read(&sb->s_umount);
+}
+
+static ssize_t
+trace_pagecache_write(struct file *filp, const char __user *ubuf, size_t count,
+		      loff_t *ppos)
+{
+	struct file *file = NULL;
+	char *name;
+	int err = 0;
+
+	if (count > PATH_MAX + 1)
+		return -ENAMETOOLONG;
+
+	name = kmalloc(count+1, GFP_KERNEL);
+	if (!name)
+		return -ENOMEM;
+
+	if (copy_from_user(name, ubuf, count)) {
+		err = -EFAULT;
+		goto out;
+	}
+
+	/* strip the newline added by `echo` */
+	if (count)
+		name[count-1] = '\0';
+
+	file = filp_open(name, O_RDONLY|O_LARGEFILE, 0);
+	if (IS_ERR(file)) {
+		err = PTR_ERR(file);
+		file = NULL;
+		goto out;
+	}
+
+	if (tracing_update_buffers() < 0) {
+		err = -ENOMEM;
+		goto out;
+	}
+	if (trace_set_clr_event("mm", "dump_pagecache_range", 1)) {
+		err = -EINVAL;
+		goto out;
+	}
+	if (trace_set_clr_event("mm", "dump_inode", 1)) {
+		err = -EINVAL;
+		goto out;
+	}
+
+	if (filp->f_path.dentry->d_inode->i_private) {
+		dump_fs_pagecache(file->f_path.dentry->d_sb);
+	} else {
+		dump_pagecache(file->f_mapping);
+	}
+
+out:
+	if (file)
+		fput(file);
+	kfree(name);
+
+	return err ? err : count;
+}
+
+static const struct file_operations trace_pagecache_fops = {
+	.open		= tracing_open_generic,
+	.read		= trace_mm_dump_range_read,
+	.write		= trace_pagecache_write,
+};
+
 /* move this into trace_objects.c when that file is created */
 static struct dentry *trace_objects_dir(void)
 {

@@ -167,6 +326,12 @@ static __init int trace_objects_mm_init(
 	trace_create_file("dump_range", 0600, d_pages, NULL,
 			  &trace_mm_fops);
 
+	trace_create_file("walk-file", 0600, d_pages, NULL,
+			  &trace_pagecache_fops);
+
+	trace_create_file("walk-fs", 0600, d_pages, (void *)1,
+			  &trace_pagecache_fops);
+
 	return 0;
 }
 fs_initcall(trace_objects_mm_init);

fs/inode.c +1 -2

@@ -149,7 +149,7 @@ struct inode *inode_init_always(struct s
 	inode->i_bdev = NULL;
 	inode->i_cdev = NULL;
 	inode->i_rdev = 0;
-	inode->dirtied_when = 0;
+	inode->dirtied_when = jiffies;
 
 	if (security_inode_alloc(inode))
 		goto out_free_inode;
--

To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to [email protected]
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/

Quoted 85 lines · On Mon, 8 Feb 2010 23:54:50 +0800 Wu Fengguang <[email protected]> wrote:

Hi Ingo,

Quoted 18 lines

Note that there's also these older experimental commits in tip:tracing/mm that introduce the notion of 'object collections' and adds the ability to trace them:

3383e37: tracing, page-allocator: Add a postprocessing script for page-allocator-related ftrace events
c33b359: tracing, page-allocator: Add trace event for page traffic related to the buddy lists 0d524fb: tracing, mm: Add trace events for anti-fragmentation falling back to other migratetypes
b9a2817: tracing, page-allocator: Add trace events for page allocation and page freeing 08b6cb8: perf_counter tools: Provide default bfd_demangle() function in case it's not around
eb46710: tracing/mm: rename 'trigger' file to 'dump_range'
1487a7a: tracing/mm: fix mapcount trace record field
dcac8cd: tracing/mm: add page frame snapshot trace

this concept, if refreshed a bit and extended to the page cache, would allow the recording/snapshotting of the MM state of all currently present pages in the page-cache - a possibly nice addition to the dynamic technique you apply in your patches.

Quoted 4 lines

there's similar "object collections" work underway for 'perf lock' btw., by Hitoshi Mitake and Frederic.

So there's lots of common ground and lots of interest.

Here is a scratch patch to exercise the "object collections" idea :)

Interestingly, the pagecache walk is pretty fast, while copying out the trace data takes more time:

        # time (echo / > walk-fs)
        (; echo / > walk-fs; )  0.01s user 0.11s system 82% cpu 0.145 total

        # time wc /debug/tracing/trace
        4570 45893 551282 /debug/tracing/trace
        wc /debug/tracing/trace  0.75s user 0.55s system 88% cpu 1.470 total

        # time (cat /debug/tracing/trace > /dev/shm/t)
        (; cat /debug/tracing/trace > /dev/shm/t; )  0.04s user 0.49s system 95% cpu 0.548 total

        # time (dd if=/debug/tracing/trace of=/dev/shm/t bs=1M)
        0+138 records in
        0+138 records out
        551282 bytes (551 kB) copied, 0.380454 s, 1.4 MB/s
        (; dd if=/debug/tracing/trace of=/dev/shm/t bs=1M; )  0.09s user 0.48s system 96% cpu 0.600 total

The patch is based on tip/tracing/mm.

Thanks,
Fengguang
---
tracing: pagecache object collections

This dumps
- all cached files of a mounted fs (the inode-cache)
- all cached pages of a cached file (the page-cache)

Usage and Sample output:

# echo / > /debug/tracing/objects/mm/pages/walk-fs
# head /debug/tracing/trace

# tracer: nop
#
# TASK-PID CPU# TIMESTAMP FUNCTION
# | | | | |

             zsh-3078  [000]   526.272587: dump_inode: ino=102223 size=169291 cached=172032 age=9 dirty=6 dev=0:15 file=<TODO>
             zsh-3078  [000]   526.274260: dump_pagecache_range: index=0 len=41 flags=10000000000002c count=1 mapcount=0
             zsh-3078  [000]   526.274340: dump_pagecache_range: index=41 len=1 flags=10000000000006c count=1 mapcount=0
             zsh-3078  [000]   526.274401: dump_inode: ino=8966 size=442 cached=4096 age=49 dirty=0 dev=0:15 file=<TODO>
             zsh-3078  [000]   526.274425: dump_pagecache_range: index=0 len=1 flags=10000000000002c count=1 mapcount=0
             zsh-3078  [000]   526.274440: dump_inode: ino=8964 size=4096 cached=0 age=49 dirty=0 dev=0:15 file=<TODO>

Here "age" is either age from inode create time, or from last dirty time.

TODO:

correctness
- show file path name
XXX: can trace_seq_path() be called directly inside TRACE_EVENT()?
- reliably prevent ring buffer overflow,
by replacing cond_resched() with some wait function (eg. wait until 2+ pages are free in ring buffer)
- use stable_page_flags() in recent kernel

Quoted 6 lines

output style
- use plain tracing output format (no fancy TASK-PID/.../FUNCTION fields)
- clear ring buffer before dumping the objects?
- output format: key=value pairs ==> header + tabbed values?
- add filtering options if necessary

Can we dump page's cgroup ? If so, I'm happy. Maybe
==
struct page_cgroup *pc = lookup_page_cgroup(page); struct mem_cgroup *mem = pc->mem_cgroup; shodt mem_cgroup_id = mem->css.css_id;

And statistics can be counted per css_id.

And then, some output like

dump_pagecache_range: index=0 len=1 flags=10000000000002c count=1 mapcount=0 file=XXX memcg=group_A:x,group_B:y

Is it okay to add a new field after your work finish ?

Quoted 7 lines · KAMEZAWA Hiroyuki

Can we dump page's cgroup ? If so, I'm happy. Maybe
==
struct page_cgroup *pc = lookup_page_cgroup(page); struct mem_cgroup *mem = pc->mem_cgroup; shodt mem_cgroup_id = mem->css.css_id;

Quoted 2 lines

And statistics can be counted per css_id.

Good idea, all of this needs to happen with a check to see if memcg is enabled/disabled at boot as well. pc can be NULL if CONFIG_CGROUP_MEM_RES_CTLR is not enabled.

Can we dump page's cgroup ? If so, I'm happy.

Maybe
==
struct page_cgroup *pc = lookup_page_cgroup(page); struct mem_cgroup *mem = pc->mem_cgroup; shodt mem_cgroup_id = mem->css.css_id;

And statistics can be counted per css_id.

And then, some output like

dump_pagecache_range: index=0 len=1 flags=10000000000002c count=1 mapcount=0 file=XXX memcg=group_A:x,group_B:y

Is it okay to add a new field after your work finish ?

If so, I'll think about some infrastructure to get above based on your patch.

Hello,

This is v3 of a patchset to add some tracepoints for pagecache.

I would propose several tracepoints for tracing pagecache behavior and a script for these.
By using both the tracepoints and the script, we can analysis pagecache behavior like usage or hit ratio with high resolution like per process or per file. Example output of the script looks like:

[process list]
o yum-3215
cache find cache hit cache hit
device inode count count ratio
--------------------------------------------------------

         253:0         16      34434      34130     99.12%
         253:0        198       9692       9463     97.64%
         253:0        639        647        628     97.06%
         253:0        778         32         29     90.62%
         253:0       7305      50225      49005     97.57%
         253:0     144217         12         10     83.33%
         253:0     262775         16         13     81.25%

*snip*

-------------------------------------------------------------------------------

[file list]
device cached
(maj:min) inode pages
--------------------------------

         253:0         16     5752
         253:0        198     2233
         253:0        639       51
         253:0        778       86
         253:0       7305    12307
         253:0     144217       11
         253:0     262775       39

*snip*

[process list]
o yum-3215
device cached added removed indirect
(maj:min) inode pages pages pages removed pages
----------------------------------------------------------------

         253:0         16    34130     5752        0             0
         253:0        198     9463     2233        0             0
         253:0        639      628       51        0             0
         253:0        778       29       78        0             0
         253:0       7305    49005    12307        0             0
         253:0     144217       10       11        0             0
         253:0     262775       13       39        0             0

*snip*
----------------------------------------------------------------
total: 102346 26165 1 0

We can now know system-wide pagecache usage by /proc/meminfo. But we have no method to get higher resolution information like per file or per process usage than system-wide one.

A process may share some pagecache or add a pagecache to the memory or remove a pagecache from the memory.
If a pagecache miss hit ratio rises, maybe it leads to extra I/O and affects system performance.

So, by using the tracepoints we can get the following information.
1. how many pagecaches each process has per each file
2. how many pages are cached per each file
3. how many pagecaches each process shares
4. how often each process adds/removes pagecache
5. how long a pagecache stays in the memory
6. pagecache hit rate per file

Especially, the monitoring pagecache usage per each file and pagecache hit ratio would help us tune some applications like database.
And it will also help us tune the kernel parameters like "vm.dirty_*".

Changelog since v2
o add new script to monitor pagecache hit ratio per process.
o use DECLARE_EVENT_CLASS

Changelog since v1
o Add a script based on "perf trace stream scripting support".

Any comments are welcome.