1 : // Copyright 2013 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/sampler/sampler_app.h"
16 :
17 : #include <psapi.h>
18 :
19 : #include "base/bind.h"
20 : #include "base/files/file_util.h"
21 : #include "base/strings/string_number_conversions.h"
22 : #include "base/strings/string_split.h"
23 : #include "base/strings/stringprintf.h"
24 : #include "syzygy/common/align.h"
25 : #include "syzygy/common/buffer_writer.h"
26 : #include "syzygy/pe/pe_file.h"
27 : #include "syzygy/trace/common/clock.h"
28 : #include "syzygy/trace/protocol/call_trace_defs.h"
29 : #include "syzygy/trace/service/trace_file_writer.h"
30 :
31 : namespace sampler {
32 :
33 : namespace {
34 :
35 : typedef trace::service::TraceFileWriter TraceFileWriter;
36 :
37 : const char kUsageFormatStr[] =
38 : "Usage: %ls [options] MODULE_PATH1 [MODULE_PATH2 ...]\n"
39 : "\n"
40 : " A tool that polls running processes and profiles modules of interest.\n"
41 : "\n"
42 : " The tool works by monitoring running processes. Any process that gets\n"
43 : " through the optional PID filter will be inspected, and if any of the\n"
44 : " specified modules are loaded in that process they will be profiled.\n"
45 : "\n"
46 : "Options:\n"
47 : "\n"
48 : " --blacklist-pids If a list of PIDs is specified with --pids, this\n"
49 : " makes the list a blacklist of processes not to\n"
50 : " be monitored. Defaults to false, in which case\n"
51 : " the list is a whitelist.\n"
52 : " --bucket-size=POSINT Specifies the bucket size. This must be a power\n"
53 : " of two, and must be >= 4. Defaults to 4.\n"
54 : " --output-dir=DIR The path to write trace-files. Will be created\n"
55 : " if it doesn't exist. Defaults to the current\n"
56 : " working directory.\n"
57 : " --pids=PID1,PID2,... Specifies a list of PIDs. If specified these are\n"
58 : " used as a filter (by default a whitelist) for\n"
59 : " processes to be profiled. If not specified all\n"
60 : " processes will be potentially profiled.\n"
61 : " --sampling-interval=INTERVAL\n"
62 : " Sets the sampling interval. This is a floating\n"
63 : " point value in seconds. Scientific notation is\n"
64 : " acceptable. Defaults to the current system\n"
65 : " setting. Not all sampling intervals are\n"
66 : " available on all systems so the closest value\n"
67 : " available will be used. The actual sampling\n"
68 : " interval used will be reported.\n"
69 : " --output-dir=DIR Specifies the output directory into which trace\n"
70 : " files will be written.\n"
71 : "\n";
72 :
73 : // Parses the bucket size. Leaves the value unchanged if it is not specified.
74 : bool ParseBucketSize(const base::CommandLine* command_line,
75 E : size_t* log2_bucket_size) {
76 E : DCHECK(command_line != NULL);
77 E : DCHECK(log2_bucket_size != NULL);
78 :
79 E : if (!command_line->HasSwitch(SamplerApp::kBucketSize))
80 E : return true;
81 :
82 E : std::string s = command_line->GetSwitchValueASCII(SamplerApp::kBucketSize);
83 E : size_t bucket_size = 0;
84 E : if (!base::StringToSizeT(s, &bucket_size)) {
85 E : LOG(ERROR) << "--" << SamplerApp::kBucketSize << " must be an integer.";
86 E : return false;
87 : }
88 E : if (!common::IsPowerOfTwo(bucket_size)) {
89 E : LOG(ERROR) << "--" << SamplerApp::kBucketSize << " must be a power of 2.";
90 E : return false;
91 : }
92 E : if (bucket_size < 4) {
93 E : LOG(ERROR) << "--" << SamplerApp::kBucketSize << " must be >= 4.";
94 E : return false;
95 : }
96 :
97 : // Convert to a power of two, as required by the SamplingProfiler API.
98 E : *log2_bucket_size = 2;
99 E : while (bucket_size != 4) {
100 E : bucket_size >>= 1;
101 E : ++(*log2_bucket_size);
102 E : }
103 :
104 E : return true;
105 E : }
106 :
107 : // Parses the sampling interval. Leaves the value unchanged if it is not
108 : // specified.
109 : bool ParseSamplingInterval(const base::CommandLine* command_line,
110 E : base::TimeDelta* sampling_interval) {
111 E : DCHECK(command_line != NULL);
112 E : DCHECK(sampling_interval != NULL);
113 :
114 E : if (!command_line->HasSwitch(SamplerApp::kSamplingInterval))
115 E : return true;
116 :
117 : std::string s = command_line->GetSwitchValueASCII(
118 E : SamplerApp::kSamplingInterval);
119 E : double d = 0;
120 E : if (!base::StringToDouble(s, &d)) {
121 E : LOG(ERROR) << "--" << SamplerApp::kSamplingInterval << " must be a double.";
122 E : return false;
123 : }
124 E : if (d <= 0) {
125 i : LOG(ERROR) << "-- " << SamplerApp::kSamplingInterval
126 : << " must be positive.";
127 i : return false;
128 : }
129 :
130 E : int64 us = static_cast<int64>(1000000 * d);
131 E : if (us <= 0) {
132 E : LOG(ERROR) << "--" << SamplerApp::kSamplingInterval
133 : << " must be at least 1us.";
134 E : return false;
135 : }
136 :
137 : // TimeDelta has its finest resolution in microseconds, so we convert to
138 : // that.
139 E : *sampling_interval = base::TimeDelta::FromMicroseconds(us);
140 E : return true;
141 E : }
142 :
143 : // A utility function for converting a time delta to a human readable string.
144 i : const std::string TimeDeltaToString(const base::TimeDelta& td) {
145 : // Aliases to constants from base::Time (which have overly long names).
146 i : const int64& kMillisecond = base::Time::kMicrosecondsPerMillisecond;
147 i : const int64& kSecond = base::Time::kMicrosecondsPerSecond;
148 i : const int64& kMinute = base::Time::kMicrosecondsPerMinute;
149 i : const int64& kHour = base::Time::kMicrosecondsPerHour;
150 i : const int64& kDay = base::Time::kMicrosecondsPerDay;
151 i : int64 us = td.InMicroseconds();
152 :
153 i : if (us == 0)
154 i : return "0s";
155 :
156 i : bool negative = us < 0;
157 i : if (negative)
158 i : us *= -1;
159 :
160 i : std::string s;
161 i : if (negative)
162 i : s = "-";
163 :
164 : // Special case: We're less than a second.
165 i : if (us < kSecond) {
166 : // We're in the hundreds of milliseconds.
167 i : if (us >= 100 * kMillisecond) {
168 i : s.append(base::StringPrintf("%.6fs", static_cast<double>(us) / kSecond));
169 i : } else if (us >= kMillisecond) {
170 : // We're in the milliseconds.
171 : s.append(base::StringPrintf("%.3fms",
172 i : static_cast<double>(us) / kMillisecond));
173 i : } else {
174 : // We're in microseconds.
175 i : s.append(base::StringPrintf("%lldus", us));
176 : }
177 i : return s;
178 : }
179 :
180 i : int64 days = us / kDay;
181 i : int64 hours = (us % kDay) / kHour;
182 i : int64 minutes = (us % kHour) / kMinute;
183 i : int64 seconds = (us % kMinute) / kSecond;
184 i : us %= kSecond;
185 :
186 i : if (days > 0)
187 i : s.append(base::StringPrintf("%lldd", days));
188 i : if (hours > 0)
189 i : s.append(base::StringPrintf("%lldh", hours));
190 i : if (minutes > 0)
191 i : s.append(base::StringPrintf("%lldm", minutes));
192 i : if (seconds > 0 || us > 0)
193 i : s.append(base::StringPrintf("%lld.%06llds", seconds, us));
194 :
195 i : return s;
196 i : }
197 :
198 : // Sets the sampling interval used across all sampling profilers.
199 E : bool SetSamplingInterval(base::TimeDelta* sampling_interval) {
200 E : bool use_system_default = sampling_interval->ToInternalValue() == 0;
201 :
202 E : if (!use_system_default) {
203 : // Set the sampling interval.
204 E : if (!SamplingProfiler::SetSamplingInterval(*sampling_interval)) {
205 i : LOG(ERROR) << "SetSamplingInterval failed.";
206 i : return false;
207 : }
208 : }
209 :
210 : // Get the actual sampling interval.
211 E : base::TimeDelta actual_sampling_interval;
212 E : if (!SamplingProfiler::GetSamplingInterval(&actual_sampling_interval)) {
213 i : LOG(ERROR) << "GetSamplingInterval failed.";
214 i : return false;
215 : }
216 :
217 E : if (use_system_default) {
218 : // If we're using the system default then report it.
219 i : LOG(INFO) << "Using system default sampling interval of "
220 : << TimeDeltaToString(actual_sampling_interval) << ".";
221 i : } else {
222 : // If the actual sampling interval and the requested one don't match, then
223 : // output a warning.
224 E : if (actual_sampling_interval != *sampling_interval) {
225 i : LOG(WARNING) << "Requested sampling interval of "
226 : << TimeDeltaToString(*sampling_interval)
227 : << " but actual sampling interval is "
228 : << TimeDeltaToString(actual_sampling_interval) << ".";
229 : }
230 : }
231 :
232 E : *sampling_interval = actual_sampling_interval;
233 :
234 E : return true;
235 E : }
236 :
237 : // Populates a vector of active process IDs on the system. By the time has
238 : // returned some of the PIDs may no longer be active, and others may have
239 : // started. Returns true on success, false otherwise.
240 : typedef std::vector<DWORD> PidVector;
241 E : bool GetRunningProcessIds(PidVector* pids) {
242 E : DCHECK(pids != NULL);
243 :
244 : // Start with a fairly large size.
245 E : pids->resize(512);
246 E : while (true) {
247 E : DWORD bytes_avail = pids->size() * sizeof(PidVector::value_type);
248 E : DWORD bytes_used = 0;
249 E : BOOL result = ::EnumProcesses(&((*pids)[0]), bytes_avail, &bytes_used);
250 E : if (!result) {
251 i : DWORD error = ::GetLastError();
252 i : LOG(ERROR) << "EnumProcess failed: " << common::LogWe(error);
253 i : return false;
254 : }
255 :
256 : // We know that we've finished reading the list if the system call didn't
257 : // use the entire available buffer. Shrink it back down to minimum size
258 : // and return it.
259 E : if (bytes_used < bytes_avail) {
260 E : size_t pid_count = bytes_used / sizeof(PidVector::value_type);
261 E : pids->resize(pid_count);
262 E : return true;
263 : }
264 :
265 : // Making it to this point means there wasn't enough room for all of the
266 : // PIDs. Grow bigger and try again.
267 i : pids->resize(pids->size() * 2);
268 i : }
269 E : }
270 :
271 : // Opens the given process. If the process no longer exists or if access is
272 : // denied this returns true but sets @p process to NULL. If it fails for any
273 : // other reason this returns false. Upon success @p process will be set to the
274 : // process handle (which must be closed by the caller) and returns true.
275 E : bool GetProcessHandle(DWORD pid, HANDLE* process) {
276 E : DCHECK(process != NULL);
277 :
278 : // Get a handle to the process.
279 E : const DWORD kDesiredAccess = PROCESS_QUERY_INFORMATION | PROCESS_VM_READ;
280 E : *process = ::OpenProcess(kDesiredAccess, FALSE /* inherit_handle */, pid);
281 E : if (*process != NULL)
282 E : return true;
283 :
284 i : DWORD error = ::GetLastError();
285 :
286 : // If access is denied this is not an unexpected failure and we simply
287 : // return an empty module list. If the PID is not valid (the process has
288 : // since shut down) we can also safely ignore failure.
289 i : if (error == ERROR_ACCESS_DENIED || error == ERROR_INVALID_PARAMETER)
290 i : return true;
291 :
292 : // Getting here means we were unable to open a handle to the process.
293 i : LOG(ERROR) << "OpenProcess failed: " << common::LogWe(error);
294 i : return false;
295 E : }
296 :
297 : // Populates a vector of module handles for the given process. By the time this
298 : // call has returned some modules may no longer be in memory and others may
299 : // have been loaded. If the process is unable to be read because it is 64-bit
300 : // then this will return an empty module list. Returns true on success, false
301 : // otherwise.
302 : typedef std::vector<HMODULE> HmoduleVector;
303 E : bool GetProcessModules(HANDLE process, HmoduleVector* modules) {
304 E : DCHECK(process != NULL);
305 E : DCHECK(modules != NULL);
306 :
307 E : modules->resize(32);
308 E : while (true) {
309 E : DWORD bytes_avail = modules->size() * sizeof(HmoduleVector::value_type);
310 E : DWORD bytes_used = 0;
311 : if (!::EnumProcessModules(process, &modules->at(0),
312 E : bytes_avail, &bytes_used)) {
313 i : DWORD error = ::GetLastError();
314 :
315 : // Trying to enumerate the modules of a 64-bit process from this 32-bit
316 : // process is not possible. We simply return an empty module list.
317 i : if (error == ERROR_PARTIAL_COPY) {
318 i : modules->clear();
319 i : return true;
320 : }
321 :
322 i : LOG(ERROR) << "EnumProcessModules failed: " << common::LogWe(error);
323 i : return false;
324 : }
325 :
326 : // We know that we've finished reading the list if the system call didn't
327 : // use the entire available buffer. Shrink it back down to minimum size
328 : // and return it.
329 E : if (bytes_used < bytes_avail) {
330 E : size_t module_count = bytes_used / sizeof(HmoduleVector::value_type);
331 E : modules->resize(module_count);
332 E : return true;
333 : }
334 :
335 : // Making it to this point means that there wasn't enough room for all of
336 : // the modules. Grow bigger and try again.
337 i : modules->resize(modules->size() * 2);
338 i : }
339 :
340 i : return true;
341 E : }
342 :
343 : // Gets the signature of the given loaded module. Returns true on success,
344 : // false otherwise.
345 : bool GetModuleSignature(HANDLE process,
346 : HMODULE module,
347 E : SamplerApp::ModuleSignature* module_sig) {
348 E : DCHECK(process != NULL);
349 E : DCHECK(module != NULL);
350 E : DCHECK(module_sig != NULL);
351 :
352 E : uint8 buffer[4096] = {};
353 : static_assert(
354 : sizeof(buffer) >= sizeof(IMAGE_DOS_HEADER) + sizeof(IMAGE_NT_HEADERS),
355 : "buffer must be at least as big as headers.");
356 :
357 : // Read the first page of the module from the remote process. We use
358 : // this to get the module headers so we can grab its signature.
359 E : SIZE_T bytes_read = 0;
360 : if (!::ReadProcessMemory(process, module, buffer, sizeof(buffer),
361 E : &bytes_read)) {
362 i : DWORD error = ::GetLastError();
363 i : LOG(ERROR) << "ReadProcessMemory failed: " << common::LogWe(error);
364 i : return false;
365 : }
366 E : if (bytes_read != sizeof(buffer)) {
367 i : LOG(ERROR) << "ReadProcessMemory only performed a partial read.";
368 i : return false;
369 : }
370 :
371 : // Get the DOS header and make sure the NT headers are contained entirely in
372 : // the buffer.
373 : const IMAGE_DOS_HEADER* dos_header =
374 E : reinterpret_cast<const IMAGE_DOS_HEADER*>(buffer);
375 E : if (dos_header->e_lfanew + sizeof(IMAGE_NT_HEADERS) > sizeof(buffer)) {
376 i : LOG(ERROR) << "NT headers not contained in buffer.";
377 i : return false;
378 : }
379 :
380 : // Grab the NT headers.
381 : const IMAGE_NT_HEADERS* nt_headers =
382 E : reinterpret_cast<const IMAGE_NT_HEADERS*>(buffer + dos_header->e_lfanew);
383 :
384 : // Extract the signature.
385 E : module_sig->checksum = nt_headers->OptionalHeader.CheckSum;
386 E : module_sig->size = nt_headers->OptionalHeader.SizeOfImage;
387 E : module_sig->time_date_stamp = nt_headers->FileHeader.TimeDateStamp;
388 :
389 E : return true;
390 E : }
391 :
392 : typedef base::Callback<void (const SampledModuleCache::Module*)>
393 : StartProfilingCallback;
394 :
395 : // Attaches to the running process with the specified PID and iterates over
396 : // its modules. If any of them is found in the list of modules to be profiled
397 : // adds the process/module pair to the sample module cache.
398 : bool InspectProcessModules(DWORD pid,
399 : SamplerApp::ModuleSignatureSet& module_sigs,
400 : StartProfilingCallback callback,
401 E : SampledModuleCache* cache) {
402 E : DCHECK(!callback.is_null());
403 E : DCHECK(cache != NULL);
404 :
405 E : base::win::ScopedHandle handle;
406 : HANDLE temp_handle;
407 E : if (!GetProcessHandle(pid, &temp_handle))
408 i : return false;
409 E : handle.Set(temp_handle);
410 :
411 : // GetProcessHandle can succeed but return no handle. In this case the
412 : // process has since exited.
413 E : if (!handle.IsValid())
414 i : return true;
415 :
416 : // Get a list of modules in the process.
417 E : HmoduleVector modules;
418 E : if (!GetProcessModules(handle.Get(), &modules))
419 i : return false;
420 :
421 : // Iterate over the modules in the process.
422 E : for (size_t i = 0; i < modules.size(); ++i) {
423 E : SamplerApp::ModuleSignature module_sig = {};
424 E : if (!GetModuleSignature(handle.Get(), modules[i], &module_sig))
425 i : return false;
426 :
427 : // Skip over this module if its not in the set of modules of interest.
428 E : if (module_sigs.find(module_sig) == module_sigs.end())
429 E : continue;
430 :
431 : // Add this module to the list of those being profiled.
432 : SampledModuleCache::ProfilingStatus status =
433 E : SampledModuleCache::kProfilingStarted;
434 E : const SampledModuleCache::Module* module = NULL;
435 E : if (!cache->AddModule(handle.Get(), modules[i], &status, &module))
436 i : return false;
437 :
438 : // If this module was just added for the first time then invoke the
439 : // testing seam callback.
440 E : if (status == SampledModuleCache::kProfilingStarted)
441 E : callback.Run(module);
442 E : }
443 :
444 E : return true;
445 E : }
446 :
447 : // Writes a trace data object to a trace file, preceding it with a record
448 : // prefix and trace-file segment header as necessary.
449 : template<typename TraceDataType>
450 : bool WriteTraceRecord(const TraceDataType* trace_data,
451 : size_t size,
452 : TraceEventType data_type,
453 E : TraceFileWriter* writer) {
454 E : DCHECK(writer != NULL);
455 :
456 E : std::vector<uint8> buffer;
457 E : common::VectorBufferWriter w(&buffer);
458 :
459 : // Write the record prefix for the segment header.
460 E : RecordPrefix record = {};
461 E : record.timestamp = trace::common::GetTsc();
462 E : record.size = sizeof(TraceFileSegmentHeader);
463 E : record.type = TraceFileSegmentHeader::kTypeId;
464 E : record.version.hi = TRACE_VERSION_HI;
465 E : record.version.lo = TRACE_VERSION_LO;
466 E : if (!w.Write(record))
467 i : return false;
468 :
469 : // Write the segment header.
470 E : TraceFileSegmentHeader segment = {};
471 E : segment.thread_id = 0;
472 E : segment.segment_length = sizeof(RecordPrefix) + size;
473 E : if (!w.Write(segment))
474 i : return false;
475 :
476 : // Now write a record-prefix for the actual data.
477 E : record.size = size;
478 E : record.type = data_type;
479 E : if (!w.Write(record))
480 i : return false;
481 :
482 : // Write the actual data.
483 E : if (!w.Write(size, reinterpret_cast<const void*>(trace_data)))
484 i : return false;
485 :
486 : // Align the output to the block size.
487 E : if (!w.Align(writer->block_size()))
488 i : return false;
489 :
490 : // Write the whole chunk of data.
491 E : if (!writer->WriteRecord(buffer.data(), buffer.size()))
492 i : return false;
493 :
494 E : return true;
495 E : }
496 :
497 : // Output a TRACE_PROCESS_ATTACH_EVENT for |module|. This allows the grinder
498 : // to tie subsequent sample data to a module on disk.
499 : bool WriteTraceModuleDataRecord(const SampledModuleCache::Module* module,
500 E : TraceFileWriter* writer) {
501 E : DCHECK(module != NULL);
502 E : DCHECK(writer != NULL);
503 :
504 E : TraceModuleData module_data = {};
505 E : module_data.module_base_addr = reinterpret_cast<ModuleAddr>(module->module());
506 E : module_data.module_base_size = module->module_size();
507 E : module_data.module_checksum = module->module_checksum();
508 E : module_data.module_time_date_stamp = module->module_time_date_stamp();
509 :
510 E : base::FilePath basename = module->module_path().BaseName();
511 : ::wcsncpy(module_data.module_name, basename.value().c_str(),
512 E : arraysize(module_data.module_name) - 1);
513 :
514 : ::wcsncpy(module_data.module_exe, module->module_path().value().c_str(),
515 E : arraysize(module_data.module_exe) - 1);
516 :
517 : // We simulate a 'process attached to module' event. The sampling is across
518 : // all threads in a process, so we can't actually tie the data to any
519 : // particular thread.
520 : if (!WriteTraceRecord(&module_data, sizeof(module_data),
521 E : TRACE_PROCESS_ATTACH_EVENT, writer)) {
522 i : return false;
523 : }
524 :
525 E : return true;
526 E : }
527 :
528 : // Converts the sample data in |module| to a TraceSampleData buffer and outputs
529 : // it to the provided TraceFileWriter.
530 : bool WriteTraceSampleDataRecord(uint64 sampling_interval_in_cycles,
531 : const SampledModuleCache::Module* module,
532 E : TraceFileWriter* writer) {
533 E : DCHECK(module != NULL);
534 E : DCHECK(writer != NULL);
535 :
536 E : const ULONG* buckets = module->profiler().buckets().data();
537 E : size_t bucket_count = module->profiler().buckets().size();
538 E : DCHECK_LT(0u, bucket_count);
539 :
540 : // Calculate the size of the buffer required to store the samples.
541 : size_t size = offsetof(TraceSampleData, buckets) +
542 E : sizeof(buckets[0]) * bucket_count;
543 :
544 E : std::vector<uint8> buffer(size);
545 E : TraceSampleData* data = reinterpret_cast<TraceSampleData*>(buffer.data());
546 :
547 : static_assert(sizeof(buckets[0]) == sizeof(data->buckets[0]),
548 : "buckets have mismatched sizes.");
549 :
550 : // Populate the TraceSampleData structure.
551 E : data->module_base_addr = reinterpret_cast<ModuleAddr>(module->module());
552 E : data->module_size = module->module_size();
553 E : data->module_checksum = module->module_checksum();
554 E : data->module_time_date_stamp = module->module_time_date_stamp();
555 E : data->bucket_size = 1 << module->log2_bucket_size();
556 E : data->bucket_start = reinterpret_cast<ModuleAddr>(module->buckets_begin());
557 E : data->bucket_count = bucket_count;
558 E : data->sampling_start_time = module->profiling_start_time();
559 E : data->sampling_end_time = module->profiling_stop_time();
560 E : data->sampling_interval = sampling_interval_in_cycles;
561 :
562 : // Copy the samples into the buffer.
563 E : ::memcpy(data->buckets, buckets, sizeof(buckets[0]) * bucket_count);
564 :
565 E : if (!WriteTraceRecord(data, size, TRACE_SAMPLE_DATA, writer))
566 i : return false;
567 :
568 E : return true;
569 E : }
570 :
571 : } // namespace
572 :
573 : const char SamplerApp::kBlacklistPids[] = "blacklist-pids";
574 : const char SamplerApp::kBucketSize[] = "bucket-size";
575 : const char SamplerApp::kPids[] = "pids";
576 : const char SamplerApp::kSamplingInterval[] = "sampling-interval";
577 : const char SamplerApp::kOutputDir[] = "output-dir";
578 :
579 : const size_t SamplerApp::kDefaultLog2BucketSize = 2;
580 :
581 E : base::Lock SamplerApp::console_ctrl_lock_;
582 : SamplerApp* SamplerApp::console_ctrl_owner_ = NULL;
583 :
584 : SamplerApp::SamplerApp()
585 : : application::AppImplBase("Sampler"),
586 : blacklist_pids_(true),
587 : log2_bucket_size_(kDefaultLog2BucketSize),
588 : sampling_interval_(),
589 : running_(true),
590 E : sampling_interval_in_cycles_(0) {
591 E : }
592 :
593 E : SamplerApp::~SamplerApp() {
594 E : }
595 :
596 E : bool SamplerApp::ParseCommandLine(const base::CommandLine* command_line) {
597 E : DCHECK(command_line != NULL);
598 :
599 E : if (command_line->HasSwitch("help"))
600 i : return PrintUsage(command_line->GetProgram(), "");
601 :
602 : // Parse the profiler parameters.
603 : if (!ParseBucketSize(command_line, &log2_bucket_size_) ||
604 E : !ParseSamplingInterval(command_line, &sampling_interval_)) {
605 E : return PrintUsage(command_line->GetProgram(), "");
606 : }
607 :
608 : // By default we set up an empty PID blacklist. This means that all PIDs
609 : // will be profiled.
610 E : if (command_line->HasSwitch(kPids)) {
611 : // If PIDs have been specified then parse them.
612 E : if (!ParsePids(command_line->GetSwitchValueASCII(kPids)))
613 E : return PrintUsage(command_line->GetProgram(), "");
614 :
615 E : blacklist_pids_ = command_line->HasSwitch(kBlacklistPids);
616 : }
617 :
618 E : output_dir_ = command_line->GetSwitchValuePath(kOutputDir);
619 :
620 E : const base::CommandLine::StringVector& args = command_line->GetArgs();
621 E : if (args.size() == 0) {
622 : return PrintUsage(command_line->GetProgram(),
623 E : "Must specify at least one module to profile.");
624 : }
625 :
626 : // Parse the list of modules to profile.
627 E : for (size_t i = 0; i < args.size(); ++i) {
628 E : ModuleSignature sig = {};
629 E : if (!GetModuleSignature(base::FilePath(args[i]), &sig))
630 E : return PrintUsage(command_line->GetProgram(), "");
631 E : module_sigs_.insert(sig);
632 E : }
633 :
634 E : return true;
635 E : }
636 :
637 E : int SamplerApp::Run() {
638 : // Grab the console control if we can.
639 : {
640 E : base::AutoLock auto_lock(console_ctrl_lock_);
641 E : if (console_ctrl_owner_ == NULL) {
642 E : if (!::SetConsoleCtrlHandler(&OnConsoleCtrl, TRUE)) {
643 i : DWORD error = ::GetLastError();
644 i : LOG(ERROR) << "SetConsoleCtrlHandler failed: " << common::LogWe(error);
645 i : return false;
646 : }
647 E : console_ctrl_owner_ = this;
648 : }
649 E : }
650 :
651 E : int i = RunImpl();
652 :
653 : // Clean up the console control hook if we own it.
654 : {
655 E : base::AutoLock auto_lock(console_ctrl_lock_);
656 E : if (console_ctrl_owner_ == this) {
657 E : if (!::SetConsoleCtrlHandler(&OnConsoleCtrl, FALSE)) {
658 i : DWORD error = ::GetLastError();
659 i : LOG(ERROR) << "SetConsoleCtrlHandler failed: " << common::LogWe(error);
660 i : return false;
661 : }
662 E : console_ctrl_owner_ = NULL;
663 : }
664 E : }
665 :
666 E : return i;
667 E : }
668 :
669 E : int SamplerApp::RunImpl() {
670 : // Ensure the output directory exists.
671 E : if (!output_dir_.empty()) {
672 E : if (!base::PathExists(output_dir_)) {
673 E : LOG(INFO) << "Creating output directory \"" << output_dir_.value()
674 : << "\".";
675 : }
676 E : if (!base::CreateDirectory(output_dir_)) {
677 i : LOG(ERROR) << "Failed to create output directory \""
678 : << output_dir_.value() << "\".";
679 i : return false;
680 : }
681 : }
682 :
683 E : if (!SetSamplingInterval(&sampling_interval_))
684 i : return 1;
685 :
686 : // TODO(chrisha): Output the clock information to the trace file. This should
687 : // be part of the header!
688 :
689 : // Get the system clock information and calculate our sampling interval in
690 : // system clock cycles.
691 E : trace::common::ClockInfo clock_info = {};
692 E : trace::common::GetClockInfo(&clock_info);
693 E : double interval_in_seconds = sampling_interval_.InSecondsF();
694 : sampling_interval_in_cycles_ =
695 E : interval_in_seconds * clock_info.tsc_info.frequency;
696 :
697 E : SampledModuleCache cache(log2_bucket_size_);
698 : cache.set_dead_module_callback(
699 E : base::Bind(&SamplerApp::OnDeadModule, base::Unretained(this)));
700 :
701 : // These are used for keeping track of how many modules are being profiled.
702 E : size_t process_count = 0;
703 E : size_t module_count = 0;
704 :
705 : // Sit in a loop, actively monitoring running processes.
706 E : while (running()) {
707 : // Mark all profiling module as dead. If they aren't remarked as alive after
708 : // iterating through processes and modules then they will be reaped and
709 : // their profile data written to disk.
710 E : cache.MarkAllModulesDead();
711 :
712 E : PidVector pids;
713 E : if (!GetRunningProcessIds(&pids))
714 i : return 1;
715 :
716 : // Those PIDs in the pids_ filter that aren't seen at all in the list of
717 : // running processes have to be removed so that they aren't re-filtered if
718 : // that PID is reused again. We keep track of the PIDs that have been seen
719 : // in every iteration here.
720 E : PidSet filtered_pids;
721 :
722 : // Iterate over the processes.
723 E : for (size_t i = 0; i < pids.size(); ++i) {
724 E : DWORD pid = pids[i];
725 :
726 E : if (blacklist_pids_) {
727 : // We have a blacklist filter. Skip this process if it is in the
728 : // blacklist.
729 i : if (pids_.find(pid) != pids_.end()) {
730 i : filtered_pids.insert(pid);
731 i : continue;
732 : }
733 i : } else {
734 : // If our PID filter is empty then we have no more work to do, so
735 : // we can skip out this loop.
736 E : if (pids_.empty()) {
737 i : LOG(INFO) << "Whitelist is empty, no more work to do.";
738 i : set_running(false);
739 i : continue;
740 : }
741 :
742 : // We have a whitelist filter. Skip this process if it isn't in the
743 : // whitelist.
744 E : if (pids_.find(pid) == pids_.end()) {
745 E : continue;
746 i : } else {
747 E : filtered_pids.insert(pid);
748 : }
749 : }
750 :
751 : // If we get here the process corresponding to this PID needs to be
752 : // examined.
753 : StartProfilingCallback callback = base::Bind(
754 E : &SamplerApp::OnStartProfiling, base::Unretained(this));
755 E : if (!InspectProcessModules(pid, module_sigs_, callback, &cache))
756 i : return 1;
757 E : }
758 :
759 : // Remove any profiled modules that are 'dead'. This invokes the callback
760 : // and causes the profile information to be written to a trace file.
761 E : cache.RemoveDeadModules();
762 :
763 : // Count the number of actively profiled modules and processes.
764 E : size_t new_process_count = cache.processes().size();
765 E : size_t new_module_count = cache.module_count();
766 :
767 : // Output some quick statistics.
768 : if (process_count != new_process_count ||
769 E : module_count != new_module_count) {
770 E : process_count = new_process_count;
771 E : module_count = new_module_count;
772 E : LOG(INFO) << "Profiling " << module_count << " module"
773 : << (module_count != 1 ? "s" : "") << " across "
774 : << process_count << " process"
775 : << (process_count != 1 ? "es" : "") << ".";
776 : }
777 :
778 : // Update our list of filtered PIDs.
779 E : pids_ = filtered_pids;
780 :
781 : // We poll every second so as not to consume too much CPU time, but to not
782 : // get caught too easily by PID reuse.
783 E : ::Sleep(1000);
784 E : }
785 :
786 : // Mark all modules as dead and remove them. This will clean up any in
787 : // progress profiling data.
788 E : cache.MarkAllModulesDead();
789 E : cache.RemoveDeadModules();
790 :
791 E : return 0;
792 E : }
793 :
794 : bool SamplerApp::PrintUsage(const base::FilePath& program,
795 E : const base::StringPiece& message) {
796 E : if (!message.empty()) {
797 E : ::fwrite(message.data(), 1, message.length(), out());
798 E : ::fprintf(out(), "\n\n");
799 : }
800 :
801 E : ::fprintf(out(), kUsageFormatStr, program.BaseName().value().c_str());
802 :
803 E : return false;
804 E : }
805 :
806 E : bool SamplerApp::ParsePids(const std::string& pids) {
807 : std::vector<std::string> split =
808 E : base::SplitString(pids, ",", base::TRIM_WHITESPACE, base::SPLIT_WANT_ALL);
809 :
810 E : for (size_t i = 0; i < split.size(); ++i) {
811 : // Skip empty strings.
812 E : if (split[i].empty())
813 E : continue;
814 :
815 E : uint32 pid = 0;
816 E : if (!base::StringToUint(split[i], &pid)) {
817 E : LOG(ERROR) << "Unable to parse \"" << split[i] << "\" as a PID.";
818 E : return false;
819 : }
820 E : pids_.insert(pid);
821 E : }
822 :
823 E : if (pids_.empty()) {
824 E : LOG(ERROR) << "--" << kPids << " must not be empty.";
825 E : return false;
826 : }
827 :
828 E : return true;
829 E : }
830 :
831 E : void SamplerApp::OnDeadModule(const SampledModuleCache::Module* module) {
832 E : DCHECK(module != NULL);
833 :
834 : // Invoke our testing seam callback.
835 E : OnStopProfiling(module);
836 :
837 E : const SampledModuleCache::Process* process = module->process();
838 E : DCHECK(process != NULL);
839 :
840 : base::FilePath basename = TraceFileWriter::GenerateTraceFileBaseName(
841 E : process->process_info());
842 E : base::FilePath trace_file_path = output_dir_.Append(basename);
843 :
844 E : LOG(INFO) << "Writing module samples to \"" << trace_file_path.value()
845 : << "\".";
846 :
847 : // TODO(chrisha): If we deal with processes with multiple profiled modules
848 : // or repeatedly loaded and unloaded modules, we could persist a trace
849 : // file writer for each process and use it repeatedly.
850 :
851 E : TraceFileWriter writer;
852 E : if (!writer.Open(trace_file_path))
853 i : return;
854 :
855 E : if (!writer.WriteHeader(process->process_info()))
856 i : return;
857 :
858 E : if (!WriteTraceModuleDataRecord(module, &writer))
859 i : return;
860 :
861 : if (!WriteTraceSampleDataRecord(sampling_interval_in_cycles_, module,
862 E : &writer)) {
863 i : return;
864 : }
865 :
866 E : return;
867 E : }
868 :
869 : bool SamplerApp::GetModuleSignature(
870 E : const base::FilePath& module, ModuleSignature* sig) {
871 E : DCHECK(sig != NULL);
872 :
873 E : pe::PEFile pe_file;
874 E : if (!pe_file.Init(module))
875 E : return false;
876 :
877 E : pe::PEFile::Signature pe_sig;
878 E : pe_file.GetSignature(&pe_sig);
879 :
880 E : sig->size = pe_sig.module_size;
881 E : sig->time_date_stamp = pe_sig.module_time_date_stamp;
882 E : sig->checksum = pe_sig.module_checksum;
883 :
884 E : return true;
885 E : }
886 :
887 : // Handler for Ctrl-C keypresses.
888 i : BOOL WINAPI SamplerApp::OnConsoleCtrl(DWORD ctrl_type) {
889 i : base::AutoLock auto_lock(console_ctrl_lock_);
890 :
891 : // If we're getting messages we should have an owner.
892 i : DCHECK(console_ctrl_owner_ != NULL);
893 :
894 : // We don't handle logoff events.
895 i : if (ctrl_type == CTRL_LOGOFF_EVENT)
896 i : return FALSE;
897 :
898 : // Any console signal means we should shutdown.
899 i : console_ctrl_owner_->set_running(false);
900 :
901 i : LOG(INFO) << "Caught console signal, shutting down.";
902 :
903 i : return TRUE;
904 i : }
905 :
906 E : bool SamplerApp::running() {
907 E : base::AutoLock auto_lock(lock_);
908 E : return running_;
909 E : }
910 :
911 E : void SamplerApp::set_running(bool running) {
912 E : base::AutoLock auto_lock(lock_);
913 E : running_ = running;
914 E : }
915 :
916 E : bool SamplerApp::ModuleSignature::operator<(const ModuleSignature& rhs) const {
917 E : if (size != rhs.size)
918 E : return size < rhs.size;
919 E : if (time_date_stamp != rhs.time_date_stamp)
920 i : return time_date_stamp < rhs.time_date_stamp;
921 E : return checksum < rhs.checksum;
922 E : }
923 :
924 : } // namespace sampler
|