Index: compiler-rt/cmake/Modules/AddCompilerRT.cmake =================================================================== --- compiler-rt/cmake/Modules/AddCompilerRT.cmake +++ compiler-rt/cmake/Modules/AddCompilerRT.cmake @@ -357,6 +357,16 @@ -I${COMPILER_RT_GTEST_PATH} ) +# Mocking support. +set(COMPILER_RT_GMOCK_PATH ${LLVM_MAIN_SRC_DIR}/utils/unittest/googlemock) +set(COMPILER_RT_GMOCK_SOURCE ${COMPILER_RT_GMOCK_PATH}/src/gmock-all.cc) +set(COMPILER_RT_GMOCK_CFLAGS + -DGTEST_NO_LLVM_RAW_OSTREAM=1 + -DGTEST_HAS_RTTI=0 + -I${COMPILER_RT_GMOCK_PATH}/include + -I${COMPILER_RT_GMOCK_PATH} +) + append_list_if(COMPILER_RT_DEBUG -DSANITIZER_DEBUG=1 COMPILER_RT_UNITTEST_CFLAGS) append_list_if(COMPILER_RT_HAS_WCOVERED_SWITCH_DEFAULT_FLAG -Wno-covered-switch-default COMPILER_RT_UNITTEST_CFLAGS) Index: compiler-rt/lib/xray/tests/CMakeLists.txt =================================================================== --- compiler-rt/lib/xray/tests/CMakeLists.txt +++ compiler-rt/lib/xray/tests/CMakeLists.txt @@ -19,9 +19,13 @@ ${XRAY_CFLAGS} ${COMPILER_RT_UNITTEST_CFLAGS} ${COMPILER_RT_GTEST_CFLAGS} + ${COMPILER_RT_GMOCK_CFLAGS} -I${COMPILER_RT_SOURCE_DIR}/include -I${COMPILER_RT_SOURCE_DIR}/lib/xray - -I${COMPILER_RT_SOURCE_DIR}/lib) + -I${COMPILER_RT_SOURCE_DIR}/lib + -I${LLVM_MAIN_SRC_DIR}/include + -I${LLVM_INCLUDE_DIR} + ) function(add_xray_lib library) add_library(${library} STATIC ${ARGN}) @@ -68,11 +72,14 @@ COMPILE_DEPS ${TEST_SOURCES} ${COMPILER_RT_GTEST_SOURCE} ${XRAY_HEADERS} ${XRAY_ALL_SOURCE_FILES_ABS_PATHS} RUNTIME "${XRAY_RUNTIME_LIBS}" - DEPS gtest xray llvm-xray + DEPS gtest xray llvm-xray LLVMXRay LLVMTestingSupport CFLAGS ${XRAY_UNITTEST_CFLAGS} - LINK_FLAGS ${TARGET_LINK_FLAGS} ${XRAY_UNITTEST_LINK_FLAGS}) + LINK_FLAGS ${TARGET_LINK_FLAGS} ${XRAY_UNITTEST_LINK_FLAGS} + -lLLVMXRay -lLLVMSupport -lLLVMTestingSupport -ltinfo + ) set_target_properties(XRayUnitTests - PROPERTIES RUNTIME_OUTPUT_DIRECTORY ${CMAKE_CURRENT_BINARY_DIR}) + PROPERTIES + RUNTIME_OUTPUT_DIRECTORY ${CMAKE_CURRENT_BINARY_DIR}) endforeach() endif() endmacro() Index: compiler-rt/lib/xray/tests/unit/CMakeLists.txt =================================================================== --- compiler-rt/lib/xray/tests/unit/CMakeLists.txt +++ compiler-rt/lib/xray/tests/unit/CMakeLists.txt @@ -8,3 +8,7 @@ function_call_trie_test.cc xray_unit_test_main.cc) add_xray_unittest(XRayProfileCollectorTest SOURCES profile_collector_test.cc xray_unit_test_main.cc) + +add_xray_unittest(XRayFDRLoggingTest SOURCES + fdr_log_writer_test.cc + xray_unit_test_main.cc) Index: compiler-rt/lib/xray/tests/unit/fdr_log_writer_test.cc =================================================================== --- /dev/null +++ compiler-rt/lib/xray/tests/unit/fdr_log_writer_test.cc @@ -0,0 +1,87 @@ +//===-- fdr_log_writer_test.cc --------------------------------------------===// +// +// The LLVM Compiler Infrastructure +// +// This file is distributed under the University of Illinois Open Source +// License. See LICENSE.TXT for details. +// +//===----------------------------------------------------------------------===// +// +// This file is a part of XRay, a function call tracing system. +// +//===----------------------------------------------------------------------===// +#include + +#include "xray/xray_records.h" +#include "xray_fdr_log_writer.h" +#include "llvm/Support/DataExtractor.h" +#include "llvm/Testing/Support/Error.h" +#include "llvm/XRay/Trace.h" +#include "gmock/gmock.h" +#include "gtest/gtest.h" + +namespace __xray { +namespace { + +static constexpr size_t kSize = 4096; + +using ::llvm::HasValue; +using ::testing::SizeIs; + +// Exercise the common code path where we initialize a buffer and are able to +// write some records successfully. +TEST(FdrLogWriterTest, WriteSomeRecords) { + bool Success = false; + BufferQueue Buffers(kSize, 1, Success); + BufferQueue::Buffer B; + ASSERT_EQ(Buffers.getBuffer(B), BufferQueue::ErrorCode::Ok); + + FDRLogWriter Writer(B); + ASSERT_TRUE(Writer.writeMetadata(1)); + ASSERT_TRUE( + Writer.writeMetadata(1, 2)); + ASSERT_TRUE(Writer.writeMetadata(3)); + ASSERT_TRUE(Writer.writeMetadata(1)); + ASSERT_TRUE( + Writer.writeFunction(FDRLogWriter::FunctionRecordKind::Enter, 1, 1)); + ASSERT_TRUE( + Writer.writeFunction(FDRLogWriter::FunctionRecordKind::Exit, 1, 1)); + ASSERT_EQ(Buffers.releaseBuffer(B), BufferQueue::ErrorCode::Ok); + ASSERT_EQ(B.Data, nullptr); + ASSERT_EQ(Buffers.finalize(), BufferQueue::ErrorCode::Ok); + + // We then need to go through each element of the Buffers, and re-create a + // flat buffer that we would see if they were laid out in a file. This also + // means we need to write out the header manually. + // TODO: Isolate the file header writing. + std::string Serialized; + std::aligned_storage::type + HeaderStorage; + auto *Header = reinterpret_cast(&HeaderStorage); + new (Header) XRayFileHeader(); + Header->Version = 3; + Header->Type = FileTypes::FDR_LOG; + Header->CycleFrequency = 3e9; + Header->ConstantTSC = 1; + Header->NonstopTSC = 1; + Serialized.append(reinterpret_cast(&HeaderStorage), + sizeof(XRayFileHeader)); + size_t BufferCount = 0; + Buffers.apply([&](const BufferQueue::Buffer &B) { + ++BufferCount; + auto Size = atomic_load_relaxed(&B.Extents); + auto Extents = + createMetadataRecord(Size); + Serialized.append(reinterpret_cast(&Extents), + sizeof(Extents)); + Serialized.append(reinterpret_cast(B.Data), Size); + }); + ASSERT_EQ(BufferCount, 1u); + + llvm::DataExtractor DE(Serialized, true, 8); + auto TraceOrErr = llvm::xray::loadTrace(DE); + EXPECT_THAT_EXPECTED(TraceOrErr, HasValue(SizeIs(2))); +} + +} // namespace +} // namespace __xray Index: compiler-rt/lib/xray/xray_fdr_log_records.h =================================================================== --- compiler-rt/lib/xray/xray_fdr_log_records.h +++ compiler-rt/lib/xray/xray_fdr_log_records.h @@ -12,6 +12,9 @@ //===----------------------------------------------------------------------===// #ifndef XRAY_XRAY_FDR_LOG_RECORDS_H #define XRAY_XRAY_FDR_LOG_RECORDS_H +#include + +namespace __xray { enum class RecordType : uint8_t { Function, Metadata }; @@ -68,4 +71,6 @@ static_assert(sizeof(FunctionRecord) == 8, "Wrong size for FunctionRecord."); +} // namespace __xray + #endif // XRAY_XRAY_FDR_LOG_RECORDS_H Index: compiler-rt/lib/xray/xray_fdr_log_writer.h =================================================================== --- /dev/null +++ compiler-rt/lib/xray/xray_fdr_log_writer.h @@ -0,0 +1,117 @@ +//===-- xray_fdr_log_writer.h ---------------------------------------------===// +// +// The LLVM Compiler Infrastructure +// +// This file is distributed under the University of Illinois Open Source +// License. See LICENSE.TXT for details. +// +//===----------------------------------------------------------------------===// +// +// This file is a part of XRay, a function call tracing system. +// +//===----------------------------------------------------------------------===// +#ifndef COMPILER_RT_LIB_XRAY_XRAY_FDR_LOG_WRITER_H_ +#define COMPILER_RT_LIB_XRAY_XRAY_FDR_LOG_WRITER_H_ + +#include "xray_buffer_queue.h" +#include "xray_fdr_log_records.h" +#include +#include +#include +#include + +namespace __xray { + +template struct SerializerImpl { + template ::type>::value, + int>::type = 0> static void serializeTo(char *Buffer, + Tuple &&T) { + auto P = reinterpret_cast(&std::get(T)); + constexpr auto Size = sizeof(std::get(T)); + internal_memcpy(Buffer, P, Size); + SerializerImpl::serializeTo(Buffer + Size, T); + } + + template = std::tuple_size::type>::value, + int>::type = 0> + static void serializeTo(char *, Tuple &&){}; +}; + +using Serializer = SerializerImpl<0>; + +template +MetadataRecord createMetadataRecord(Data &&... Ds) { + MetadataRecord R; + R.Type = 1; + R.RecordKind = static_cast(Kind); + Serializer::serializeTo(R.Data, std::make_tuple(std::forward(Ds)...)); + return R; +} + +class FDRLogWriter { + BufferQueue::Buffer &Buffer; + char *NextRecord = nullptr; + + template void writeRecord(const T &R) { + internal_memcpy(NextRecord, reinterpret_cast(&R), sizeof(T)); + NextRecord += sizeof(T); + atomic_fetch_add(&Buffer.Extents, sizeof(T), memory_order_acq_rel); + } + +public: + explicit FDRLogWriter(BufferQueue::Buffer &B, char *P) + : Buffer(B), NextRecord(P) { + DCHECK_NE(Buffer.Data, nullptr); + DCHECK_NE(NextRecord, nullptr); + } + + explicit FDRLogWriter(BufferQueue::Buffer &B) + : FDRLogWriter(B, static_cast(B.Data)) {} + + template + bool writeMetadata(Data &&... Ds) { + // TODO: Check boundary conditions: + // 1) Buffer is full, and cannot handle one metadata record. + // 2) Buffer queue is finalising. + writeRecord(createMetadataRecord(std::forward(Ds)...)); + return true; + } + + template size_t writeMetadataRecords(MetadataRecord (&Recs)[N]) { + constexpr auto Size = sizeof(MetadataRecord) * N; + internal_memcpy(NextRecord, reinterpret_cast(Recs), Size); + NextRecord += Size; + atomic_fetch_add(&Buffer.Extents, Size, memory_order_acq_rel); + return Size; + } + + enum class FunctionRecordKind : uint8_t { + Enter = 0x00, + Exit = 0x01, + TailExit = 0x02, + EnterArg = 0x03, + }; + + bool writeFunction(FunctionRecordKind Kind, int32_t FuncId, int32_t Delta) { + FunctionRecord R; + R.Type = 0; + R.RecordKind = uint8_t(Kind); + R.FuncId = FuncId; + R.TSCDelta = Delta; + writeRecord(R); + return true; + } + + char *getNextRecord() const { return NextRecord; } + +}; // namespace __xray + +} // namespace __xray + +#endif // COMPILER-RT_LIB_XRAY_XRAY_FDR_LOG_WRITER_H_ Index: compiler-rt/lib/xray/xray_fdr_logging.cc =================================================================== --- compiler-rt/lib/xray/xray_fdr_logging.cc +++ compiler-rt/lib/xray/xray_fdr_logging.cc @@ -34,6 +34,7 @@ #include "xray_buffer_queue.h" #include "xray_defs.h" #include "xray_fdr_flags.h" +#include "xray_fdr_log_writer.h" #include "xray_flags.h" #include "xray_recursion_guard.h" #include "xray_tsc.h" @@ -138,59 +139,35 @@ static void writeNewBufferPreamble(tid_t Tid, timespec TS, pid_t Pid) XRAY_NEVER_INSTRUMENT { - static constexpr int InitRecordsCount = 3; + static_assert(sizeof(time_t) <= 8, "time_t needs to be at most 8 bytes"); auto &TLD = getThreadLocalData(); - MetadataRecord Metadata[InitRecordsCount]; - { - // Write out a MetadataRecord to signify that this is the start of a new - // buffer, associated with a particular thread, with a new CPU. For the - // data, we have 15 bytes to squeeze as much information as we can. At this - // point we only write down the following bytes: - // - Thread ID (tid_t, cast to 4 bytes type due to Darwin being 8 bytes) - auto &NewBuffer = Metadata[0]; - NewBuffer.Type = uint8_t(RecordType::Metadata); - NewBuffer.RecordKind = uint8_t(MetadataRecord::RecordKinds::NewBuffer); - int32_t tid = static_cast(Tid); - internal_memcpy(&NewBuffer.Data, &tid, sizeof(tid)); - } - - // Also write the WalltimeMarker record. - { - static_assert(sizeof(time_t) <= 8, "time_t needs to be at most 8 bytes"); - auto &WalltimeMarker = Metadata[1]; - WalltimeMarker.Type = uint8_t(RecordType::Metadata); - WalltimeMarker.RecordKind = - uint8_t(MetadataRecord::RecordKinds::WalltimeMarker); - - // We only really need microsecond precision here, and enforce across - // platforms that we need 64-bit seconds and 32-bit microseconds encoded in - // the Metadata record. - int32_t Micros = TS.tv_nsec / 1000; - int64_t Seconds = TS.tv_sec; - internal_memcpy(WalltimeMarker.Data, &Seconds, sizeof(Seconds)); - internal_memcpy(WalltimeMarker.Data + sizeof(Seconds), &Micros, - sizeof(Micros)); - } - - // Also write the Pid record. - { - // Write out a MetadataRecord that contains the current pid - auto &PidMetadata = Metadata[2]; - PidMetadata.Type = uint8_t(RecordType::Metadata); - PidMetadata.RecordKind = uint8_t(MetadataRecord::RecordKinds::Pid); - int32_t pid = static_cast(Pid); - internal_memcpy(&PidMetadata.Data, &pid, sizeof(pid)); - } + MetadataRecord Metadata[] = { + // Write out a MetadataRecord to signify that this is the start of a new + // buffer, associated with a particular thread, with a new CPU. For the + // data, we have 15 bytes to squeeze as much information as we can. At + // this point we only write down the following bytes: + // - Thread ID (tid_t, cast to 4 bytes type due to Darwin being 8 bytes) + createMetadataRecord( + static_cast(Tid)), + + // Also write the WalltimeMarker record. We only really need microsecond + // precision here, and enforce across platforms that we need 64-bit + // seconds and 32-bit microseconds encoded in the Metadata record. + createMetadataRecord( + static_cast(TS.tv_sec), + static_cast(TS.tv_nsec / 1000)), + + // Also write the Pid record. + createMetadataRecord( + static_cast(Pid)), + }; TLD.NumConsecutiveFnEnters = 0; TLD.NumTailCalls = 0; if (TLD.BQ == nullptr || TLD.BQ->finalizing()) return; - internal_memcpy(TLD.RecordPtr, Metadata, - sizeof(MetadataRecord) * InitRecordsCount); - TLD.RecordPtr += sizeof(MetadataRecord) * InitRecordsCount; - atomic_store(&TLD.Buffer.Extents, sizeof(MetadataRecord) * InitRecordsCount, - memory_order_release); + FDRLogWriter Writer(TLD.Buffer); + TLD.RecordPtr += Writer.writeMetadataRecords(Metadata); } static void setupNewBuffer(int (*wall_clock_reader)( @@ -198,6 +175,7 @@ auto &TLD = getThreadLocalData(); auto &B = TLD.Buffer; TLD.RecordPtr = static_cast(B.Data); + atomic_store(&B.Extents, 0, memory_order_release); tid_t Tid = GetTid(); timespec TS{0, 0}; pid_t Pid = internal_getpid(); @@ -221,52 +199,38 @@ static void writeNewCPUIdMetadata(uint16_t CPU, uint64_t TSC) XRAY_NEVER_INSTRUMENT { auto &TLD = getThreadLocalData(); - MetadataRecord NewCPUId; - NewCPUId.Type = uint8_t(RecordType::Metadata); - NewCPUId.RecordKind = uint8_t(MetadataRecord::RecordKinds::NewCPUId); + FDRLogWriter W(TLD.Buffer, TLD.RecordPtr); // The data for the New CPU will contain the following bytes: // - CPU ID (uint16_t, 2 bytes) // - Full TSC (uint64_t, 8 bytes) // Total = 10 bytes. - internal_memcpy(&NewCPUId.Data, &CPU, sizeof(CPU)); - internal_memcpy(&NewCPUId.Data[sizeof(CPU)], &TSC, sizeof(TSC)); - internal_memcpy(TLD.RecordPtr, &NewCPUId, sizeof(MetadataRecord)); - TLD.RecordPtr += sizeof(MetadataRecord); + W.writeMetadata(CPU, TSC); + TLD.RecordPtr = W.getNextRecord(); TLD.NumConsecutiveFnEnters = 0; TLD.NumTailCalls = 0; - incrementExtents(sizeof(MetadataRecord)); } static void writeTSCWrapMetadata(uint64_t TSC) XRAY_NEVER_INSTRUMENT { auto &TLD = getThreadLocalData(); - MetadataRecord TSCWrap; - TSCWrap.Type = uint8_t(RecordType::Metadata); - TSCWrap.RecordKind = uint8_t(MetadataRecord::RecordKinds::TSCWrap); + FDRLogWriter W(TLD.Buffer, TLD.RecordPtr); // The data for the TSCWrap record contains the following bytes: // - Full TSC (uint64_t, 8 bytes) // Total = 8 bytes. - internal_memcpy(&TSCWrap.Data, &TSC, sizeof(TSC)); - internal_memcpy(TLD.RecordPtr, &TSCWrap, sizeof(MetadataRecord)); - TLD.RecordPtr += sizeof(MetadataRecord); + W.writeMetadata(TSC); + TLD.RecordPtr = W.getNextRecord(); TLD.NumConsecutiveFnEnters = 0; TLD.NumTailCalls = 0; - incrementExtents(sizeof(MetadataRecord)); } // Call Argument metadata records store the arguments to a function in the // order of their appearance; holes are not supported by the buffer format. static void writeCallArgumentMetadata(uint64_t A) XRAY_NEVER_INSTRUMENT { auto &TLD = getThreadLocalData(); - MetadataRecord CallArg; - CallArg.Type = uint8_t(RecordType::Metadata); - CallArg.RecordKind = uint8_t(MetadataRecord::RecordKinds::CallArgument); - - internal_memcpy(CallArg.Data, &A, sizeof(A)); - internal_memcpy(TLD.RecordPtr, &CallArg, sizeof(MetadataRecord)); - TLD.RecordPtr += sizeof(MetadataRecord); - incrementExtents(sizeof(MetadataRecord)); + FDRLogWriter W(TLD.Buffer, TLD.RecordPtr); + W.writeMetadata(A); + TLD.RecordPtr = W.getNextRecord(); } static void writeFunctionRecord(int32_t FuncId, uint32_t TSCDelta, @@ -279,8 +243,8 @@ return; } - FunctionRecord FuncRecord; - FuncRecord.Type = uint8_t(RecordType::Function); + auto &TLD = getThreadLocalData(); + FDRLogWriter W(TLD.Buffer, TLD.RecordPtr); // Only take 28 bits of the function id. // @@ -289,27 +253,25 @@ // to the first 28 bits. To do this properly, this means we need to mask the // function id with (2 ^ 28) - 1 == 0x0fffffff. // - FuncRecord.FuncId = FuncId & MaxFuncId; - FuncRecord.TSCDelta = TSCDelta; + auto TruncatedId = FuncId & MaxFuncId; + auto Kind = FDRLogWriter::FunctionRecordKind::Enter; - auto &TLD = getThreadLocalData(); switch (EntryType) { case XRayEntryType::ENTRY: ++TLD.NumConsecutiveFnEnters; - FuncRecord.RecordKind = uint8_t(FunctionRecord::RecordKinds::FunctionEnter); break; case XRayEntryType::LOG_ARGS_ENTRY: // We should not rewind functions with logged args. TLD.NumConsecutiveFnEnters = 0; TLD.NumTailCalls = 0; - FuncRecord.RecordKind = uint8_t(FunctionRecord::RecordKinds::FunctionEnter); + Kind = FDRLogWriter::FunctionRecordKind::EnterArg; break; case XRayEntryType::EXIT: // If we've decided to log the function exit, we will never erase the log // before it. TLD.NumConsecutiveFnEnters = 0; TLD.NumTailCalls = 0; - FuncRecord.RecordKind = uint8_t(FunctionRecord::RecordKinds::FunctionExit); + Kind = FDRLogWriter::FunctionRecordKind::Exit; break; case XRayEntryType::TAIL: // If we just entered the function we're tail exiting from or erased every @@ -324,8 +286,7 @@ TLD.NumTailCalls = 0; TLD.NumConsecutiveFnEnters = 0; } - FuncRecord.RecordKind = - uint8_t(FunctionRecord::RecordKinds::FunctionTailExit); + Kind = FDRLogWriter::FunctionRecordKind::TailExit; break; case XRayEntryType::CUSTOM_EVENT: { // This is a bug in patching, so we'll report it once and move on. @@ -346,9 +307,8 @@ } } - internal_memcpy(TLD.RecordPtr, &FuncRecord, sizeof(FunctionRecord)); - TLD.RecordPtr += sizeof(FunctionRecord); - incrementExtents(sizeof(FunctionRecord)); + W.writeFunction(Kind, TruncatedId, TSCDelta); + TLD.RecordPtr = W.getNextRecord(); } static atomic_uint64_t TicksPerSec{0}; @@ -423,6 +383,9 @@ static bool releaseThreadLocalBuffer(BufferQueue &BQArg) { auto &TLD = getThreadLocalData(); auto EC = BQArg.releaseBuffer(TLD.Buffer); + if (TLD.Buffer.Data == nullptr) + return true; + if (EC != BufferQueue::ErrorCode::Ok) { Report("Failed to release buffer at %p; error=%s\n", TLD.Buffer.Data, BufferQueue::getErrorString(EC)); @@ -1174,6 +1137,8 @@ auto &TLD = *reinterpret_cast(TLDPtr); if (TLD.BQ == nullptr) return; + if (TLD.Buffer.Data == nullptr) + return; auto EC = TLD.BQ->releaseBuffer(TLD.Buffer); if (EC != BufferQueue::ErrorCode::Ok) Report("At thread exit, failed to release buffer at %p; error=%s\n", Index: llvm/include/llvm/XRay/Trace.h =================================================================== --- llvm/include/llvm/XRay/Trace.h +++ llvm/include/llvm/XRay/Trace.h @@ -46,20 +46,25 @@ /// class Trace { XRayFileHeader FileHeader; - std::vector Records; + using RecordVector = std::vector; + RecordVector Records; typedef std::vector::const_iterator citerator; friend Expected loadTrace(const DataExtractor &, bool); public: + using size_type = RecordVector::size_type; + using value_type = RecordVector::value_type; + using const_iterator = RecordVector::const_iterator; + /// Provides access to the loaded XRay trace file header. const XRayFileHeader &getFileHeader() const { return FileHeader; } - citerator begin() const { return Records.begin(); } - citerator end() const { return Records.end(); } + const_iterator begin() const { return Records.begin(); } + const_iterator end() const { return Records.end(); } bool empty() const { return Records.empty(); } - size_t size() const { return Records.size(); } + size_type size() const { return Records.size(); } }; /// This function will attempt to load XRay trace records from the provided