On Wed, Sep 21 2016, Kees Cook <keesc...@chromium.org> wrote: > On Tue, Sep 20, 2016 at 3:28 PM, Rasmus Villemoes > <li...@rasmusvillemoes.dk> wrote: >> format_decode and vsnprintf occasionally show up in perf top, so I >> went looking for places that might not need the full printf >> power. With the help of kprobes, I gathered some statistics on which >> format strings we mostly pass to vsnprintf. On a trivial desktop >> workload, I hit "%x" 25% of the time, so something apparently reads >> /proc/pid/status (which does 5*16 printf("%x") calls) a lot. >> >> With this patch, reading /proc/pid/status is 30% faster according to >> this microbenchmark: >> >> char buf[4096]; >> int i, fd; >> for (i = 0; i < 10000; ++i) { >> fd = open("/proc/self/status", O_RDONLY); >> read(fd, buf, sizeof(buf)); >> close(fd); >> } >> >> Signed-off-by: Rasmus Villemoes <li...@rasmusvillemoes.dk> > > Heheh. Nice. :) > > Acked-by: Kees Cook <keesc...@chromium.org> > > Out of curiosity, what other stuff ended up near the top? I'd be > curious to see your kprobes too.
I don't have the results from the other machine handy, but it very much depends on what one is doing. I ran a 'find $HOME ...', and "%.2x" ended up accounting for 99%. Turns out ecryptfs does a lot of bin-to-hex conversions, but very inefficiently (calling sprintf("%.2x") in a loop...). Patch sent. Other than that, the top consists of stuff like "%c%c " (/proc/pid/smaps, VmFlags:) " %s" (/proc/cpuinfo, the flags: line) "%*s" (maybe from seq_pad, but not sure who the user of that is) and a lot of other short strings which are rather hard to trace to their source, but presumably most are related to some /proc file. The kprobe is just echo 'p:vsnprintf vsnprintf fmt=+0(%dx):string' > /sys/kernel/debug/tracing/kprobe_events This doesn't escape the strings, so embedded newlines mess up the trace buffer slightly. I used this little piece of line noise to extract the format strings. use File::Slurp; my $txt = read_file($ARGV[0]); while ($txt =~ m/fmt="(.*?)"\n/mg) { $_ = $1; s/\\/\\\\/g; s/\n/\\n/g; s/\t/\\t/g; s/"/\\"/g; print "\"$_\"\n"; } Rasmus