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