Date: Thu, 26 Jun 2008 16:44:55 -0700 From: Marcus Reid <marcus@blazingdot.com> To: freebsd-stable@FreeBSD.org Subject: Performance of madvise / msync Message-ID: <20080626234455.GA77263@blazingdot.com>
next in thread | raw e-mail | index | archive | help
Hi,
I'm using py-rrdtool 0.2.1 with rrdtool 1.3.0 under 7.0-STABLE, and
there's a couple of things about this new version of rrdtool that
hurt performance under FreeBSD, but apparently help on whatever they
tested on.
For every update, the database file is opened, mapped into memory,
madvise() is called, contents are modified, msync() is called, and
the file is unmapped and closed:
65074 python 0.000009 CALL open(0x831a1b4,O_RDWR,<unused>0)
65074 python 0.000013 NAMI "rg2.rrd"
65074 python 0.000024 RET open 7
65074 python 0.000007 CALL fstat(0x7,0xbfbfe428)
65074 python 0.000011 RET fstat 0
65074 python 0.000008 CALL mmap(0,0x453b7618,PROT_READ|PROT_WRITE,MAP_SHARED,0x7,0,0)
65074 python 0.000018 RET mmap 679235584/0x287c5000
65074 python 0.000007 CALL madvise(0x287c5000,0x453b7618,_MADV_RANDOM)
65074 python 0.000008 RET madvise 0
65074 python 0.000006 CALL madvise(0x287c5000,0x70,_MADV_WILLNEED)
65074 python 0.027455 RET madvise 0
65074 python 0.000058 CALL madvise(0x287c5000,0x1c20,_MADV_WILLNEED)
65074 python 0.016904 RET madvise 0
65074 python 0.000179 CALL madvise(0x287c6000,0x1950,_MADV_WILLNEED)
65074 python 0.008629 RET madvise 0
65074 python 0.000040 CALL madvise(0x287c8000,0x8,_MADV_WILLNEED)
65074 python 0.004173 RET madvise 0
65074 python 0.000048 CALL gettimeofday(0xbfbfe554,0)
65074 python 0.000009 RET gettimeofday 0
65074 python 0.000012 CALL fcntl(0x7,<invalid=12>,0xbfbfe478)
65074 python 0.000024 RET fcntl 0
65074 python 0.006084 CALL msync(0x287c5000,0x453b7618,MS_ASYNC)
65074 python 0.106284 RET msync 0
65074 python 0.000483 CALL munmap(0x287c5000,0x453b7618)
65074 python 0.000356 RET munmap 0
65074 python 0.000012 CALL close(0x7)
65074 python 0.000046 RET close 0
65074 python 0.000173 CALL __sysctl(0xbfbfe388,0x2,0xbfbfe394,0xbfbfe398,0,0)
65074 python 0.000016 RET __sysctl 0
Here's a similar update without the calls to madvise and msync:
96372 python 0.000011 CALL open(0x831aa34,O_RDWR,<unused>0)
96372 python 0.000016 NAMI "rg2.rrd"
96372 python 0.000025 RET open 7
96372 python 0.000009 CALL fstat(0x7,0xbfbfe428)
96372 python 0.000014 RET fstat 0
96372 python 0.000010 CALL mmap(0,0x453b7618,PROT_READ|PROT_WRITE,MAP_SHARED,0x7,0,0)
96372 python 0.000021 RET mmap 679235584/0x287c5000
96372 python 0.000101 CALL madvise(0x287c5000,0x1c20,_MADV_WILLNEED)
96372 python 0.000013 RET madvise 0
96372 python 0.000010 CALL madvise(0x287c6000,0x1950,_MADV_WILLNEED)
96372 python 0.000010 RET madvise 0
96372 python 0.000009 CALL madvise(0x287c8000,0x8,_MADV_WILLNEED)
96372 python 0.000009 RET madvise 0
96372 python 0.000010 CALL gettimeofday(0xbfbfe554,0)
96372 python 0.000009 RET gettimeofday 0
96372 python 0.000011 CALL fcntl(0x7,<invalid=12>,0xbfbfe478)
96372 python 0.000016 RET fcntl 0
96372 python 0.002024 CALL munmap(0x287c5000,0x453b7618)
96372 python 0.000366 RET munmap 0
96372 python 0.000016 CALL close(0x7)
96372 python 0.000046 RET close 0
96372 python 0.000108 CALL __sysctl(0xbfbfe388,0x2,0xbfbfe394,0xbfbfe398,0,0)
96372 python 0.000017 RET __sysctl 0
As you can see, it's quite a bit faster.
I know that msync is necessary under Linux but obsolete under FreeBSD, but
it's still funny that it takes a tenth of a second to return even with
MS_ASYNC specified.
Also, why is it that the madvise() calls take so much longer when the
program does a couple of its own madvise() calls? Was madvise() never
intended to be run so frequently and is therefore a little slower than
it could be?
Here's the diff between the code for the first kdump above and the
second one.
*** src/rrd_open.c.orig Tue Jun 10 23:12:55 2008
--- src/rrd_open.c Wed Jun 25 21:43:54 2008
***************
*** 175,191 ****
#endif
if (rdwr & RRD_CREAT)
goto out_done;
- #ifdef USE_MADVISE
- if (rdwr & RRD_COPY) {
- /* We will read everything in a moment (copying) */
- madvise(data, rrd_file->file_len, MADV_WILLNEED | MADV_SEQUENTIAL);
- } else {
- /* We do not need to read anything in for the moment */
- madvise(data, rrd_file->file_len, MADV_RANDOM);
- /* the stat_head will be needed soonish, so hint accordingly */
- madvise(data, sizeof(stat_head_t), MADV_WILLNEED | MADV_RANDOM);
- }
- #endif
__rrd_read(rrd->stat_head, stat_head_t,
1);
--- 175,180 ----
***************
*** 388,396 ****
int ret;
#ifdef HAVE_MMAP
- ret = msync(rrd_file->file_start, rrd_file->file_len, MS_ASYNC);
- if (ret != 0)
- rrd_set_error("msync rrd_file: %s", rrd_strerror(errno));
ret = munmap(rrd_file->file_start, rrd_file->file_len);
if (ret != 0)
rrd_set_error("munmap rrd_file: %s", rrd_strerror(errno));
--- 377,382 ----
Thanks,
Marcus
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?20080626234455.GA77263>