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 <windows.h> // NOLINT
16 : #include <stdio.h>
17 : #include <vector>
18 :
19 : #include "base/at_exit.h"
20 : #include "base/command_line.h"
21 : #include "base/file_util.h"
22 : #include "base/logging.h"
23 : #include "base/files/file_path.h"
24 : #include "base/threading/simple_thread.h"
25 : #include "base/win/event_trace_consumer.h"
26 : #include "base/win/event_trace_controller.h"
27 : #include "base/win/scoped_handle.h"
28 : #include "base/win/windows_version.h"
29 : #include "syzygy/common/indexed_frequency_data.h"
30 : #include "syzygy/trace/parse/parser.h"
31 : #include "syzygy/trace/service/service.h"
32 :
33 m : namespace {
34 :
35 m : using trace::parser::Parser;
36 m : using trace::parser::ParseEventHandler;
37 m : using trace::parser::ModuleInformation;
38 :
39 m : const char* GetIndexedDataTypeStr(uint8 data_type) {
40 m : const char* ret = NULL;
41 m : switch (data_type) {
42 m : case common::IndexedFrequencyData::BASIC_BLOCK_ENTRY:
43 m : ret = "basic-block entry counts";
44 m : break;
45 m : case common::IndexedFrequencyData::JUMP_TABLE:
46 m : ret = "jump-table case counts";
47 m : break;
48 m : default:
49 m : NOTREACHED();
50 m : break;
51 m : }
52 m : return ret;
53 m : }
54 :
55 m : class TraceFileDumper : public ParseEventHandler {
56 m : public:
57 m : explicit TraceFileDumper(FILE* file)
58 m : : file_(file ? file : stdout),
59 m : indentation_("") {
60 m : }
61 :
62 m : void PrintFunctionEvent(const char* event_type,
63 m : base::Time time,
64 m : DWORD process_id,
65 m : DWORD thread_id,
66 m : const TraceEnterExitEventData* data) {
67 m : DCHECK(event_type != NULL);
68 m : DCHECK(data != NULL);
69 m : DCHECK(data->function != NULL);
70 m : ::fprintf(file_,
71 m : "[%012lld] %s%s: process-id=%d; thread-id=%d; address=0x%08X\n",
72 m : time.ToInternalValue(),
73 m : indentation_,
74 m : event_type,
75 m : process_id,
76 m : thread_id,
77 m : data->function);
78 m : }
79 :
80 m : void PrintModuleEvent(const char* event_type,
81 m : base::Time time,
82 m : DWORD process_id,
83 m : DWORD thread_id,
84 m : const TraceModuleData* data) {
85 m : DCHECK(event_type != NULL);
86 m : DCHECK(data != NULL);
87 m : DCHECK(data->module_base_addr != NULL);
88 m : ::fprintf(file_,
89 m : "[%012lld] %s: process-id=%d; thread-id=%d;"
90 m : " module-name='%ls';"
91 m : " module-addr=0x%08X; module-size=%d\n",
92 m : time.ToInternalValue(),
93 m : event_type,
94 m : process_id,
95 m : thread_id,
96 m : data->module_name,
97 m : data->module_base_addr,
98 m : data->module_base_size);
99 m : }
100 :
101 m : void PrintOsVersionInfo(base::Time time,
102 m : const OSVERSIONINFOEX& os_version_info) {
103 m : ::fprintf(file_,
104 m : "[%012lld] %sOsVersionInfo: platform_id=%d; product_type=%d; "
105 m : "version=%d.%d; build=%d; service_pack=%d.%d\n",
106 m : time.ToInternalValue(),
107 m : indentation_,
108 m : os_version_info.dwPlatformId,
109 m : os_version_info.wProductType,
110 m : os_version_info.dwMajorVersion,
111 m : os_version_info.dwMinorVersion,
112 m : os_version_info.dwBuildNumber,
113 m : os_version_info.wServicePackMajor,
114 m : os_version_info.wServicePackMinor);
115 m : }
116 :
117 m : void PrintSystemInfo(base::Time time, const SYSTEM_INFO& system_info) {
118 m : ::fprintf(file_,
119 m : "[%012lld] %sSystemInfo: cpu_arch=%d; cpu_count=%d; "
120 m : "cpu_level=%d; cpu_rev=%d\n",
121 m : time.ToInternalValue(),
122 m : indentation_,
123 m : system_info.wProcessorArchitecture,
124 m : system_info.dwNumberOfProcessors,
125 m : system_info.wProcessorLevel,
126 m : system_info.wProcessorRevision);
127 m : }
128 :
129 m : void PrintMemoryStatus(base::Time time, const MEMORYSTATUSEX& memory_status) {
130 m : ::fprintf(file_,
131 m : "[%012lld] %sMemoryStatus: load=%d; total_phys=%lld; "
132 m : "avail_phys=%lld\n",
133 m : time.ToInternalValue(),
134 m : indentation_,
135 m : memory_status.dwMemoryLoad,
136 m : memory_status.ullTotalPhys,
137 m : memory_status.ullAvailPhys);
138 m : }
139 :
140 m : void PrintEnvironmentString(base::Time time,
141 m : const std::wstring& key,
142 m : const std::wstring& value) {
143 m : ::fprintf(file_,
144 m : "[%012lld] %sEnvironment: %ls=%ls\n",
145 m : time.ToInternalValue(),
146 m : indentation_,
147 m : key.c_str(),
148 m : value.c_str());
149 m : }
150 :
151 m : void PrintEnvironmentStrings(base::Time time,
152 m : const TraceEnvironmentStrings& env_strings) {
153 m : for (size_t i = 0; i < env_strings.size(); ++i)
154 m : PrintEnvironmentString(time, env_strings[i].first, env_strings[i].second);
155 m : }
156 :
157 m : virtual void OnProcessStarted(base::Time time,
158 m : DWORD process_id,
159 m : const TraceSystemInfo* data) {
160 m : ::fprintf(file_,
161 m : "[%012lld] OnProcessStarted: process-id=%d\n",
162 m : time.ToInternalValue(),
163 m : process_id);
164 :
165 m : if (data == NULL)
166 m : return;
167 :
168 m : indentation_ = " ";
169 m : PrintOsVersionInfo(time, data->os_version_info);
170 m : PrintSystemInfo(time, data->system_info);
171 m : PrintMemoryStatus(time, data->memory_status);
172 m : PrintEnvironmentStrings(time, data->environment_strings);
173 m : indentation_ = "";
174 m : }
175 :
176 m : virtual void OnProcessEnded(base::Time time, DWORD process_id) {
177 m : ::fprintf(file_,
178 m : "[%012lld] OnProcessEnded: process-id=%d\n",
179 m : time.ToInternalValue(),
180 m : process_id);
181 m : }
182 :
183 m : virtual void OnFunctionEntry(base::Time time,
184 m : DWORD process_id,
185 m : DWORD thread_id,
186 m : const TraceEnterExitEventData* data) {
187 m : PrintFunctionEvent("OnFunctionEntry", time, process_id, thread_id, data);
188 m : }
189 :
190 m : virtual void OnFunctionExit(base::Time time,
191 m : DWORD process_id,
192 m : DWORD thread_id,
193 m : const TraceEnterExitEventData* data) {
194 m : PrintFunctionEvent("OnFunctionEntry", time, process_id, thread_id, data);
195 m : }
196 :
197 m : virtual void OnBatchFunctionEntry(base::Time time,
198 m : DWORD process_id,
199 m : DWORD thread_id,
200 m : const TraceBatchEnterData* data) {
201 m : DCHECK(data != NULL);
202 m : DCHECK_EQ(thread_id, data->thread_id);
203 m : ::fprintf(file_,
204 m : "[%012lld] OnBatchFunctionEntry: " \
205 m : "process-id=%d; thread-id=%d; num-calls=%d\n",
206 m : time.ToInternalValue(),
207 m : process_id,
208 m : thread_id,
209 m : data->num_calls);
210 :
211 : // Explode the batch event into individual function entry events.
212 m : TraceEnterExitEventData new_data = {};
213 m : indentation_ = " ";
214 m : for (size_t i = 0; i < data->num_calls; ++i) {
215 m : new_data.function = data->calls[i].function;
216 m : OnFunctionEntry(time, process_id, thread_id, &new_data);
217 m : }
218 m : indentation_ = "";
219 m : }
220 :
221 m : virtual void OnProcessAttach(base::Time time,
222 m : DWORD process_id,
223 m : DWORD thread_id,
224 m : const TraceModuleData* data) {
225 m : PrintModuleEvent("OnProcessAttach", time, process_id, thread_id, data);
226 m : }
227 :
228 m : virtual void OnProcessDetach(base::Time time,
229 m : DWORD process_id,
230 m : DWORD thread_id,
231 m : const TraceModuleData* data) {
232 m : PrintModuleEvent("OnProcessDetach", time, process_id, thread_id, data);
233 m : }
234 :
235 m : virtual void OnThreadAttach(base::Time time,
236 m : DWORD process_id,
237 m : DWORD thread_id,
238 m : const TraceModuleData* data) {
239 m : PrintModuleEvent("OnThreadAttach", time, process_id, thread_id, data);
240 m : }
241 :
242 m : virtual void OnThreadDetach(base::Time time,
243 m : DWORD process_id,
244 m : DWORD thread_id,
245 m : const TraceModuleData* data) {
246 m : PrintModuleEvent("OnThreadDetach", time, process_id, thread_id, data);
247 m : }
248 :
249 m : virtual void OnInvocationBatch(base::Time time,
250 m : DWORD process_id,
251 m : DWORD thread_id,
252 m : size_t num_invocations,
253 m : const TraceBatchInvocationInfo* data) {
254 m : DCHECK(data != NULL);
255 m : ::fprintf(file_,
256 m : "OnInvocationBatch: process-id=%d; thread-id=%d;\n",
257 m : process_id,
258 m : thread_id);
259 m : for (size_t i = 0; i < num_invocations; ++i) {
260 m : const InvocationInfo& invocation = data->invocations[i];
261 :
262 m : if ((invocation.flags & kCallerIsSymbol) != 0) {
263 m : ::fprintf(file_,
264 m : " caller_sym=0x%X, offs=%d;",
265 m : invocation.caller_symbol_id,
266 m : invocation.caller_offset);
267 m : } else {
268 m : ::fprintf(file_,
269 m : " caller=0x%08X;",
270 m : invocation.caller);
271 m : }
272 :
273 m : if ((invocation.flags & kFunctionIsSymbol) != 0) {
274 m : ::fprintf(file_, " function_sym=0x%X;", invocation.function_symbol_id);
275 m : } else {
276 m : ::fprintf(file_, " function=0x%08X;", invocation.function);
277 m : }
278 :
279 m : ::fprintf(file_,
280 m : " num-calls=%d;\n"
281 m : " cycles-min=%lld; cycles-max=%lld; cycles-sum=%lld\n",
282 m : data->invocations[i].num_calls,
283 m : data->invocations[i].cycles_min,
284 m : data->invocations[i].cycles_max,
285 m : data->invocations[i].cycles_sum);
286 m : }
287 m : }
288 :
289 m : virtual void OnThreadName(base::Time time,
290 m : DWORD process_id,
291 m : DWORD thread_id,
292 m : const base::StringPiece& thread_name) OVERRIDE {
293 m : ::fprintf(file_, "OnThreadName: process-id=%d; thread-id=%d;\n"
294 m : " name=%s\n",
295 m : process_id, thread_id, thread_name.as_string().c_str());
296 m : }
297 :
298 m : virtual void OnIndexedFrequency(
299 m : base::Time time,
300 m : DWORD process_id,
301 m : DWORD thread_id,
302 m : const TraceIndexedFrequencyData* data) OVERRIDE {
303 m : DCHECK(data != NULL);
304 m : ::fprintf(file_,
305 m : "OnIndexedFrequency: process-id=%d; thread-id=%d;\n"
306 m : " module-base-addr=0x%08X; module-base-size=%d\n"
307 m : " module-checksum=0x%08X; module-time-date-stamp=0x%08X\n"
308 m : " frequency-size=%d; data-type=%s; num-entries=%d\n",
309 m : process_id,
310 m : thread_id,
311 m : data->module_base_addr,
312 m : data->module_base_size,
313 m : data->module_checksum,
314 m : data->module_time_date_stamp,
315 m : data->frequency_size,
316 m : GetIndexedDataTypeStr(data->data_type),
317 m : data->num_entries);
318 m : }
319 :
320 m : virtual void OnDynamicSymbol(DWORD process_id,
321 m : uint32 symbol_id,
322 m : const base::StringPiece& symbol_name) OVERRIDE {
323 m : ::fprintf(file_, "OnDynamicSymbol: process-id=%d;\n"
324 m : " symbol_id=%d\n"
325 m : " symbol_name=%s\n",
326 m : process_id, symbol_id, symbol_name.as_string().c_str());
327 m : }
328 :
329 m : virtual void OnSampleData(base::Time Time,
330 m : DWORD process_id,
331 m : const TraceSampleData* data) OVERRIDE {
332 m : DCHECK(data != NULL);
333 :
334 m : uint64 samples = 0;
335 m : for (uint32 i = 0; i < data->bucket_count; ++i)
336 m : samples += data->buckets[i];
337 :
338 m : ::fprintf(file_,
339 m : "OnSampleData: process-id=%d; module-base-addr=0x%08X;\n"
340 m : " module-size=%d; module-checksum=0x%08X;\n"
341 m : " module-time-date-stamp=0x%08X; bucket-size=%d;\n"
342 m : " bucket-start=0x%08x; bucket-count=%d;\n"
343 m : " sampling-start-time=0x%016llx;\n"
344 m : " sampling-end-time=0x%016llx; sampling-rate=0x%016llx;\n"
345 m : " samples=%lld\n",
346 m : process_id,
347 m : data->module_base_addr,
348 m : data->module_size,
349 m : data->module_checksum,
350 m : data->module_time_date_stamp,
351 m : data->bucket_size,
352 m : data->bucket_start,
353 m : data->bucket_count,
354 m : data->sampling_start_time,
355 m : data->sampling_end_time,
356 m : data->sampling_rate,
357 m : samples);
358 m : }
359 :
360 m : private:
361 m : FILE* file_;
362 m : const char* indentation_;
363 :
364 m : DISALLOW_COPY_AND_ASSIGN(TraceFileDumper);
365 m : };
366 :
367 m : bool DumpTraceFiles(FILE* out_file,
368 m : const std::vector<base::FilePath>& file_paths) {
369 m : Parser parser;
370 m : TraceFileDumper dumper(out_file);
371 m : if (!parser.Init(&dumper))
372 m : return false;
373 :
374 m : std::vector<base::FilePath>::const_iterator iter = file_paths.begin();
375 m : for (; iter != file_paths.end(); ++iter) {
376 m : if (!parser.OpenTraceFile(*iter))
377 m : return false;
378 m : }
379 :
380 m : return parser.Consume() && !parser.error_occurred();
381 m : }
382 :
383 m : } // namespace
384 :
385 m : int main(int argc, const char** argv) {
386 m : base::AtExitManager at_exit_manager;
387 m : CommandLine::Init(argc, argv);
388 :
389 m : if (!logging::InitLogging(
390 m : L"",
391 m : logging::LOG_ONLY_TO_SYSTEM_DEBUG_LOG,
392 m : logging::DONT_LOCK_LOG_FILE,
393 m : logging::APPEND_TO_OLD_LOG_FILE,
394 m : logging::ENABLE_DCHECK_FOR_NON_OFFICIAL_RELEASE_BUILDS)) {
395 m : return 1;
396 m : }
397 :
398 m : CommandLine* cmd_line = CommandLine::ForCurrentProcess();
399 m : CHECK(cmd_line != NULL);
400 :
401 m : std::vector<base::FilePath> trace_file_paths;
402 m : for (size_t i = 0; i < cmd_line->GetArgs().size(); ++i)
403 m : trace_file_paths.push_back(base::FilePath(cmd_line->GetArgs()[i]));
404 :
405 m : if (trace_file_paths.empty()) {
406 m : LOG(ERROR) << "No trace file paths specified.";
407 :
408 m : ::fprintf(stderr,
409 m : "Usage: %ls [--out=OUTPUT] TRACE_FILE(s)...\n\n",
410 m : cmd_line->GetProgram().value().c_str());
411 m : return 1;
412 m : }
413 :
414 m : base::FilePath out_file_path(cmd_line->GetSwitchValuePath("out"));
415 m : file_util::ScopedFILE out_file;
416 m : if (!out_file_path.empty()) {
417 m : out_file.reset(file_util::OpenFile(out_file_path, "w"));
418 m : if (out_file.get() == NULL) {
419 m : LOG(ERROR) << "Failed to open output file: '" << out_file_path.value()
420 m : << "'.";
421 m : return 1;
422 m : }
423 m : }
424 :
425 m : if (!DumpTraceFiles(out_file.get(), trace_file_paths)) {
426 m : LOG(ERROR) << "Failed to dump trace files.";
427 m : return 1;
428 m : }
429 :
430 m : return 0;
431 m : }
|