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