From c3b3622158009ea9db85607a4901d05c63108875 Mon Sep 17 00:00:00 2001 From: David Reiss Date: Wed, 6 Oct 2010 17:10:10 +0000 Subject: [PATCH] THRIFT-922. cpp: Add profiling code to help conversion to C++ templates Add some profiling code to track when potentially unnecessary virtual calls are made in the thrift C++ serialization and deserialization code. This can be used to help service implementors determine which places in their code should be updated to use an appropriate thrift template class. git-svn-id: https://svn.apache.org/repos/asf/incubator/thrift/trunk@1005140 13f79535-47bb-0310-9956-ffa450edef68 --- compiler/cpp/src/generate/t_cpp_generator.cc | 16 +- contrib/parse_profiling.py | 310 +++++++++++++ lib/cpp/src/TLogging.h | 42 +- lib/cpp/src/Thrift.h | 10 + lib/cpp/src/VirtualProfiling.cpp | 455 +++++++++++++++++++ 5 files changed, 815 insertions(+), 18 deletions(-) create mode 100755 contrib/parse_profiling.py create mode 100644 lib/cpp/src/VirtualProfiling.cpp diff --git a/compiler/cpp/src/generate/t_cpp_generator.cc b/compiler/cpp/src/generate/t_cpp_generator.cc index a0e11f83..f4b0316f 100644 --- a/compiler/cpp/src/generate/t_cpp_generator.cc +++ b/compiler/cpp/src/generate/t_cpp_generator.cc @@ -2768,7 +2768,9 @@ void t_cpp_generator::generate_process_function(t_service* tservice, indent() << "if (_iprot && _oprot) {" << endl << indent() << " return process_" << tfunction->get_name() << "(seqid, _iprot, _oprot, callContext);" << endl << - indent() << "}" << endl << endl; + indent() << "}" << endl << + indent() << "T_GENERIC_PROTOCOL(this, iprot, _iprot);" << endl << + indent() << "T_GENERIC_PROTOCOL(this, oprot, _oprot);" << endl << endl; } string argsname = tservice->get_name() + "_" + tfunction->get_name() + "_args"; @@ -2934,7 +2936,9 @@ void t_cpp_generator::generate_process_function(t_service* tservice, indent() << "if (_iprot && _oprot) {" << endl << indent() << " return process_" << tfunction->get_name() << "(cob, seqid, _iprot, _oprot);" << endl << - indent() << "}" << endl << endl; + indent() << "}" << endl << + indent() << "T_GENERIC_PROTOCOL(this, iprot, _iprot);" << endl << + indent() << "T_GENERIC_PROTOCOL(this, oprot, _oprot);" << endl << endl; } out << @@ -3066,7 +3070,9 @@ void t_cpp_generator::generate_process_function(t_service* tservice, indent() << "if (_oprot) {" << endl << indent() << " return return_" << tfunction->get_name() << "(cob, seqid, _oprot, ctx" << ret_arg_name << ");" << endl << - indent() << "}" << endl << endl; + indent() << "}" << endl << + indent() << "T_GENERIC_PROTOCOL(this, oprot, _oprot);" << + endl << endl; } out << @@ -3124,7 +3130,9 @@ void t_cpp_generator::generate_process_function(t_service* tservice, indent() << "if (_oprot) {" << endl << indent() << " return throw_" << tfunction->get_name() << "(cob, seqid, _oprot, ctx, _throw);" << endl << - indent() << "}" << endl << endl; + indent() << "}" << endl << + indent() << " T_GENERIC_PROTOCOL(this, oprot, _oprot);" << + endl << endl; } out << diff --git a/contrib/parse_profiling.py b/contrib/parse_profiling.py new file mode 100755 index 00000000..52d22117 --- /dev/null +++ b/contrib/parse_profiling.py @@ -0,0 +1,310 @@ +#!/usr/bin/env python +# +# Licensed to the Apache Software Foundation (ASF) under one +# or more contributor license agreements. See the NOTICE file +# distributed with this work for additional information +# regarding copyright ownership. The ASF licenses this file +# to you under the Apache License, Version 2.0 (the +# "License"); you may not use this file except in compliance +# with the License. You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, +# software distributed under the License is distributed on an +# "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY +# KIND, either express or implied. See the License for the +# specific language governing permissions and limitations +# under the License. +# +""" +This script can be used to make the output from +apache::thrift::profile_print_info() more human-readable. + +It translates each executable file name and address into the corresponding +source file name, line number, and function name. By default, it also +demangles C++ symbol names. +""" + +import optparse +import os +import re +import subprocess +import sys + + +class AddressInfo(object): + """ + A class to store information about a particular address in an object file. + """ + def __init__(self, obj_file, address): + self.objectFile = obj_file + self.address = address + self.sourceFile = None + self.sourceLine = None + self.funtion = None + + +g_addrs_by_filename = {} +def get_address(filename, address): + """ + Retrieve an AddressInfo object for the specified object file and address. + + Keeps a global list of AddressInfo objects. Two calls to get_address() + with the same filename and address will always return the same AddressInfo + object. + """ + global g_addrs_by_filename + try: + by_address = g_addrs_by_filename[filename] + except KeyError: + by_address = {} + g_addrs_by_filename[filename] = by_address + + try: + addr_info = by_address[address] + except KeyError: + addr_info = AddressInfo(filename, address) + by_address[address] = addr_info + return addr_info + + +def translate_file_addresses(filename, addresses, options): + """ + Use addr2line to look up information for the specified addresses. + All of the addresses must belong to the same object file. + """ + # Do nothing if we can't find the file + if not os.path.isfile(filename): + return + + args = ['addr2line'] + if options.printFunctions: + args.append('-f') + args.extend(['-e', filename]) + + proc = subprocess.Popen(args, stdin=subprocess.PIPE, + stdout=subprocess.PIPE) + for address in addresses: + assert address.objectFile == filename + proc.stdin.write(address.address + '\n') + + if options.printFunctions: + function = proc.stdout.readline() + function = function.strip() + if not function: + raise Exception('unexpected EOF from addr2line') + address.function = function + + file_and_line = proc.stdout.readline() + file_and_line = file_and_line.strip() + if not file_and_line: + raise Exception('unexpected EOF from addr2line') + idx = file_and_line.rfind(':') + if idx < 0: + msg = 'expected file and line number from addr2line; got %r' % \ + (file_and_line,) + msg += '\nfile=%r, address=%r' % (filename, address.address) + raise Exception(msg) + + address.sourceFile = file_and_line[:idx] + address.sourceLine = file_and_line[idx+1:] + + (remaining_out, cmd_err) = proc.communicate() + retcode = proc.wait() + if retcode != 0: + raise subprocess.CalledProcessError(retcode, args) + + +def lookup_addresses(options): + """ + Look up source file information for all of the addresses currently stored + in the global list of AddressInfo objects. + """ + global g_addrs_by_filename + for (file, addresses) in g_addrs_by_filename.items(): + translate_file_addresses(file, addresses.values(), options) + + +class Entry(object): + """ + An entry in the thrift profile output. + Contains a header line, and a backtrace. + """ + def __init__(self, header): + self.header = header + self.bt = [] + + def addFrame(self, filename, address): + # If libc was able to determine the symbols names, the filename + # argument will be of the form (+) + # So, strip off anything after the last '(' + idx = filename.rfind('(') + if idx >= 0: + filename = filename[:idx] + + addr = get_address(filename, address) + self.bt.append(addr) + + def write(self, f, options): + f.write(self.header) + f.write('\n') + n = 0 + for address in self.bt: + f.write(' #%-2d %s:%s\n' % (n, address.sourceFile, + address.sourceLine)) + n += 1 + if options.printFunctions: + if address.function: + f.write(' %s\n' % (address.function,)) + else: + f.write(' ??\n') + + +def process_file(in_file, out_file, options): + """ + Read thrift profile output from the specified input file, and print + prettier information on the output file. + """ + # + # A naive approach would be to read the input line by line, + # and each time we come to a filename and address, pass it to addr2line + # and print the resulting information. Unfortunately, addr2line can be + # quite slow, especially with large executables. + # + # This approach is much faster. We read in all of the input, storing + # the addresses in each file that need to be resolved. We then call + # addr2line just once for each file. This is much faster than calling + # addr2line once per address. + # + + virt_call_regex = re.compile(r'^\s*T_VIRTUAL_CALL: (\d+) calls on (.*):$') + gen_prot_regex = re.compile( + r'^\s*T_GENERIC_PROTOCOL: (\d+) calls to (.*) with a (.*):$') + bt_regex = re.compile(r'^\s*#(\d+)\s*(.*) \[(0x[0-9A-Za-z]+)\]$') + + # Parse all of the input, and store it as Entry objects + entries = [] + current_entry = None + while True: + line = in_file.readline() + if not line: + break + + if line == '\n' or line.startswith('Thrift virtual call info:'): + continue + + virt_call_match = virt_call_regex.match(line) + if virt_call_match: + num_calls = int(virt_call_match.group(1)) + type_name = virt_call_match.group(2) + if options.cxxfilt: + # Type names reported by typeid() are internal names. + # By default, c++filt doesn't demangle internal type names. + # (Some versions of c++filt have a "-t" option to enable this. + # Other versions don't have this argument, but demangle type + # names passed as an argument, but not on stdin.) + # + # If the output is being filtered through c++filt, prepend + # "_Z" to the type name to make it look like an external name. + type_name = '_Z' + type_name + header = 'T_VIRTUAL_CALL: %d calls on "%s"' % \ + (num_calls, type_name) + if current_entry is not None: + entries.append(current_entry) + current_entry = Entry(header) + continue + + gen_prot_match = gen_prot_regex.match(line) + if gen_prot_match: + num_calls = int(gen_prot_match.group(1)) + type_name1 = gen_prot_match.group(2) + type_name2 = gen_prot_match.group(3) + if options.cxxfilt: + type_name1 = '_Z' + type_name1 + type_name2 = '_Z' + type_name2 + header = 'T_GENERIC_PROTOCOL: %d calls to "%s" with a "%s"' % \ + (num_calls, type_name1, type_name2) + if current_entry is not None: + entries.append(current_entry) + current_entry = Entry(header) + continue + + bt_match = bt_regex.match(line) + if bt_match: + if current_entry is None: + raise Exception('found backtrace frame before entry header') + frame_num = int(bt_match.group(1)) + filename = bt_match.group(2) + address = bt_match.group(3) + current_entry.addFrame(filename, address) + continue + + raise Exception('unexpected line in input: %r' % (line,)) + + # Add the last entry we were processing to the list + if current_entry is not None: + entries.append(current_entry) + current_entry = None + + # Look up all of the addresses + lookup_addresses(options) + + # Print out the entries, now that the information has been translated + for entry in entries: + entry.write(out_file, options) + out_file.write('\n') + + +def start_cppfilt(): + (read_pipe, write_pipe) = os.pipe() + + # Fork. Run c++filt in the parent process, + # and then continue normal processing in the child. + pid = os.fork() + if pid == 0: + # child + os.dup2(write_pipe, sys.stdout.fileno()) + os.close(read_pipe) + os.close(write_pipe) + return + else: + # parent + os.dup2(read_pipe, sys.stdin.fileno()) + os.close(read_pipe) + os.close(write_pipe) + + cmd = ['c++filt'] + os.execvp(cmd[0], cmd) + + +def main(argv): + parser = optparse.OptionParser(usage='%prog [options] []') + parser.add_option('--no-functions', help='Don\'t print function names', + dest='printFunctions', action='store_false', + default=True) + parser.add_option('--no-demangle', + help='Don\'t demangle C++ symbol names', + dest='cxxfilt', action='store_false', + default=True) + + (options, args) = parser.parse_args(argv[1:]) + num_args = len(args) + if num_args == 0: + in_file = sys.stdin + elif num_args == 1: + in_file = open(argv[1], 'r') + else: + parser.print_usage(sys.stderr) + print >> sys.stderr, 'trailing arguments: %s' % (' '.join(args[1:],)) + return 1 + + if options.cxxfilt: + start_cppfilt() + + process_file(in_file, sys.stdout, options) + + +if __name__ == '__main__': + rc = main(sys.argv) + sys.exit(rc) diff --git a/lib/cpp/src/TLogging.h b/lib/cpp/src/TLogging.h index 54cccbec..2c23f0aa 100644 --- a/lib/cpp/src/TLogging.h +++ b/lib/cpp/src/TLogging.h @@ -162,24 +162,38 @@ /** - * T_GLOBAL_DEBUG_VIRTUAL = 0: normal operation, - * virtual call debug messages disabled - * T_GLOBAL_DEBUG_VIRTUAL = 1: log a debug messages whenever an - * avoidable virtual call is made + * T_GLOBAL_DEBUG_VIRTUAL = 0 or unset: normal operation, + * virtual call debug messages disabled + * T_GLOBAL_DEBUG_VIRTUAL = 1: log a debug messages whenever an + * avoidable virtual call is made + * T_GLOBAL_DEBUG_VIRTUAL = 2: record detailed info that can be + * printed by calling + * apache::thrift::profile_print_info() */ -#define T_GLOBAL_DEBUG_VIRTUAL 0 - -/** - * Log a message indicating that a virtual function call is being made. - * - * This should be disabled during normal use. It is intended to be used - * only to help debug serialization performance. - */ -#if T_GLOBAL_DEBUG_VIRTUAL > 0 - #define T_VIRTUAL_CALL() \ +#if T_GLOBAL_DEBUG_VIRTUAL > 1 + #define T_VIRTUAL_CALL() \ + ::apache::thrift::profile_virtual_call(typeid(*this)) + #define T_GENERIC_PROTOCOL(template_class, generic_prot, specific_prot) \ + do { \ + if (!(specific_prot)) { \ + ::apache::thrift::profile_generic_protocol( \ + typeid(*template_class), typeid(*generic_prot)); \ + } \ + } while (0) +#elif T_GLOBAL_DEBUG_VIRTUAL == 1 + #define T_VIRTUAL_CALL() \ fprintf(stderr,"[%s,%d] virtual call\n", __FILE__, __LINE__) + #define T_GENERIC_PROTOCOL(template_class, generic_prot, specific_prot) \ + do { \ + if (!(specific_prot)) { \ + fprintf(stderr, \ + "[%s,%d] failed to cast to specific protocol type\n", \ + __FILE__, __LINE__); \ + } \ + } while (0) #else #define T_VIRTUAL_CALL() + #define T_GENERIC_PROTOCOL(template_class, generic_prot, specific_prot) #endif #endif // #ifndef _THRIFT_TLOGGING_H_ diff --git a/lib/cpp/src/Thrift.h b/lib/cpp/src/Thrift.h index cb7d55a0..a8bf2a82 100644 --- a/lib/cpp/src/Thrift.h +++ b/lib/cpp/src/Thrift.h @@ -36,6 +36,7 @@ #include #include #include +#include #include "TLogging.h" @@ -134,6 +135,15 @@ TDelayedException* TDelayedException::delayException(const E& e) { return new TExceptionWrapper(e); } +#if T_GLOBAL_DEBUG_VIRTUAL > 1 +void profile_virtual_call(const std::type_info& info); +void profile_generic_protocol(const std::type_info& template_type, + const std::type_info& prot_type); +void profile_print_info(FILE *f); +void profile_print_info(); +void profile_write_pprof(FILE* gen_calls_f, FILE* virtual_calls_f); +#endif + }} // apache::thrift #endif // #ifndef _THRIFT_THRIFT_H_ diff --git a/lib/cpp/src/VirtualProfiling.cpp b/lib/cpp/src/VirtualProfiling.cpp new file mode 100644 index 00000000..0b023af2 --- /dev/null +++ b/lib/cpp/src/VirtualProfiling.cpp @@ -0,0 +1,455 @@ +/* + * Licensed to the Apache Software Foundation (ASF) under one + * or more contributor license agreements. See the NOTICE file + * distributed with this work for additional information + * regarding copyright ownership. The ASF licenses this file + * to you under the Apache License, Version 2.0 (the + * "License"); you may not use this file except in compliance + * with the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, + * software distributed under the License is distributed on an + * "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY + * KIND, either express or implied. See the License for the + * specific language governing permissions and limitations + * under the License. + */ + +#include + +// Do nothing if virtual call profiling is not enabled +#if T_GLOBAL_DEBUG_VIRTUAL > 1 + +// TODO: This code only works with g++ (since we rely on the fact +// that all std::type_info instances referring to a particular type +// always return the exact same pointer value from name().) +#ifndef __GNUG__ +#error "Thrift virtual function profiling currently only works with gcc" +#endif // !__GNUG__ + +// TODO: We also require glibc for the backtrace() and backtrace_symbols() +// functions. +#ifndef __GLIBC__ +#error "Thrift virtual function profiling currently requires glibc" +#endif // !__GLIBC__ + + +#include + +#include +#include +#include + +namespace apache { namespace thrift { + +using ::apache::thrift::concurrency::Mutex; +using ::apache::thrift::concurrency::Guard; + +static const unsigned int MAX_STACK_DEPTH = 15; + +/** + * A stack trace + */ +class Backtrace { + public: + Backtrace(int skip = 0); + Backtrace(Backtrace const &bt); + + void operator=(Backtrace const &bt) { + numCallers_ = bt.numCallers_; + if (numCallers_ >= 0) { + memcpy(callers_, bt.callers_, numCallers_ * sizeof(void*)); + } + } + + bool operator==(Backtrace const &bt) const { + return (cmp(bt) == 0); + } + + size_t hash() const { + intptr_t ret = 0; + for (int n = 0; n < numCallers_; ++n) { + ret ^= reinterpret_cast(callers_[n]); + } + return static_cast(ret); + } + + int cmp(Backtrace const& bt) const { + int depth_diff = (numCallers_ - bt.numCallers_); + if (depth_diff != 0) { + return depth_diff; + } + + for (int n = 0; n < numCallers_; ++n) { + int diff = reinterpret_cast(callers_[n]) - + reinterpret_cast(bt.callers_[n]); + if (diff != 0) { + return diff; + } + } + + return 0; + } + + void print(FILE *f, int indent=0, int start=0) const { + char **strings = backtrace_symbols(callers_, numCallers_); + if (strings) { + start += skip_; + if (start < 0) { + start = 0; + } + for (int n = start; n < numCallers_; ++n) { + fprintf(f, "%*s#%-2d %s\n", indent, "", n, strings[n]); + } + free(strings); + } else { + fprintf(f, "%*s\n", indent, ""); + } + } + + int getDepth() const { + return numCallers_ - skip_; + } + + void *getFrame(int index) const { + int adjusted_index = index + skip_; + if (adjusted_index < 0 || adjusted_index >= numCallers_) { + return NULL; + } + return callers_[adjusted_index]; + } + + private: + void *callers_[MAX_STACK_DEPTH]; + int numCallers_; + int skip_; +}; + +// Define the constructors non-inline, so they consistently add a single +// frame to the stack trace, regardless of whether optimization is enabled +Backtrace::Backtrace(int skip) + : skip_(skip + 1) // ignore the constructor itself +{ + numCallers_ = backtrace(callers_, MAX_STACK_DEPTH); + if (skip_ > numCallers_) { + skip_ = numCallers_; + } +} + +Backtrace::Backtrace(Backtrace const &bt) + : numCallers_(bt.numCallers_) + , skip_(bt.skip_) { + if (numCallers_ >= 0) { + memcpy(callers_, bt.callers_, numCallers_ * sizeof(void*)); + } +} + +/** + * A backtrace, plus one or two type names + */ +class Key { + public: + class Hash { + public: + size_t operator()(Key const& k) const { + return k.hash(); + } + }; + + Key(const Backtrace* bt, const std::type_info& type_info) + : backtrace_(bt) + , typeName1_(type_info.name()) + , typeName2_(NULL) { + } + + Key(const Backtrace* bt, const std::type_info& type_info1, + const std::type_info& type_info2) + : backtrace_(bt) + , typeName1_(type_info1.name()) + , typeName2_(type_info2.name()) { + } + + Key(const Key& k) + : backtrace_(k.backtrace_) + , typeName1_(k.typeName1_) + , typeName2_(k.typeName2_) { + } + + void operator=(const Key& k) { + backtrace_ = k.backtrace_; + typeName1_ = k.typeName1_; + typeName2_ = k.typeName2_; + } + + const Backtrace* getBacktrace() const { + return backtrace_; + } + + const char* getTypeName() const { + return typeName1_; + } + + const char* getTypeName2() const { + return typeName2_; + } + + void makePersistent() { + // Copy the Backtrace object + backtrace_ = new Backtrace(*backtrace_); + + // NOTE: We don't copy the type name. + // The GNU libstdc++ implementation of type_info::name() returns a value + // that will be valid for the lifetime of the program. (Although the C++ + // standard doesn't guarantee this will be true on all implementations.) + } + + /** + * Clean up memory allocated by makePersistent() + * + * Should only be invoked if makePersistent() has previously been called. + * The Key should no longer be used after cleanup() is called. + */ + void cleanup() { + delete backtrace_; + backtrace_ = NULL; + } + + int cmp(const Key& k) const { + int ret = backtrace_->cmp(*k.backtrace_); + if (ret != 0) { + return ret; + } + + // NOTE: We compare just the name pointers. + // With GNU libstdc++, every type_info object for the same type points to + // exactly the same name string. (Although this isn't guaranteed by the + // C++ standard.) + ret = k.typeName1_ - typeName1_; + if (ret != 0) { + return ret; + } + return k.typeName2_ - typeName2_; + } + + bool operator==(const Key& k) const { + return cmp(k) == 0; + } + + size_t hash() const { + // NOTE: As above, we just use the name pointer value. + // Works with GNU libstdc++, but not guaranteed to be correct on all + // implementations. + return backtrace_->hash() ^ + reinterpret_cast(typeName1_) ^ + reinterpret_cast(typeName2_); + } + + private: + const Backtrace* backtrace_; + const char* typeName1_; + const char* typeName2_; +}; + +/** + * A functor that determines which of two BacktraceMap entries + * has a higher count. + */ +class CountGreater { + public: + bool operator()(std::pair bt1, + std::pair bt2) const { + return bt1.second > bt2.second; + } +}; + +typedef __gnu_cxx::hash_map BacktraceMap; + +/** + * A map describing how many times T_VIRTUAL_CALL() has been invoked. + */ +BacktraceMap virtual_calls; +Mutex virtual_calls_mutex; + +/** + * A map describing how many times T_GENERIC_PROTOCOL() has been invoked. + */ +BacktraceMap generic_calls; +Mutex generic_calls_mutex; + + +void _record_backtrace(BacktraceMap* map, const Mutex& mutex, Key *k) { + Guard guard(mutex); + + BacktraceMap::iterator it = map->find(*k); + if (it == map->end()) { + k->makePersistent(); + map->insert(std::make_pair(*k, 1)); + } else { + // increment the count + // NOTE: we could assert if it->second is 0 afterwards, since that would + // mean we've wrapped. + ++(it->second); + } +} + +/** + * Record an unnecessary virtual function call. + * + * This method is invoked by the T_VIRTUAL_CALL() macro. + */ +void profile_virtual_call(const std::type_info& type) { + int const skip = 1; // ignore this frame + Backtrace bt(skip); + Key k(&bt, type); + _record_backtrace(&virtual_calls, virtual_calls_mutex, &k); +} + +/** + * Record a call to a template processor with a protocol that is not the one + * specified in the template parameter. + * + * This method is invoked by the T_GENERIC_PROTOCOL() macro. + */ +void profile_generic_protocol(const std::type_info& template_type, + const std::type_info& prot_type) { + int const skip = 1; // ignore this frame + Backtrace bt(skip); + Key k(&bt, template_type, prot_type); + _record_backtrace(&generic_calls, generic_calls_mutex, &k); +} + +/** + * Print the recorded profiling information to the specified file. + */ +void profile_print_info(FILE* f) { + typedef std::vector< std::pair > BacktraceVector; + + CountGreater is_greater; + + // Grab both locks for the duration of the print operation, + // to ensure the output is a consistent snapshot of a single point in time + Guard generic_calls_guard(generic_calls_mutex); + Guard virtual_calls_guard(virtual_calls_mutex); + + // print the info from generic_calls, sorted by frequency + // + // We print the generic_calls info ahead of virtual_calls, since it is more + // useful in some cases. All T_GENERIC_PROTOCOL calls can be eliminated + // from most programs. Not all T_VIRTUAL_CALLs will be eliminated by + // converting to templates. + BacktraceVector gp_sorted(generic_calls.begin(), generic_calls.end()); + std::sort(gp_sorted.begin(), gp_sorted.end(), is_greater); + + for (BacktraceVector::const_iterator it = gp_sorted.begin(); + it != gp_sorted.end(); + ++it) { + Key const &key = it->first; + size_t const count = it->second; + fprintf(f, "T_GENERIC_PROTOCOL: %zu calls to %s with a %s:\n", + count, key.getTypeName(), key.getTypeName2()); + key.getBacktrace()->print(f, 2); + fprintf(f, "\n"); + } + + // print the info from virtual_calls, sorted by frequency + BacktraceVector vc_sorted(virtual_calls.begin(), virtual_calls.end()); + std::sort(vc_sorted.begin(), vc_sorted.end(), is_greater); + + for (BacktraceVector::const_iterator it = vc_sorted.begin(); + it != vc_sorted.end(); + ++it) { + Key const &key = it->first; + size_t const count = it->second; + fprintf(f, "T_VIRTUAL_CALL: %zu calls on %s:\n", count, key.getTypeName()); + key.getBacktrace()->print(f, 2); + fprintf(f, "\n"); + } +} + +/** + * Print the recorded profiling information to stdout. + */ +void profile_print_info() { + profile_print_info(stdout); +} + +/** + * Write a BacktraceMap as Google CPU profiler binary data. + */ +static void profile_write_pprof_file(FILE* f, BacktraceMap const& map) { + // Write the header + uintptr_t header[5] = { 0, 3, 0, 0, 0 }; + fwrite(&header, sizeof(header), 1, f); + + // Write the profile records + for (BacktraceMap::const_iterator it = map.begin(); it != map.end(); ++it) { + uintptr_t count = it->second; + fwrite(&count, sizeof(count), 1, f); + + Backtrace const* bt = it->first.getBacktrace(); + uintptr_t num_pcs = bt->getDepth(); + fwrite(&num_pcs, sizeof(num_pcs), 1, f); + + for (uintptr_t n = 0; n < num_pcs; ++n) { + void* pc = bt->getFrame(n); + fwrite(&pc, sizeof(pc), 1, f); + } + } + + // Write the trailer + uintptr_t trailer[3] = { 0, 1, 0 }; + fwrite(&trailer, sizeof(trailer), 1, f); + + // Write /proc/self/maps + // TODO(simpkins): This only works on linux + FILE *proc_maps = fopen("/proc/self/maps", "r"); + if (proc_maps) { + uint8_t buf[4096]; + while (true) { + size_t bytes_read = fread(buf, 1, sizeof(buf), proc_maps); + if (bytes_read == 0) { + break; + } + fwrite(buf, 1, bytes_read, f); + } + fclose(proc_maps); + } +} + +/** + * Write the recorded profiling information as pprof files. + * + * This writes the information using the Google CPU profiler binary data + * format, so it can be analyzed with pprof. Note that information about the + * protocol/transport data types cannot be stored in this file format. + * + * See http://code.google.com/p/google-perftools/ for more details. + * + * @param gen_calls_f The information about calls to + * profile_generic_protocol() will be written to this + * file. + * @param virtual_calls_f The information about calls to + * profile_virtual_call() will be written to this file. + */ +void profile_write_pprof(FILE* gen_calls_f, FILE* virtual_calls_f) { + typedef std::vector< std::pair > BacktraceVector; + + CountGreater is_greater; + + // Grab both locks for the duration of the print operation, + // to ensure the output is a consistent snapshot of a single point in time + Guard generic_calls_guard(generic_calls_mutex); + Guard virtual_calls_guard(virtual_calls_mutex); + + // write the info from generic_calls + profile_write_pprof_file(gen_calls_f, generic_calls); + + // write the info from virtual_calls + profile_write_pprof_file(virtual_calls_f, virtual_calls); +} + +}} // apache::thrift + +#endif // T_GLOBAL_PROFILE_VIRTUAL > 0 -- 2.17.1