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/trace/service/service.h"
16 :
17 : #include <psapi.h>
18 : #include <userenv.h>
19 :
20 : #include "base/command_line.h"
21 : #include "base/environment.h"
22 : #include "base/file_util.h"
23 : #include "base/files/file_enumerator.h"
24 : #include "base/files/scoped_temp_dir.h"
25 : #include "base/memory/scoped_ptr.h"
26 : #include "base/process/kill.h"
27 : #include "base/process/launch.h"
28 : #include "base/strings/string_util.h"
29 : #include "base/strings/stringprintf.h"
30 : #include "base/strings/utf_string_conversions.h"
31 : #include "gmock/gmock.h"
32 : #include "gtest/gtest.h"
33 : #include "syzygy/common/align.h"
34 : #include "syzygy/common/rpc/helpers.h"
35 : #include "syzygy/core/unittest_util.h"
36 : #include "syzygy/trace/client/client_utils.h"
37 : #include "syzygy/trace/parse/parse_utils.h"
38 : #include "syzygy/trace/protocol/call_trace_defs.h"
39 : #include "syzygy/trace/service/service_rpc_impl.h"
40 : #include "syzygy/trace/service/session_trace_file_writer_factory.h"
41 :
42 : using ::common::rpc::InvokeRpc;
43 : using ::common::rpc::RpcStatus;
44 : using trace::client::TraceFileSegment;
45 :
46 : namespace trace {
47 : namespace service {
48 :
49 : namespace {
50 :
51 : using base::ProcessHandle;
52 : using base::TERMINATION_STATUS_STILL_RUNNING;
53 : using base::win::ScopedHandle;
54 : using ::common::AlignUp;
55 : using trace::parser::ParseEnvironmentStrings;
56 : using trace::parser::ParseTraceFileHeaderBlob;
57 :
58 : // Calculates the size of the given header on disk.
59 E : size_t RoundedSize(const TraceFileHeader& header) {
60 E : return AlignUp(header.header_size, header.block_size);
61 E : }
62 :
63 : class ScopedEnvironment {
64 : public:
65 E : ScopedEnvironment() {
66 E : env_ = ::GetEnvironmentStrings();
67 E : DCHECK(env_ != NULL);
68 E : }
69 :
70 E : ~ScopedEnvironment() {
71 E : ::FreeEnvironmentStrings(env_);
72 E : }
73 :
74 E : const wchar_t* Get() { return env_; }
75 :
76 : private:
77 : wchar_t* env_;
78 : };
79 :
80 : class CallTraceServiceTest : public testing::Test {
81 : public:
82 : typedef testing::Test Super;
83 :
84 : struct MyRecordType {
85 : enum { kTypeId = 0xBEEF };
86 : char message[128];
87 : };
88 :
89 : struct LargeRecordType {
90 : enum { kTypeId = 0xF00D };
91 : // This needs to be bigger than the default buffer size, which is
92 : // 2 MB.
93 : unsigned char binary_data[4 * 1024 * 1024];
94 : };
95 :
96 : CallTraceServiceTest()
97 : : consumer_thread_("profiler-test-consumer-thread"),
98 : consumer_thread_has_started_(
99 : consumer_thread_.StartWithOptions(
100 : base::Thread::Options(base::MessageLoop::TYPE_IO, 0))),
101 : session_trace_file_writer_factory_(consumer_thread_.message_loop()),
102 : call_trace_service_(&session_trace_file_writer_factory_),
103 : rpc_service_instance_manager_(&call_trace_service_),
104 E : client_rpc_binding_(NULL) {
105 E : }
106 :
107 : // Sets up each test invocation.
108 E : virtual void SetUp() OVERRIDE {
109 E : Super::SetUp();
110 :
111 E : ASSERT_TRUE(consumer_thread_has_started_);
112 :
113 : // Create a temporary directory for the call trace files.
114 E : ASSERT_TRUE(temp_dir_.CreateUniqueTempDir());
115 E : ASSERT_TRUE(session_trace_file_writer_factory_.SetTraceFileDirectory(
116 : temp_dir_.path()));
117 :
118 : // We give the service instance a "unique" id so that it does not interfere
119 : // with any other instances or tests that might be concurrently active.
120 E : instance_id_ = base::StringPrintf(L"%d", ::GetCurrentProcessId());
121 E : call_trace_service_.set_instance_id(instance_id_);
122 :
123 : // The instance id needs to be in the environment to be picked up by the
124 : // client library. We prefix the existing environment variable, if any.
125 E : scoped_ptr<base::Environment> env(base::Environment::Create());
126 E : ASSERT_FALSE(env.get() == NULL);
127 E : std::string env_var;
128 E : env->GetVar(::kSyzygyRpcInstanceIdEnvVar, &env_var);
129 E : env_var.insert(0, ";");
130 E : env_var.insert(0, base::WideToUTF8(instance_id_));
131 E : ASSERT_TRUE(env->SetVar(::kSyzygyRpcInstanceIdEnvVar, env_var));
132 E : }
133 :
134 : // Cleans up after each test invocation.
135 E : virtual void TearDown() OVERRIDE {
136 E : FreeMappings();
137 :
138 E : if (client_rpc_binding_) {
139 E : ASSERT_EQ(RPC_S_OK, RpcBindingFree(&client_rpc_binding_));
140 : }
141 E : EXPECT_TRUE(call_trace_service_.Stop());
142 E : EXPECT_FALSE(call_trace_service_.is_running());
143 :
144 E : Super::TearDown();
145 E : }
146 :
147 E : void BindRPC() {
148 E : RPC_WSTR string_binding = NULL;
149 E : std::wstring protocol;
150 E : std::wstring endpoint;
151 :
152 E : ::GetSyzygyCallTraceRpcProtocol(&protocol);
153 E : ::GetSyzygyCallTraceRpcEndpoint(instance_id_, &endpoint);
154 :
155 E : ASSERT_TRUE(client_rpc_binding_ == 0);
156 :
157 E : ASSERT_EQ(RPC_S_OK,
158 : ::RpcStringBindingCompose(NULL, // UUID.
159 : ::common::rpc::AsRpcWstr(&protocol[0]),
160 : NULL, // Address.
161 : ::common::rpc::AsRpcWstr(&endpoint[0]),
162 : NULL, // Options.
163 : &string_binding));
164 :
165 E : ASSERT_EQ(RPC_S_OK, ::RpcBindingFromStringBinding(string_binding,
166 : &client_rpc_binding_));
167 :
168 E : ::RpcStringFree(&string_binding);
169 :
170 E : ASSERT_TRUE(client_rpc_binding_ != 0);
171 E : }
172 :
173 E : void MapSegmentBuffer(TraceFileSegment* segment) {
174 E : ASSERT_TRUE(segment != NULL);
175 :
176 : HANDLE mem_handle =
177 E : reinterpret_cast<HANDLE>(segment->buffer_info.shared_memory_handle);
178 E : uint8*& base_ptr = base_ptr_map_[mem_handle];
179 E : if (base_ptr == NULL) {
180 : base_ptr = reinterpret_cast<uint8*>(
181 : ::MapViewOfFile(mem_handle, FILE_MAP_WRITE, 0, 0,
182 E : segment->buffer_info.mapping_size));
183 : }
184 E : ASSERT_TRUE(base_ptr != NULL);
185 :
186 E : segment->header = NULL; // A real client should write/init the header here.
187 E : segment->base_ptr = base_ptr;
188 E : segment->write_ptr = base_ptr + segment->buffer_info.buffer_offset;
189 E : segment->end_ptr = segment->write_ptr + segment->buffer_info.buffer_size;
190 E : }
191 :
192 E : void FreeMappings() {
193 E : BasePtrMap::iterator it = base_ptr_map_.begin();
194 E : for (; it != base_ptr_map_.end(); ++it)
195 E : ::UnmapViewOfFile(it->second);
196 E : base_ptr_map_.clear();
197 E : }
198 :
199 : void CreateSession(SessionHandle* session_handle,
200 E : TraceFileSegment* segment) {
201 E : ASSERT_TRUE(segment != NULL);
202 E : ZeroMemory(segment, sizeof(*segment));
203 E : BindRPC();
204 :
205 E : unsigned long flags = 0;
206 : RpcStatus status = InvokeRpc(CallTraceClient_CreateSession,
207 : client_rpc_binding_,
208 : session_handle,
209 : &segment->buffer_info,
210 E : &flags);
211 :
212 E : ASSERT_FALSE(status.exception_occurred);
213 E : ASSERT_TRUE(status.result);
214 :
215 E : MapSegmentBuffer(segment);
216 E : }
217 :
218 : void AllocateBuffer(SessionHandle session_handle,
219 E : TraceFileSegment* segment) {
220 : RpcStatus status = InvokeRpc(CallTraceClient_AllocateBuffer,
221 : session_handle,
222 E : &segment->buffer_info);
223 :
224 E : ASSERT_FALSE(status.exception_occurred);
225 E : ASSERT_TRUE(status.result);
226 :
227 E : MapSegmentBuffer(segment);
228 E : }
229 :
230 : void AllocateLargeBuffer(SessionHandle session_handle,
231 : size_t minimum_size,
232 E : TraceFileSegment* segment) {
233 : RpcStatus status = InvokeRpc(CallTraceClient_AllocateLargeBuffer,
234 : session_handle,
235 : minimum_size,
236 E : &segment->buffer_info);
237 :
238 E : ASSERT_FALSE(status.exception_occurred);
239 E : ASSERT_TRUE(status.result);
240 :
241 E : MapSegmentBuffer(segment);
242 E : }
243 :
244 : void ExchangeBuffer(SessionHandle session_handle,
245 E : TraceFileSegment* segment) {
246 : RpcStatus status = InvokeRpc(CallTraceClient_ExchangeBuffer,
247 : session_handle,
248 E : &segment->buffer_info);
249 :
250 E : ASSERT_FALSE(status.exception_occurred);
251 E : ASSERT_TRUE(status.result);
252 :
253 E : MapSegmentBuffer(segment);
254 E : }
255 :
256 : void ReturnBuffer(SessionHandle session_handle,
257 E : TraceFileSegment* segment) {
258 : RpcStatus status = InvokeRpc(CallTraceClient_ReturnBuffer,
259 : session_handle,
260 E : &segment->buffer_info);
261 :
262 E : ASSERT_FALSE(status.exception_occurred);
263 E : ASSERT_TRUE(status.result);
264 :
265 : CallTraceBuffer zeroes;
266 E : ZeroMemory(&zeroes, sizeof(zeroes));
267 E : ASSERT_EQ(0, ::memcmp(&segment->buffer_info, &zeroes, sizeof(zeroes)));
268 :
269 E : segment->write_ptr = NULL;
270 E : segment->end_ptr = NULL;
271 E : segment->header = NULL;
272 E : }
273 :
274 E : void CloseSession(SessionHandle* session_handle) {
275 : // Free all outstanding mappings associated with this session.
276 E : FreeMappings();
277 :
278 : RpcStatus status = InvokeRpc(CallTraceClient_CloseSession,
279 E : session_handle);
280 :
281 E : ASSERT_FALSE(status.exception_occurred);
282 E : ASSERT_TRUE(status.result);
283 :
284 E : ASSERT_TRUE(*session_handle == NULL);
285 E : }
286 :
287 E : void ReadTraceFile(std::string* contents) {
288 : base::FileEnumerator enumerator(temp_dir_.path(),
289 : false,
290 : base::FileEnumerator::FILES,
291 E : L"trace-*.bin");
292 E : base::FilePath trace_file_name(enumerator.Next());
293 E : ASSERT_FALSE(trace_file_name.empty());
294 E : ASSERT_TRUE(enumerator.Next().empty());
295 E : ASSERT_TRUE(base::ReadFileToString(trace_file_name, contents));
296 E : }
297 :
298 E : void ValidateTraceFileHeader(const TraceFileHeader& header) {
299 E : std::wstring cmd_line(::GetCommandLineW());
300 :
301 : wchar_t module_path[MAX_PATH];
302 E : ASSERT_TRUE(::GetModuleFileName(NULL,
303 : &module_path[0],
304 : arraysize(module_path)));
305 :
306 : MODULEINFO module_info;
307 E : ASSERT_TRUE(::GetModuleInformation(::GetCurrentProcess(),
308 : ::GetModuleHandle(NULL),
309 : &module_info,
310 : sizeof(module_info)));
311 :
312 E : ScopedEnvironment env_;
313 E : TraceEnvironmentStrings env_strings;
314 E : ASSERT_TRUE(ParseEnvironmentStrings(env_.Get(), &env_strings));
315 :
316 : // Parse the blob at the end of the header, and make sure its parsable.
317 E : std::wstring blob_module_path;
318 E : std::wstring blob_command_line;
319 E : TraceEnvironmentStrings blob_env_strings;
320 E : ASSERT_TRUE(ParseTraceFileHeaderBlob(header,
321 : &blob_module_path,
322 : &blob_command_line,
323 : &blob_env_strings));
324 :
325 E : ASSERT_EQ(header.server_version.hi, TRACE_VERSION_HI);
326 E : ASSERT_EQ(header.server_version.lo, TRACE_VERSION_LO);
327 E : ASSERT_EQ(header.process_id, ::GetCurrentProcessId());
328 E : ASSERT_EQ(header.module_base_address,
329 : reinterpret_cast<uint32>(module_info.lpBaseOfDll));
330 E : ASSERT_EQ(header.module_size,
331 : static_cast<uint32>(module_info.SizeOfImage));
332 :
333 E : ASSERT_EQ(blob_module_path, std::wstring(module_path));
334 E : ASSERT_EQ(blob_command_line, cmd_line);
335 E : ASSERT_THAT(blob_env_strings, ::testing::ContainerEq(env_strings));
336 E : }
337 :
338 :
339 : // The thread on which the trace file writer will consumer buffers and a
340 : // helper variable whose initialization we use as a trigger to start the
341 : // thread (ensuring its message_loop is created). These declarations MUST
342 : // remain in this order and preceed that of trace_file_writer_factory_;
343 : base::Thread consumer_thread_;
344 : bool consumer_thread_has_started_;
345 :
346 : // The call trace service related objects. These declarations MUST be in
347 : // this order.
348 : SessionTraceFileWriterFactory session_trace_file_writer_factory_;
349 : Service call_trace_service_;
350 : RpcServiceInstanceManager rpc_service_instance_manager_;
351 :
352 : // The directory where trace file output will be written.
353 : base::ScopedTempDir temp_dir_;
354 :
355 : // We give each service instance a "unique" id so that it doesn't interfere
356 : // with any other concurrrently running instances or tests.
357 : std::wstring instance_id_;
358 :
359 : // The client rpc binding.
360 : handle_t client_rpc_binding_;
361 :
362 : // A map to track the base pointers for the buffers returned from the call
363 : // trace service.
364 : typedef std::map<HANDLE, uint8*> BasePtrMap;
365 : BasePtrMap base_ptr_map_;
366 : };
367 :
368 : template<typename T1, typename T2>
369 E : inline ptrdiff_t RawPtrDiff(const T1* p1, const T2* p2) {
370 E : const uint8* const u1 = reinterpret_cast<const uint8*>(p1);
371 E : const uint8* const u2 = reinterpret_cast<const uint8*>(p2);
372 E : return u1 - u2;
373 E : }
374 :
375 : void ControlExternalCallTraceService(const std::string& command,
376 : const std::wstring& instance_id_,
377 E : ScopedHandle* handle) {
378 E : ASSERT_TRUE(command == "start" || command == "stop");
379 E : ASSERT_FALSE(instance_id_.empty());
380 E : ASSERT_FALSE(handle == NULL);
381 :
382 E : CommandLine cmd_line(testing::GetExeRelativePath(L"call_trace_service.exe"));
383 E : cmd_line.AppendArg(command);
384 E : cmd_line.AppendSwitchNative("instance-id", instance_id_);
385 :
386 E : base::LaunchOptions options;
387 E : HANDLE temp_handle = NULL;
388 E : ASSERT_TRUE(base::LaunchProcess(cmd_line, options, &temp_handle));
389 E : handle->Set(temp_handle);
390 E : }
391 :
392 : void StartExternalCallTraceService(const std::wstring& instance_id_,
393 E : ScopedHandle* handle) {
394 E : ControlExternalCallTraceService("start", instance_id_, handle);
395 E : }
396 :
397 : void StopExternalCallTraceService(const std::wstring& instance_id_,
398 E : ScopedHandle* service_handle) {
399 E : ASSERT_FALSE(service_handle == NULL);
400 E : ScopedHandle controller_handle;
401 E : ControlExternalCallTraceService("stop", instance_id_, &controller_handle);
402 :
403 E : static base::TimeDelta k30Seconds = base::TimeDelta::FromSeconds(30);
404 : int exit_code;
405 : EXPECT_TRUE(base::WaitForExitCodeWithTimeout(controller_handle.Take(),
406 : &exit_code,
407 E : k30Seconds));
408 E : EXPECT_EQ(0, exit_code);
409 :
410 : EXPECT_TRUE(base::WaitForExitCodeWithTimeout(service_handle->Take(),
411 : &exit_code,
412 E : k30Seconds));
413 E : EXPECT_EQ(0, exit_code);
414 E : }
415 :
416 E : void CheckIsStillRunning(ProcessHandle handle) {
417 E : ::Sleep(1000);
418 :
419 E : int exit_code = 0;
420 : base::TerminationStatus status = base::GetTerminationStatus(handle,
421 E : &exit_code);
422 :
423 E : ASSERT_EQ(TERMINATION_STATUS_STILL_RUNNING, status);
424 E : ASSERT_EQ(WAIT_TIMEOUT, exit_code);
425 E : }
426 :
427 : } // namespace
428 :
429 E : TEST_F(CallTraceServiceTest, StartStop) {
430 E : EXPECT_TRUE(call_trace_service_.Start(true));
431 E : EXPECT_TRUE(call_trace_service_.Stop());
432 E : }
433 :
434 E : TEST_F(CallTraceServiceTest, StartFailsIfEventNameOccupied) {
435 E : std::wstring event_name;
436 E : ::GetSyzygyCallTraceRpcEventName(instance_id_, &event_name);
437 :
438 : // Create a mutex with the event name, to thwart the event creation.
439 : base::win::ScopedHandle mutex(
440 E : ::CreateMutex(NULL, FALSE, event_name.c_str()));
441 :
442 E : EXPECT_FALSE(call_trace_service_.Start(true));
443 E : }
444 :
445 E : TEST_F(CallTraceServiceTest, StartSetsStopResetsEvent) {
446 E : std::wstring event_name;
447 E : ::GetSyzygyCallTraceRpcEventName(instance_id_, &event_name);
448 :
449 : // Create the event and make sure it's not set.
450 : base::win::ScopedHandle event(
451 E : ::CreateEvent(NULL, FALSE, FALSE, event_name.c_str()));
452 :
453 E : EXPECT_TRUE(call_trace_service_.Start(true));
454 :
455 E : ASSERT_EQ(WAIT_OBJECT_0, ::WaitForSingleObject(event.Get(), 0));
456 :
457 E : EXPECT_TRUE(call_trace_service_.Stop());
458 :
459 E : ASSERT_EQ(WAIT_TIMEOUT, ::WaitForSingleObject(event.Get(), 0));
460 E : }
461 :
462 E : TEST_F(CallTraceServiceTest, IsSingletonPerInstanceId) {
463 : // Create a new instance id to use for this test.
464 E : std::wstring duplicate_id = instance_id_ + L"-foo";
465 :
466 : // Start an external service with the new instance id.
467 E : ScopedHandle handle;
468 E : ASSERT_NO_FATAL_FAILURE(StartExternalCallTraceService(duplicate_id, &handle));
469 E : ASSERT_NO_FATAL_FAILURE(CheckIsStillRunning(handle));
470 :
471 : // Create a new local service instance and see if it starts. We use a new
472 : // instance to pick up the new instance id and to make sure any state in
473 : // the static service instance doesn't compromise the test.
474 E : Service local_call_trace_service(&session_trace_file_writer_factory_);
475 E : local_call_trace_service.set_instance_id(duplicate_id);
476 E : EXPECT_FALSE(local_call_trace_service.Start(true));
477 E : EXPECT_TRUE(local_call_trace_service.Stop());
478 :
479 : // The external instance should still be running.
480 E : CheckIsStillRunning(handle);
481 E : StopExternalCallTraceService(duplicate_id, &handle);
482 E : }
483 :
484 E : TEST_F(CallTraceServiceTest, IsConcurrentWithDifferentInstanceId) {
485 : // Create new instance ids "bar-1" and "bar-2" to use for the external
486 : // and internal services in this test.
487 E : std::wstring external_id = instance_id_ + L"-bar-1";
488 E : std::wstring internal_id = instance_id_ + L"-bar-2";
489 :
490 : // Start an external service with the external instance id.
491 E : ScopedHandle handle;
492 E : ASSERT_NO_FATAL_FAILURE(StartExternalCallTraceService(external_id, &handle));
493 E : ASSERT_NO_FATAL_FAILURE(CheckIsStillRunning(handle));
494 :
495 : // Create a new local service instance and see if it starts. We use a new
496 : // instance to pick up the new instance id and to make sure any state in
497 : // the static service instance doesn't compromise the test.
498 E : Service local_call_trace_service(&session_trace_file_writer_factory_);
499 E : local_call_trace_service.set_instance_id(internal_id);
500 E : EXPECT_TRUE(local_call_trace_service.Start(true));
501 E : EXPECT_TRUE(local_call_trace_service.Stop());
502 :
503 : // The external instance should still be running.
504 E : CheckIsStillRunning(handle);
505 E : StopExternalCallTraceService(external_id, &handle);
506 E : }
507 :
508 E : TEST_F(CallTraceServiceTest, Connect) {
509 E : SessionHandle session_handle = NULL;
510 E : TraceFileSegment segment;
511 :
512 E : ASSERT_TRUE(call_trace_service_.Start(true));
513 E : ASSERT_NO_FATAL_FAILURE(CreateSession(&session_handle, &segment));
514 E : ASSERT_TRUE(call_trace_service_.Stop());
515 :
516 E : std::string trace_file_contents;
517 E : ReadTraceFile(&trace_file_contents);
518 :
519 : TraceFileHeader* header =
520 E : reinterpret_cast<TraceFileHeader*>(&trace_file_contents[0]);
521 :
522 E : ASSERT_NO_FATAL_FAILURE(ValidateTraceFileHeader(*header));
523 : ASSERT_EQ(trace_file_contents.length(),
524 E : RoundedSize(*header) + header->block_size);
525 E : }
526 :
527 E : TEST_F(CallTraceServiceTest, Allocate) {
528 E : SessionHandle session_handle = NULL;
529 E : TraceFileSegment segment1;
530 E : TraceFileSegment segment2;
531 :
532 E : ASSERT_TRUE(call_trace_service_.Start(true));
533 :
534 : // Simulate some work on the main thread.
535 E : ASSERT_NO_FATAL_FAILURE(CreateSession(&session_handle, &segment1));
536 E : segment1.WriteSegmentHeader(session_handle);
537 E : MyRecordType* record1 = segment1.AllocateTraceRecord<MyRecordType>();
538 E : base::strlcpy(record1->message, "Message 1", arraysize(record1->message));
539 E : size_t length1 = segment1.header->segment_length;
540 :
541 : // Simulate some work on a second thread.
542 E : ASSERT_NO_FATAL_FAILURE(AllocateBuffer(session_handle, &segment2));
543 E : segment2.WriteSegmentHeader(session_handle);
544 E : segment2.header->thread_id += 1;
545 E : MyRecordType* record2 = segment2.AllocateTraceRecord<MyRecordType>(256);
546 E : base::strlcpy(record2->message, "Message 2", arraysize(record2->message));
547 E : size_t length2 = segment2.header->segment_length;
548 :
549 : // Commit the buffers in the opposite order.
550 E : ASSERT_NO_FATAL_FAILURE(ReturnBuffer(session_handle, &segment2));
551 E : ASSERT_NO_FATAL_FAILURE(CloseSession(&session_handle));
552 :
553 : // Make sure everything is flushed.
554 E : ASSERT_TRUE(call_trace_service_.Stop());
555 :
556 E : std::string trace_file_contents;
557 E : ASSERT_NO_FATAL_FAILURE(ReadTraceFile(&trace_file_contents));
558 :
559 : TraceFileHeader* header =
560 E : reinterpret_cast<TraceFileHeader*>(&trace_file_contents[0]);
561 :
562 E : ASSERT_NO_FATAL_FAILURE(ValidateTraceFileHeader(*header));
563 : ASSERT_EQ(trace_file_contents.length(),
564 E : RoundedSize(*header) + 3 * header->block_size);
565 :
566 : // Locate and validate the segment header prefix and segment header.
567 : // This should be segment 2.
568 E : size_t offset = AlignUp(header->header_size, header->block_size);
569 : RecordPrefix* prefix =
570 E : reinterpret_cast<RecordPrefix*>(&trace_file_contents[0] + offset);
571 E : ASSERT_EQ(prefix->type, TraceFileSegmentHeader::kTypeId);
572 E : ASSERT_EQ(prefix->size, sizeof(TraceFileSegmentHeader));
573 E : ASSERT_EQ(prefix->version.hi, TRACE_VERSION_HI);
574 E : ASSERT_EQ(prefix->version.lo, TRACE_VERSION_LO);
575 : TraceFileSegmentHeader* segment_header =
576 E : reinterpret_cast<TraceFileSegmentHeader*>(prefix + 1);
577 E : ASSERT_EQ(segment_header->segment_length, length2);
578 E : ASSERT_EQ(segment_header->thread_id, 1 + ::GetCurrentThreadId());
579 :
580 : // The segment header is followed by the message prefix and record.
581 : // This should be message 2.
582 E : prefix = reinterpret_cast<RecordPrefix*>(segment_header + 1);
583 E : ASSERT_EQ(prefix->type, MyRecordType::kTypeId);
584 E : ASSERT_EQ(prefix->size, 256);
585 E : ASSERT_EQ(prefix->version.hi, TRACE_VERSION_HI);
586 E : ASSERT_EQ(prefix->version.lo, TRACE_VERSION_LO);
587 E : MyRecordType* record = reinterpret_cast<MyRecordType*>(prefix + 1);
588 E : ASSERT_STREQ(record->message, "Message 2");
589 :
590 : // Locate and validate the next segment header prefix and segment header.
591 : // This should be segment 1.
592 :
593 : offset = AlignUp(RawPtrDiff(record + 1, &trace_file_contents[0]),
594 E : header->block_size);
595 E : prefix = reinterpret_cast<RecordPrefix*>(&trace_file_contents[0] + offset);
596 E : ASSERT_EQ(prefix->type, TraceFileSegmentHeader::kTypeId);
597 E : ASSERT_EQ(prefix->size, sizeof(TraceFileSegmentHeader));
598 E : ASSERT_EQ(prefix->version.hi, TRACE_VERSION_HI);
599 E : ASSERT_EQ(prefix->version.lo, TRACE_VERSION_LO);
600 E : segment_header = reinterpret_cast<TraceFileSegmentHeader*>(prefix + 1);
601 E : ASSERT_EQ(segment_header->segment_length, length1);
602 E : ASSERT_EQ(segment_header->thread_id, ::GetCurrentThreadId());
603 :
604 : // The segment header is followed by the message prefix and record.
605 : // This should be message 1.
606 E : prefix = reinterpret_cast<RecordPrefix*>(segment_header + 1);
607 E : ASSERT_EQ(prefix->type, MyRecordType::kTypeId);
608 E : ASSERT_EQ(prefix->size, sizeof(MyRecordType));
609 E : ASSERT_EQ(prefix->version.hi, TRACE_VERSION_HI);
610 E : ASSERT_EQ(prefix->version.lo, TRACE_VERSION_LO);
611 E : record = reinterpret_cast<MyRecordType*>(prefix + 1);
612 E : ASSERT_STREQ(record->message, "Message 1");
613 E : }
614 :
615 E : TEST_F(CallTraceServiceTest, AllocateLargeBuffer) {
616 E : SessionHandle session_handle = NULL;
617 E : TraceFileSegment segment1;
618 E : TraceFileSegment segment2;
619 :
620 E : ASSERT_TRUE(call_trace_service_.Start(true));
621 :
622 : // Simulate some work on the main thread.
623 E : ASSERT_NO_FATAL_FAILURE(CreateSession(&session_handle, &segment1));
624 E : segment1.WriteSegmentHeader(session_handle);
625 E : MyRecordType* record1 = segment1.AllocateTraceRecord<MyRecordType>();
626 E : base::strlcpy(record1->message, "Message 1", arraysize(record1->message));
627 E : size_t length1 = segment1.header->segment_length;
628 :
629 : // Allocate a large buffer.
630 : ASSERT_NO_FATAL_FAILURE(AllocateLargeBuffer(
631 : session_handle,
632 : sizeof(LargeRecordType) + sizeof(RecordPrefix),
633 E : &segment2));
634 E : segment2.WriteSegmentHeader(session_handle);
635 E : LargeRecordType* record2 = segment2.AllocateTraceRecord<LargeRecordType>();
636 E : size_t length2 = segment2.header->segment_length;
637 :
638 : // Commit the buffers and close the session.
639 E : ASSERT_NO_FATAL_FAILURE(ReturnBuffer(session_handle, &segment1));
640 E : ASSERT_NO_FATAL_FAILURE(ReturnBuffer(session_handle, &segment2));
641 E : ASSERT_NO_FATAL_FAILURE(CloseSession(&session_handle));
642 :
643 : // Make sure everything is flushed.
644 E : ASSERT_TRUE(call_trace_service_.Stop());
645 :
646 E : std::string trace_file_contents;
647 E : ASSERT_NO_FATAL_FAILURE(ReadTraceFile(&trace_file_contents));
648 :
649 : TraceFileHeader* header =
650 E : reinterpret_cast<TraceFileHeader*>(&trace_file_contents[0]);
651 :
652 E : ASSERT_NO_FATAL_FAILURE(ValidateTraceFileHeader(*header));
653 : ASSERT_EQ(trace_file_contents.length(),
654 : RoundedSize(*header) + 3 * header->block_size +
655 E : sizeof(LargeRecordType));
656 :
657 : // Locate and validate the segment header prefix and segment header.
658 : // This should be segment 1.
659 E : size_t offset = AlignUp(header->header_size, header->block_size);
660 : RecordPrefix* prefix =
661 E : reinterpret_cast<RecordPrefix*>(&trace_file_contents[0] + offset);
662 E : ASSERT_EQ(prefix->type, TraceFileSegmentHeader::kTypeId);
663 E : ASSERT_EQ(prefix->size, sizeof(TraceFileSegmentHeader));
664 E : ASSERT_EQ(prefix->version.hi, TRACE_VERSION_HI);
665 E : ASSERT_EQ(prefix->version.lo, TRACE_VERSION_LO);
666 : TraceFileSegmentHeader* segment_header =
667 E : reinterpret_cast<TraceFileSegmentHeader*>(prefix + 1);
668 E : ASSERT_EQ(segment_header->segment_length, length1);
669 E : ASSERT_EQ(segment_header->thread_id, ::GetCurrentThreadId());
670 :
671 : // The segment header is followed by the message prefix and record.
672 : // This should be message 1.
673 E : prefix = reinterpret_cast<RecordPrefix*>(segment_header + 1);
674 E : ASSERT_EQ(prefix->type, MyRecordType::kTypeId);
675 E : ASSERT_EQ(prefix->size, sizeof(MyRecordType));
676 E : ASSERT_EQ(prefix->version.hi, TRACE_VERSION_HI);
677 E : ASSERT_EQ(prefix->version.lo, TRACE_VERSION_LO);
678 E : MyRecordType* record = reinterpret_cast<MyRecordType*>(prefix + 1);
679 E : ASSERT_STREQ(record->message, "Message 1");
680 :
681 : // Locate and validate the next segment header prefix and segment header.
682 : // This should be segment 2.
683 :
684 : offset = AlignUp(RawPtrDiff(record + 1, &trace_file_contents[0]),
685 E : header->block_size);
686 E : prefix = reinterpret_cast<RecordPrefix*>(&trace_file_contents[0] + offset);
687 E : ASSERT_EQ(prefix->type, TraceFileSegmentHeader::kTypeId);
688 E : ASSERT_EQ(prefix->size, sizeof(TraceFileSegmentHeader));
689 E : ASSERT_EQ(prefix->version.hi, TRACE_VERSION_HI);
690 E : ASSERT_EQ(prefix->version.lo, TRACE_VERSION_LO);
691 E : segment_header = reinterpret_cast<TraceFileSegmentHeader*>(prefix + 1);
692 E : ASSERT_EQ(segment_header->segment_length, length2);
693 E : ASSERT_EQ(segment_header->thread_id, ::GetCurrentThreadId());
694 :
695 : // The segment header is followed by the message prefix and record.
696 : // This should be the large buffer contents.
697 E : prefix = reinterpret_cast<RecordPrefix*>(segment_header + 1);
698 E : ASSERT_EQ(prefix->type, LargeRecordType::kTypeId);
699 E : ASSERT_EQ(prefix->size, sizeof(LargeRecordType));
700 E : ASSERT_EQ(prefix->version.hi, TRACE_VERSION_HI);
701 E : ASSERT_EQ(prefix->version.lo, TRACE_VERSION_LO);
702 : LargeRecordType* large_record =
703 E : reinterpret_cast<LargeRecordType*>(prefix + 1);
704 E : }
705 :
706 E : TEST_F(CallTraceServiceTest, SendBuffer) {
707 E : SessionHandle session_handle = NULL;
708 E : TraceFileSegment segment;
709 :
710 E : const size_t num_blocks = 3;
711 E : size_t segment_length[] = {0, 0, 0};
712 : const char* messages[] = {
713 : "This is message number 1",
714 : "The quick brown fox jumped over the lazy dog.",
715 : "And now for something completely different ...",
716 E : };
717 :
718 E : ASSERT_EQ(arraysize(segment_length), num_blocks);
719 E : ASSERT_EQ(arraysize(messages), num_blocks);
720 :
721 : // Start up the service and create a session
722 E : ASSERT_TRUE(call_trace_service_.Start(true));
723 E : ASSERT_NO_FATAL_FAILURE(CreateSession(&session_handle, &segment));
724 :
725 : // Write the initial block plus num_blocks "message" blocks. The n-th block
726 : // will have n message written to it (i.e., block will have 1 message, the 2nd
727 : // two, etc)
728 E : for (int block = 0; block < num_blocks; ++block) {
729 E : segment.WriteSegmentHeader(session_handle);
730 E : for (int i = 0; i <= block; ++i) {
731 E : MyRecordType* record = segment.AllocateTraceRecord<MyRecordType>();
732 E : base::strlcpy(record->message, messages[i], arraysize(record->message));
733 E : }
734 E : segment_length[block] = segment.header->segment_length;
735 E : ASSERT_NO_FATAL_FAILURE(ExchangeBuffer(session_handle, &segment));
736 E : }
737 E : ASSERT_NO_FATAL_FAILURE(ReturnBuffer(session_handle, &segment));
738 E : ASSERT_NO_FATAL_FAILURE(CloseSession(&session_handle));
739 E : ASSERT_TRUE(call_trace_service_.Stop());
740 E : ASSERT_FALSE(call_trace_service_.is_running());
741 :
742 : // Load the trace file contents into memory.
743 E : std::string trace_file_contents;
744 E : ASSERT_NO_FATAL_FAILURE(ReadTraceFile(&trace_file_contents));
745 :
746 : // Read and validate the trace file header. We expect to have written
747 : // the header (rounded up to a block) plus num_blocks of data,
748 : // plus 1 block containing the process ended event.
749 : TraceFileHeader* header =
750 E : reinterpret_cast<TraceFileHeader*>(&trace_file_contents[0]);
751 E : ASSERT_NO_FATAL_FAILURE(ValidateTraceFileHeader(*header));
752 E : size_t total_blocks = 1 + num_blocks;
753 : EXPECT_EQ(trace_file_contents.length(),
754 E : RoundedSize(*header) + total_blocks * header->block_size);
755 :
756 : // Read each data block and validate its contents.
757 E : size_t segment_offset = AlignUp(header->header_size, header->block_size);
758 E : for (int block = 0; block < num_blocks; ++block) {
759 : // Locate and validate the segment header prefix.
760 : RecordPrefix* prefix = reinterpret_cast<RecordPrefix*>(
761 E : &trace_file_contents[0] + segment_offset);
762 E : ASSERT_EQ(prefix->type, TraceFileSegmentHeader::kTypeId);
763 E : ASSERT_EQ(prefix->size, sizeof(TraceFileSegmentHeader));
764 E : ASSERT_EQ(prefix->version.hi, TRACE_VERSION_HI);
765 E : ASSERT_EQ(prefix->version.lo, TRACE_VERSION_LO);
766 :
767 : // The segment header prefix is followed by the actual segment header.
768 : TraceFileSegmentHeader* segment_header =
769 E : reinterpret_cast<TraceFileSegmentHeader*>(prefix + 1);
770 E : ASSERT_EQ(segment_header->segment_length, segment_length[block]);
771 E : ASSERT_EQ(segment_header->thread_id, ::GetCurrentThreadId());
772 :
773 : // The segment header is followed by the n message records, where N
774 : // is the same as the block number we're currently on (1 based).
775 E : prefix = reinterpret_cast<RecordPrefix*>(segment_header + 1);
776 E : for (int j = 0; j <= block; ++j) {
777 E : ASSERT_EQ(prefix->type, MyRecordType::kTypeId);
778 E : ASSERT_EQ(prefix->size, sizeof(MyRecordType));
779 E : ASSERT_EQ(prefix->version.hi, TRACE_VERSION_HI);
780 E : ASSERT_EQ(prefix->version.lo, TRACE_VERSION_LO);
781 E : MyRecordType* record = reinterpret_cast<MyRecordType*>(prefix + 1);
782 E : ASSERT_STREQ(record->message, messages[j]);
783 E : prefix = reinterpret_cast<RecordPrefix*>(record + 1);
784 E : }
785 :
786 : EXPECT_EQ(segment_header->segment_length,
787 E : RawPtrDiff(prefix, segment_header + 1));
788 :
789 : segment_offset = AlignUp(
790 : RawPtrDiff(prefix, &trace_file_contents[0]),
791 E : header->block_size);
792 E : }
793 :
794 : // Locate and validate the segment header prefix for the process ended
795 : // event block.
796 : RecordPrefix* prefix = reinterpret_cast<RecordPrefix*>(
797 E : &trace_file_contents[0] + segment_offset);
798 E : ASSERT_EQ(prefix->type, TraceFileSegmentHeader::kTypeId);
799 E : ASSERT_EQ(prefix->size, sizeof(TraceFileSegmentHeader));
800 E : ASSERT_EQ(prefix->version.hi, TRACE_VERSION_HI);
801 E : ASSERT_EQ(prefix->version.lo, TRACE_VERSION_LO);
802 :
803 : // The segment header prefix is followed by the actual segment header.
804 : TraceFileSegmentHeader* segment_header =
805 E : reinterpret_cast<TraceFileSegmentHeader*>(prefix + 1);
806 E : ASSERT_EQ(sizeof(RecordPrefix), segment_header->segment_length);
807 E : ASSERT_EQ(0, segment_header->thread_id);
808 :
809 : // Validate the process ended event.
810 E : prefix = reinterpret_cast<RecordPrefix*>(segment_header + 1);
811 E : ASSERT_EQ(TRACE_PROCESS_ENDED, prefix->type);
812 E : ASSERT_EQ(0, prefix->size);
813 E : ASSERT_EQ(TRACE_VERSION_HI, prefix->version.hi);
814 E : ASSERT_EQ(TRACE_VERSION_LO, prefix->version.lo);
815 : EXPECT_EQ(segment_header->segment_length,
816 E : RawPtrDiff(prefix + 1, segment_header + 1));
817 E : }
818 :
819 : } // namespace service
820 : } // namespace trace
|