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