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 : // Implementation of RPC call-trace parsing.
16 :
17 : #include "syzygy/trace/parse/parse_engine_rpc.h"
18 :
19 : #include "base/file_util.h"
20 : #include "base/logging.h"
21 : #include "sawbuck/common/com_utils.h"
22 : #include "syzygy/common/align.h"
23 : #include "syzygy/trace/parse/parse_utils.h"
24 :
25 : using common::AlignUp;
26 : using common::AlignUp64;
27 :
28 : namespace trace {
29 : namespace parser {
30 :
31 E : ParseEngineRpc::ParseEngineRpc() : ParseEngine("RPC", true) {
32 E : }
33 :
34 E : ParseEngineRpc::~ParseEngineRpc() {
35 E : }
36 :
37 : bool ParseEngineRpc::IsRecognizedTraceFile(
38 E : const base::FilePath& trace_file_path) {
39 E : file_util::ScopedFILE trace_file(file_util::OpenFile(trace_file_path, "rb"));
40 E : if (!trace_file.get()) {
41 i : DWORD error = ::GetLastError();
42 i : LOG(ERROR) << "Unable to open '" << trace_file_path.value() << "': "
43 : << com::LogWe(error) << ".";
44 i : return false;
45 : }
46 :
47 E : TraceFileHeader::Signature signature = {};
48 : size_t bytes_read = ::fread(&signature,
49 : 1,
50 : sizeof(signature),
51 E : trace_file.get());
52 E : if (bytes_read < sizeof(signature)) {
53 i : LOG(ERROR) << "Failed to read trace file signature.";
54 i : return false;
55 : }
56 :
57 : return 0 == ::memcmp(&signature,
58 : &TraceFileHeader::kSignatureValue,
59 E : sizeof(signature));
60 E : }
61 :
62 E : bool ParseEngineRpc::OpenTraceFile(const base::FilePath& trace_file_path) {
63 E : trace_file_set_.push_back(trace_file_path);
64 E : return true;
65 E : }
66 :
67 E : bool ParseEngineRpc::CloseAllTraceFiles() {
68 E : trace_file_set_.clear();
69 E : return true;
70 E : }
71 :
72 E : bool ParseEngineRpc::ConsumeAllEvents() {
73 E : TraceFileIter it = trace_file_set_.begin();
74 E : for (; it != trace_file_set_.end(); ++it) {
75 E : if (!ConsumeTraceFile(*it)) {
76 i : LOG(ERROR) << "Failed to consume '" << it->value() << "'.";
77 i : return false;
78 : }
79 E : }
80 :
81 E : return true;
82 E : }
83 :
84 E : bool ParseEngineRpc::ConsumeTraceFile(const base::FilePath& trace_file_path) {
85 E : DCHECK(!trace_file_path.empty());
86 :
87 E : LOG(INFO) << "Processing '" << trace_file_path.BaseName().value() << "'.";
88 :
89 E : file_util::ScopedFILE trace_file(file_util::OpenFile(trace_file_path, "rb"));
90 E : if (!trace_file.get()) {
91 i : DWORD error = ::GetLastError();
92 i : LOG(ERROR) << "Unable to open '" << trace_file_path.value() << "': "
93 : << com::LogWe(error) << ".";
94 i : return false;
95 : }
96 :
97 : // Let's reserve some space for the variable length header.
98 E : const size_t kReasonableHeaderSize = 4096;
99 E : std::vector<uint8> raw_buffer;
100 E : raw_buffer.reserve(kReasonableHeaderSize);
101 E : raw_buffer.resize(sizeof(TraceFileHeader));
102 :
103 : // Populate the buffer.
104 E : DCHECK_EQ(raw_buffer.size(), sizeof(TraceFileHeader));
105 : size_t bytes_read = ::fread(&raw_buffer[0],
106 : 1,
107 : raw_buffer.size(),
108 E : trace_file.get());
109 E : if (bytes_read != raw_buffer.size()) {
110 i : LOG(ERROR) << "Failed to read trace file header.";
111 i : return false;
112 : }
113 :
114 : // Create a typed alias to the raw buffer.
115 : const TraceFileHeader* file_header =
116 E : reinterpret_cast<const TraceFileHeader*>(&raw_buffer[0]);
117 :
118 : // Check the file signature.
119 : if (0 != memcmp(&file_header->signature,
120 : &TraceFileHeader::kSignatureValue,
121 E : sizeof(file_header->signature))) {
122 i : LOG(ERROR) << "Not a valid RPC call-trace file.";
123 i : return false;
124 : }
125 :
126 : // Make sure there's enough room for the variable length part of the header
127 : // and then append read the rest of the header. Note that the underlying raw
128 : // buffer might move when it is resized.
129 E : size_t bytes_to_read = file_header->header_size - raw_buffer.size();
130 E : raw_buffer.resize(file_header->header_size);
131 E : file_header = reinterpret_cast<const TraceFileHeader*>(&raw_buffer[0]);
132 : bytes_read = ::fread(&raw_buffer[sizeof(TraceFileHeader)],
133 : 1,
134 : bytes_to_read,
135 E : trace_file.get());
136 E : if (bytes_read != bytes_to_read) {
137 i : LOG(ERROR) << "Failed to read trace file header.";
138 i : return false;
139 : }
140 :
141 : // Populate the system information which will be fed to the OnProcessStarted
142 : // event.
143 E : TraceSystemInfo system_info = {};
144 E : system_info.os_version_info = file_header->os_version_info;
145 E : system_info.system_info = file_header->system_info;
146 E : system_info.memory_status = file_header->memory_status;
147 :
148 : // Parse the header blob. This fails if there is any extra data, enforcing
149 : // a valid header size as a side effect.
150 E : std::wstring module_path;
151 E : std::wstring command_line;
152 : if (!ParseTraceFileHeaderBlob(*file_header, &module_path, &command_line,
153 E : &system_info.environment_strings)) {
154 i : LOG(ERROR) << "Unable to parse trace file header blob.";
155 i : return false;
156 : }
157 :
158 : // Add the executable's module information to the process map. This is in
159 : // case the executable itself is instrumented, so that trace events will map
160 : // to a module in the process map.
161 E : ModuleInformation module_info = {};
162 E : module_info.base_address = file_header->module_base_address;
163 E : module_info.image_file_name = module_path;
164 E : module_info.module_size = file_header->module_size;
165 E : module_info.image_checksum = file_header->module_checksum;
166 E : module_info.time_date_stamp = file_header->module_time_date_stamp;
167 E : AddModuleInformation(file_header->process_id, module_info);
168 :
169 : // Notify the event handler that a process has started.
170 E : LARGE_INTEGER big_timestamp = {};
171 E : big_timestamp.QuadPart = file_header->timestamp;
172 : base::Time start_time(base::Time::FromFileTime(
173 E : *reinterpret_cast<FILETIME*>(&big_timestamp)));
174 : event_handler_->OnProcessStarted(start_time, file_header->process_id,
175 E : &system_info);
176 :
177 : // Consume the body of the trace file.
178 : uint64 next_segment = AlignUp64(file_header->header_size,
179 E : file_header->block_size);
180 E : scoped_ptr_malloc<uint8> buffer;
181 E : size_t buffer_size = 0;
182 E : while (true) {
183 E : if (::_fseeki64(trace_file.get(), next_segment, SEEK_SET) != 0) {
184 i : LOG(ERROR) << "Failed to seek segment boundary " << next_segment << ".";
185 i : return false;
186 : }
187 :
188 : RecordPrefix segment_prefix;
189 : if (::fread(&segment_prefix,
190 : sizeof(segment_prefix),
191 : 1,
192 E : trace_file.get()) != 1) {
193 E : if (::feof(trace_file.get()))
194 E : break;
195 :
196 i : LOG(ERROR) << "Failed to read segment header prefix.";
197 i : return false;
198 : }
199 :
200 : if (segment_prefix.type != TraceFileSegmentHeader::kTypeId ||
201 : segment_prefix.size != sizeof(TraceFileSegmentHeader) ||
202 : segment_prefix.version.hi != TRACE_VERSION_HI ||
203 E : segment_prefix.version.lo != TRACE_VERSION_LO) {
204 i : LOG(ERROR) << "Unrecognized record prefix for segment header.";
205 i : return false;
206 : }
207 :
208 : TraceFileSegmentHeader segment_header;
209 : if (::fread(&segment_header,
210 : sizeof(segment_header),
211 : 1,
212 E : trace_file.get()) != 1) {
213 i : LOG(ERROR) << "Failed to read segment header.";
214 i : return false;
215 : }
216 :
217 : size_t aligned_size = AlignUp(segment_header.segment_length,
218 E : file_header->block_size);
219 :
220 E : if (aligned_size > buffer_size) {
221 E : buffer.reset(reinterpret_cast<uint8*>(::malloc(aligned_size)));
222 E : buffer_size = aligned_size;
223 : }
224 :
225 : if (::fread(buffer.get(), segment_header.segment_length, 1,
226 E : trace_file.get()) != 1) {
227 i : LOG(ERROR) << "Failed to read segment.";
228 i : return false;
229 : }
230 :
231 : if (!ConsumeSegmentEvents(*file_header,
232 : segment_header,
233 : buffer.get(),
234 E : segment_header.segment_length)) {
235 i : return false;
236 : }
237 :
238 : next_segment = AlignUp64(
239 : next_segment + sizeof(segment_prefix) + sizeof(segment_header) +
240 : segment_header.segment_length,
241 E : file_header->block_size);
242 E : }
243 :
244 E : return true;
245 E : }
246 :
247 : bool ParseEngineRpc::ConsumeSegmentEvents(
248 : const TraceFileHeader& file_header,
249 : const TraceFileSegmentHeader& segment_header,
250 : uint8* buffer,
251 E : size_t buffer_length) {
252 E : DCHECK(buffer != NULL);
253 E : DCHECK(event_handler_ != NULL);
254 :
255 E : EVENT_TRACE event_record = {};
256 :
257 E : event_record.Header.ProcessId = file_header.process_id;
258 E : event_record.Header.ThreadId = segment_header.thread_id;
259 E : event_record.Header.Guid = kCallTraceEventClass;
260 :
261 E : uint8* read_ptr = buffer;
262 E : uint8* end_ptr = read_ptr + buffer_length;
263 :
264 E : while (read_ptr < end_ptr) {
265 E : RecordPrefix* prefix = reinterpret_cast<RecordPrefix*>(read_ptr);
266 E : read_ptr += sizeof(RecordPrefix) + prefix->size;
267 E : if (read_ptr > end_ptr) {
268 : // For batch-oriented records (where the record size is updated after
269 : // the record is initially written) there's a race condition between
270 : // updating the size of the segment and updating the number of items
271 : // in the batch record wherein the client process could be terminated
272 : // leaving a truncated batch record.
273 i : LOG(WARNING) << "Encountered truncated record at end of segment.";
274 i : continue;
275 : }
276 :
277 E : event_record.Header.Class.Type = prefix->type;
278 E : event_record.Header.TimeStamp.QuadPart = prefix->timestamp;
279 E : event_record.MofData = prefix + 1;
280 E : event_record.MofLength = prefix->size;
281 E : if (!DispatchEvent(&event_record)) {
282 i : LOG(ERROR) << "Failed to process event of type " << prefix->type << ".";
283 i : return false;
284 : }
285 :
286 E : if (error_occurred()) {
287 i : return false;
288 : }
289 E : }
290 :
291 E : return true;
292 E : }
293 :
294 : } // namespace trace::parser
295 : } // namespace trace
|