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