[XRAY] [x86_64] Adding a Flight Data filetype reader to the llvm-xray Trace implementation.

Summary:
The file type packs function trace data onto disk from potentially multiple
threads that are aggregated and flushed during the course of an instrumented
program's runtime.

It is named FDR mode or Flight Data recorder as an analogy to plane
blackboxes, which instrument a running system without access to IO.

The writer code is defined in compiler-rt in xray_fdr_logging.h/cc

Reviewers: rSerge, kcc, dberris

Reviewed By: dberris

Subscribers: llvm-commits

Differential Revision: https://reviews.llvm.org/D29697

llvm-svn: 295397
This commit is contained in:
Dean Michael Berris 2017-02-17 01:47:16 +00:00
parent 4f94a94bea
commit 4f83c4d1a6
6 changed files with 334 additions and 23 deletions

View File

@ -54,8 +54,8 @@ struct XRayRecord {
/// The type of record.
uint16_t RecordType;
/// The CPU where the thread is running. We assume number of CPUs <= 256.
uint8_t CPU;
/// The CPU where the thread is running. We assume number of CPUs <= 65536.
uint16_t CPU;
/// Identifies the type of record.
RecordTypes Type;

View File

@ -31,7 +31,7 @@ struct YAMLXRayFileHeader {
struct YAMLXRayRecord {
uint16_t RecordType;
uint8_t CPU;
uint16_t CPU;
RecordTypes Type;
int32_t FuncId;
std::string Function;

View File

@ -24,8 +24,8 @@ using llvm::yaml::Input;
using XRayRecordStorage =
std::aligned_storage<sizeof(XRayRecord), alignof(XRayRecord)>::type;
static Error NaiveLogLoader(StringRef Data, XRayFileHeader &FileHeader,
std::vector<XRayRecord> &Records) {
// Populates the FileHeader reference by reading the first 32 bytes of the file.
Error readBinaryFormatHeader(StringRef Data, XRayFileHeader &FileHeader) {
// FIXME: Maybe deduce whether the data is little or big-endian using some
// magic bytes in the beginning of the file?
@ -37,16 +37,6 @@ static Error NaiveLogLoader(StringRef Data, XRayFileHeader &FileHeader,
// (4) uint32 : bitfield
// (8) uint64 : cycle frequency
// (16) - : padding
//
if (Data.size() < 32)
return make_error<StringError>(
"Not enough bytes for an XRay log.",
std::make_error_code(std::errc::invalid_argument));
if (Data.size() - 32 == 0 || Data.size() % 32 != 0)
return make_error<StringError>(
"Invalid-sized XRay data.",
std::make_error_code(std::errc::invalid_argument));
DataExtractor HeaderExtractor(Data, true, 8);
uint32_t OffsetPtr = 0;
@ -61,6 +51,24 @@ static Error NaiveLogLoader(StringRef Data, XRayFileHeader &FileHeader,
return make_error<StringError>(
Twine("Unsupported XRay file version: ") + Twine(FileHeader.Version),
std::make_error_code(std::errc::invalid_argument));
return Error::success();
}
Error loadNaiveFormatLog(StringRef Data, XRayFileHeader &FileHeader,
std::vector<XRayRecord> &Records) {
// Check that there is at least a header
if (Data.size() < 32)
return make_error<StringError>(
"Not enough bytes for an XRay log.",
std::make_error_code(std::errc::invalid_argument));
if (Data.size() - 32 == 0 || Data.size() % 32 != 0)
return make_error<StringError>(
"Invalid-sized XRay data.",
std::make_error_code(std::errc::invalid_argument));
if (auto E = readBinaryFormatHeader(Data, FileHeader))
return E;
// Each record after the header will be 32 bytes, in the following format:
//
@ -98,9 +106,279 @@ static Error NaiveLogLoader(StringRef Data, XRayFileHeader &FileHeader,
return Error::success();
}
static Error YAMLLogLoader(StringRef Data, XRayFileHeader &FileHeader,
std::vector<XRayRecord> &Records) {
/// When reading from a Flight Data Recorder mode log, metadata records are
/// sparse compared to packed function records, so we must maintain state as we
/// read through the sequence of entries. This allows the reader to denormalize
/// the CPUId and Thread Id onto each Function Record and transform delta
/// encoded TSC values into absolute encodings on each record.
struct FDRState {
uint16_t CPUId;
uint16_t ThreadId;
uint64_t BaseTSC;
/// Encode some of the state transitions for the FDR log reader as explicit
/// checks. These are expectations for the next Record in the stream.
enum class Token {
NEW_BUFFER_RECORD_OR_EOF,
WALLCLOCK_RECORD,
NEW_CPU_ID_RECORD,
FUNCTION_SEQUENCE
};
Token Expects;
};
/// State transition when a NewBufferRecord is encountered.
Error processFDRNewBufferRecord(FDRState &State, uint8_t RecordFirstByte,
DataExtractor &RecordExtractor) {
if (State.Expects != FDRState::Token::NEW_BUFFER_RECORD_OR_EOF) {
return make_error<StringError>(
"Malformed log. Read New Buffer record kind out of sequence",
std::make_error_code(std::errc::executable_format_error));
}
uint32_t OffsetPtr = 1; // 1 byte into record.
State.ThreadId = RecordExtractor.getU16(&OffsetPtr);
State.Expects = FDRState::Token::WALLCLOCK_RECORD;
return Error::success();
}
/// State transition when an EndOfBufferRecord is encountered.
Error processFDREndOfBufferRecord(FDRState &State, uint8_t RecordFirstByte,
DataExtractor &RecordExtractor) {
if (State.Expects == FDRState::Token::NEW_BUFFER_RECORD_OR_EOF) {
return make_error<StringError>(
"Malformed log. Received EOB message without current buffer.",
std::make_error_code(std::errc::executable_format_error));
}
State.Expects = FDRState::Token::NEW_BUFFER_RECORD_OR_EOF;
return Error::success();
}
/// State transition when a NewCPUIdRecord is encountered.
Error processFDRNewCPUIdRecord(FDRState &State, uint8_t RecordFirstByte,
DataExtractor &RecordExtractor) {
if (State.Expects != FDRState::Token::FUNCTION_SEQUENCE &&
State.Expects != FDRState::Token::NEW_CPU_ID_RECORD) {
return make_error<StringError>(
"Malformed log. Read NewCPUId record kind out of sequence",
std::make_error_code(std::errc::executable_format_error));
}
uint32_t OffsetPtr = 1; // Read starting after the first byte.
State.CPUId = RecordExtractor.getU16(&OffsetPtr);
State.BaseTSC = RecordExtractor.getU64(&OffsetPtr);
State.Expects = FDRState::Token::FUNCTION_SEQUENCE;
return Error::success();
}
/// State transition when a TSCWrapRecord (overflow detection) is encountered.
Error processFDRTSCWrapRecord(FDRState &State, uint8_t RecordFirstByte,
DataExtractor &RecordExtractor) {
if (State.Expects != FDRState::Token::FUNCTION_SEQUENCE) {
return make_error<StringError>(
"Malformed log. Read TSCWrap record kind out of sequence",
std::make_error_code(std::errc::executable_format_error));
}
uint32_t OffsetPtr = 1; // Read starting after the first byte.
State.BaseTSC = RecordExtractor.getU64(&OffsetPtr);
return Error::success();
}
/// State transition when a WallTimeMarkerRecord is encountered.
Error processFDRWallTimeRecord(FDRState &State, uint8_t RecordFirstByte,
DataExtractor &RecordExtractor) {
if (State.Expects != FDRState::Token::WALLCLOCK_RECORD) {
return make_error<StringError>(
"Malformed log. Read Wallclock record kind out of sequence",
std::make_error_code(std::errc::executable_format_error));
}
// We don't encode the wall time into any of the records.
// XRayRecords are concerned with the TSC instead.
State.Expects = FDRState::Token::NEW_CPU_ID_RECORD;
return Error::success();
}
/// Advances the state machine for reading the FDR record type by reading one
/// Metadata Record and updating the State approriately based on the kind of
/// record encountered. The RecordKind is encoded in the first byte of the
/// Record, which the caller should pass in because they have already read it
/// to determine that this is a metadata record as opposed to a function record.
Error processFDRMetadataRecord(FDRState &State, uint8_t RecordFirstByte,
DataExtractor &RecordExtractor) {
// The remaining 7 bits are the RecordKind enum.
uint8_t RecordKind = RecordFirstByte >> 1;
switch (RecordKind) {
case 0: // NewBuffer
if (auto E =
processFDRNewBufferRecord(State, RecordFirstByte, RecordExtractor))
return E;
break;
case 1: // EndOfBuffer
if (auto E = processFDREndOfBufferRecord(State, RecordFirstByte,
RecordExtractor))
return E;
break;
case 2: // NewCPUId
if (auto E =
processFDRNewCPUIdRecord(State, RecordFirstByte, RecordExtractor))
return E;
break;
case 3: // TSCWrap
if (auto E =
processFDRTSCWrapRecord(State, RecordFirstByte, RecordExtractor))
return E;
break;
case 4: // WallTimeMarker
if (auto E =
processFDRWallTimeRecord(State, RecordFirstByte, RecordExtractor))
return E;
break;
default:
// Widen the record type to uint16_t to prevent conversion to char.
return make_error<StringError>(
Twine("Illegal metadata record type: ")
.concat(Twine(static_cast<unsigned>(RecordKind))),
std::make_error_code(std::errc::executable_format_error));
}
return Error::success();
}
/// Reads a function record from an FDR format log, appending a new XRayRecord
/// to the vector being populated and updating the State with a new value
/// reference value to interpret TSC deltas.
///
/// The XRayRecord constructed includes information from the function record
/// processed here as well as Thread ID and CPU ID formerly extracted into
/// State.
Error processFDRFunctionRecord(FDRState &State, uint8_t RecordFirstByte,
DataExtractor &RecordExtractor,
std::vector<XRayRecord> &Records) {
switch (State.Expects) {
case FDRState::Token::NEW_BUFFER_RECORD_OR_EOF:
return make_error<StringError>(
"Malformed log. Received Function Record before new buffer setup.",
std::make_error_code(std::errc::executable_format_error));
case FDRState::Token::WALLCLOCK_RECORD:
return make_error<StringError>(
"Malformed log. Received Function Record when expecting wallclock.",
std::make_error_code(std::errc::executable_format_error));
case FDRState::Token::NEW_CPU_ID_RECORD:
return make_error<StringError>(
"Malformed log. Received Function Record before first CPU record.",
std::make_error_code(std::errc::executable_format_error));
default:
Records.emplace_back();
auto &Record = Records.back();
Record.RecordType = 0; // Record is type NORMAL.
// Strip off record type bit and use the next three bits.
uint8_t RecordType = (RecordFirstByte >> 1) & 0x07;
switch (RecordType) {
case static_cast<uint8_t>(RecordTypes::ENTER):
Record.Type = RecordTypes::ENTER;
break;
case static_cast<uint8_t>(RecordTypes::EXIT):
case 2: // TAIL_EXIT is not yet defined in RecordTypes.
Record.Type = RecordTypes::EXIT;
break;
default:
// When initializing the error, convert to uint16_t so that the record
// type isn't interpreted as a char.
return make_error<StringError>(
Twine("Illegal function record type: ")
.concat(Twine(static_cast<unsigned>(RecordType))),
std::make_error_code(std::errc::executable_format_error));
}
Record.CPU = State.CPUId;
Record.TId = State.ThreadId;
// Back up to read first 32 bits, including the 8 we pulled RecordType
// and RecordKind out of. The remaining 28 are FunctionId.
uint32_t OffsetPtr = 0;
// Despite function Id being a signed int on XRayRecord,
// when it is written to an FDR format, the top bits are truncated,
// so it is effectively an unsigned value. When we shift off the
// top four bits, we want the shift to be logical, so we read as
// uint32_t.
uint32_t FuncIdBitField = RecordExtractor.getU32(&OffsetPtr);
Record.FuncId = FuncIdBitField >> 4;
// FunctionRecords have a 32 bit delta from the previous absolute TSC
// or TSC delta. If this would overflow, we should read a TSCWrap record
// with an absolute TSC reading.
uint64_t new_tsc = State.BaseTSC + RecordExtractor.getU32(&OffsetPtr);
State.BaseTSC = new_tsc;
Record.TSC = new_tsc;
}
return Error::success();
}
/// Reads a log in FDR mode for version 1 of this binary format. FDR mode is
/// defined as part of the compiler-rt project in xray_fdr_logging.h, and such
/// a log consists of the familiar 32 bit XRayHeader, followed by sequences of
/// of interspersed 16 byte Metadata Records and 8 byte Function Records.
///
/// The following is an attempt to document the grammar of the format, which is
/// parsed by this function for little-endian machines. Since the format makes
/// use of BitFields, when we support big-Endian architectures, we will need to
/// adjust not only the endianess parameter to llvm's RecordExtractor, but also
/// the bit twiddling logic, which is consistent with the little-endian
/// convention that BitFields within a struct will first be packed into the
/// least significant bits the address they belong to.
///
/// We expect a format complying with the grammar in the following pseudo-EBNF.
///
/// FDRLog: XRayFileHeader ThreadBuffer*
/// XRayFileHeader: 32 bits to identify the log as FDR with machine metadata.
/// ThreadBuffer: NewBuffer WallClockTime NewCPUId FunctionSequence EOB
/// NewBuffer: 16 byte metadata record with Thread Id.
/// WallClockTime: 16 byte metadata record with human readable time.
/// NewCPUId: 16 byte metadata record with CPUId and a 64 bit TSC reading.
/// EOB: 16 byte metadata record marking the end of a thread's sequence.
/// FunctionSequence: NewCPUId | TSCWrap | FunctionRecord
/// TSCWrap: 16 byte metadata record with a full 64 bit TSC reading.
/// FunctionRecord: 8 byte record with FunctionId, entry/exit, and TSC delta.
Error loadFDRLog(StringRef Data, XRayFileHeader &FileHeader,
std::vector<XRayRecord> &Records) {
if (Data.size() < 32)
return make_error<StringError>(
"Not enough bytes for an XRay log.",
std::make_error_code(std::errc::invalid_argument));
// For an FDR log, there are records sized 16 and 8 bytes.
if (Data.size() - 32 == 0 || Data.size() % 8 != 0)
return make_error<StringError>(
"Invalid-sized XRay data.",
std::make_error_code(std::errc::invalid_argument));
if (auto E = readBinaryFormatHeader(Data, FileHeader))
return E;
FDRState State{0, 0, 0, FDRState::Token::NEW_BUFFER_RECORD_OR_EOF};
// RecordSize will tell the loop how far to seek ahead based on the record
// type that we have just read.
size_t RecordSize = 0;
for (auto S = Data.drop_front(32); !S.empty(); S = S.drop_front(RecordSize)) {
DataExtractor RecordExtractor(S, true, 8);
uint32_t OffsetPtr = 0;
uint8_t BitField = RecordExtractor.getU8(&OffsetPtr);
bool isMetadataRecord = BitField & 0x01uL;
if (isMetadataRecord) {
RecordSize = 16;
if (auto E = processFDRMetadataRecord(State, BitField, RecordExtractor))
return E;
} else { // Process Function Record
RecordSize = 8;
if (auto E = processFDRFunctionRecord(State, BitField, RecordExtractor,
Records))
return E;
}
}
if (State.Expects != FDRState::Token::NEW_BUFFER_RECORD_OR_EOF)
return make_error<StringError>(
"Encountered EOF without preceding End of Buffer record.",
std::make_error_code(std::errc::executable_format_error));
return Error::success();
}
Error loadYAMLLog(StringRef Data, XRayFileHeader &FileHeader,
std::vector<XRayRecord> &Records) {
// Load the documents from the MappedFile.
YAMLXRayTrace Trace;
Input In(Data);
@ -175,14 +453,21 @@ Expected<Trace> llvm::xray::loadTraceFile(StringRef Filename, bool Sort) {
uint16_t Version = HeaderExtractor.getU16(&OffsetPtr);
uint16_t Type = HeaderExtractor.getU16(&OffsetPtr);
enum BinaryFormatType { NAIVE_FORMAT = 0, FLIGHT_DATA_RECORDER_FORMAT = 1 };
Trace T;
if (Version == 1 && (Type == 0 || Type == 1)) {
if (auto E = NaiveLogLoader(StringRef(MappedFile.data(), MappedFile.size()),
T.FileHeader, T.Records))
if (Version == 1 && Type == NAIVE_FORMAT) {
if (auto E =
loadNaiveFormatLog(StringRef(MappedFile.data(), MappedFile.size()),
T.FileHeader, T.Records))
return std::move(E);
} else if (Version == 1 && Type == FLIGHT_DATA_RECORDER_FORMAT) {
if (auto E = loadFDRLog(StringRef(MappedFile.data(), MappedFile.size()),
T.FileHeader, T.Records))
return std::move(E);
} else {
if (auto E = YAMLLogLoader(StringRef(MappedFile.data(), MappedFile.size()),
T.FileHeader, T.Records))
if (auto E = loadYAMLLog(StringRef(MappedFile.data(), MappedFile.size()),
T.FileHeader, T.Records))
return std::move(E);
}

View File

@ -0,0 +1,24 @@
; RUN: llvm-xray convert %S/Inputs/fdr-log-version-1.xray -f=yaml -o - | FileCheck %s
; CHECK: ---
; CHECK-NEXT: header:
; CHECK-NEXT: version: 1
; CHECK-NEXT: type: 1
; CHECK-NEXT: constant-tsc: true
; CHECK-NEXT: nonstop-tsc: true
; CHECK-NEXT: cycle-frequency: 5678
; CHECK-NEXT: records:
; CHECK-NEXT: - { type: 0, func-id: 1, function: '1', cpu: 5, thread: 5, kind: function-enter, tsc: 7238225556407340 }
; CHECK-NEXT: - { type: 0, func-id: 1, function: '1', cpu: 5, thread: 5, kind: function-exit, tsc: 7238225556407346 }
; CHECK-NEXT: - { type: 0, func-id: 2, function: '2', cpu: 5, thread: 5, kind: function-enter, tsc: 7238225556407347 }
; CHECK-NEXT: - { type: 0, func-id: 3, function: '3', cpu: 5, thread: 5, kind: function-enter, tsc: 7238225556407387 }
; CHECK-NEXT: - { type: 0, func-id: 3, function: '3', cpu: 5, thread: 5, kind: function-exit, tsc: 7238225556407437 }
; CHECK-NEXT: - { type: 0, func-id: 2, function: '2', cpu: 5, thread: 5, kind: function-exit, tsc: 7238225556407467 }
; CHECK-NEXT: - { type: 0, func-id: 4, function: '4', cpu: 5, thread: 5, kind: function-enter, tsc: 7238225556407492 }
; CHECK-NEXT: - { type: 0, func-id: 5, function: '5', cpu: 5, thread: 5, kind: function-enter, tsc: 7238225556407517 }
; CHECK-NEXT: - { type: 0, func-id: 5, function: '5', cpu: 5, thread: 5, kind: function-exit, tsc: 7238225556407542 }
; CHECK-NEXT: - { type: 0, func-id: 268435455, function: '268435455', cpu: 5, thread: 5, kind: function-enter, tsc: 7238225556407552 }
; CHECK-NEXT: - { type: 0, func-id: 268435455, function: '268435455', cpu: 5, thread: 5, kind: function-exit, tsc: 7238225556407562 }
; CHECK-NEXT: - { type: 0, func-id: 6, function: '6', cpu: 6, thread: 5, kind: function-enter, tsc: 7238225556407682 }
; CHECK-NEXT: - { type: 0, func-id: 6, function: '6', cpu: 6, thread: 5, kind: function-exit, tsc: 7238225556407755 }
; CHECK-NEXT: ...

View File

@ -118,7 +118,9 @@ void TraceConverter::exportAsRAWv1(const Trace &Records, raw_ostream &OS) {
// format.
for (const auto &R : Records) {
Writer.write(R.RecordType);
Writer.write(R.CPU);
// The on disk naive raw format uses 8 bit CPUs, but the record has 16.
// There's no choice but truncation.
Writer.write(static_cast<uint8_t>(R.CPU));
switch (R.Type) {
case RecordTypes::ENTER:
Writer.write(uint8_t{0});