To measure page read times I instrumented async page I/O by measuring
the time between brw_page calling ll_rw_block and end_buffer_io_async
getting called. To test the inter-file prefetching, I wrote a simple
best case program that goes though a non-changing list of 500 file
names opening each file, reading the first 32k of the file and
sleeping for a second in-between each read.
In a normal kernel (without inter-file prefetching enabled) this
program spends an average of 4ms on each page read (a histogram below
shows the distribution). Then to test inter-file prefetching I enable
prefetching; run the program once to let the system learn the pattern
in which the files are accessed; clear the I/O caches with a program
that calls malloc until memory exhausts, evicting almost all cached
I/O data. Finally I re-run the test program and the inter-file
prefetching is able to predict the next file a do a prefetch on the
first 32k of the predicted file. My problem is that in this case this
prefetching has an average page read time of around 300ms (again
distribution below). The code called to prefetch the first 32K of a
file is below. I'm calling try_to_read_ahead() which calls the same
routines that are used to do the read for the non-prefetching case, so
I'm quite puzzled as to why the same read calls are taking about 10
time longer than when they are called by sys_read. (BTW - 2.2.9
kernel, ext2fs, and ide disk).
Is it possible that I'm over filling the device que, if so then why doesn't
this happen when sys_read calls to read exactly the same data, just on
user demand vice as a prefetch.
In any case, any ideas, thoughts or sudden rays of bright light would
be greatly appreciated. Thanks for your time,
tmk
int prefetch_file_data(struct inode * inode, unsigned long max_ahead)
{
struct dentry * dentry;
struct file * f;
int ahead,error;
unsigned long page_cache;
if (max_ahead > inode->i_size)
max_ahead = inode->i_size;
debug (4," prefetching data %ld bytes\n",max_ahead);
error = -ENFILE;
f = get_empty_filp();
if (!f)
return 0;
dentry = list_entry(inode->i_dentry.next, struct dentry, d_alias);
f->f_dentry = dentry;
f->f_pos = 0;
f->f_reada = 0;
f->f_op = NULL;
if (inode->i_op)
f->f_op = inode->i_op->default_file_ops;
#if 0/1 /* tried both with and without this */
if (f->f_op && f->f_op->open) {
error = f->f_op->open(inode,f);
if (error)
put_filp(f);
return 0;
}
#endif
ahead = 0;
while (ahead < max_ahead) {
debug (2,"PREFETCHING 0x%0x %lu offset %lu\n",
inode->i_dev, inode->i_ino,ahead);
page_cache = try_to_read_ahead(f, ahead,0);
ahead += PAGE_CACHE_SIZE;
}
put_filp(f);
return max_ahead;
}
Page read distributions for readnSleep without prefetching:
times in usecs
log_prefetch Hist: 8118 event 3890 mean 263 min 253458 max
< 1: 0
< 2: 0
< 4: 0
< 8: 0
< 16: 0
< 32: 0
< 64: 0
< 128: 0
< 256: 0
< 512: 23
< 1024: 1461
< 2048: 5586
< 4096: 77
< 8192: 97
< 16384: 253
< 32768: 511
< 65536: 74
< 131072: 31
< 262144:
< 524288: 0
< 1048576: 0
< 2097152: 0
Page read distributions for readnSleep with inter-file prefetching
log_prefetch Hist: 2508 event 299952 mean 209 min 1005362 max 0 negs
< 1: 0
< 2: 0
< 4: 0
< 8: 0
< 16: 0
< 32: 0
< 64: 0
< 128: 0
< 256: 1
< 512: 7
< 1024: 626
< 2048: 12
< 4096: 0
< 8192: 8
< 16384: 95
< 32768: 133
< 65536: 83
< 131072: 162
< 262144: 303
< 524288: 413
< 1048576: 665
< 2097152: 0
--tmk
----------------------------------------------------------------------- Tom M. Kroeger Pray for wind Graduate Student, UC Santa Cruz \ Pray for waves e-mail: tmk@cs.ucsc.edu |\ and Pray it's your day off! http://www.cse.ucsc.edu/~tmk |~\ (831) 459-4458 |__\ (831) 426-9055 home ,----+--
- To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to majordomo@vger.rutgers.edu Please read the FAQ at http://www.tux.org/lkml/