pprof: fix /pprof/contention to work with the go version of pprof The old perl version of pprof that ships with gperftools is no longer maintained. It's been replaced by github.com/google/pprof which is written in go.
The go version is slightly pickier about the output than the old perl version. This patch updates a few things so that the new version works with the /pprof/contention profile: - the expected first line format is slightly different - hex addresses must be prefixed with '0x', no tab characters expected - memory maps needs a section header ahead of it - cycles/second needs to be formatted as an integer, not float I verified that with this patch I was able to run the following: pprof -seconds=1 http://localhost:8050/pprof/contention ... and got a reasonable looking profile when running under load. It also appears that the old perl pprof is still forgiving enough to handle this new format. Change-Id: Ie25b2332688575c57be10b437566adb3f0c156e3 Reviewed-on: http://gerrit.cloudera.org:8080/9741 Tested-by: Kudu Jenkins Reviewed-by: Alexey Serbin <aser...@cloudera.com> Project: http://git-wip-us.apache.org/repos/asf/kudu/repo Commit: http://git-wip-us.apache.org/repos/asf/kudu/commit/600723e0 Tree: http://git-wip-us.apache.org/repos/asf/kudu/tree/600723e0 Diff: http://git-wip-us.apache.org/repos/asf/kudu/diff/600723e0 Branch: refs/heads/master Commit: 600723e0e954a1b199e6a0bf1dfd63fe7289a6a8 Parents: ffcadd5 Author: Todd Lipcon <t...@apache.org> Authored: Wed Mar 21 12:01:36 2018 -0700 Committer: Todd Lipcon <t...@apache.org> Committed: Thu Mar 22 18:51:47 2018 +0000 ---------------------------------------------------------------------- src/kudu/server/pprof_path_handlers.cc | 12 +++++++----- src/kudu/util/debug-util.cc | 14 ++++++++++++-- src/kudu/util/debug-util.h | 6 +++++- src/kudu/util/spinlock_profiling-test.cc | 2 +- src/kudu/util/spinlock_profiling.cc | 5 +++-- 5 files changed, 28 insertions(+), 11 deletions(-) ---------------------------------------------------------------------- http://git-wip-us.apache.org/repos/asf/kudu/blob/600723e0/src/kudu/server/pprof_path_handlers.cc ---------------------------------------------------------------------- diff --git a/src/kudu/server/pprof_path_handlers.cc b/src/kudu/server/pprof_path_handlers.cc index d371d52..634c196 100644 --- a/src/kudu/server/pprof_path_handlers.cc +++ b/src/kudu/server/pprof_path_handlers.cc @@ -171,10 +171,6 @@ static void PprofContentionHandler(const Webserver::WebRequest& req, int32_t seconds = ParseLeadingInt32Value(secs_str.c_str(), kPprofDefaultSampleSecs); int64_t discarded_samples = 0; - *output << "--- contention" << endl; - *output << "sampling period = 1" << endl; - *output << "cycles/second = " << base::CyclesPerSecond() << endl; - MonoTime end = MonoTime::Now() + MonoDelta::FromSeconds(seconds); StartSynchronizationProfiling(); while (MonoTime::Now() < end) { @@ -182,16 +178,22 @@ static void PprofContentionHandler(const Webserver::WebRequest& req, FlushSynchronizationProfile(output, &discarded_samples); } StopSynchronizationProfiling(); - FlushSynchronizationProfile(output, &discarded_samples); + ostringstream profile; + FlushSynchronizationProfile(&profile, &discarded_samples); + *output << "--- contention:" << endl; + *output << "sampling period = 1" << endl; + *output << "cycles/second = " << static_cast<int64_t>(base::CyclesPerSecond()) << endl; // pprof itself ignores this value, but we can at least look at it in the textual // output. *output << "discarded samples = " << discarded_samples << std::endl; + *output << profile.str(); #if defined(__linux__) // procfs only exists on Linux. faststring maps; ReadFileToString(Env::Default(), "/proc/self/maps", &maps); + *output << "--- Memory map: ---" << endl; *output << maps.ToString(); #endif // defined(__linux__) } http://git-wip-us.apache.org/repos/asf/kudu/blob/600723e0/src/kudu/util/debug-util.cc ---------------------------------------------------------------------- diff --git a/src/kudu/util/debug-util.cc b/src/kudu/util/debug-util.cc index c66b257..07703ea 100644 --- a/src/kudu/util/debug-util.cc +++ b/src/kudu/util/debug-util.cc @@ -632,6 +632,10 @@ void StackTrace::StringifyToHex(char* buf, size_t size, int flags) const { if (i != 0) { *dst++ = ' '; } + if (flags & HEX_0X_PREFIX) { + *dst++ = '0'; + *dst++ = 'x'; + } // See note in Symbolize() below about why we subtract 1 from each address here. uintptr_t addr = reinterpret_cast<uintptr_t>(frames_[i]); if (addr > 0 && !(flags & NO_FIX_CALLER_ADDRESSES)) { @@ -646,8 +650,14 @@ void StackTrace::StringifyToHex(char* buf, size_t size, int flags) const { string StackTrace::ToHexString(int flags) const { // Each frame requires kHexEntryLength, plus a space // We also need one more byte at the end for '\0' - char buf[kMaxFrames * (kHexEntryLength + 1) + 1]; - StringifyToHex(buf, arraysize(buf), flags); + int len_per_frame = kHexEntryLength; + len_per_frame++; // For the separating space. + if (flags & HEX_0X_PREFIX) { + len_per_frame += 2; + } + int buf_len = kMaxFrames * len_per_frame + 1; + char buf[buf_len]; + StringifyToHex(buf, buf_len, flags); return string(buf); } http://git-wip-us.apache.org/repos/asf/kudu/blob/600723e0/src/kudu/util/debug-util.h ---------------------------------------------------------------------- diff --git a/src/kudu/util/debug-util.h b/src/kudu/util/debug-util.h index 193788e..44fccc3 100644 --- a/src/kudu/util/debug-util.h +++ b/src/kudu/util/debug-util.h @@ -159,7 +159,11 @@ class StackTrace { // Do not fix up the addresses on the stack to try to point to the 'call' // instructions instead of the return address. This is necessary when dumping // addresses to be interpreted by 'pprof', which does this fix-up itself. - NO_FIX_CALLER_ADDRESSES = 1 + NO_FIX_CALLER_ADDRESSES = 1, + + // Prefix each hex address with '0x'. This is required by the go version + // of pprof when parsing stack traces. + HEX_0X_PREFIX = 1 << 1, }; // Stringify the trace into the given buffer. http://git-wip-us.apache.org/repos/asf/kudu/blob/600723e0/src/kudu/util/spinlock_profiling-test.cc ---------------------------------------------------------------------- diff --git a/src/kudu/util/spinlock_profiling-test.cc b/src/kudu/util/spinlock_profiling-test.cc index 28089df..d0ef2b4 100644 --- a/src/kudu/util/spinlock_profiling-test.cc +++ b/src/kudu/util/spinlock_profiling-test.cc @@ -74,7 +74,7 @@ TEST_F(SpinLockProfilingTest, TestStackCollection) { int64_t dropped = 0; FlushSynchronizationProfile(&str, &dropped); std::string s = str.str(); - ASSERT_STR_CONTAINS(s, "12345\t1 @ "); + ASSERT_STR_CONTAINS(s, "12345 1 @ "); ASSERT_EQ(0, dropped); } http://git-wip-us.apache.org/repos/asf/kudu/blob/600723e0/src/kudu/util/spinlock_profiling.cc ---------------------------------------------------------------------- diff --git a/src/kudu/util/spinlock_profiling.cc b/src/kudu/util/spinlock_profiling.cc index 5660760..e7f93b0 100644 --- a/src/kudu/util/spinlock_profiling.cc +++ b/src/kudu/util/spinlock_profiling.cc @@ -182,8 +182,9 @@ void ContentionStacks::Flush(std::ostringstream* out, int64_t* dropped) { int64_t cycles; int64_t count; while (g_contention_stacks->CollectSample(&iterator, &t, &count, &cycles)) { - *out << cycles << "\t" << count - << " @ " << t.ToHexString(StackTrace::NO_FIX_CALLER_ADDRESSES) + *out << cycles << " " << count + << " @ " << t.ToHexString(StackTrace::NO_FIX_CALLER_ADDRESSES | + StackTrace::HEX_0X_PREFIX) << std::endl; }
