Coverage for /Syzygy/grinder/grinders/profile_grinder.cc

CoverageLines executed / instrumented / missingexe / inst / missLanguageGroup
80.0%3434290.C++source

Line-by-line coverage:

   1    :  // Copyright 2012 Google Inc. All Rights Reserved.
   2    :  //
   3    :  // Licensed under the Apache License, Version 2.0 (the "License");
   4    :  // you may not use this file except in compliance with the License.
   5    :  // You may obtain a copy of the License at
   6    :  //
   7    :  //     http://www.apache.org/licenses/LICENSE-2.0
   8    :  //
   9    :  // Unless required by applicable law or agreed to in writing, software
  10    :  // distributed under the License is distributed on an "AS IS" BASIS,
  11    :  // WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
  12    :  // See the License for the specific language governing permissions and
  13    :  // limitations under the License.
  14    :  
  15    :  #include "syzygy/grinder/grinders/profile_grinder.h"
  16    :  
  17    :  #include "base/at_exit.h"
  18    :  #include "base/command_line.h"
  19    :  #include "base/strings/string_util.h"
  20    :  #include "base/strings/stringprintf.h"
  21    :  #include "base/strings/utf_string_conversions.h"
  22    :  #include "base/win/scoped_bstr.h"
  23    :  #include "syzygy/common/com_utils.h"
  24    :  #include "syzygy/pe/find.h"
  25    :  
  26    :  namespace grinder {
  27    :  namespace grinders {
  28    :  
  29    :  using base::win::ScopedBstr;
  30    :  using base::win::ScopedComPtr;
  31    :  using trace::parser::AbsoluteAddress64;
  32    :  using trace::parser::ParseEventHandler;
  33    :  using pe::ModuleInformation;
  34    :  
  35    :  namespace {
  36    :  
  37    :  // Compares module information without regard to base address.
  38    :  // Used to canonicalize module information, even across processes, or multiple
  39    :  // loads for the same module at different addresses in the same process.
  40    :  bool ModuleInformationKeyLess(const ModuleInformation& a,
  41  E :                                const ModuleInformation& b) {
  42  E :    if (a.module_size > b.module_size)
  43  E :      return false;
  44  E :    if (a.module_size < b.module_size)
  45  E :      return true;
  46    :  
  47  E :    if (a.module_checksum > b.module_checksum)
  48  i :      return false;
  49  E :    if (a.module_checksum < b.module_checksum)
  50  i :      return true;
  51    :  
  52  E :    if (a.module_time_date_stamp > b.module_time_date_stamp)
  53  i :      return false;
  54  E :    if (a.module_time_date_stamp < b.module_time_date_stamp)
  55  i :      return true;
  56    :  
  57  E :    return a.path < b.path;
  58  E :  }
  59    :  
  60    :  }  // namespace
  61    :  
  62    :  ProfileGrinder::CodeLocation::CodeLocation()
  63  E :      : process_id_(0), symbol_id_(0), symbol_offset_(0), is_symbol_(false) {
  64  E :  }
  65    :  
  66    :  void ProfileGrinder::CodeLocation::Set(
  67  E :      uint32 process_id, uint32 symbol_id, size_t symbol_offset) {
  68  E :    is_symbol_ = true;
  69  E :    process_id_ = process_id;
  70  E :    symbol_id_ = symbol_id;
  71  E :    symbol_offset_ = symbol_offset;
  72  E :  }
  73    :  
  74    :  void ProfileGrinder::CodeLocation::Set(
  75  E :      const pe::ModuleInformation* module, RVA rva) {
  76  E :    is_symbol_ = false;
  77  E :    module_ = module;
  78  E :    rva_ = rva;
  79  E :    symbol_offset_ = 0;
  80  E :  }
  81    :  
  82    :  std::string ProfileGrinder::CodeLocation::ToString() const {
  83    :    if (is_symbol()) {
  84    :      return base::StringPrintf("Symbol: %d, %d", process_id(), symbol_id());
  85    :    } else {
  86    :      return base::StringPrintf("Module/RVA: 0x%08X, 0x%08X", module(), rva());
  87    :    }
  88    :  }
  89    :  
  90  E :  bool ProfileGrinder::CodeLocation::operator<(const CodeLocation& o) const {
  91  E :    if (is_symbol_ < o.is_symbol_)
  92  E :      return true;
  93  E :    else if (is_symbol_ > o.is_symbol_)
  94  i :      return false;
  95    :  
  96  E :    DCHECK_EQ(o.is_symbol_, is_symbol_);
  97  E :    if (is_symbol_) {
  98  E :      if (process_id_ > o.process_id_)
  99  i :        return false;
 100  E :      if (process_id_ < o.process_id_)
 101  i :        return true;
 102    :  
 103  E :      if (symbol_id_ > o.symbol_id_)
 104  E :        return false;
 105  E :      if (symbol_id_ < o.symbol_id_)
 106  E :        return true;
 107    :  
 108  E :      return symbol_offset_ < o.symbol_offset_;
 109  i :    } else {
 110  E :      if (module_ > o.module_)
 111  E :        return false;
 112  E :      if (module_ < o.module_)
 113  E :        return true;
 114  E :      return rva_ < o.rva_;
 115    :    }
 116  E :  }
 117    :  
 118  E :  void ProfileGrinder::CodeLocation::operator=(const CodeLocation& o) {
 119  E :    is_symbol_ = o.is_symbol_;
 120  E :    symbol_offset_ = o.symbol_offset_;
 121  E :    if (is_symbol_) {
 122  E :      process_id_ = o.process_id_;
 123  E :      symbol_id_ = o.symbol_id_;
 124  E :    } else {
 125  E :      rva_ = o.rva_;
 126  E :      module_ = o.module_;
 127    :    }
 128  E :  }
 129    :  
 130    :  ProfileGrinder::PartData::PartData()
 131  E :      : process_id_(0), thread_id_(0) {
 132  E :  }
 133    :  
 134    :  ProfileGrinder::ProfileGrinder()
 135    :      : parser_(NULL),
 136    :        modules_(ModuleInformationKeyLess),
 137  E :        thread_parts_(true) {
 138  E :  }
 139    :  
 140  E :  ProfileGrinder::~ProfileGrinder() {
 141  E :  }
 142    :  
 143  E :  bool ProfileGrinder::ParseCommandLine(const base::CommandLine* command_line) {
 144  E :    thread_parts_ = command_line->HasSwitch("thread-parts");
 145  E :    return true;
 146  E :  }
 147    :  
 148  E :  void ProfileGrinder::SetParser(Parser* parser) {
 149  E :    DCHECK(parser != NULL);
 150  E :    parser_ = parser;
 151  E :  }
 152    :  
 153  E :  bool ProfileGrinder::Grind() {
 154  E :    if (!ResolveCallers()) {
 155  i :      LOG(ERROR) << "Error resolving callers.";
 156  i :      return false;
 157    :    }
 158  E :    return true;
 159  E :  }
 160    :  
 161    :  bool ProfileGrinder::GetSessionForModule(const ModuleInformation* module,
 162  E :                                           IDiaSession** session_out) {
 163  E :    DCHECK(module != NULL);
 164  E :    DCHECK(session_out != NULL);
 165  E :    DCHECK(*session_out == NULL);
 166    :  
 167    :    ModuleSessionMap::const_iterator it(
 168  E :        module_sessions_.find(module));
 169    :  
 170  E :    if (it == module_sessions_.end()) {
 171  E :      ScopedComPtr<IDiaDataSource> source;
 172  E :      HRESULT hr = source.CreateInstance(CLSID_DiaSource);
 173  E :      if (FAILED(hr)) {
 174  E :        LOG(ERROR) << "Failed to create DiaSource: "
 175    :                   << common::LogHr(hr) << ".";
 176  E :        return false;
 177    :      }
 178    :  
 179  E :      base::FilePath module_path;
 180    :      if (!pe::FindModuleBySignature(*module, &module_path) ||
 181  E :          module_path.empty()) {
 182  i :        LOG(ERROR) << "Unable to find module matching signature.";
 183  i :        return false;
 184    :      }
 185    :  
 186  E :      ScopedComPtr<IDiaSession> new_session;
 187    :      // We first try loading straight-up for the module. If the module is at
 188    :      // this path and the symsrv machinery is available, this will bring that
 189    :      // machinery to bear.
 190    :      // The downside is that if the module at this path does not match the
 191    :      // original module, we may load the wrong symbol information for the
 192    :      // module.
 193  E :      hr = source->loadDataForExe(module_path.value().c_str(), NULL, NULL);
 194  E :      if (SUCCEEDED(hr)) {
 195  E :          hr = source->openSession(new_session.Receive());
 196  E :          if (FAILED(hr))
 197  i :            LOG(ERROR) << "Failure in openSession: " << common::LogHr(hr) << ".";
 198  E :      } else {
 199  E :        DCHECK(FAILED(hr));
 200    :  
 201  E :        base::FilePath pdb_path;
 202    :        if (!pe::FindPdbForModule(module_path, &pdb_path) ||
 203  E :            pdb_path.empty()) {
 204  E :          LOG(ERROR) << "Unable to find PDB for module \""
 205    :                     << module_path.value() << "\".";
 206    :        }
 207    :  
 208  E :        hr = source->loadDataFromPdb(pdb_path.value().c_str());
 209  E :        if (SUCCEEDED(hr)) {
 210  i :          hr = source->openSession(new_session.Receive());
 211  i :          if (FAILED(hr))
 212  i :            LOG(ERROR) << "Failure in openSession: " << common::LogHr(hr) << ".";
 213  i :        } else {
 214  E :          LOG(WARNING) << "Failure in loadDataFromPdb('"
 215    :                       << module_path.value().c_str() << "'): "
 216    :                       << common::LogHr(hr) << ".";
 217    :        }
 218  E :      }
 219    :  
 220    :      DCHECK((SUCCEEDED(hr) && new_session.get() != NULL) ||
 221  E :             (FAILED(hr) && new_session.get() == NULL));
 222    :  
 223    :      // We store an entry to the cache irrespective of whether we succeeded
 224    :      // in opening a session above. This allows us to cache the failures, which
 225    :      // means we attempt to load each module only once, and consequently log
 226    :      // each failing module only once.
 227    :      it = module_sessions_.insert(
 228  E :          std::make_pair(module, new_session)).first;
 229  E :    }
 230  E :    DCHECK(it != module_sessions_.end());
 231    :  
 232  E :    if (it->second.get() == NULL) {
 233    :      // A negative session cache entry - we were previously unable to
 234    :      // load this module.
 235  E :      return false;
 236    :    }
 237    :  
 238  E :    *session_out = it->second.get();
 239  E :    (*session_out)->AddRef();
 240    :  
 241  E :    return true;
 242  E :  }
 243    :  
 244    :  ProfileGrinder::PartData* ProfileGrinder::FindOrCreatePart(DWORD process_id,
 245  E :                                                             DWORD thread_id) {
 246  E :    if (!thread_parts_) {
 247  E :      process_id = 0;
 248  E :      thread_id = 0;
 249    :    }
 250    :  
 251    :    // Lookup the part to aggregate to.
 252  E :    PartKey key(process_id, thread_id);
 253  E :    PartDataMap::iterator it = parts_.find(key);
 254  E :    if (it == parts_.end()) {
 255  E :      PartData part;
 256  E :      part.process_id_ = process_id;
 257  E :      part.thread_id_ = thread_id;
 258    :  
 259  E :      it = parts_.insert(std::make_pair(key, part)).first;
 260  E :    }
 261    :  
 262  E :    return &it->second;
 263  E :  }
 264    :  
 265    :  bool ProfileGrinder::GetFunctionSymbolByRVA(IDiaSession* session,
 266    :                                              RVA address,
 267  E :                                              IDiaSymbol** symbol) {
 268  E :    DCHECK(session != NULL);
 269  E :    DCHECK(symbol != NULL && *symbol == NULL);
 270    :  
 271  E :    ScopedComPtr<IDiaSymbol> function;
 272    :    HRESULT hr = session->findSymbolByRVA(address,
 273    :                                          SymTagFunction,
 274  E :                                          function.Receive());
 275  E :    if (FAILED(hr) || function.get() == NULL) {
 276    :      // No private function, let's try for a public symbol.
 277    :      hr = session->findSymbolByRVA(address,
 278    :                                    SymTagPublicSymbol,
 279  i :                                    function.Receive());
 280  i :      if (FAILED(hr))
 281  i :        return false;
 282    :    }
 283  E :    if (function.get() == NULL) {
 284  i :      LOG(ERROR) << "NULL function returned from findSymbolByRVA.";
 285  i :      return false;
 286    :    }
 287    :  
 288  E :    *symbol = function.Detach();
 289    :  
 290  E :    return true;
 291  E :  }
 292    :  
 293    :  bool ProfileGrinder::GetFunctionForCaller(const CallerLocation& caller,
 294    :                                            FunctionLocation* function,
 295  E :                                            size_t* line) {
 296  E :    DCHECK(function != NULL);
 297  E :    DCHECK(line != NULL);
 298    :  
 299  E :    if (caller.is_symbol()) {
 300    :      // The function symbol for a caller is simply the same symbol with a
 301    :      // zero offset.
 302  E :      function->Set(caller.process_id(), caller.symbol_id(), 0);
 303  E :      return true;
 304    :    }
 305    :  
 306  E :    DCHECK(!caller.is_symbol());
 307    :  
 308  E :    if (caller.module() == NULL) {
 309    :      // If the module is unknown, we fake a function per every K of memory.
 310    :      // Turns out that V8 generates some code outside the JS heap, and as of
 311    :      // June 2013, does not push symbols for the code.
 312  i :      function->Set(NULL, caller.rva() & ~1023);
 313  i :      *line = 0;
 314  i :      return true;
 315    :    }
 316    :  
 317  E :    ScopedComPtr<IDiaSession> session;
 318  E :    if (!GetSessionForModule(caller.module(), session.Receive()))
 319  E :      return false;
 320    :  
 321  E :    ScopedComPtr<IDiaSymbol> function_sym;
 322    :    if (!GetFunctionSymbolByRVA(session.get(),
 323    :                                caller.rva(),
 324  E :                                function_sym.Receive())) {
 325  i :      LOG(ERROR) << "No symbol info available for function in module '"
 326    :                 << caller.module()->path << "'";
 327    :    }
 328    :  
 329    :    // Get the RVA of the function.
 330  E :    DWORD rva = 0;
 331  E :    HRESULT hr = function_sym->get_relativeVirtualAddress(&rva);
 332  E :    if (FAILED(hr)) {
 333  i :      LOG(ERROR) << "Failure in get_relativeVirtualAddress: "
 334    :                 << common::LogHr(hr) << ".";
 335  i :      return false;
 336    :    }
 337    :  
 338    :    // Return the module/rva we found.
 339  E :    function->Set(caller.module(), rva);
 340    :  
 341  E :    ULONGLONG length = 0;
 342  E :    hr = function_sym->get_length(&length);
 343  E :    if (FAILED(hr)) {
 344  i :      LOG(ERROR) << "Failure in get_length: " << common::LogHr(hr) << ".";
 345  i :      return false;
 346    :    }
 347    :  
 348  E :    DWORD line_number = 0;
 349  E :    if (length != 0) {
 350  E :      ScopedComPtr<IDiaEnumLineNumbers> enum_lines;
 351    :  
 352  E :      hr = session->findLinesByRVA(caller.rva(), length, enum_lines.Receive());
 353  E :      if (FAILED(hr)) {
 354  i :        LOG(ERROR) << "Failure in findLinesByRVA: " << common::LogHr(hr) << ".";
 355  i :        return false;
 356    :      }
 357    :  
 358  E :      ScopedComPtr<IDiaLineNumber> line;
 359  E :      ULONG fetched = 0;
 360  E :      hr = enum_lines->Next(1, line.Receive(), &fetched);
 361  E :      if (FAILED(hr)) {
 362  i :        LOG(ERROR) << "Failure in IDiaLineNumber::Next: "
 363    :                   << common::LogHr(hr) << ".";
 364  i :        return false;
 365    :      }
 366    :  
 367  E :      if (fetched == 1) {
 368  E :        hr = line->get_lineNumber(&line_number);
 369  E :        if (FAILED(hr)) {
 370  i :          LOG(ERROR) << "Failure in get_lineNumber: " << common::LogHr(hr) << ".";
 371  i :          return false;
 372  E :        }
 373  i :      } else if (fetched != 0) {
 374  i :        NOTREACHED() << "IDiaLineNumber::Next unexpectedly returned "
 375    :                     << fetched << " elements.";
 376    :      }
 377  E :    }
 378    :  
 379  E :    *line = line_number;
 380  E :    return true;
 381  E :  }
 382    :  
 383    :  bool ProfileGrinder::GetInfoForFunction(const FunctionLocation& function,
 384    :                                          std::wstring* function_name,
 385    :                                          std::wstring* file_name,
 386  E :                                          size_t* line) {
 387  E :    DCHECK(function_name != NULL);
 388  E :    DCHECK(file_name != NULL);
 389  E :    DCHECK(line != NULL);
 390    :  
 391  E :    if (function.is_symbol()) {
 392  i :      DCHECK_EQ(0U, function.symbol_offset());
 393    :  
 394  i :      DynamicSymbolKey key(function.process_id(), function.symbol_id());
 395  i :      DynamicSymbolMap::iterator it(dynamic_symbols_.find(key));
 396    :  
 397  i :      if (it != dynamic_symbols_.end()) {
 398    :        // Get the function name.
 399  i :        *function_name = base::UTF8ToWide(it->second);
 400  i :        *file_name = L"*JAVASCRIPT*";
 401  i :        *line = 0;
 402  i :      } else {
 403  i :        LOG(ERROR) << "No symbol info available for symbol "
 404    :                   << function.symbol_id() << " in process "
 405    :                   << function.process_id();
 406  i :        return false;
 407    :      }
 408    :  
 409  i :      return true;
 410    :    }
 411    :  
 412  E :    DCHECK(!function.is_symbol());
 413    :  
 414  E :    if (function.module() == NULL) {
 415  i :      *function_name = base::StringPrintf(L"FakeFunction_0x%08X", function.rva());
 416  i :      *file_name = L"*UNKNOWN*";
 417  i :      return true;
 418    :    }
 419    :  
 420  E :    ScopedComPtr<IDiaSession> session;
 421  E :    if (!GetSessionForModule(function.module(), session.Receive()))
 422  i :      return false;
 423    :  
 424  E :    ScopedComPtr<IDiaSymbol> function_sym;
 425    :    if (!GetFunctionSymbolByRVA(session.get(),
 426    :                                function.rva(),
 427  E :                                function_sym.Receive())) {
 428  i :      LOG(ERROR) << "No symbol info available for function in module '"
 429    :                 << function.module()->path << "'";
 430  i :      return false;
 431    :    }
 432    :  
 433  E :    ScopedBstr function_name_bstr;
 434  E :    HRESULT hr = function_sym->get_name(function_name_bstr.Receive());
 435  E :    if (FAILED(hr)) {
 436  i :      LOG(ERROR) << "Failure in get_name: " << common::LogHr(hr) << ".";
 437  i :      return false;
 438    :    }
 439    :  
 440  E :    *function_name = common::ToString(function_name_bstr);
 441    :  
 442  E :    ULONGLONG length = 0;
 443  E :    hr = function_sym->get_length(&length);
 444  E :    if (FAILED(hr)) {
 445  i :      LOG(ERROR) << "Failure in get_length: " << common::LogHr(hr) << ".";
 446  i :      return false;
 447    :    }
 448    :  
 449  E :    ScopedBstr file_name_bstr;
 450  E :    DWORD line_number = 0;
 451  E :    if (length != 0) {
 452  E :      ScopedComPtr<IDiaEnumLineNumbers> enum_lines;
 453    :  
 454    :      hr = session->findLinesByRVA(function.rva(),
 455    :                                   length,
 456  E :                                   enum_lines.Receive());
 457  E :      if (FAILED(hr)) {
 458  i :        LOG(ERROR) << "Failure in findLinesByRVA: " << common::LogHr(hr) << ".";
 459  i :        return false;
 460    :      }
 461    :  
 462  E :      ScopedComPtr<IDiaLineNumber> line;
 463  E :      ULONG fetched = 0;
 464  E :      hr = enum_lines->Next(1, line.Receive(), &fetched);
 465  E :      if (FAILED(hr)) {
 466  i :        LOG(ERROR) << "Failure in IDialineNumber::Next: "
 467    :                   << common::LogHr(hr) << ".";
 468  i :        return false;
 469    :      }
 470  E :      if (fetched == 1) {
 471  E :        hr = line->get_lineNumber(&line_number);
 472  E :        if (FAILED(hr)) {
 473  i :          LOG(ERROR) << "Failure in get_lineNumber: " << common::LogHr(hr) << ".";
 474  i :          return false;
 475    :        }
 476  E :        ScopedComPtr<IDiaSourceFile> source_file;
 477  E :        hr = line->get_sourceFile(source_file.Receive());
 478  E :        if (FAILED(hr)) {
 479  i :          LOG(ERROR) << "Failure in get_sourceFile: " << common::LogHr(hr) << ".";
 480  i :          return false;
 481    :        }
 482  E :        hr = source_file->get_fileName(file_name_bstr.Receive());
 483  E :        if (FAILED(hr)) {
 484  i :          LOG(ERROR) << "Failure in get_fileName: " << common::LogHr(hr) << ".";
 485  i :          return false;
 486    :        }
 487  E :      }
 488  E :    }
 489    :  
 490  E :    *file_name = common::ToString(file_name_bstr);
 491  E :    *line = line_number;
 492  E :    return true;
 493  E :  }
 494    :  
 495  E :  bool ProfileGrinder::ResolveCallers() {
 496  E :    PartDataMap::iterator it = parts_.begin();
 497  E :    for (; it != parts_.end(); ++it) {
 498  E :      if (!ResolveCallersForPart(&it->second))
 499  i :        return false;
 500  E :    }
 501    :  
 502  E :    return true;
 503  E :  }
 504    :  
 505  E :  bool ProfileGrinder::ResolveCallersForPart(PartData* part) {
 506    :    // We start by iterating all the edges, connecting them up to their caller,
 507    :    // and subtracting the edge metric(s) to compute the inclusive metrics for
 508    :    // each function.
 509  E :    InvocationEdgeMap::iterator edge_it(part->edges_.begin());
 510  E :    for (; edge_it != part->edges_.end(); ++edge_it) {
 511  E :      InvocationEdge& edge = edge_it->second;
 512  E :      FunctionLocation function;
 513  E :      if (GetFunctionForCaller(edge.caller, &function, &edge.line)) {
 514  E :        InvocationNodeMap::iterator node_it(part->nodes_.find(function));
 515  E :        if (node_it == part->nodes_.end()) {
 516    :          // This is a fringe node - e.g. this is a non-instrumented caller
 517    :          // calling into an instrumented function. Create the node now,
 518    :          // but note that we won't have any metrics recorded for the function
 519    :          // and must be careful not to try and tally exclusive stats for it.
 520    :          node_it = part->nodes_.insert(
 521  E :              std::make_pair(function, InvocationNode())).first;
 522    :  
 523  E :          node_it->second.function = function;
 524  E :          DCHECK_EQ(0, node_it->second.metrics.num_calls);
 525  E :          DCHECK_EQ(0, node_it->second.metrics.cycles_sum);
 526    :        }
 527    :  
 528  E :        InvocationNode& node = node_it->second;
 529    :  
 530    :        // Hook the edge up to the node's list of outgoing edges.
 531  E :        edge.next_call = node.first_call;
 532  E :        node.first_call = &edge;
 533    :  
 534    :        // Make the function's cycle count exclusive, by subtracting all
 535    :        // the outbound (inclusive) cycle counts from the total. We make
 536    :        // special allowance for the "fringe" nodes mentioned above, by
 537    :        // noting they have no recorded calls.
 538  E :        if (node.metrics.num_calls != 0) {
 539  E :          node.metrics.cycles_sum -= edge.metrics.cycles_sum;
 540    :        }
 541  E :      } else {
 542    :        // TODO(siggi): The profile instrumentation currently doesn't record
 543    :        //     sufficient module information that we can resolve calls from
 544    :        //     system and dependent modules.
 545  E :        LOG(WARNING) << "Found no info for module: '"
 546    :                     << edge.caller.module()->path << "'.";
 547    :      }
 548  E :    }
 549    :  
 550  E :    return true;
 551  E :  }
 552    :  
 553  E :  bool ProfileGrinder::OutputData(FILE* file) {
 554    :    // Output the file header.
 555    :  
 556  E :    bool succeeded = true;
 557  E :    PartDataMap::iterator it = parts_.begin();
 558  E :    for (; it != parts_.end(); ++it) {
 559  E :      if (!OutputDataForPart(it->second, file)) {
 560    :        // Keep going despite problems in output
 561  i :        succeeded = false;
 562    :      }
 563  E :    }
 564    :  
 565  E :    return succeeded;
 566  E :  }
 567    :  
 568  E :  bool ProfileGrinder::OutputDataForPart(const PartData& part, FILE* file) {
 569    :    // TODO(siggi): Output command line here.
 570  E :    ::fprintf(file, "pid: %d\n", part.process_id_);
 571  E :    if (part.thread_id_ != 0)
 572  i :      ::fprintf(file, "thread: %d\n", part.thread_id_);
 573  E :    ::fprintf(file, "events: Calls Cycles Cycles-Min Cycles-Max\n");
 574    :  
 575  E :    if (!part.thread_name_.empty())
 576  i :      ::fprintf(file, "desc: Trigger: %s\n", part.thread_name_.c_str());
 577    :  
 578    :    // Walk the nodes and output the data.
 579  E :    InvocationNodeMap::const_iterator node_it(part.nodes_.begin());
 580  E :    for (; node_it != part.nodes_.end(); ++node_it) {
 581  E :      const InvocationNode& node = node_it->second;
 582  E :      std::wstring function_name;
 583  E :      std::wstring file_name;
 584  E :      size_t line = 0;
 585  E :      if (GetInfoForFunction(node.function, &function_name, &file_name, &line)) {
 586    :        // Rewrite file path to use forward slashes instead of back slashes.
 587  E :        base::ReplaceChars(file_name, L"\\", L"/", &file_name);
 588    :  
 589    :        // Output the function information.
 590  E :        ::fprintf(file, "fl=%ws\n", file_name.c_str());
 591  E :        ::fprintf(file, "fn=%ws\n", function_name.c_str());
 592    :        ::fprintf(file, "%d %I64d %I64d %I64d %I64d\n", line,
 593    :                  node.metrics.num_calls, node.metrics.cycles_sum,
 594  E :                  node.metrics.cycles_min, node.metrics.cycles_max);
 595    :  
 596    :        // Output the call information from this function.
 597  E :        const InvocationEdge* call = node.first_call;
 598  E :        for (; call != NULL; call = call->next_call) {
 599    :          if (GetInfoForFunction(call->function,
 600    :                                 &function_name,
 601    :                                 &file_name,
 602  E :                                 &line)) {
 603    :  
 604    :            // Rewrite file path to use forward slashes instead of back slashes.
 605  E :            base::ReplaceChars(file_name, L"\\", L"/", &file_name);
 606    :  
 607  E :            ::fprintf(file, "cfl=%ws\n", file_name.c_str());
 608  E :            ::fprintf(file, "cfn=%ws\n", function_name.c_str());
 609  E :            ::fprintf(file, "calls=%d %d\n", call->metrics.num_calls, line);
 610    :            ::fprintf(file, "%d %I64d %I64d %I64d %I64d\n", call->line,
 611    :                      call->metrics.num_calls, call->metrics.cycles_sum,
 612  E :                      call->metrics.cycles_min, call->metrics.cycles_max);
 613    :          }
 614  E :        }
 615    :      } else {
 616  i :        LOG(ERROR) << "Unable to resolve function.";
 617  i :        return false;
 618    :      }
 619  E :    }
 620    :  
 621  E :    return true;
 622  E :  }
 623    :  
 624    :  void ProfileGrinder::OnInvocationBatch(base::Time time,
 625    :                                         DWORD process_id,
 626    :                                         DWORD thread_id,
 627    :                                         size_t num_invocations,
 628  E :                                         const TraceBatchInvocationInfo* data) {
 629  E :    PartData* part = FindOrCreatePart(process_id, thread_id);
 630  E :    DCHECK(data != NULL);
 631    :  
 632    :    // Process and aggregate the individual invocation entries.
 633  E :    for (size_t i = 0; i < num_invocations; ++i) {
 634  E :      const InvocationInfo& info = data->invocations[i];
 635  E :      if (info.caller == NULL || info.function == NULL) {
 636    :        // This may happen due to a termination race when the traces are captured.
 637  i :        LOG(WARNING) << "Empty invocation record. Record " << i << " of " <<
 638    :            num_invocations << ".";
 639  i :        break;
 640    :      }
 641    :  
 642  E :      FunctionLocation function;
 643  E :      if ((info.flags & kFunctionIsSymbol) != 0) {
 644    :        // The function is a dynamic symbol
 645  E :        function.Set(process_id, info.function_symbol_id, 0);
 646  E :      } else {
 647    :        // The function is native.
 648    :        AbsoluteAddress64 function_addr =
 649  E :            reinterpret_cast<AbsoluteAddress64>(info.function);
 650    :  
 651  E :        ConvertToModuleRVA(process_id, function_addr, &function);
 652    :      }
 653    :  
 654  E :      CallerLocation caller;
 655  E :      if ((info.flags & kCallerIsSymbol) != 0) {
 656    :        // The caller is a dynamic symbol.
 657  E :        caller.Set(process_id, info.caller_symbol_id, info.caller_offset);
 658  E :      } else {
 659    :        // The caller is a native function.
 660    :        AbsoluteAddress64 caller_addr =
 661  E :            reinterpret_cast<AbsoluteAddress64>(info.caller);
 662  E :        ConvertToModuleRVA(process_id, caller_addr, &caller);
 663    :      }
 664    :  
 665  E :      AggregateEntryToPart(function, caller, info, part);
 666  E :    }
 667  E :  }
 668    :  
 669    :  void ProfileGrinder::OnThreadName(base::Time time,
 670    :                                    DWORD process_id,
 671    :                                    DWORD thread_id,
 672  E :                                    const base::StringPiece& thread_name) {
 673  E :    if (!thread_parts_)
 674  i :      return;
 675    :  
 676  E :    PartData* part = FindOrCreatePart(process_id, thread_id);
 677  E :    part->thread_name_ = thread_name.as_string();
 678  E :  }
 679    :  
 680    :  void ProfileGrinder::OnDynamicSymbol(DWORD process_id,
 681    :                                       uint32 symbol_id,
 682  E :                                       const base::StringPiece& symbol_name) {
 683  E :    DynamicSymbolKey key(process_id, symbol_id);
 684    :  
 685  E :    dynamic_symbols_[key].assign(symbol_name.begin(), symbol_name.end());
 686  E :  }
 687    :  
 688    :  void ProfileGrinder::AggregateEntryToPart(const FunctionLocation& function,
 689    :                                            const CallerLocation& caller,
 690    :                                            const InvocationInfo& info,
 691  E :                                            PartData* part) {
 692    :    // Have we recorded this node before?
 693  E :    InvocationNodeMap::iterator node_it(part->nodes_.find(function));
 694  E :    if (node_it != part->nodes_.end()) {
 695    :      // Yups, we've seen this edge before.
 696    :      // Aggregate the new data with the old.
 697  E :      InvocationNode& found = node_it->second;
 698  E :      found.metrics.num_calls += info.num_calls;
 699    :      found.metrics.cycles_min = std::min(found.metrics.cycles_min,
 700  E :                                          info.cycles_min);
 701    :      found.metrics.cycles_max = std::max(found.metrics.cycles_max,
 702  E :                                          info.cycles_max);
 703  E :      found.metrics.cycles_sum += info.cycles_sum;
 704  E :    } else {
 705    :      // Nopes, we haven't seen this pair before, insert it.
 706  E :      InvocationNode& node = part->nodes_[function];
 707  E :      node.function = function;
 708  E :      node.metrics.num_calls = info.num_calls;
 709  E :      node.metrics.cycles_min = info.cycles_min;
 710  E :      node.metrics.cycles_max = info.cycles_max;
 711  E :      node.metrics.cycles_sum = info.cycles_sum;
 712    :    }
 713    :  
 714  E :    InvocationEdgeKey key(function, caller);
 715    :  
 716    :    // Have we recorded this edge before?
 717  E :    InvocationEdgeMap::iterator edge_it(part->edges_.find(key));
 718  E :    if (edge_it != part->edges_.end()) {
 719    :      // Yups, we've seen this edge before.
 720    :      // Aggregate the new data with the old.
 721  i :      InvocationEdge& found = edge_it->second;
 722  i :      found.metrics.num_calls += info.num_calls;
 723    :      found.metrics.cycles_min = std::min(found.metrics.cycles_min,
 724  i :                                          info.cycles_min);
 725    :      found.metrics.cycles_max = std::max(found.metrics.cycles_max,
 726  i :                                          info.cycles_max);
 727  i :      found.metrics.cycles_sum += info.cycles_sum;
 728  i :    } else {
 729    :      // Nopes, we haven't seen this edge before, insert it.
 730  E :      InvocationEdge& edge = part->edges_[key];
 731  E :      edge.function = function;
 732  E :      edge.caller = caller;
 733  E :      edge.metrics.num_calls = info.num_calls;
 734  E :      edge.metrics.cycles_min = info.cycles_min;
 735  E :      edge.metrics.cycles_max = info.cycles_max;
 736  E :      edge.metrics.cycles_sum = info.cycles_sum;
 737    :    }
 738  E :  }
 739    :  
 740    :  void ProfileGrinder::ConvertToModuleRVA(uint32 process_id,
 741    :                                          AbsoluteAddress64 addr,
 742  E :                                          CodeLocation* rva) {
 743  E :    DCHECK(rva != NULL);
 744    :  
 745    :    const ModuleInformation* module =
 746  E :        parser_->GetModuleInformation(process_id, addr);
 747    :  
 748  E :    if (module == NULL) {
 749    :      // We have no module information for this address.
 750  i :      rva->Set(NULL, addr);
 751  i :      return;
 752    :    }
 753    :  
 754    :    // And find or record the canonical module information
 755    :    // for this module.
 756  E :    ModuleInformationSet::iterator it(modules_.find(*module));
 757  E :    if (it == modules_.end()) {
 758  E :      it = modules_.insert(*module).first;
 759    :    }
 760  E :    DCHECK(it != modules_.end());
 761    :  
 762  E :    rva->Set(&(*it), static_cast<RVA>(addr - module->base_address.value()));
 763  E :  }
 764    :  
 765    :  }  // namespace grinders
 766    :  }  // namespace grinder

Coverage information generated Thu Jan 14 17:40:38 2016.