Support for the Linux 'perf report' and 'perf annotate' tools.

Support for the Linux 'perf report' and 'perf annotate' tools.

In this change, the support comes in two flavours:

--perf_jit_prof - outputs the files in a new perf format that only works with a
patched perf tool (patch obtained from Stephane Eranian). Both 'perf report' and
'perf annotate' are supported (the file format also contains the machine code).

--perf_basic_prof - outputs the files in a format that the existing perf tool
can consume. Only 'perf report' is supported.

In both cases, we have to disable code compaction because the perf tool does not
understand code relocation. (We are told that code relocation should be
supported soon.)

Usage:

perf record -g d8 --perf_jit_prof --no_compact_code_space my.js
perf report

The change itself is straightforward - we simply listen to code events and
write an entry to a log file for every new piece of code.


I am not yet sure whether we should keep both versions or just one (and which
one). My hope is the reviewers can help here.

R=danno@chromium.org
BUG=

Committed: https://code.google.com/p/v8/source/detail?r=18034

[danno, 2013-11-13 17:18:09]

Going in the right direction! Feedback is mostly nits...

https://codereview.chromium.org/70013002/diff/40001/src/flag-definitions.h
File src/flag-definitions.h (right):

https://codereview.chromium.org/70013002/diff/40001/src/flag-definitions.h#ne...
src/flag-definitions.h:790: DEFINE_bool(perf_basic_prof, false, "Enable perf
linux profiler (basic support).")
nit: 80 col (tools/presubmit should have pointed this out, BTW)

https://codereview.chromium.org/70013002/diff/40001/src/flag-definitions.h#ne...
src/flag-definitions.h:791: DEFINE_bool(perf_jit_prof, false, "Enable perf linux
profiler "
How about call this one perf_annotate_support?

https://codereview.chromium.org/70013002/diff/40001/src/flag-definitions.h#ne...
src/flag-definitions.h:792: "(experimental annotate support).")
You probably want to make sure that these flags imply nocompact_code_space, or
at least in MarkCompactCollector::StartCompaction make sure, just like with the
gdbjit, that when these features are on, there is no compaction possible.

https://codereview.chromium.org/70013002/diff/40001/src/log.cc
File src/log.cc (right):

https://codereview.chromium.org/70013002/diff/40001/src/log.cc#newcode252
src/log.cc:252: explicit PerfBasicLogger();
Don't need explicit here, only for single argument constructors.

https://codereview.chromium.org/70013002/diff/40001/src/log.cc#newcode285
src/log.cc:285: perf_dump_name,
nit: 4 char indent

https://codereview.chromium.org/70013002/diff/40001/src/log.cc#newcode307
src/log.cc:307: (uint64_t)code->instruction_start(),
nit: 4 char indent (2 is for nested scopes only)

https://codereview.chromium.org/70013002/diff/40001/src/log.cc#newcode316
src/log.cc:316: explicit PerfJitLogger();
Don't need explicit here, only for single argument constructor.

https://codereview.chromium.org/70013002/diff/40001/src/log.cc#newcode404
src/log.cc:404: perf_dump_name,
Indent 4 characters on line continuations

https://codereview.chromium.org/70013002/diff/40001/src/log.cc#newcode422
src/log.cc:422: SharedFunctionInfo*,
nit: indentation one char too many on this line and below.

[bnoordhuis, 2013-11-13 23:40:51]

Left some comments.  I really like this patch.  Tested it with node.js master
and it works great (as long as V8 can write to /tmp :-))

https://codereview.chromium.org/70013002/diff/40001/src/log.cc
File src/log.cc (right):

https://codereview.chromium.org/70013002/diff/40001/src/log.cc#newcode289
src/log.cc:289: perf_output_handle_ = OS::FOpen(perf_dump_name.start(),
OS::LogFileOpenMode);
This should check for NULL, shouldn't it?  Calling setvbuf() or fclose() on a
NULL stream will segfault.

https://codereview.chromium.org/70013002/diff/40001/src/log.cc#newcode307
src/log.cc:307: (uint64_t)code->instruction_start(),
static_cast?  (Here and in a few other places.)

https://codereview.chromium.org/70013002/diff/40001/src/log.cc#newcode452
src/log.cc:452: ASSERT(static_cast<size_t>(size) == rv);
I don't think that's a safe assumption to make.  fwrite() can (and will)
sometimes write fewer bytes than requested, e.g. when the write() system call
got interrupted by a signal.

Minor nit: you probably meant `ssize_t` one line up.

[Jarin, 2013-11-14 07:51:34]

On 2013/11/13 17:18:09, danno wrote:
> Going in the right direction! Feedback is mostly nits...
> 
> https://codereview.chromium.org/70013002/diff/40001/src/flag-definitions.h
> File src/flag-definitions.h (right):
> 
>
https://codereview.chromium.org/70013002/diff/40001/src/flag-definitions.h#ne...
> src/flag-definitions.h:790: DEFINE_bool(perf_basic_prof, false, "Enable perf
> linux profiler (basic support).")
> nit: 80 col (tools/presubmit should have pointed this out, BTW)
> 
>
https://codereview.chromium.org/70013002/diff/40001/src/flag-definitions.h#ne...
> src/flag-definitions.h:791: DEFINE_bool(perf_jit_prof, false, "Enable perf
linux
> profiler "
> How about call this one perf_annotate_support?
> 
>
https://codereview.chromium.org/70013002/diff/40001/src/flag-definitions.h#ne...
> src/flag-definitions.h:792: "(experimental annotate support).")
> You probably want to make sure that these flags imply nocompact_code_space, or
> at least in MarkCompactCollector::StartCompaction make sure, just like with
the
> gdbjit, that when these features are on, there is no compaction possible.
> 
> https://codereview.chromium.org/70013002/diff/40001/src/log.cc
> File src/log.cc (right):
> 
> https://codereview.chromium.org/70013002/diff/40001/src/log.cc#newcode252
> src/log.cc:252: explicit PerfBasicLogger();
> Don't need explicit here, only for single argument constructors.
> 
> https://codereview.chromium.org/70013002/diff/40001/src/log.cc#newcode285
> src/log.cc:285: perf_dump_name,
> nit: 4 char indent
> 
> https://codereview.chromium.org/70013002/diff/40001/src/log.cc#newcode307
> src/log.cc:307: (uint64_t)code->instruction_start(),
> nit: 4 char indent (2 is for nested scopes only)
> 
> https://codereview.chromium.org/70013002/diff/40001/src/log.cc#newcode316
> src/log.cc:316: explicit PerfJitLogger();
> Don't need explicit here, only for single argument constructor.
> 
> https://codereview.chromium.org/70013002/diff/40001/src/log.cc#newcode404
> src/log.cc:404: perf_dump_name,
> Indent 4 characters on line continuations
> 
> https://codereview.chromium.org/70013002/diff/40001/src/log.cc#newcode422
> src/log.cc:422: SharedFunctionInfo*,
> nit: indentation one char too many on this line and below.

Addressed everything in patch set 3, except the change of the flag name. The
--perf-jit-prof flag does not support just 'perf annotate', it also supports
'perf report'. Once the perf tool changes make it to the mainline kernel, we
should only keep --perf-jit-prof.

I should also say that with release build of v8, I see that there are still some
addresses that are not accounted for. I will try to chase them down. Today, I
have also seen 'perf report' crashing occasionally on start, so there is still
some something funny going on...

[Jarin, 2013-11-14 07:56:48]

Thanks for the great comments. In patch set 3, I fixed everything except the
fwrite bit. According to the fwrite man page, fwrite only writes shorter chunks
if there is an error (not to be confused with the low-level 'write', which can
be indeed interrupted by a signal). Also, according to the man page, fwrite's
return type is size_t (unlike 'write', which is indeed ssize_t).

On 2013/11/13 23:40:51, bnoordhuis wrote:
> Left some comments.  I really like this patch.  Tested it with node.js master
> and it works great (as long as V8 can write to /tmp :-))
> 
> https://codereview.chromium.org/70013002/diff/40001/src/log.cc
> File src/log.cc (right):
> 
> https://codereview.chromium.org/70013002/diff/40001/src/log.cc#newcode289
> src/log.cc:289: perf_output_handle_ = OS::FOpen(perf_dump_name.start(),
> OS::LogFileOpenMode);
> This should check for NULL, shouldn't it?  Calling setvbuf() or fclose() on a
> NULL stream will segfault.
> 
> https://codereview.chromium.org/70013002/diff/40001/src/log.cc#newcode307
> src/log.cc:307: (uint64_t)code->instruction_start(),
> static_cast?  (Here and in a few other places.)
> 
> https://codereview.chromium.org/70013002/diff/40001/src/log.cc#newcode452
> src/log.cc:452: ASSERT(static_cast<size_t>(size) == rv);
> I don't think that's a safe assumption to make.  fwrite() can (and will)
> sometimes write fewer bytes than requested, e.g. when the write() system call
> got interrupted by a signal.
> 
> Minor nit: you probably meant `ssize_t` one line up.

[bnoordhuis, 2013-11-14 12:02:03]

On 2013/11/14 07:56:48, jarin wrote:
> Thanks for the great comments. In patch set 3, I fixed everything except the
> fwrite bit. According to the fwrite man page, fwrite only writes shorter
chunks
> if there is an error (not to be confused with the low-level 'write', which can
> be indeed interrupted by a signal). Also, according to the man page, fwrite's
> return type is size_t (unlike 'write', which is indeed ssize_t).

Oh, you're right about size_t.  Sorry about that.

As to fwrite() writing fewer bytes than requested, I can only speak for glibc
here but when the write() system call fails (including because of EINTR), glibc
sets the error flag and moves on.  It won't try to write again until the next
call to fwrite() or fclose().  That second function is especially problematic
because if the flush in fclose() fails, the data is gone forever and you end up
with a truncated file.

[Jarin, 2013-11-14 16:04:11]

On 2013/11/14 12:02:03, bnoordhuis wrote:
> ...
>
> As to fwrite() writing fewer bytes than requested, I can only speak for glibc
> here but when the write() system call fails (including because of EINTR),
glibc
> sets the error flag and moves on.  It won't try to write again until the next
> call to fwrite() or fclose().  That second function is especially problematic
> because if the flush in fclose() fails, the data is gone forever and you end
up
> with a truncated file.

I understand what you are saying, and I appreciate that Linux deviates from
POSIX a bit here, but I would still prefer to leave the code as is here. Here
are my reasons:
- the code should work according to POSIX spec of fwrite,
- there does not seem to be an easy way to test the fix (short of writing a
version of write that sometimes writes fewer bytes, which seems to be an
overkill)
- the existing version of ll_prof was doing the same thing. Yes, I admit I just
copy-and-pasted from there.

Thanks.

[Sven Panne, 2013-11-15 07:24:32]

On 2013/11/14 16:04:11, jarin wrote:
> I understand what you are saying, and I appreciate that Linux deviates from
> POSIX a bit here, but I would still prefer to leave the code as is here. Here
> are my reasons:
> - the code should work according to POSIX spec of fwrite,
> - there does not seem to be an easy way to test the fix (short of writing a
> version of write that sometimes writes fewer bytes, which seems to be an
> overkill)
> - the existing version of ll_prof was doing the same thing. Yes, I admit I
just
> copy-and-pasted from there.

Another option might be using write/_write directly.

[danno, 2013-11-21 20:16:09]

Given that the write handling is no worse than what existed before for ll_prof,
I'm giving this a lgtm in its current form.

[Jarin, 2013-11-25 06:44:30]

Committed patchset #4 manually as r18034 (presubmit successful).

[Yang, 2013-11-25 08:14:47]

On 2013/11/25 06:44:30, jarin wrote:
> Committed patchset #4 manually as r18034 (presubmit successful).

Up till now we use a wrapper script (tools/run-llprof.sh) to run perf. I wonder
whether you can simply update it. What's the difference between "-e cycles" and
"-g"? Also, the script increases the kernel limit on sampling rate so that we
don't have missing ticks. Is this still necessary?

[bnoordhuis, 2013-11-25 10:55:34]

Not the author but maybe I can comment.

On 2013/11/25 08:14:47, Yang wrote:
> Up till now we use a wrapper script (tools/run-llprof.sh) to run perf. I
wonder
> whether you can simply update it. What's the difference between "-e cycles"
and
> "-g"? Also, the script increases the kernel limit on sampling rate so that we
> don't have missing ticks. Is this still necessary?

-e cycles collects CPU cycles, -g call graphs (in other words: one collects
events, the other metadata.)

Upping the sampling rate with -c is a good idea; the default is 4k and that's
arguably a little on the low side.

I don't know if the suggestion to increase kernel.perf_event_max_sample_rate is
all that valuable.  It defaults to 100k, which means you can record one sample
every 10 us.  You'd increase that when sampling at a rate of > 100k samples/sec
but the script samples at 25k samples/sec IIRC and most systems are probably not
fast enough to keep up anyway.

[Jarin, 2013-11-25 12:00:22]

On 2013/11/25 08:14:47, Yang wrote:
> Up till now we use a wrapper script (tools/run-llprof.sh) to run perf. I
wonder
> whether you can simply update it. What's the difference between "-e cycles"
and
> "-g"? Also, the script increases the kernel limit on sampling rate so that we
> don't have missing ticks. Is this still necessary?

We are still keeping the existing ll_prof support as is for a while, at least
until the JIT support for perf-annotate makes it to the mainline Linux. (As for
the questions - Ben has answered them better than I could.)