Strange delays and CPU usage reading mmapped file

[Shawn Bohrer <sbohrer@rgmadvisors.com>]

Hello,

I'm seeing some strange delays and high CPU usage when reading from a
memory mapped file.  It appears there is some threshold of number of
pages read, that triggers the problem and that threshold varies
depending on the machine.  I'm hoping someone can help explain what is
happening here.  See the simple example program at the end.


$ gcc mmap_read.c -o mmap_read
$ dd if=/dev/urandom of=testfile bs=4096 count=35000
$ /usr/bin/time ./mmap_read testfile 5000
Pages Touched: 35000
0.54user 0.17system 0:05.68elapsed 12%CPU (0avgtext+0avgdata 0maxresident)k
0inputs+0outputs (0major+35122minor)pagefaults 0swaps

Which is what I would expect, but if I increase the number of pages:

$ dd if=/dev/urandom of=testfile bs=4096 count=40000
$ /usr/bin/time ./mmap_read testfile 5000
Pages Touched: 40000
5.00user 0.05system 0:10.06elapsed 50%CPU (0avgtext+0avgdata 0maxresident)k
0inputs+0outputs (0major+40122minor)pagefaults 0swaps

The user time jumps to 5.00s and I get 50% CPU usage.  I've run this
on a couple of machines with the same result, but the number of pages
required to trigger the problem seems to vary.  The specs of this
machine are:

$ uname -a
Linux BohrerMBP 2.6.31.12-174.2.3.fc12.x86_64 #1 SMP Mon Jan 18 19:52:07 UTC 2010 x86_64 x86_64 x86_64 GNU/Linux

$ cat /proc/cpuinfo | grep "model name"
model name      : Intel(R) Core(TM)2 Duo CPU     T9400  @ 2.53GHz
model name      : Intel(R) Core(TM)2 Duo CPU     T9400  @ 2.53GHz

$ free
             total       used       free     shared    buffers     cached
Mem:       4035088     849936    3185152          0      44268     420356
-/+ buffers/cache:     385312    3649776
Swap:      4244472          0    4244472



The example program used:


#include <stdio.h>
#include <stdlib.h>
#include <sys/mman.h>
#include <sys/types.h>
#include <sys/epoll.h>
#include <sys/stat.h>
#include <fcntl.h>

int main(int argc, char *argv[])
{
	struct stat sb;
	off_t len;
	char *p;
	int sum, i, cnt;
	int fd;
	int epfd = epoll_create(1);

	if (argc < 3){
		fprintf(stderr, "usage: %s <file> <iterations>\n", argv[0]);
		return 1;
	}

	fd = open(argv[1], O_RDONLY);
	if (fd == -1) {
		perror("open");
		return 1;
	}

	if (fstat(fd, &sb) == -1) {
		perror ("fstat");
		return 1;
	}

	if (!S_ISREG(sb.st_mode)) {
		fprintf(stderr, "%s is not a file\n", argv[1]);
		return 1;
	}

	p = mmap(0, sb.st_size, PROT_READ, MAP_PRIVATE, fd, 0);
	if (p == MAP_FAILED) {
		perror("mmap");
		return 1;
	}

	if (close(fd) == -1) {
		perror("close");
		return 1;
	}

	cnt = atoi(argv[2]);
	for (i = 0; i < cnt; ++i) {
		for (len =0; len < sb.st_size; len += 4096) {
			sum += p[len];
		}
                /* Sleep 1ms */
		epoll_wait(epfd, 0, 1, 1);
	}
	printf("Pages Touched: %d\n", len/4096);

	if (munmap(p, sb.st_size) == -1) {
		perror("munmap");
		return 1;
	}

	return 0;
}