1 : // Copyright 2014 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 : // Function call logger unittests.
16 :
17 : #include "syzygy/agent/memprof/function_call_logger.h"
18 :
19 : #include "base/bind.h"
20 : #include "gmock/gmock.h"
21 : #include "gtest/gtest.h"
22 :
23 : namespace agent {
24 : namespace memprof {
25 :
26 : namespace {
27 :
28 : using trace::client::TraceFileSegment;
29 :
30 : // TODO(chrisha): Centralize this for use elsewhere.
31 : class TestRpcSession : public trace::client::RpcSession {
32 : public:
33 E : TestRpcSession() : closed_(false) {
34 E : }
35 :
36 i : virtual bool CreateSession(TraceFileSegment* segment) {
37 i : DCHECK_NE(static_cast<TraceFileSegment*>(nullptr), segment);
38 i : return AllocateBuffer(segment);
39 i : }
40 :
41 E : virtual bool AllocateBuffer(TraceFileSegment* segment) {
42 E : DCHECK_NE(static_cast<TraceFileSegment*>(nullptr), segment);
43 E : return AllocateBuffer(2 * 1024 * 1024, segment);
44 E : }
45 :
46 E : virtual bool AllocateBuffer(size_t min_size, TraceFileSegment* segment) {
47 E : DCHECK_NE(static_cast<TraceFileSegment*>(nullptr), segment);
48 E : if (closed_)
49 i : return false;
50 E : auto it = buffers_.insert(buffers_.begin(), std::vector<uint8_t>());
51 E : it->resize(min_size);
52 E : segment->base_ptr = it->data();
53 E : segment->buffer_info.buffer_offset = 0;
54 E : segment->buffer_info.buffer_size = min_size;
55 E : segment->buffer_info.shared_memory_handle = 0;
56 E : segment->end_ptr = segment->base_ptr + min_size;
57 E : segment->header = reinterpret_cast<TraceFileSegmentHeader*>(
58 : segment->base_ptr);
59 E : segment->write_ptr = reinterpret_cast<uint8_t*>(segment->header + 1);
60 E : segment->header->thread_id = ::GetCurrentThreadId();
61 E : segment->header->segment_length = 0;
62 E : return true;
63 E : }
64 :
65 i : virtual bool ExchangeBuffer(TraceFileSegment* segment) {
66 i : DCHECK_NE(static_cast<TraceFileSegment*>(nullptr), segment);
67 i : return AllocateBuffer(segment);
68 i : }
69 :
70 i : virtual bool ReturnBuffer(TraceFileSegment* segment) {
71 i : DCHECK_NE(static_cast<TraceFileSegment*>(nullptr), segment);
72 i : if (closed_)
73 i : return false;
74 i : segment->base_ptr = nullptr;
75 i : segment->buffer_info.buffer_offset = 0;
76 i : segment->buffer_info.buffer_size = 0;
77 i : segment->buffer_info.shared_memory_handle = 0;
78 i : segment->end_ptr = nullptr;
79 i : segment->header = nullptr;
80 i : segment->write_ptr = nullptr;
81 i : return true;
82 i : }
83 :
84 i : virtual bool CloseSession() {
85 i : if (closed_)
86 i : return false;
87 i : closed_ = true;
88 i : return true;
89 i : }
90 :
91 i : virtual void FreeSharedMemory() {
92 : return;
93 i : }
94 :
95 : private:
96 : // All generated buffers are kept around so that the contents of flushed
97 : // buffers can be inspected.
98 : std::list<std::vector<uint8_t>> buffers_;
99 : bool closed_;
100 : };
101 :
102 : class TestFunctionCallLogger : public FunctionCallLogger {
103 : public:
104 E : TestFunctionCallLogger()
105 E : : FunctionCallLogger(&test_session_) {
106 E : test_segment_.allocate_callback =
107 : base::Bind(&TestFunctionCallLogger::AllocateCallback,
108 : base::Unretained(this));
109 E : test_session_.AllocateBuffer(&test_segment_);
110 E : }
111 :
112 : using FunctionCallLogger::function_id_map_;
113 : using FunctionCallLogger::emitted_stack_ids_;
114 :
115 : // The session and segment that are passed to the function call logger.
116 : TestRpcSession test_session_;
117 : TraceFileSegment test_segment_;
118 :
119 : // Stores information about the allocations made to test_segment.
120 : struct AllocationInfo {
121 : int record_type;
122 : size_t record_size;
123 : void* record;
124 : };
125 : std::vector<AllocationInfo> allocation_infos;
126 :
127 : // This callback is invoked whenever test_segment is written to.
128 : void AllocateCallback(
129 E : int record_type, size_t record_size, void* record) {
130 E : AllocationInfo info = { record_type, record_size, record };
131 E : allocation_infos.push_back(info);
132 E : }
133 : };
134 :
135 E : void TestEmitDetailedFunctionCall(TestFunctionCallLogger* fcl) {
136 E : ASSERT_NE(static_cast<TestFunctionCallLogger*>(nullptr), fcl);
137 E : EMIT_DETAILED_FUNCTION_CALL(fcl, &fcl->test_segment_, fcl);
138 E : }
139 :
140 : } // namespace
141 :
142 E : TEST(FunctionCallLoggerTest, TraceFunctionNameTableEntry) {
143 E : TestFunctionCallLogger fcl;
144 E : EXPECT_EQ(0u, fcl.function_id_map_.size());
145 :
146 E : std::string name("foo");
147 E : EXPECT_EQ(0u, fcl.GetFunctionId(&fcl.test_segment_, name));
148 E : EXPECT_EQ(1u, fcl.function_id_map_.size());
149 E : EXPECT_THAT(fcl.function_id_map_,
150 E : testing::Contains(std::make_pair(name, 0)));
151 E : EXPECT_EQ(1u, fcl.allocation_infos.size());
152 :
153 E : const auto& info = fcl.allocation_infos.front();
154 E : EXPECT_EQ(TraceFunctionNameTableEntry::kTypeId,
155 E : info.record_type);
156 E : EXPECT_TRUE(info.record != nullptr);
157 : TraceFunctionNameTableEntry* data =
158 : reinterpret_cast<TraceFunctionNameTableEntry*>(
159 E : info.record);
160 E : EXPECT_LE(
161 : FIELD_OFFSET(TraceFunctionNameTableEntry, name) + data->name_length,
162 E : info.record_size);
163 E : EXPECT_EQ(name, data->name);
164 E : fcl.allocation_infos.empty();
165 :
166 : // Adding the same name again should do nothing.
167 E : EXPECT_EQ(0u, fcl.GetFunctionId(&fcl.test_segment_, "foo"));
168 E : EXPECT_EQ(1u, fcl.function_id_map_.size());
169 E : EXPECT_THAT(fcl.function_id_map_,
170 E : testing::Contains(std::make_pair(std::string("foo"), 0)));
171 E : EXPECT_EQ(1u, fcl.allocation_infos.size());
172 E : }
173 :
174 E : TEST(FunctionCallLoggerTest, TraceStackTrace) {
175 E : TestFunctionCallLogger fcl;
176 E : EXPECT_EQ(0u, fcl.emitted_stack_ids_.size());
177 :
178 E : fcl.set_stack_trace_tracking(kTrackingNone);
179 E : EXPECT_EQ(0u, fcl.GetStackTraceId(&fcl.test_segment_));
180 E : EXPECT_EQ(0u, fcl.emitted_stack_ids_.size());
181 E : EXPECT_EQ(0u, fcl.allocation_infos.size());
182 :
183 E : fcl.set_stack_trace_tracking(kTrackingTrack);
184 E : EXPECT_NE(0u, fcl.GetStackTraceId(&fcl.test_segment_));
185 E : EXPECT_EQ(0u, fcl.emitted_stack_ids_.size());
186 E : EXPECT_EQ(0u, fcl.allocation_infos.size());
187 :
188 E : fcl.set_stack_trace_tracking(kTrackingEmit);
189 E : uint32_t stack_trace_id = fcl.GetStackTraceId(&fcl.test_segment_);
190 E : EXPECT_NE(0u, stack_trace_id);
191 E : EXPECT_THAT(fcl.emitted_stack_ids_, testing::ElementsAre(stack_trace_id));
192 E : EXPECT_EQ(1u, fcl.allocation_infos.size());
193 E : const auto& info = fcl.allocation_infos[0];
194 E : EXPECT_EQ(TraceStackTrace::kTypeId, info.record_type);
195 E : EXPECT_TRUE(info.record != nullptr);
196 E : TraceStackTrace* data = reinterpret_cast<TraceStackTrace*>(info.record);
197 E : EXPECT_EQ(stack_trace_id, data->stack_trace_id);
198 E : EXPECT_LT(0u, data->num_frames);
199 E : size_t expected_size = data->num_frames * sizeof(void*) +
200 : FIELD_OFFSET(TraceStackTrace, frames);
201 E : EXPECT_LE(expected_size, info.record_size);
202 E : }
203 :
204 E : TEST(FunctionCallLoggerTest, TraceDetailedFunctionCall) {
205 E : TestFunctionCallLogger fcl;
206 E : fcl.set_stack_trace_tracking(kTrackingEmit);
207 E : EXPECT_EQ(0u, fcl.function_id_map_.size());
208 :
209 E : std::string name("agent::memprof::`anonymous-namespace'::"
210 : "TestEmitDetailedFunctionCall");
211 E : TestEmitDetailedFunctionCall(&fcl);
212 E : EXPECT_EQ(1u, fcl.function_id_map_.size());
213 E : EXPECT_THAT(fcl.function_id_map_,
214 E : testing::Contains(std::make_pair(name, 0)));
215 E : EXPECT_EQ(3u, fcl.allocation_infos.size());
216 :
217 : // Validate that the name record was appropriately written.
218 E : const auto& info0 = fcl.allocation_infos[0];
219 E : EXPECT_EQ(TraceFunctionNameTableEntry::kTypeId,
220 E : info0.record_type);
221 E : EXPECT_TRUE(info0.record != nullptr);
222 : TraceFunctionNameTableEntry* data0 =
223 : reinterpret_cast<TraceFunctionNameTableEntry*>(
224 E : info0.record);
225 E : EXPECT_LE(
226 : FIELD_OFFSET(TraceFunctionNameTableEntry, name) + data0->name_length,
227 E : info0.record_size);
228 E : EXPECT_EQ(name, data0->name);
229 :
230 : // Validate that the stack trace was written correctly.
231 E : const auto& info1 = fcl.allocation_infos[1];
232 E : EXPECT_EQ(TraceStackTrace::kTypeId, info1.record_type);
233 E : EXPECT_TRUE(info1.record != nullptr);
234 E : TraceStackTrace* data1 = reinterpret_cast<TraceStackTrace*>(info1.record);
235 E : EXPECT_LT(0u, data1->num_frames);
236 E : size_t expected_size = data1->num_frames * sizeof(void*) +
237 : FIELD_OFFSET(TraceStackTrace, frames);
238 E : EXPECT_LE(expected_size, info1.record_size);
239 :
240 : // Validate that the detailed function call record was written correctly.
241 E : const auto& info2 = fcl.allocation_infos[2];
242 E : EXPECT_EQ(TraceDetailedFunctionCall::kTypeId,
243 E : info2.record_type);
244 E : EXPECT_TRUE(info2.record != nullptr);
245 : TraceDetailedFunctionCall* data2 =
246 E : reinterpret_cast<TraceDetailedFunctionCall*>(info2.record);
247 E : EXPECT_LE(
248 : FIELD_OFFSET(TraceDetailedFunctionCall, argument_data) +
249 : data2->argument_data_size,
250 E : info2.record_size);
251 E : EXPECT_EQ(0u, data2->function_id);
252 E : EXPECT_EQ(data1->stack_trace_id, data2->stack_trace_id);
253 E : EXPECT_NE(0ull, data2->timestamp);
254 : // Number of arguments, size of argument, content of argument.
255 E : EXPECT_EQ(2 * sizeof(uint32_t) + sizeof(void*), data2->argument_data_size);
256 :
257 E : void* fcl_ptr = &fcl;
258 E : uint8_t ptr[4] = {};
259 E : ::memcpy(ptr, &fcl_ptr, sizeof(ptr));
260 : const uint8_t kExpectedContents[] = {
261 E : 0x01,
262 E : 0x00,
263 E : 0x00,
264 E : 0x00, // 1 argument...
265 E : 0x04,
266 E : 0x00,
267 E : 0x00,
268 E : 0x00, // ...of size 4...
269 E : ptr[0],
270 E : ptr[1],
271 E : ptr[2],
272 E : ptr[3], // ...pointing to |fcl|.
273 : };
274 E : ASSERT_EQ(arraysize(kExpectedContents), data2->argument_data_size);
275 E : EXPECT_EQ(0u, ::memcmp(kExpectedContents, data2->argument_data,
276 E : data2->argument_data_size));
277 E : }
278 :
279 E : TEST(FunctionCallLoggerTest, TraceDetailedFunctionCallSerializeTimestamps) {
280 E : TestFunctionCallLogger fcl;
281 E : fcl.set_stack_trace_tracking(kTrackingNone);
282 E : fcl.set_serialize_timestamps(true);
283 E : EXPECT_EQ(0u, fcl.function_id_map_.size());
284 :
285 E : std::string name("agent::memprof::`anonymous-namespace'::"
286 : "TestEmitDetailedFunctionCall");
287 E : for (size_t i = 0; i < 3; ++i)
288 E : TestEmitDetailedFunctionCall(&fcl);
289 E : EXPECT_EQ(1u, fcl.function_id_map_.size());
290 E : EXPECT_THAT(fcl.function_id_map_,
291 E : testing::Contains(std::make_pair(name, 0)));
292 : // 1 name, 3 calls.
293 E : EXPECT_EQ(4u, fcl.allocation_infos.size());
294 :
295 : // Validate that the name record was appropriately written.
296 E : const auto& info0 = fcl.allocation_infos[0];
297 E : EXPECT_EQ(TraceFunctionNameTableEntry::kTypeId,
298 E : info0.record_type);
299 E : EXPECT_NE(nullptr, info0.record);
300 : TraceFunctionNameTableEntry* data0 =
301 : reinterpret_cast<TraceFunctionNameTableEntry*>(
302 E : info0.record);
303 E : EXPECT_LE(
304 : FIELD_OFFSET(TraceFunctionNameTableEntry, name) + data0->name_length,
305 E : info0.record_size);
306 E : EXPECT_EQ(name, data0->name);
307 :
308 E : for (size_t i = 0; i < 3; ++i) {
309 : // Validate that the detailed function call has the appropriate timestamp.
310 E : const auto& info1 = fcl.allocation_infos[1 + i];
311 E : EXPECT_EQ(TraceDetailedFunctionCall::kTypeId, info1.record_type);
312 E : EXPECT_NE(nullptr, info0.record);
313 : TraceDetailedFunctionCall* data1 =
314 E : reinterpret_cast<TraceDetailedFunctionCall*>(info1.record);
315 E : EXPECT_EQ(static_cast<uint64_t>(i), data1->timestamp);
316 E : }
317 E : }
318 :
319 : } // namespace memprof
320 : } // namespace agent
|