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