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