Glenn Fowler wrote:
[I split the email thread into multiple topics]
> I think the point is that if the common usage is to
> sum many different files, or one file at a time over
> long spans of time then the performance of getting
> the bytes from the filesystem to user space may
> outweigh any cache optimization gains
>
> the ast apps are already at a disadvantage because they
> pull in extra .so's over the base case(s) they are measured against
>
> what I need is a big view analysis of at least a few more variables
> so that resonable decisions can be made of ifdef'ing up the code
>
> e.g.,
>
> what is the startup cost of the extra .so's?
Example:
"truss -d" for the old "mkfifo" looks like this:
-- snip --
Base time stamp: 1253739410.3487 [ Wed Sep 23 22:56:50 CEST 2009 ]
0.0000
execve("/home/test001/ksh93/svn/scripts/benchmarks/tmp/oldcmd/mkfifo",
0xFFBFFB5C, 0xFFBFFB68) argc = 2
0.0040 mmap(0x00000000, 8192, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_ANON, -1, 0) = 0xFF3A0000
0.0041 mmap(0x00000000, 8192, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_ANON, -1, 0) = 0xFF390000
0.0043 memcntl(0xFF3B0000, 31928, MC_ADVISE, MADV_WILLNEED, 0, 0) = 0
0.0043 memcntl(0x00010000, 2332, MC_ADVISE, MADV_WILLNEED, 0, 0) = 0
0.0044 resolvepath("/usr/lib/ld.so.1", "/lib/ld.so.1", 1023) = 12
0.0045
resolvepath("/home/test001/ksh93/svn/scripts/benchmarks/tmp/oldcmd/mkfifo",
"/home/test001/ksh93/svn/scripts/benchmarks/tmp/oldcmd/mkfifo", 1023) =
60
0.0047
stat64("/home/test001/ksh93/svn/scripts/benchmarks/tmp/oldcmd/mkfifo",
0xFFBFF780) = 0
0.0047 open("/var/ld/ld.config", O_RDONLY) Err#2 ENOENT
0.0048 stat64("/lib/libc.so.1", 0xFFBFEF18) = 0
0.0049 resolvepath("/lib/libc.so.1", "/lib/libc.so.1", 1023) = 14
0.0050 open("/lib/libc.so.1", O_RDONLY) = 3
0.0052 mmapobj(3, 0x00020000, 0xFF3F79A8, 0xFFBFEFAC, 0x00000000) = 0
0.0052 close(3) = 0
0.0054 memcntl(0xFF200000, 200528, MC_ADVISE, MADV_WILLNEED, 0, 0) = 0
0.0055 mmap(0x00000000, 8192, PROT_READ|PROT_WRITE|PROT_EXEC,
MAP_PRIVATE|MAP_ANON, -1, 0) = 0xFF380000
0.0060 mmap(0x00010000, 24576, PROT_READ|PROT_WRITE|PROT_EXEC,
MAP_PRIVATE|MAP_ANON|MAP_ALIGN, -1, 0) = 0xFF370000
0.0061 getcontext(0xFFBFF5F0)
0.0062 getrlimit(RLIMIT_STACK, 0xFFBFF5D0) = 0
0.0062 getpid() = 25515 [25514]
0.0063 setustack(0xFF372A88)
0.0065 umask(0) = 022
0.0066 brk(0x00022530) = 0
0.0067 brk(0x00024530) = 0
0.0068 stat64("/usr/lib/locale/en_US.UTF-8/en_US.UTF-8.so.3",
0xFFBFE9A8) = 0
0.0069 resolvepath("/usr/lib/locale/en_US.UTF-8/en_US.UTF-8.so.3",
"/usr/lib/locale/en_US.UTF-8/en_US.UTF-8.so.3", 1023) = 44
0.0070 open("/usr/lib/locale/en_US.UTF-8/en_US.UTF-8.so.3", O_RDONLY) =
3
0.0071 mmapobj(3, 0x00020000, 0xFF380600, 0xFFBFEA3C, 0x00000000) = 0
0.0071 close(3) = 0
0.0072 memcntl(0xFEF70000, 9776, MC_ADVISE, MADV_WILLNEED, 0, 0) = 0
0.0073 stat64("/usr/lib/locale/en_US.UTF-8/libc.so.1", 0xFFBFE860)
Err#2 ENOENT
0.0074 stat64("/usr/lib/locale/en_US.UTF-8/methods_unicode.so.3",
0xFFBFE860) = 0
0.0075 resolvepath("/usr/lib/locale/en_US.UTF-8/methods_unicode.so.3",
"/usr/lib/locale/common/methods_unicode.so.3", 1023) = 43
0.0076 open("/usr/lib/locale/en_US.UTF-8/methods_unicode.so.3",
O_RDONLY) = 3
0.0078 mmapobj(3, 0x00020000, 0xFF380C68, 0xFFBFE8F4, 0x00000000) = 0
0.0078 close(3)
-- snip --
the same for the new (AST-based) "mkfifo" version looks like this:
-- snip --
Base time stamp: 1253739365.6076 [ Wed Sep 23 22:56:05 CEST 2009 ]
0.0000 execve("/usr/bin/mkfifo", 0xFFFFFFFF7FFFFAC8,
0xFFFFFFFF7FFFFAE0) argc = 2
0.0042 mmap(0x00000000, 8192, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_ANON, -1, 0) = 0xFFFFFFFF7F500000
0.0044 mmap(0x00000000, 8192, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_ANON, -1, 0) = 0xFFFFFFFF7F400000
0.0045 memcntl(0xFFFFFFFF7F600000, 42272, MC_ADVISE, MADV_WILLNEED, 0,
0) = 0
0.0046 memcntl(0x100000000, 6976, MC_ADVISE, MADV_WILLNEED, 0, 0) = 0
0.0046 resolvepath("/usr/lib/sparcv9/ld.so.1", "/lib/sparcv9/ld.so.1",
1023) = 20
0.0047 resolvepath("/usr/bin/mkfifo", "/usr/bin/mkfifo", 1023) = 15
0.0048 stat("/usr/bin/mkfifo", 0xFFFFFFFF7FFFF618) = 0
0.0049 open("/var/ld/64/ld.config", O_RDONLY) Err#2 ENOENT
0.0050 stat("/lib/64/libc.so.1", 0xFFFFFFFF7FFFED00) = 0
0.0051 resolvepath("/lib/64/libc.so.1", "/lib/sparcv9/libc.so.1", 1023)
= 22
0.0052 open("/lib/64/libc.so.1", O_RDONLY) = 3
0.0052 mmap(0x00000000, 8192, PROT_READ|PROT_WRITE|PROT_EXEC,
MAP_PRIVATE|MAP_ANON, -1, 0) = 0xFFFFFFFF7F300000
0.0054 mmapobj(3, 0x00020000, 0xFFFFFFFF7F300030, 0xFFFFFFFF7FFFE83C,
0x00000000) = 0
0.0055 close(3) = 0
0.0057 memcntl(0xFFFFFFFF7F000000, 228176, MC_ADVISE, MADV_WILLNEED, 0,
0) = 0
0.0062 mmap(0x00010000, 24576, PROT_READ|PROT_WRITE|PROT_EXEC,
MAP_PRIVATE|MAP_ANON|MAP_ALIGN, -1, 0) = 0xFFFFFFFF7EF00000
0.0063 getcontext(0xFFFFFFFF7FFFF120)
0.0064 getrlimit(RLIMIT_STACK, 0xFFFFFFFF7FFFF0E0) = 0
0.0064 getpid() = 25508 [25507]
0.0065 setustack(0xFFFFFFFF7EF02AC0)
0.0067 stat("/lib/64/libast.so.1", 0xFFFFFFFF7FFFE9E0) Err#2 ENOENT
0.0068 stat("/usr/lib/64/libast.so.1", 0xFFFFFFFF7FFFE9E0) = 0
0.0069 resolvepath("/usr/lib/64/libast.so.1",
"/usr/lib/sparcv9/libast.so.1", 1023) = 28
0.0070 open("/usr/lib/64/libast.so.1", O_RDONLY) = 3
0.0072 mmapobj(3, 0x00020000, 0xFFFFFFFF7F301338, 0xFFFFFFFF7FFFE51C,
0x00000000) = 0
0.0072 close(3) = 0
0.0074 memcntl(0xFFFFFFFF7EB00000, 138392, MC_ADVISE, MADV_WILLNEED, 0,
0) = 0
0.0082 readlink("/proc/self/path/a.out", "/usr/bin/mkfifo", 1025) = 15
0.0085 sysconfig(_CONFIG_PAGESIZE) = 8192
0.0086 brk(0x100104BC0) = 0
0.0086 brk(0x10010CBC0) = 0
0.0087 stat("/platform/SUNW,A70/lib/sparcv9/libc_psr.so.1",
0xFFFFFFFF7FFFDDD0) = 0
0.0088 resolvepath("/platform/SUNW,A70/lib/sparcv9/libc_psr.so.1",
"/platform/sun4u-us3/lib/sparcv9/libc_psr.so.1", 1023) = 45
0.0090 open("/platform/SUNW,A70/lib/sparcv9/libc_psr.so.1", O_RDONLY) =
3
0.0091 mmapobj(3, 0x00020000, 0xFFFFFFFF7F301E60, 0xFFFFFFFF7FFFD90C,
0x00000000) = 0
0.0091 close(3) = 0
0.0092 mmap(0x00000000, 8192, PROT_READ|PROT_WRITE|PROT_EXEC,
MAP_PRIVATE|MAP_ANON, -1, 0) = 0xFFFFFFFF7E900000
0.0093 schedctl() =
0xFFFFFFFF7E8E8000
0.0094 sigaction(SIGSEGV, 0xFFFFFFFF7FFFEA90, 0xFFFFFFFF7FFFEB80) = 0
0.0095 sigaction(SIGSEGV, 0xFFFFFFFF7FFFEA90, 0xFFFFFFFF7FFFEB80) = 0
0.0095 sigfillset(0xFFFFFFFF7F252904) = 0
0.0096 lwp_sigmask(SIG_SETMASK, 0x00000000, 0x00000000) = 0xFFBFFEFF
[0x0000FFFF]
0.0097 brk(0x10010CBC0) = 0
0.0097 brk(0x100110BC0) = 0
0.0099 stat("/usr/lib/locale/en_US.UTF-8/sparcv9/en_US.UTF-8.so.3",
0xFFFFFFFF7FFFDC50) = 0
0.0101
resolvepath("/usr/lib/locale/en_US.UTF-8/sparcv9/en_US.UTF-8.so.3",
"/usr/lib/locale/en_US.UTF-8/sparcv9/en_US.UTF-8.so.3", 1023) = 52
0.0102 open("/usr/lib/locale/en_US.UTF-8/sparcv9/en_US.UTF-8.so.3",
O_RDONLY) = 3
0.0103 mmapobj(3, 0x00020000, 0xFFFFFFFF7E9009C0, 0xFFFFFFFF7FFFD78C,
0x00000000) = 0
0.0104 close(3) = 0
0.0105 memcntl(0xFFFFFFFF7E500000, 16168, MC_ADVISE, MADV_WILLNEED, 0,
0) = 0
0.0106 stat("/usr/lib/locale/en_US.UTF-8/sparcv9/libc.so.1",
0xFFFFFFFF7FFFD9D0) Err#2 ENOENT
0.0107 stat("./libc.so.1", 0xFFFFFFFF7FFFD9D0) Err#2 ENOENT
0.0108 stat("/usr/lib/locale/en_US.UTF-8/sparcv9/methods_unicode.so.3",
0xFFFFFFFF7FFFD9D0) = 0
0.0109
resolvepath("/usr/lib/locale/en_US.UTF-8/sparcv9/methods_unicode.so.3",
"/usr/lib/locale/common/sparcv9/methods_unicode.so.3", 1023) = 51
0.0110 open("/usr/lib/locale/en_US.UTF-8/sparcv9/methods_unicode.so.3",
O_RDONLY) = 3
0.0111 mmapobj(3, 0x00020000, 0xFFFFFFFF7E9015F0, 0xFFFFFFFF7FFFD50C,
0x00000000) = 0
0.0112 close(3)
-- snip --
The difference here is 0.0034 seconds. This sounds tiny but this sum-up
over 1000000 iterations in the benchmarks of the Sun performance people
and the C team will only look at the absolute numbers and treat these
extra costs as "regression" (which means the change cannot make it into
OS/Net with today's rules).
----
Bye,
Roland
--
__ . . __
(o.\ \/ /.o) roland.ma...@nrubsig.org
\__\/\/__/ MPEG specialist, C&&JAVA&&Sun&&Unix programmer
/O /==\ O\ TEL +49 641 3992797
(;O/ \/ \O;)
_______________________________________________
perf-discuss mailing list
perf-discuss@opensolaris.org
