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/string_util.h"
20 : #include "base/stringprintf.h"
21 : #include "base/strings/utf_string_conversions.h"
22 : #include "base/win/scoped_bstr.h"
23 : #include "sawbuck/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 sym_util::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.image_checksum > b.image_checksum)
48 i : return false;
49 E : if (a.image_checksum < b.image_checksum)
50 i : return true;
51 :
52 E : if (a.time_date_stamp > b.time_date_stamp)
53 i : return false;
54 E : if (a.time_date_stamp < b.time_date_stamp)
55 i : return true;
56 :
57 E : return a.image_file_name < b.image_file_name;
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 sym_util::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 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 i : LOG(ERROR) << "Failed to create DiaSource: "
175 : << com::LogHr(hr) << ".";
176 i : return false;
177 : }
178 :
179 E : pe::PEFile::Signature signature;
180 E : signature.path = module->image_file_name;
181 : signature.base_address = core::AbsoluteAddress(
182 E : static_cast<uint32>(module->base_address));
183 E : signature.module_size = module->module_size;
184 E : signature.module_time_date_stamp = module->time_date_stamp;
185 E : signature.module_checksum = module->image_checksum;
186 :
187 E : base::FilePath module_path;
188 : if (!pe::FindModuleBySignature(signature, &module_path) ||
189 E : module_path.empty()) {
190 i : LOG(ERROR) << "Unable to find module matching signature.";
191 i : return false;
192 : }
193 :
194 E : ScopedComPtr<IDiaSession> new_session;
195 : // We first try loading straight-up for the module. If the module is at
196 : // this path and the symsrv machinery is available, this will bring that
197 : // machinery to bear.
198 : // The downside is that if the module at this path does not match the
199 : // original module, we may load the wrong symbol information for the
200 : // module.
201 E : hr = source->loadDataForExe(module_path.value().c_str(), NULL, NULL);
202 E : if (SUCCEEDED(hr)) {
203 E : hr = source->openSession(new_session.Receive());
204 E : if (FAILED(hr))
205 i : LOG(ERROR) << "Failure in openSession: " << com::LogHr(hr) << ".";
206 E : } else {
207 E : DCHECK(FAILED(hr));
208 :
209 E : base::FilePath pdb_path;
210 : if (!pe::FindPdbForModule(module_path, &pdb_path) ||
211 E : pdb_path.empty()) {
212 E : LOG(ERROR) << "Unable to find PDB for module \""
213 : << module_path.value() << "\".";
214 : }
215 :
216 E : hr = source->loadDataFromPdb(pdb_path.value().c_str());
217 E : if (SUCCEEDED(hr)) {
218 i : hr = source->openSession(new_session.Receive());
219 i : if (FAILED(hr))
220 i : LOG(ERROR) << "Failure in openSession: " << com::LogHr(hr) << ".";
221 i : } else {
222 E : LOG(WARNING) << "Failure in loadDataFromPdb('"
223 : << module_path.value().c_str() << "'): "
224 : << com::LogHr(hr) << ".";
225 : }
226 E : }
227 :
228 : DCHECK((SUCCEEDED(hr) && new_session.get() != NULL) ||
229 E : (FAILED(hr) && new_session.get() == NULL));
230 :
231 : // We store an entry to the cache irrespective of whether we succeeded
232 : // in opening a session above. This allows us to cache the failures, which
233 : // means we attempt to load each module only once, and consequently log
234 : // each failing module only once.
235 : it = module_sessions_.insert(
236 E : std::make_pair(module, new_session)).first;
237 E : }
238 E : DCHECK(it != module_sessions_.end());
239 :
240 E : if (it->second.get() == NULL) {
241 : // A negative session cache entry - we were previously unable to
242 : // load this module.
243 E : return false;
244 : }
245 :
246 E : *session_out = it->second;
247 E : (*session_out)->AddRef();
248 :
249 E : return true;
250 E : }
251 :
252 : ProfileGrinder::PartData* ProfileGrinder::FindOrCreatePart(DWORD process_id,
253 E : DWORD thread_id) {
254 E : if (!thread_parts_) {
255 E : process_id = 0;
256 E : thread_id = 0;
257 : }
258 :
259 : // Lookup the part to aggregate to.
260 E : PartKey key(process_id, thread_id);
261 E : PartDataMap::iterator it = parts_.find(key);
262 E : if (it == parts_.end()) {
263 E : PartData part;
264 E : part.process_id_ = process_id;
265 E : part.thread_id_ = thread_id;
266 :
267 E : it = parts_.insert(std::make_pair(key, part)).first;
268 E : }
269 :
270 E : return &it->second;
271 E : }
272 :
273 : bool ProfileGrinder::GetFunctionSymbolByRVA(IDiaSession* session,
274 : RVA address,
275 E : IDiaSymbol** symbol) {
276 E : DCHECK(session != NULL);
277 E : DCHECK(symbol != NULL && *symbol == NULL);
278 :
279 E : ScopedComPtr<IDiaSymbol> function;
280 : HRESULT hr = session->findSymbolByRVA(address,
281 : SymTagFunction,
282 E : function.Receive());
283 E : if (FAILED(hr) || function.get() == NULL) {
284 : // No private function, let's try for a public symbol.
285 : hr = session->findSymbolByRVA(address,
286 : SymTagPublicSymbol,
287 i : function.Receive());
288 i : if (FAILED(hr))
289 i : return false;
290 : }
291 E : if (function.get() == NULL) {
292 i : LOG(ERROR) << "NULL function returned from findSymbolByRVA.";
293 i : return false;
294 : }
295 :
296 E : *symbol = function.Detach();
297 :
298 E : return true;
299 E : }
300 :
301 : bool ProfileGrinder::GetFunctionForCaller(const CallerLocation& caller,
302 : FunctionLocation* function,
303 E : size_t* line) {
304 E : DCHECK(function != NULL);
305 E : DCHECK(line != NULL);
306 :
307 E : if (caller.is_symbol()) {
308 : // The function symbol for a caller is simply the same symbol with a
309 : // zero offset.
310 E : function->Set(caller.process_id(), caller.symbol_id(), 0);
311 E : return true;
312 : }
313 :
314 E : DCHECK(!caller.is_symbol());
315 :
316 E : if (caller.module() == NULL) {
317 : // If the module is unknown, we fake a function per every K of memory.
318 : // Turns out that V8 generates some code outside the JS heap, and as of
319 : // June 2013, does not push symbols for the code.
320 i : function->Set(NULL, caller.rva() & ~1023);
321 i : *line = 0;
322 i : return true;
323 : }
324 :
325 E : ScopedComPtr<IDiaSession> session;
326 E : if (!GetSessionForModule(caller.module(), session.Receive()))
327 E : return false;
328 :
329 E : ScopedComPtr<IDiaSymbol> function_sym;
330 : if (!GetFunctionSymbolByRVA(session.get(),
331 : caller.rva(),
332 E : function_sym.Receive())) {
333 i : LOG(ERROR) << "No symbol info available for function in module '"
334 : << caller.module()->image_file_name << "'";
335 : }
336 :
337 : // Get the RVA of the function.
338 E : DWORD rva = 0;
339 E : HRESULT hr = function_sym->get_relativeVirtualAddress(&rva);
340 E : if (FAILED(hr)) {
341 i : LOG(ERROR) << "Failure in get_relativeVirtualAddress: "
342 : << com::LogHr(hr) << ".";
343 i : return false;
344 : }
345 :
346 : // Return the module/rva we found.
347 E : function->Set(caller.module(), rva);
348 :
349 E : ULONGLONG length = 0;
350 E : hr = function_sym->get_length(&length);
351 E : if (FAILED(hr)) {
352 i : LOG(ERROR) << "Failure in get_length: " << com::LogHr(hr) << ".";
353 i : return false;
354 : }
355 :
356 E : DWORD line_number = 0;
357 E : if (length != 0) {
358 E : ScopedComPtr<IDiaEnumLineNumbers> enum_lines;
359 :
360 E : hr = session->findLinesByRVA(caller.rva(), length, enum_lines.Receive());
361 E : if (FAILED(hr)) {
362 i : LOG(ERROR) << "Failure in findLinesByRVA: " << com::LogHr(hr) << ".";
363 i : return false;
364 : }
365 :
366 E : ScopedComPtr<IDiaLineNumber> line;
367 E : ULONG fetched = 0;
368 E : hr = enum_lines->Next(1, line.Receive(), &fetched);
369 E : if (FAILED(hr)) {
370 i : LOG(ERROR) << "Failure in IDiaLineNumber::Next: "
371 : << com::LogHr(hr) << ".";
372 i : return false;
373 : }
374 :
375 E : if (fetched == 1) {
376 E : hr = line->get_lineNumber(&line_number);
377 E : if (FAILED(hr)) {
378 i : LOG(ERROR) << "Failure in get_lineNumber: " << com::LogHr(hr) << ".";
379 i : return false;
380 E : }
381 E : } else if (fetched != 0) {
382 i : NOTREACHED() << "IDiaLineNumber::Next unexpectedly returned "
383 : << fetched << " elements.";
384 : }
385 E : }
386 :
387 E : *line = line_number;
388 E : return true;
389 E : }
390 :
391 : bool ProfileGrinder::GetInfoForFunction(const FunctionLocation& function,
392 : std::wstring* function_name,
393 : std::wstring* file_name,
394 E : size_t* line) {
395 E : DCHECK(function_name != NULL);
396 E : DCHECK(file_name != NULL);
397 E : DCHECK(line != NULL);
398 :
399 E : if (function.is_symbol()) {
400 i : DCHECK_EQ(0U, function.symbol_offset());
401 :
402 i : DynamicSymbolKey key(function.process_id(), function.symbol_id());
403 i : DynamicSymbolMap::iterator it(dynamic_symbols_.find(key));
404 :
405 i : if (it != dynamic_symbols_.end()) {
406 : // Get the function name.
407 i : *function_name = base::UTF8ToWide(it->second);
408 i : *file_name = L"*JAVASCRIPT*";
409 i : *line = 0;
410 i : } else {
411 i : LOG(ERROR) << "No symbol info available for symbol "
412 : << function.symbol_id() << " in process "
413 : << function.process_id();
414 i : return false;
415 : }
416 :
417 i : return true;
418 : }
419 :
420 E : DCHECK(!function.is_symbol());
421 :
422 E : if (function.module() == NULL) {
423 i : *function_name = base::StringPrintf(L"FakeFunction_0x%08X", function.rva());
424 i : *file_name = L"*UNKNOWN*";
425 i : return true;
426 : }
427 :
428 E : ScopedComPtr<IDiaSession> session;
429 E : if (!GetSessionForModule(function.module(), session.Receive()))
430 i : return false;
431 :
432 E : ScopedComPtr<IDiaSymbol> function_sym;
433 : if (!GetFunctionSymbolByRVA(session.get(),
434 : function.rva(),
435 E : function_sym.Receive())) {
436 i : LOG(ERROR) << "No symbol info available for function in module '"
437 : << function.module()->image_file_name << "'";
438 i : return false;
439 : }
440 :
441 E : ScopedBstr function_name_bstr;
442 E : HRESULT hr = function_sym->get_name(function_name_bstr.Receive());
443 E : if (FAILED(hr)) {
444 i : LOG(ERROR) << "Failure in get_name: " << com::LogHr(hr) << ".";
445 i : return false;
446 : }
447 :
448 E : *function_name = com::ToString(function_name_bstr);
449 :
450 E : ULONGLONG length = 0;
451 E : hr = function_sym->get_length(&length);
452 E : if (FAILED(hr)) {
453 i : LOG(ERROR) << "Failure in get_length: " << com::LogHr(hr) << ".";
454 i : return false;
455 : }
456 :
457 E : ScopedBstr file_name_bstr;
458 E : DWORD line_number = 0;
459 E : if (length != 0) {
460 E : ScopedComPtr<IDiaEnumLineNumbers> enum_lines;
461 :
462 : hr = session->findLinesByRVA(function.rva(),
463 : length,
464 E : enum_lines.Receive());
465 E : if (FAILED(hr)) {
466 i : LOG(ERROR) << "Failure in findLinesByRVA: " << com::LogHr(hr) << ".";
467 i : return false;
468 : }
469 :
470 E : ScopedComPtr<IDiaLineNumber> line;
471 E : ULONG fetched = 0;
472 E : hr = enum_lines->Next(1, line.Receive(), &fetched);
473 E : if (FAILED(hr)) {
474 i : LOG(ERROR) << "Failure in IDialineNumber::Next: "
475 : << com::LogHr(hr) << ".";
476 i : return false;
477 : }
478 E : if (fetched == 1) {
479 E : hr = line->get_lineNumber(&line_number);
480 E : if (FAILED(hr)) {
481 i : LOG(ERROR) << "Failure in get_lineNumber: " << com::LogHr(hr) << ".";
482 i : return false;
483 : }
484 E : ScopedComPtr<IDiaSourceFile> source_file;
485 E : hr = line->get_sourceFile(source_file.Receive());
486 E : if (FAILED(hr)) {
487 i : LOG(ERROR) << "Failure in get_sourceFile: " << com::LogHr(hr) << ".";
488 i : return false;
489 : }
490 E : hr = source_file->get_fileName(file_name_bstr.Receive());
491 E : if (FAILED(hr)) {
492 i : LOG(ERROR) << "Failure in get_fileName: " << com::LogHr(hr) << ".";
493 i : return false;
494 : }
495 E : }
496 E : }
497 :
498 E : *file_name = com::ToString(file_name_bstr);
499 E : *line = line_number;
500 E : return true;
501 E : }
502 :
503 E : bool ProfileGrinder::ResolveCallers() {
504 E : PartDataMap::iterator it = parts_.begin();
505 E : for (; it != parts_.end(); ++it) {
506 E : if (!ResolveCallersForPart(&it->second))
507 i : return false;
508 E : }
509 :
510 E : return true;
511 E : }
512 :
513 E : bool ProfileGrinder::ResolveCallersForPart(PartData* part) {
514 : // We start by iterating all the edges, connecting them up to their caller,
515 : // and subtracting the edge metric(s) to compute the inclusive metrics for
516 : // each function.
517 E : InvocationEdgeMap::iterator edge_it(part->edges_.begin());
518 E : for (; edge_it != part->edges_.end(); ++edge_it) {
519 E : InvocationEdge& edge = edge_it->second;
520 E : FunctionLocation function;
521 E : if (GetFunctionForCaller(edge.caller, &function, &edge.line)) {
522 E : InvocationNodeMap::iterator node_it(part->nodes_.find(function));
523 E : if (node_it == part->nodes_.end()) {
524 : // This is a fringe node - e.g. this is a non-instrumented caller
525 : // calling into an instrumented function. Create the node now,
526 : // but note that we won't have any metrics recorded for the function
527 : // and must be careful not to try and tally exclusive stats for it.
528 : node_it = part->nodes_.insert(
529 E : std::make_pair(function, InvocationNode())).first;
530 :
531 E : node_it->second.function = function;
532 E : DCHECK_EQ(0, node_it->second.metrics.num_calls);
533 E : DCHECK_EQ(0, node_it->second.metrics.cycles_sum);
534 : }
535 :
536 E : InvocationNode& node = node_it->second;
537 :
538 : // Hook the edge up to the node's list of outgoing edges.
539 E : edge.next_call = node.first_call;
540 E : node.first_call = &edge;
541 :
542 : // Make the function's cycle count exclusive, by subtracting all
543 : // the outbound (inclusive) cycle counts from the total. We make
544 : // special allowance for the "fringe" nodes mentioned above, by
545 : // noting they have no recorded calls.
546 E : if (node.metrics.num_calls != 0) {
547 E : node.metrics.cycles_sum -= edge.metrics.cycles_sum;
548 : }
549 E : } else {
550 : // TODO(siggi): The profile instrumentation currently doesn't record
551 : // sufficient module information that we can resolve calls from
552 : // system and dependent modules.
553 E : LOG(WARNING) << "Found no info for module: '"
554 : << edge.caller.module()->image_file_name << "'.";
555 : }
556 E : }
557 :
558 E : return true;
559 E : }
560 :
561 E : bool ProfileGrinder::OutputData(FILE* file) {
562 : // Output the file header.
563 :
564 E : bool succeeded = true;
565 E : PartDataMap::iterator it = parts_.begin();
566 E : for (; it != parts_.end(); ++it) {
567 E : if (!OutputDataForPart(it->second, file)) {
568 : // Keep going despite problems in output
569 i : succeeded = false;
570 : }
571 E : }
572 :
573 E : return succeeded;
574 E : }
575 :
576 E : bool ProfileGrinder::OutputDataForPart(const PartData& part, FILE* file) {
577 : // TODO(siggi): Output command line here.
578 E : ::fprintf(file, "pid: %d\n", part.process_id_);
579 E : if (part.thread_id_ != 0)
580 i : ::fprintf(file, "thread: %d\n", part.thread_id_);
581 E : ::fprintf(file, "events: Calls Cycles Cycles-Min Cycles-Max\n");
582 :
583 E : if (!part.thread_name_.empty())
584 i : ::fprintf(file, "desc: Trigger: %s\n", part.thread_name_.c_str());
585 :
586 : // Walk the nodes and output the data.
587 E : InvocationNodeMap::const_iterator node_it(part.nodes_.begin());
588 E : for (; node_it != part.nodes_.end(); ++node_it) {
589 E : const InvocationNode& node = node_it->second;
590 E : std::wstring function_name;
591 E : std::wstring file_name;
592 E : size_t line = 0;
593 E : if (GetInfoForFunction(node.function, &function_name, &file_name, &line)) {
594 : // Rewrite file path to use forward slashes instead of back slashes.
595 E : ::ReplaceChars(file_name, L"\\", L"/", &file_name);
596 :
597 : // Output the function information.
598 E : ::fprintf(file, "fl=%ws\n", file_name.c_str());
599 E : ::fprintf(file, "fn=%ws\n", function_name.c_str());
600 : ::fprintf(file, "%d %I64d %I64d %I64d %I64d\n", line,
601 : node.metrics.num_calls, node.metrics.cycles_sum,
602 E : node.metrics.cycles_min, node.metrics.cycles_max);
603 :
604 : // Output the call information from this function.
605 E : const InvocationEdge* call = node.first_call;
606 E : for (; call != NULL; call = call->next_call) {
607 : if (GetInfoForFunction(call->function,
608 : &function_name,
609 : &file_name,
610 E : &line)) {
611 :
612 : // Rewrite file path to use forward slashes instead of back slashes.
613 E : ::ReplaceChars(file_name, L"\\", L"/", &file_name);
614 :
615 E : ::fprintf(file, "cfl=%ws\n", file_name.c_str());
616 E : ::fprintf(file, "cfn=%ws\n", function_name.c_str());
617 E : ::fprintf(file, "calls=%d %d\n", call->metrics.num_calls, line);
618 : ::fprintf(file, "%d %I64d %I64d %I64d %I64d\n", call->line,
619 : call->metrics.num_calls, call->metrics.cycles_sum,
620 E : call->metrics.cycles_min, call->metrics.cycles_max);
621 : }
622 E : }
623 : } else {
624 i : LOG(ERROR) << "Unable to resolve function.";
625 i : return false;
626 : }
627 E : }
628 :
629 E : return true;
630 E : }
631 :
632 : void ProfileGrinder::OnInvocationBatch(base::Time time,
633 : DWORD process_id,
634 : DWORD thread_id,
635 : size_t num_invocations,
636 E : const TraceBatchInvocationInfo* data) {
637 E : PartData* part = FindOrCreatePart(process_id, thread_id);
638 E : DCHECK(data != NULL);
639 :
640 : // Process and aggregate the individual invocation entries.
641 E : for (size_t i = 0; i < num_invocations; ++i) {
642 E : const InvocationInfo& info = data->invocations[i];
643 E : if (info.caller == NULL || info.function == NULL) {
644 : // This may happen due to a termination race when the traces are captured.
645 i : LOG(WARNING) << "Empty invocation record. Record " << i << " of " <<
646 : num_invocations << ".";
647 i : break;
648 : }
649 :
650 E : FunctionLocation function;
651 E : if ((info.flags & kFunctionIsSymbol) != 0) {
652 : // The function is a dynamic symbol
653 E : function.Set(process_id, info.function_symbol_id, 0);
654 E : } else {
655 : // The function is native.
656 : AbsoluteAddress64 function_addr =
657 E : reinterpret_cast<AbsoluteAddress64>(info.function);
658 :
659 E : ConvertToModuleRVA(process_id, function_addr, &function);
660 : }
661 :
662 E : CallerLocation caller;
663 E : if ((info.flags & kCallerIsSymbol) != 0) {
664 : // The caller is a dynamic symbol.
665 E : caller.Set(process_id, info.caller_symbol_id, info.caller_offset);
666 E : } else {
667 : // The caller is a native function.
668 : AbsoluteAddress64 caller_addr =
669 E : reinterpret_cast<AbsoluteAddress64>(info.caller);
670 E : ConvertToModuleRVA(process_id, caller_addr, &caller);
671 : }
672 :
673 E : AggregateEntryToPart(function, caller, info, part);
674 E : }
675 E : }
676 :
677 : void ProfileGrinder::OnThreadName(base::Time time,
678 : DWORD process_id,
679 : DWORD thread_id,
680 E : const base::StringPiece& thread_name) {
681 E : if (!thread_parts_)
682 i : return;
683 :
684 E : PartData* part = FindOrCreatePart(process_id, thread_id);
685 E : part->thread_name_ = thread_name.as_string();
686 E : }
687 :
688 : void ProfileGrinder::OnDynamicSymbol(DWORD process_id,
689 : uint32 symbol_id,
690 E : const base::StringPiece& symbol_name) {
691 E : DynamicSymbolKey key(process_id, symbol_id);
692 :
693 E : dynamic_symbols_[key].assign(symbol_name.begin(), symbol_name.end());
694 E : }
695 :
696 : void ProfileGrinder::AggregateEntryToPart(const FunctionLocation& function,
697 : const CallerLocation& caller,
698 : const InvocationInfo& info,
699 E : PartData* part) {
700 : // Have we recorded this node before?
701 E : InvocationNodeMap::iterator node_it(part->nodes_.find(function));
702 E : if (node_it != part->nodes_.end()) {
703 : // Yups, we've seen this edge before.
704 : // Aggregate the new data with the old.
705 E : InvocationNode& found = node_it->second;
706 E : found.metrics.num_calls += info.num_calls;
707 : found.metrics.cycles_min = std::min(found.metrics.cycles_min,
708 E : info.cycles_min);
709 : found.metrics.cycles_max = std::max(found.metrics.cycles_max,
710 E : info.cycles_max);
711 E : found.metrics.cycles_sum += info.cycles_sum;
712 E : } else {
713 : // Nopes, we haven't seen this pair before, insert it.
714 E : InvocationNode& node = part->nodes_[function];
715 E : node.function = function;
716 E : node.metrics.num_calls = info.num_calls;
717 E : node.metrics.cycles_min = info.cycles_min;
718 E : node.metrics.cycles_max = info.cycles_max;
719 E : node.metrics.cycles_sum = info.cycles_sum;
720 : }
721 :
722 E : InvocationEdgeKey key(function, caller);
723 :
724 : // Have we recorded this edge before?
725 E : InvocationEdgeMap::iterator edge_it(part->edges_.find(key));
726 E : if (edge_it != part->edges_.end()) {
727 : // Yups, we've seen this edge before.
728 : // Aggregate the new data with the old.
729 i : InvocationEdge& found = edge_it->second;
730 i : found.metrics.num_calls += info.num_calls;
731 : found.metrics.cycles_min = std::min(found.metrics.cycles_min,
732 i : info.cycles_min);
733 : found.metrics.cycles_max = std::max(found.metrics.cycles_max,
734 i : info.cycles_max);
735 i : found.metrics.cycles_sum += info.cycles_sum;
736 i : } else {
737 : // Nopes, we haven't seen this edge before, insert it.
738 E : InvocationEdge& edge = part->edges_[key];
739 E : edge.function = function;
740 E : edge.caller = caller;
741 E : edge.metrics.num_calls = info.num_calls;
742 E : edge.metrics.cycles_min = info.cycles_min;
743 E : edge.metrics.cycles_max = info.cycles_max;
744 E : edge.metrics.cycles_sum = info.cycles_sum;
745 : }
746 E : }
747 :
748 : void ProfileGrinder::ConvertToModuleRVA(uint32 process_id,
749 : AbsoluteAddress64 addr,
750 E : CodeLocation* rva) {
751 E : DCHECK(rva != NULL);
752 :
753 : const ModuleInformation* module =
754 E : parser_->GetModuleInformation(process_id, addr);
755 :
756 E : if (module == NULL) {
757 : // We have no module information for this address.
758 i : rva->Set(NULL, addr);
759 i : return;
760 : }
761 :
762 : // And find or record the canonical module information
763 : // for this module.
764 E : ModuleInformationSet::iterator it(modules_.find(*module));
765 E : if (it == modules_.end()) {
766 E : it = modules_.insert(*module).first;
767 : }
768 E : DCHECK(it != modules_.end());
769 :
770 E : rva->Set(&(*it), static_cast<RVA>(addr - module->base_address));
771 E : }
772 :
773 : } // namespace grinders
774 : } // namespace grinder
|