1//===-- fdr_controller_test.cc --------------------------------------------===//
2//
3//                     The LLVM Compiler Infrastructure
4//
5// This file is distributed under the University of Illinois Open Source
6// License. See LICENSE.TXT for details.
7//
8//===----------------------------------------------------------------------===//
9//
10// This file is a part of XRay, a function call tracing system.
11//
12//===----------------------------------------------------------------------===//
13#include <algorithm>
14#include <memory>
15#include <time.h>
16
17#include "test_helpers.h"
18#include "xray/xray_records.h"
19#include "xray_buffer_queue.h"
20#include "xray_fdr_controller.h"
21#include "xray_fdr_log_writer.h"
22#include "llvm/Support/DataExtractor.h"
23#include "llvm/Testing/Support/Error.h"
24#include "llvm/XRay/Trace.h"
25#include "llvm/XRay/XRayRecord.h"
26#include "gmock/gmock.h"
27#include "gtest/gtest.h"
28
29namespace __xray {
30namespace {
31
32using ::llvm::HasValue;
33using ::llvm::xray::testing::FuncId;
34using ::llvm::xray::testing::HasArg;
35using ::llvm::xray::testing::RecordType;
36using ::llvm::xray::testing::TSCIs;
37using ::testing::AllOf;
38using ::testing::ElementsAre;
39using ::testing::Eq;
40using ::testing::Field;
41using ::testing::Gt;
42using ::testing::IsEmpty;
43using ::testing::SizeIs;
44
45class FunctionSequenceTest : public ::testing::Test {
46protected:
47  BufferQueue::Buffer B{};
48  std::unique_ptr<BufferQueue> BQ;
49  std::unique_ptr<FDRLogWriter> W;
50  std::unique_ptr<FDRController<>> C;
51
52public:
53  void SetUp() override {
54    bool Success;
55    BQ = llvm::make_unique<BufferQueue>(4096, 1, Success);
56    ASSERT_TRUE(Success);
57    ASSERT_EQ(BQ->getBuffer(B), BufferQueue::ErrorCode::Ok);
58    W = llvm::make_unique<FDRLogWriter>(B);
59    C = llvm::make_unique<FDRController<>>(BQ.get(), B, *W, clock_gettime, 0);
60  }
61};
62
63TEST_F(FunctionSequenceTest, DefaultInitFinalizeFlush) {
64  ASSERT_TRUE(C->functionEnter(1, 2, 3));
65  ASSERT_TRUE(C->functionExit(1, 2, 3));
66  ASSERT_TRUE(C->flush());
67  ASSERT_EQ(BQ->finalize(), BufferQueue::ErrorCode::Ok);
68
69  // Serialize the buffers then test to see we find the expected records.
70  std::string Serialized = serialize(*BQ, 3);
71  llvm::DataExtractor DE(Serialized, true, 8);
72  auto TraceOrErr = llvm::xray::loadTrace(DE);
73  EXPECT_THAT_EXPECTED(
74      TraceOrErr,
75      HasValue(ElementsAre(
76          AllOf(FuncId(1), RecordType(llvm::xray::RecordTypes::ENTER)),
77          AllOf(FuncId(1), RecordType(llvm::xray::RecordTypes::EXIT)))));
78}
79
80TEST_F(FunctionSequenceTest, BoundaryFuncIdEncoding) {
81  // We ensure that we can write function id's that are at the boundary of the
82  // acceptable function ids.
83  int32_t FId = (1 << 28) - 1;
84  uint64_t TSC = 2;
85  uint16_t CPU = 1;
86  ASSERT_TRUE(C->functionEnter(FId, TSC++, CPU));
87  ASSERT_TRUE(C->functionExit(FId, TSC++, CPU));
88  ASSERT_TRUE(C->functionEnterArg(FId, TSC++, CPU, 1));
89  ASSERT_TRUE(C->functionTailExit(FId, TSC++, CPU));
90  ASSERT_TRUE(C->flush());
91  ASSERT_EQ(BQ->finalize(), BufferQueue::ErrorCode::Ok);
92
93  // Serialize the buffers then test to see we find the expected records.
94  std::string Serialized = serialize(*BQ, 3);
95  llvm::DataExtractor DE(Serialized, true, 8);
96  auto TraceOrErr = llvm::xray::loadTrace(DE);
97  EXPECT_THAT_EXPECTED(
98      TraceOrErr,
99      HasValue(ElementsAre(
100          AllOf(FuncId(FId), RecordType(llvm::xray::RecordTypes::ENTER)),
101          AllOf(FuncId(FId), RecordType(llvm::xray::RecordTypes::EXIT)),
102          AllOf(FuncId(FId), RecordType(llvm::xray::RecordTypes::ENTER_ARG)),
103          AllOf(FuncId(FId), RecordType(llvm::xray::RecordTypes::TAIL_EXIT)))));
104}
105
106TEST_F(FunctionSequenceTest, ThresholdsAreEnforced) {
107  C = llvm::make_unique<FDRController<>>(BQ.get(), B, *W, clock_gettime, 1000);
108  ASSERT_TRUE(C->functionEnter(1, 2, 3));
109  ASSERT_TRUE(C->functionExit(1, 2, 3));
110  ASSERT_TRUE(C->flush());
111  ASSERT_EQ(BQ->finalize(), BufferQueue::ErrorCode::Ok);
112
113  // Serialize the buffers then test to see we find the *no* records, because
114  // the function entry-exit comes under the cycle threshold.
115  std::string Serialized = serialize(*BQ, 3);
116  llvm::DataExtractor DE(Serialized, true, 8);
117  auto TraceOrErr = llvm::xray::loadTrace(DE);
118  EXPECT_THAT_EXPECTED(TraceOrErr, HasValue(IsEmpty()));
119}
120
121TEST_F(FunctionSequenceTest, ArgsAreHandledAndKept) {
122  C = llvm::make_unique<FDRController<>>(BQ.get(), B, *W, clock_gettime, 1000);
123  ASSERT_TRUE(C->functionEnterArg(1, 2, 3, 4));
124  ASSERT_TRUE(C->functionExit(1, 2, 3));
125  ASSERT_TRUE(C->flush());
126  ASSERT_EQ(BQ->finalize(), BufferQueue::ErrorCode::Ok);
127
128  // Serialize the buffers then test to see we find the function enter arg
129  // record with the specified argument.
130  std::string Serialized = serialize(*BQ, 3);
131  llvm::DataExtractor DE(Serialized, true, 8);
132  auto TraceOrErr = llvm::xray::loadTrace(DE);
133  EXPECT_THAT_EXPECTED(
134      TraceOrErr,
135      HasValue(ElementsAre(
136          AllOf(FuncId(1), RecordType(llvm::xray::RecordTypes::ENTER_ARG),
137                HasArg(4)),
138          AllOf(FuncId(1), RecordType(llvm::xray::RecordTypes::EXIT)))));
139}
140
141TEST_F(FunctionSequenceTest, PreservedCallsHaveCorrectTSC) {
142  C = llvm::make_unique<FDRController<>>(BQ.get(), B, *W, clock_gettime, 1000);
143  uint64_t TSC = 1;
144  uint16_t CPU = 0;
145  ASSERT_TRUE(C->functionEnter(1, TSC++, CPU));
146  ASSERT_TRUE(C->functionEnter(2, TSC++, CPU));
147  ASSERT_TRUE(C->functionExit(2, TSC++, CPU));
148  ASSERT_TRUE(C->functionExit(1, TSC += 1000, CPU));
149  ASSERT_TRUE(C->flush());
150  ASSERT_EQ(BQ->finalize(), BufferQueue::ErrorCode::Ok);
151
152  // Serialize the buffers then test to see if we find the remaining records,
153  // because the function entry-exit comes under the cycle threshold.
154  std::string Serialized = serialize(*BQ, 3);
155  llvm::DataExtractor DE(Serialized, true, 8);
156  auto TraceOrErr = llvm::xray::loadTrace(DE);
157  EXPECT_THAT_EXPECTED(
158      TraceOrErr,
159      HasValue(ElementsAre(
160          AllOf(FuncId(1), RecordType(llvm::xray::RecordTypes::ENTER),
161                TSCIs(Eq(1uL))),
162          AllOf(FuncId(1), RecordType(llvm::xray::RecordTypes::EXIT),
163                TSCIs(Gt(1000uL))))));
164}
165
166TEST_F(FunctionSequenceTest, PreservedCallsSupportLargeDeltas) {
167  C = llvm::make_unique<FDRController<>>(BQ.get(), B, *W, clock_gettime, 1000);
168  uint64_t TSC = 1;
169  uint16_t CPU = 0;
170  const auto LargeDelta = uint64_t{std::numeric_limits<int32_t>::max()};
171  ASSERT_TRUE(C->functionEnter(1, TSC++, CPU));
172  ASSERT_TRUE(C->functionExit(1, TSC += LargeDelta, CPU));
173  ASSERT_TRUE(C->flush());
174  ASSERT_EQ(BQ->finalize(), BufferQueue::ErrorCode::Ok);
175
176  // Serialize the buffer then test to see if we find the right TSC with a large
177  // delta.
178  std::string Serialized = serialize(*BQ, 3);
179  llvm::DataExtractor DE(Serialized, true, 8);
180  auto TraceOrErr = llvm::xray::loadTrace(DE);
181  EXPECT_THAT_EXPECTED(
182      TraceOrErr,
183      HasValue(ElementsAre(
184          AllOf(FuncId(1), RecordType(llvm::xray::RecordTypes::ENTER),
185                TSCIs(Eq(1uL))),
186          AllOf(FuncId(1), RecordType(llvm::xray::RecordTypes::EXIT),
187                TSCIs(Gt(LargeDelta))))));
188}
189
190TEST_F(FunctionSequenceTest, RewindingMultipleCalls) {
191  C = llvm::make_unique<FDRController<>>(BQ.get(), B, *W, clock_gettime, 1000);
192
193  // First we construct an arbitrarily deep function enter/call stack.
194  // We also ensure that we are in the same CPU.
195  uint64_t TSC = 1;
196  uint16_t CPU = 1;
197  ASSERT_TRUE(C->functionEnter(1, TSC++, CPU));
198  ASSERT_TRUE(C->functionEnter(2, TSC++, CPU));
199  ASSERT_TRUE(C->functionEnter(3, TSC++, CPU));
200
201  // Then we exit them one at a time, in reverse order of entry.
202  ASSERT_TRUE(C->functionExit(3, TSC++, CPU));
203  ASSERT_TRUE(C->functionExit(2, TSC++, CPU));
204  ASSERT_TRUE(C->functionExit(1, TSC++, CPU));
205
206  ASSERT_TRUE(C->flush());
207  ASSERT_EQ(BQ->finalize(), BufferQueue::ErrorCode::Ok);
208
209  // Serialize the buffers then test to see we find that all the calls have been
210  // unwound because all of them are under the cycle counter threshold.
211  std::string Serialized = serialize(*BQ, 3);
212  llvm::DataExtractor DE(Serialized, true, 8);
213  auto TraceOrErr = llvm::xray::loadTrace(DE);
214  EXPECT_THAT_EXPECTED(TraceOrErr, HasValue(IsEmpty()));
215}
216
217TEST_F(FunctionSequenceTest, RewindingIntermediaryTailExits) {
218  C = llvm::make_unique<FDRController<>>(BQ.get(), B, *W, clock_gettime, 1000);
219
220  // First we construct an arbitrarily deep function enter/call stack.
221  // We also ensure that we are in the same CPU.
222  uint64_t TSC = 1;
223  uint16_t CPU = 1;
224  ASSERT_TRUE(C->functionEnter(1, TSC++, CPU));
225  ASSERT_TRUE(C->functionEnter(2, TSC++, CPU));
226  ASSERT_TRUE(C->functionEnter(3, TSC++, CPU));
227
228  // Next we tail-exit into a new function multiple times.
229  ASSERT_TRUE(C->functionTailExit(3, TSC++, CPU));
230  ASSERT_TRUE(C->functionEnter(4, TSC++, CPU));
231  ASSERT_TRUE(C->functionTailExit(4, TSC++, CPU));
232  ASSERT_TRUE(C->functionEnter(5, TSC++, CPU));
233  ASSERT_TRUE(C->functionTailExit(5, TSC++, CPU));
234  ASSERT_TRUE(C->functionEnter(6, TSC++, CPU));
235
236  // Then we exit them one at a time, in reverse order of entry.
237  ASSERT_TRUE(C->functionExit(6, TSC++, CPU));
238  ASSERT_TRUE(C->functionExit(2, TSC++, CPU));
239  ASSERT_TRUE(C->functionExit(1, TSC++, CPU));
240  ASSERT_TRUE(C->flush());
241  ASSERT_EQ(BQ->finalize(), BufferQueue::ErrorCode::Ok);
242
243  // Serialize the buffers then test to see we find that all the calls have been
244  // unwound because all of them are under the cycle counter threshold.
245  std::string Serialized = serialize(*BQ, 3);
246  llvm::DataExtractor DE(Serialized, true, 8);
247  auto TraceOrErr = llvm::xray::loadTrace(DE);
248  EXPECT_THAT_EXPECTED(TraceOrErr, HasValue(IsEmpty()));
249}
250
251TEST_F(FunctionSequenceTest, RewindingAfterMigration) {
252  C = llvm::make_unique<FDRController<>>(BQ.get(), B, *W, clock_gettime, 1000);
253
254  // First we construct an arbitrarily deep function enter/call stack.
255  // We also ensure that we are in the same CPU.
256  uint64_t TSC = 1;
257  uint16_t CPU = 1;
258  ASSERT_TRUE(C->functionEnter(1, TSC++, CPU));
259  ASSERT_TRUE(C->functionEnter(2, TSC++, CPU));
260  ASSERT_TRUE(C->functionEnter(3, TSC++, CPU));
261
262  // Next we tail-exit into a new function multiple times.
263  ASSERT_TRUE(C->functionTailExit(3, TSC++, CPU));
264  ASSERT_TRUE(C->functionEnter(4, TSC++, CPU));
265  ASSERT_TRUE(C->functionTailExit(4, TSC++, CPU));
266
267  // But before we enter the next function, we migrate to a different CPU.
268  CPU = 2;
269  ASSERT_TRUE(C->functionEnter(5, TSC++, CPU));
270  ASSERT_TRUE(C->functionTailExit(5, TSC++, CPU));
271  ASSERT_TRUE(C->functionEnter(6, TSC++, CPU));
272
273  // Then we exit them one at a time, in reverse order of entry.
274  ASSERT_TRUE(C->functionExit(6, TSC++, CPU));
275  ASSERT_TRUE(C->functionExit(2, TSC++, CPU));
276  ASSERT_TRUE(C->functionExit(1, TSC++, CPU));
277
278  ASSERT_TRUE(C->flush());
279  ASSERT_EQ(BQ->finalize(), BufferQueue::ErrorCode::Ok);
280
281  // Serialize buffers then test that we can find all the events that span the
282  // CPU migration.
283  std::string Serialized = serialize(*BQ, 3);
284  llvm::DataExtractor DE(Serialized, true, 8);
285  auto TraceOrErr = llvm::xray::loadTrace(DE);
286  EXPECT_THAT_EXPECTED(
287      TraceOrErr,
288      HasValue(ElementsAre(
289          AllOf(FuncId(1), RecordType(llvm::xray::RecordTypes::ENTER)),
290          AllOf(FuncId(2), RecordType(llvm::xray::RecordTypes::ENTER)),
291          AllOf(FuncId(2), RecordType(llvm::xray::RecordTypes::EXIT)),
292          AllOf(FuncId(1), RecordType(llvm::xray::RecordTypes::EXIT)))));
293}
294
295class BufferManagementTest : public ::testing::Test {
296protected:
297  BufferQueue::Buffer B{};
298  std::unique_ptr<BufferQueue> BQ;
299  std::unique_ptr<FDRLogWriter> W;
300  std::unique_ptr<FDRController<>> C;
301
302  static constexpr size_t kBuffers = 10;
303
304public:
305  void SetUp() override {
306    bool Success;
307    BQ = llvm::make_unique<BufferQueue>(sizeof(MetadataRecord) * 5 +
308                                            sizeof(FunctionRecord) * 2,
309                                        kBuffers, Success);
310    ASSERT_TRUE(Success);
311    ASSERT_EQ(BQ->getBuffer(B), BufferQueue::ErrorCode::Ok);
312    W = llvm::make_unique<FDRLogWriter>(B);
313    C = llvm::make_unique<FDRController<>>(BQ.get(), B, *W, clock_gettime, 0);
314  }
315};
316
317constexpr size_t BufferManagementTest::kBuffers;
318
319TEST_F(BufferManagementTest, HandlesOverflow) {
320  uint64_t TSC = 1;
321  uint16_t CPU = 1;
322  for (size_t I = 0; I < kBuffers + 1; ++I) {
323    ASSERT_TRUE(C->functionEnter(1, TSC++, CPU));
324    ASSERT_TRUE(C->functionExit(1, TSC++, CPU));
325  }
326  ASSERT_TRUE(C->flush());
327  ASSERT_THAT(BQ->finalize(), Eq(BufferQueue::ErrorCode::Ok));
328
329  std::string Serialized = serialize(*BQ, 3);
330  llvm::DataExtractor DE(Serialized, true, 8);
331  auto TraceOrErr = llvm::xray::loadTrace(DE);
332  EXPECT_THAT_EXPECTED(TraceOrErr, HasValue(SizeIs(kBuffers * 2)));
333}
334
335TEST_F(BufferManagementTest, HandlesOverflowWithArgs) {
336  uint64_t TSC = 1;
337  uint16_t CPU = 1;
338  uint64_t ARG = 1;
339  for (size_t I = 0; I < kBuffers + 1; ++I) {
340    ASSERT_TRUE(C->functionEnterArg(1, TSC++, CPU, ARG++));
341    ASSERT_TRUE(C->functionExit(1, TSC++, CPU));
342  }
343  ASSERT_TRUE(C->flush());
344  ASSERT_THAT(BQ->finalize(), Eq(BufferQueue::ErrorCode::Ok));
345
346  std::string Serialized = serialize(*BQ, 3);
347  llvm::DataExtractor DE(Serialized, true, 8);
348  auto TraceOrErr = llvm::xray::loadTrace(DE);
349  EXPECT_THAT_EXPECTED(TraceOrErr, HasValue(SizeIs(kBuffers)));
350}
351
352TEST_F(BufferManagementTest, HandlesOverflowWithCustomEvents) {
353  uint64_t TSC = 1;
354  uint16_t CPU = 1;
355  int32_t D = 0x9009;
356  for (size_t I = 0; I < kBuffers; ++I) {
357    ASSERT_TRUE(C->functionEnter(1, TSC++, CPU));
358    ASSERT_TRUE(C->functionExit(1, TSC++, CPU));
359    ASSERT_TRUE(C->customEvent(TSC++, CPU, &D, sizeof(D)));
360  }
361  ASSERT_TRUE(C->flush());
362  ASSERT_THAT(BQ->finalize(), Eq(BufferQueue::ErrorCode::Ok));
363
364  std::string Serialized = serialize(*BQ, 3);
365  llvm::DataExtractor DE(Serialized, true, 8);
366  auto TraceOrErr = llvm::xray::loadTrace(DE);
367
368  // We expect to also now count the kBuffers/2 custom event records showing up
369  // in the Trace.
370  EXPECT_THAT_EXPECTED(TraceOrErr, HasValue(SizeIs(kBuffers + (kBuffers / 2))));
371}
372
373TEST_F(BufferManagementTest, HandlesFinalizedBufferQueue) {
374  uint64_t TSC = 1;
375  uint16_t CPU = 1;
376
377  // First write one function entry.
378  ASSERT_TRUE(C->functionEnter(1, TSC++, CPU));
379
380  // Then we finalize the buffer queue, simulating the case where the logging
381  // has been finalized.
382  ASSERT_EQ(BQ->finalize(), BufferQueue::ErrorCode::Ok);
383
384  // At this point further calls to the controller must fail.
385  ASSERT_FALSE(C->functionExit(1, TSC++, CPU));
386
387  // But flushing should succeed.
388  ASSERT_TRUE(C->flush());
389
390  // We expect that we'll only be able to find the function enter event, but not
391  // the function exit event.
392  std::string Serialized = serialize(*BQ, 3);
393  llvm::DataExtractor DE(Serialized, true, 8);
394  auto TraceOrErr = llvm::xray::loadTrace(DE);
395  EXPECT_THAT_EXPECTED(
396      TraceOrErr, HasValue(ElementsAre(AllOf(
397                      FuncId(1), RecordType(llvm::xray::RecordTypes::ENTER)))));
398}
399
400TEST_F(BufferManagementTest, HandlesGenerationalBufferQueue) {
401  uint64_t TSC = 1;
402  uint16_t CPU = 1;
403
404  ASSERT_TRUE(C->functionEnter(1, TSC++, CPU));
405  ASSERT_THAT(BQ->finalize(), Eq(BufferQueue::ErrorCode::Ok));
406  ASSERT_THAT(BQ->init(sizeof(MetadataRecord) * 4 + sizeof(FunctionRecord) * 2,
407                       kBuffers),
408              Eq(BufferQueue::ErrorCode::Ok));
409  EXPECT_TRUE(C->functionExit(1, TSC++, CPU));
410  ASSERT_TRUE(C->flush());
411
412  // We expect that we will only be able to find the function exit event, but
413  // not the function enter event, since we only have information about the new
414  // generation of the buffers.
415  std::string Serialized = serialize(*BQ, 3);
416  llvm::DataExtractor DE(Serialized, true, 8);
417  auto TraceOrErr = llvm::xray::loadTrace(DE);
418  EXPECT_THAT_EXPECTED(
419      TraceOrErr, HasValue(ElementsAre(AllOf(
420                      FuncId(1), RecordType(llvm::xray::RecordTypes::EXIT)))));
421}
422
423} // namespace
424} // namespace __xray
425