2018-08-31 16:04:56 +08:00
|
|
|
//===- FDRRecordProducer.cpp - XRay FDR Mode Record Producer --------------===//
|
|
|
|
//
|
2019-01-19 16:50:56 +08:00
|
|
|
// Part of the LLVM Project, under the Apache License v2.0 with LLVM Exceptions.
|
|
|
|
// See https://llvm.org/LICENSE.txt for license information.
|
|
|
|
// SPDX-License-Identifier: Apache-2.0 WITH LLVM-exception
|
2018-08-31 16:04:56 +08:00
|
|
|
//
|
|
|
|
//===----------------------------------------------------------------------===//
|
|
|
|
#include "llvm/XRay/FDRRecordProducer.h"
|
|
|
|
#include "llvm/Support/DataExtractor.h"
|
|
|
|
|
[XRay] Improve FDR trace handling and error messaging
Summary:
This change covers a number of things spanning LLVM and compiler-rt,
which are related in a non-trivial way.
In LLVM, we have a library that handles the FDR mode even log loading,
which uses C++'s runtime polymorphism feature to better faithfully
represent the events that are written down by the FDR mode runtime. We
do this by interpreting a trace that's serliased in a common format
agreed upon by both the trace loading library and the FDR mode runtime.
This library is under active development, which consists of features
allowing us to reconstitute a higher-level event log.
This event log is used by the conversion and visualisation tools we have
for interpreting XRay traces.
One of the tools we have is a diagnostic tool in llvm-xray called
`fdr-dump` which we've been using to debug our expectations of what the
FDR runtime should be writing and what the logical FDR event log
structures are. We use this fairly extensively to reason about why some
non-trivial traces we're generating with FDR mode runtimes fail to
convert or fail to parse correctly.
One of these failures we've found in manual debugging of some of the
traces we've seen involve an inconsistency between the buffer extents (a
record indicating how many bytes to follow are part of a logical
thread's event log) and the record of the bytes written into the log --
sometimes it turns out the data could be garbage, due to buffers being
recycled, but sometimes we're seeing the buffer extent indicating a log
is "shorter" than the actual records associated with the buffer. This
case happens particularly with function entry records with a call
argument.
This change for now updates the FDR mode runtime to write the bytes for
the function call and arg record before updating the buffer extents
atomically, allowing multiple threads to see a consistent view of the
data in the buffer using the atomic counter associated with a buffer.
What we're trying to prevent here is partial updates where we see the
intermediary updates to the buffer extents (function record size then
call argument record size) becoming observable from another thread, for
instance, one doing the serialization/flushing.
To do both diagnose this issue properly, we need to be able to honour
the extents being set in the `BufferExtents` records marking the
beginning of the logical buffers when reading an FDR trace. Since LLVM
doesn't use C++'s RTTI mechanism, we instead follow the advice in the
documentation for LLVM Style RTTI
(https://llvm.org/docs/HowToSetUpLLVMStyleRTTI.html). We then rely on
this RTTI feature to ensure that our file-based record producer (our
streaming "deserializer") can honour the extents of individual buffers
as we interpret traces.
This also sets us up to be able to eventually do smart
skipping/continuation of FDR logs, seeking instead to find BufferExtents
records in cases where we find potentially recoverable errors. In the
meantime, we make this change to operate in a strict mode when reading
logical buffers with extent records.
Reviewers: mboerger
Subscribers: hiraditya, llvm-commits, jfb
Differential Revision: https://reviews.llvm.org/D54201
llvm-svn: 346473
2018-11-09 14:26:48 +08:00
|
|
|
#include <cstdint>
|
|
|
|
|
2018-08-31 16:04:56 +08:00
|
|
|
namespace llvm {
|
|
|
|
namespace xray {
|
|
|
|
|
|
|
|
namespace {
|
|
|
|
|
[XRay] Improve FDR trace handling and error messaging
Summary:
This change covers a number of things spanning LLVM and compiler-rt,
which are related in a non-trivial way.
In LLVM, we have a library that handles the FDR mode even log loading,
which uses C++'s runtime polymorphism feature to better faithfully
represent the events that are written down by the FDR mode runtime. We
do this by interpreting a trace that's serliased in a common format
agreed upon by both the trace loading library and the FDR mode runtime.
This library is under active development, which consists of features
allowing us to reconstitute a higher-level event log.
This event log is used by the conversion and visualisation tools we have
for interpreting XRay traces.
One of the tools we have is a diagnostic tool in llvm-xray called
`fdr-dump` which we've been using to debug our expectations of what the
FDR runtime should be writing and what the logical FDR event log
structures are. We use this fairly extensively to reason about why some
non-trivial traces we're generating with FDR mode runtimes fail to
convert or fail to parse correctly.
One of these failures we've found in manual debugging of some of the
traces we've seen involve an inconsistency between the buffer extents (a
record indicating how many bytes to follow are part of a logical
thread's event log) and the record of the bytes written into the log --
sometimes it turns out the data could be garbage, due to buffers being
recycled, but sometimes we're seeing the buffer extent indicating a log
is "shorter" than the actual records associated with the buffer. This
case happens particularly with function entry records with a call
argument.
This change for now updates the FDR mode runtime to write the bytes for
the function call and arg record before updating the buffer extents
atomically, allowing multiple threads to see a consistent view of the
data in the buffer using the atomic counter associated with a buffer.
What we're trying to prevent here is partial updates where we see the
intermediary updates to the buffer extents (function record size then
call argument record size) becoming observable from another thread, for
instance, one doing the serialization/flushing.
To do both diagnose this issue properly, we need to be able to honour
the extents being set in the `BufferExtents` records marking the
beginning of the logical buffers when reading an FDR trace. Since LLVM
doesn't use C++'s RTTI mechanism, we instead follow the advice in the
documentation for LLVM Style RTTI
(https://llvm.org/docs/HowToSetUpLLVMStyleRTTI.html). We then rely on
this RTTI feature to ensure that our file-based record producer (our
streaming "deserializer") can honour the extents of individual buffers
as we interpret traces.
This also sets us up to be able to eventually do smart
skipping/continuation of FDR logs, seeking instead to find BufferExtents
records in cases where we find potentially recoverable errors. In the
meantime, we make this change to operate in a strict mode when reading
logical buffers with extent records.
Reviewers: mboerger
Subscribers: hiraditya, llvm-commits, jfb
Differential Revision: https://reviews.llvm.org/D54201
llvm-svn: 346473
2018-11-09 14:26:48 +08:00
|
|
|
// Keep this in sync with the values written in the XRay FDR mode runtime in
|
|
|
|
// compiler-rt.
|
|
|
|
enum MetadataRecordKinds : uint8_t {
|
|
|
|
NewBufferKind,
|
|
|
|
EndOfBufferKind,
|
|
|
|
NewCPUIdKind,
|
|
|
|
TSCWrapKind,
|
|
|
|
WalltimeMarkerKind,
|
|
|
|
CustomEventMarkerKind,
|
|
|
|
CallArgumentKind,
|
|
|
|
BufferExtentsKind,
|
|
|
|
TypedEventMarkerKind,
|
|
|
|
PidKind,
|
|
|
|
// This is an end marker, used to identify the upper bound for this enum.
|
|
|
|
EnumEndMarker,
|
|
|
|
};
|
|
|
|
|
2018-08-31 16:04:56 +08:00
|
|
|
Expected<std::unique_ptr<Record>>
|
|
|
|
metadataRecordType(const XRayFileHeader &Header, uint8_t T) {
|
2018-08-31 19:41:08 +08:00
|
|
|
|
2018-08-31 16:04:56 +08:00
|
|
|
if (T >= static_cast<uint8_t>(MetadataRecordKinds::EnumEndMarker))
|
|
|
|
return createStringError(std::make_error_code(std::errc::invalid_argument),
|
|
|
|
"Invalid metadata record type: %d", T);
|
2018-08-31 19:41:08 +08:00
|
|
|
switch (T) {
|
|
|
|
case MetadataRecordKinds::NewBufferKind:
|
2019-08-15 23:54:37 +08:00
|
|
|
return std::make_unique<NewBufferRecord>();
|
2018-08-31 19:41:08 +08:00
|
|
|
case MetadataRecordKinds::EndOfBufferKind:
|
2018-08-31 16:04:56 +08:00
|
|
|
if (Header.Version >= 2)
|
|
|
|
return createStringError(
|
|
|
|
std::make_error_code(std::errc::executable_format_error),
|
|
|
|
"End of buffer records are no longer supported starting version "
|
|
|
|
"2 of the log.");
|
2019-08-15 23:54:37 +08:00
|
|
|
return std::make_unique<EndBufferRecord>();
|
2018-08-31 19:41:08 +08:00
|
|
|
case MetadataRecordKinds::NewCPUIdKind:
|
2019-08-15 23:54:37 +08:00
|
|
|
return std::make_unique<NewCPUIDRecord>();
|
2018-08-31 19:41:08 +08:00
|
|
|
case MetadataRecordKinds::TSCWrapKind:
|
2019-08-15 23:54:37 +08:00
|
|
|
return std::make_unique<TSCWrapRecord>();
|
2018-08-31 19:41:08 +08:00
|
|
|
case MetadataRecordKinds::WalltimeMarkerKind:
|
2019-08-15 23:54:37 +08:00
|
|
|
return std::make_unique<WallclockRecord>();
|
2018-08-31 19:41:08 +08:00
|
|
|
case MetadataRecordKinds::CustomEventMarkerKind:
|
2018-11-07 12:37:42 +08:00
|
|
|
if (Header.Version >= 5)
|
2019-08-15 23:54:37 +08:00
|
|
|
return std::make_unique<CustomEventRecordV5>();
|
|
|
|
return std::make_unique<CustomEventRecord>();
|
2018-08-31 19:41:08 +08:00
|
|
|
case MetadataRecordKinds::CallArgumentKind:
|
2019-08-15 23:54:37 +08:00
|
|
|
return std::make_unique<CallArgRecord>();
|
2018-08-31 19:41:08 +08:00
|
|
|
case MetadataRecordKinds::BufferExtentsKind:
|
2019-08-15 23:54:37 +08:00
|
|
|
return std::make_unique<BufferExtents>();
|
2018-08-31 19:41:08 +08:00
|
|
|
case MetadataRecordKinds::TypedEventMarkerKind:
|
2019-08-15 23:54:37 +08:00
|
|
|
return std::make_unique<TypedEventRecord>();
|
2018-08-31 19:41:08 +08:00
|
|
|
case MetadataRecordKinds::PidKind:
|
2019-08-15 23:54:37 +08:00
|
|
|
return std::make_unique<PIDRecord>();
|
2018-08-31 16:04:56 +08:00
|
|
|
case MetadataRecordKinds::EnumEndMarker:
|
|
|
|
llvm_unreachable("Invalid MetadataRecordKind");
|
|
|
|
}
|
2018-08-31 17:24:09 +08:00
|
|
|
llvm_unreachable("Unhandled MetadataRecordKinds enum value");
|
2018-08-31 16:04:56 +08:00
|
|
|
}
|
|
|
|
|
[XRay] Improve FDR trace handling and error messaging
Summary:
This change covers a number of things spanning LLVM and compiler-rt,
which are related in a non-trivial way.
In LLVM, we have a library that handles the FDR mode even log loading,
which uses C++'s runtime polymorphism feature to better faithfully
represent the events that are written down by the FDR mode runtime. We
do this by interpreting a trace that's serliased in a common format
agreed upon by both the trace loading library and the FDR mode runtime.
This library is under active development, which consists of features
allowing us to reconstitute a higher-level event log.
This event log is used by the conversion and visualisation tools we have
for interpreting XRay traces.
One of the tools we have is a diagnostic tool in llvm-xray called
`fdr-dump` which we've been using to debug our expectations of what the
FDR runtime should be writing and what the logical FDR event log
structures are. We use this fairly extensively to reason about why some
non-trivial traces we're generating with FDR mode runtimes fail to
convert or fail to parse correctly.
One of these failures we've found in manual debugging of some of the
traces we've seen involve an inconsistency between the buffer extents (a
record indicating how many bytes to follow are part of a logical
thread's event log) and the record of the bytes written into the log --
sometimes it turns out the data could be garbage, due to buffers being
recycled, but sometimes we're seeing the buffer extent indicating a log
is "shorter" than the actual records associated with the buffer. This
case happens particularly with function entry records with a call
argument.
This change for now updates the FDR mode runtime to write the bytes for
the function call and arg record before updating the buffer extents
atomically, allowing multiple threads to see a consistent view of the
data in the buffer using the atomic counter associated with a buffer.
What we're trying to prevent here is partial updates where we see the
intermediary updates to the buffer extents (function record size then
call argument record size) becoming observable from another thread, for
instance, one doing the serialization/flushing.
To do both diagnose this issue properly, we need to be able to honour
the extents being set in the `BufferExtents` records marking the
beginning of the logical buffers when reading an FDR trace. Since LLVM
doesn't use C++'s RTTI mechanism, we instead follow the advice in the
documentation for LLVM Style RTTI
(https://llvm.org/docs/HowToSetUpLLVMStyleRTTI.html). We then rely on
this RTTI feature to ensure that our file-based record producer (our
streaming "deserializer") can honour the extents of individual buffers
as we interpret traces.
This also sets us up to be able to eventually do smart
skipping/continuation of FDR logs, seeking instead to find BufferExtents
records in cases where we find potentially recoverable errors. In the
meantime, we make this change to operate in a strict mode when reading
logical buffers with extent records.
Reviewers: mboerger
Subscribers: hiraditya, llvm-commits, jfb
Differential Revision: https://reviews.llvm.org/D54201
llvm-svn: 346473
2018-11-09 14:26:48 +08:00
|
|
|
constexpr bool isMetadataIntroducer(uint8_t FirstByte) {
|
|
|
|
return FirstByte & 0x01u;
|
|
|
|
}
|
|
|
|
|
2018-08-31 16:04:56 +08:00
|
|
|
} // namespace
|
|
|
|
|
[XRay] Improve FDR trace handling and error messaging
Summary:
This change covers a number of things spanning LLVM and compiler-rt,
which are related in a non-trivial way.
In LLVM, we have a library that handles the FDR mode even log loading,
which uses C++'s runtime polymorphism feature to better faithfully
represent the events that are written down by the FDR mode runtime. We
do this by interpreting a trace that's serliased in a common format
agreed upon by both the trace loading library and the FDR mode runtime.
This library is under active development, which consists of features
allowing us to reconstitute a higher-level event log.
This event log is used by the conversion and visualisation tools we have
for interpreting XRay traces.
One of the tools we have is a diagnostic tool in llvm-xray called
`fdr-dump` which we've been using to debug our expectations of what the
FDR runtime should be writing and what the logical FDR event log
structures are. We use this fairly extensively to reason about why some
non-trivial traces we're generating with FDR mode runtimes fail to
convert or fail to parse correctly.
One of these failures we've found in manual debugging of some of the
traces we've seen involve an inconsistency between the buffer extents (a
record indicating how many bytes to follow are part of a logical
thread's event log) and the record of the bytes written into the log --
sometimes it turns out the data could be garbage, due to buffers being
recycled, but sometimes we're seeing the buffer extent indicating a log
is "shorter" than the actual records associated with the buffer. This
case happens particularly with function entry records with a call
argument.
This change for now updates the FDR mode runtime to write the bytes for
the function call and arg record before updating the buffer extents
atomically, allowing multiple threads to see a consistent view of the
data in the buffer using the atomic counter associated with a buffer.
What we're trying to prevent here is partial updates where we see the
intermediary updates to the buffer extents (function record size then
call argument record size) becoming observable from another thread, for
instance, one doing the serialization/flushing.
To do both diagnose this issue properly, we need to be able to honour
the extents being set in the `BufferExtents` records marking the
beginning of the logical buffers when reading an FDR trace. Since LLVM
doesn't use C++'s RTTI mechanism, we instead follow the advice in the
documentation for LLVM Style RTTI
(https://llvm.org/docs/HowToSetUpLLVMStyleRTTI.html). We then rely on
this RTTI feature to ensure that our file-based record producer (our
streaming "deserializer") can honour the extents of individual buffers
as we interpret traces.
This also sets us up to be able to eventually do smart
skipping/continuation of FDR logs, seeking instead to find BufferExtents
records in cases where we find potentially recoverable errors. In the
meantime, we make this change to operate in a strict mode when reading
logical buffers with extent records.
Reviewers: mboerger
Subscribers: hiraditya, llvm-commits, jfb
Differential Revision: https://reviews.llvm.org/D54201
llvm-svn: 346473
2018-11-09 14:26:48 +08:00
|
|
|
Expected<std::unique_ptr<Record>>
|
|
|
|
FileBasedRecordProducer::findNextBufferExtent() {
|
|
|
|
// We seek one byte at a time until we find a suitable buffer extents metadata
|
|
|
|
// record introducer.
|
|
|
|
std::unique_ptr<Record> R;
|
|
|
|
while (!R) {
|
|
|
|
auto PreReadOffset = OffsetPtr;
|
|
|
|
uint8_t FirstByte = E.getU8(&OffsetPtr);
|
|
|
|
if (OffsetPtr == PreReadOffset)
|
|
|
|
return createStringError(
|
|
|
|
std::make_error_code(std::errc::executable_format_error),
|
2019-08-06 18:49:40 +08:00
|
|
|
"Failed reading one byte from offset %" PRId64 ".", OffsetPtr);
|
[XRay] Improve FDR trace handling and error messaging
Summary:
This change covers a number of things spanning LLVM and compiler-rt,
which are related in a non-trivial way.
In LLVM, we have a library that handles the FDR mode even log loading,
which uses C++'s runtime polymorphism feature to better faithfully
represent the events that are written down by the FDR mode runtime. We
do this by interpreting a trace that's serliased in a common format
agreed upon by both the trace loading library and the FDR mode runtime.
This library is under active development, which consists of features
allowing us to reconstitute a higher-level event log.
This event log is used by the conversion and visualisation tools we have
for interpreting XRay traces.
One of the tools we have is a diagnostic tool in llvm-xray called
`fdr-dump` which we've been using to debug our expectations of what the
FDR runtime should be writing and what the logical FDR event log
structures are. We use this fairly extensively to reason about why some
non-trivial traces we're generating with FDR mode runtimes fail to
convert or fail to parse correctly.
One of these failures we've found in manual debugging of some of the
traces we've seen involve an inconsistency between the buffer extents (a
record indicating how many bytes to follow are part of a logical
thread's event log) and the record of the bytes written into the log --
sometimes it turns out the data could be garbage, due to buffers being
recycled, but sometimes we're seeing the buffer extent indicating a log
is "shorter" than the actual records associated with the buffer. This
case happens particularly with function entry records with a call
argument.
This change for now updates the FDR mode runtime to write the bytes for
the function call and arg record before updating the buffer extents
atomically, allowing multiple threads to see a consistent view of the
data in the buffer using the atomic counter associated with a buffer.
What we're trying to prevent here is partial updates where we see the
intermediary updates to the buffer extents (function record size then
call argument record size) becoming observable from another thread, for
instance, one doing the serialization/flushing.
To do both diagnose this issue properly, we need to be able to honour
the extents being set in the `BufferExtents` records marking the
beginning of the logical buffers when reading an FDR trace. Since LLVM
doesn't use C++'s RTTI mechanism, we instead follow the advice in the
documentation for LLVM Style RTTI
(https://llvm.org/docs/HowToSetUpLLVMStyleRTTI.html). We then rely on
this RTTI feature to ensure that our file-based record producer (our
streaming "deserializer") can honour the extents of individual buffers
as we interpret traces.
This also sets us up to be able to eventually do smart
skipping/continuation of FDR logs, seeking instead to find BufferExtents
records in cases where we find potentially recoverable errors. In the
meantime, we make this change to operate in a strict mode when reading
logical buffers with extent records.
Reviewers: mboerger
Subscribers: hiraditya, llvm-commits, jfb
Differential Revision: https://reviews.llvm.org/D54201
llvm-svn: 346473
2018-11-09 14:26:48 +08:00
|
|
|
|
|
|
|
if (isMetadataIntroducer(FirstByte)) {
|
|
|
|
auto LoadedType = FirstByte >> 1;
|
|
|
|
if (LoadedType == MetadataRecordKinds::BufferExtentsKind) {
|
|
|
|
auto MetadataRecordOrErr = metadataRecordType(Header, LoadedType);
|
|
|
|
if (!MetadataRecordOrErr)
|
|
|
|
return MetadataRecordOrErr.takeError();
|
|
|
|
|
|
|
|
R = std::move(MetadataRecordOrErr.get());
|
|
|
|
RecordInitializer RI(E, OffsetPtr);
|
|
|
|
if (auto Err = R->apply(RI))
|
|
|
|
return std::move(Err);
|
|
|
|
return std::move(R);
|
|
|
|
}
|
|
|
|
}
|
|
|
|
}
|
|
|
|
llvm_unreachable("Must always terminate with either an error or a record.");
|
|
|
|
}
|
|
|
|
|
2018-08-31 16:04:56 +08:00
|
|
|
Expected<std::unique_ptr<Record>> FileBasedRecordProducer::produce() {
|
[XRay] Improve FDR trace handling and error messaging
Summary:
This change covers a number of things spanning LLVM and compiler-rt,
which are related in a non-trivial way.
In LLVM, we have a library that handles the FDR mode even log loading,
which uses C++'s runtime polymorphism feature to better faithfully
represent the events that are written down by the FDR mode runtime. We
do this by interpreting a trace that's serliased in a common format
agreed upon by both the trace loading library and the FDR mode runtime.
This library is under active development, which consists of features
allowing us to reconstitute a higher-level event log.
This event log is used by the conversion and visualisation tools we have
for interpreting XRay traces.
One of the tools we have is a diagnostic tool in llvm-xray called
`fdr-dump` which we've been using to debug our expectations of what the
FDR runtime should be writing and what the logical FDR event log
structures are. We use this fairly extensively to reason about why some
non-trivial traces we're generating with FDR mode runtimes fail to
convert or fail to parse correctly.
One of these failures we've found in manual debugging of some of the
traces we've seen involve an inconsistency between the buffer extents (a
record indicating how many bytes to follow are part of a logical
thread's event log) and the record of the bytes written into the log --
sometimes it turns out the data could be garbage, due to buffers being
recycled, but sometimes we're seeing the buffer extent indicating a log
is "shorter" than the actual records associated with the buffer. This
case happens particularly with function entry records with a call
argument.
This change for now updates the FDR mode runtime to write the bytes for
the function call and arg record before updating the buffer extents
atomically, allowing multiple threads to see a consistent view of the
data in the buffer using the atomic counter associated with a buffer.
What we're trying to prevent here is partial updates where we see the
intermediary updates to the buffer extents (function record size then
call argument record size) becoming observable from another thread, for
instance, one doing the serialization/flushing.
To do both diagnose this issue properly, we need to be able to honour
the extents being set in the `BufferExtents` records marking the
beginning of the logical buffers when reading an FDR trace. Since LLVM
doesn't use C++'s RTTI mechanism, we instead follow the advice in the
documentation for LLVM Style RTTI
(https://llvm.org/docs/HowToSetUpLLVMStyleRTTI.html). We then rely on
this RTTI feature to ensure that our file-based record producer (our
streaming "deserializer") can honour the extents of individual buffers
as we interpret traces.
This also sets us up to be able to eventually do smart
skipping/continuation of FDR logs, seeking instead to find BufferExtents
records in cases where we find potentially recoverable errors. In the
meantime, we make this change to operate in a strict mode when reading
logical buffers with extent records.
Reviewers: mboerger
Subscribers: hiraditya, llvm-commits, jfb
Differential Revision: https://reviews.llvm.org/D54201
llvm-svn: 346473
2018-11-09 14:26:48 +08:00
|
|
|
// First, we set up our result record.
|
|
|
|
std::unique_ptr<Record> R;
|
|
|
|
|
|
|
|
// Before we do any further reading, we should check whether we're at the end
|
|
|
|
// of the current buffer we're been consuming. In FDR logs version >= 3, we
|
|
|
|
// rely on the buffer extents record to determine how many bytes we should be
|
|
|
|
// considering as valid records.
|
|
|
|
if (Header.Version >= 3 && CurrentBufferBytes == 0) {
|
|
|
|
// Find the next buffer extents record.
|
|
|
|
auto BufferExtentsOrError = findNextBufferExtent();
|
|
|
|
if (!BufferExtentsOrError)
|
|
|
|
return joinErrors(
|
|
|
|
BufferExtentsOrError.takeError(),
|
|
|
|
createStringError(
|
|
|
|
std::make_error_code(std::errc::executable_format_error),
|
|
|
|
"Failed to find the next BufferExtents record."));
|
|
|
|
|
|
|
|
R = std::move(BufferExtentsOrError.get());
|
|
|
|
assert(R != nullptr);
|
|
|
|
assert(isa<BufferExtents>(R.get()));
|
2019-09-23 02:47:00 +08:00
|
|
|
auto BE = cast<BufferExtents>(R.get());
|
[XRay] Improve FDR trace handling and error messaging
Summary:
This change covers a number of things spanning LLVM and compiler-rt,
which are related in a non-trivial way.
In LLVM, we have a library that handles the FDR mode even log loading,
which uses C++'s runtime polymorphism feature to better faithfully
represent the events that are written down by the FDR mode runtime. We
do this by interpreting a trace that's serliased in a common format
agreed upon by both the trace loading library and the FDR mode runtime.
This library is under active development, which consists of features
allowing us to reconstitute a higher-level event log.
This event log is used by the conversion and visualisation tools we have
for interpreting XRay traces.
One of the tools we have is a diagnostic tool in llvm-xray called
`fdr-dump` which we've been using to debug our expectations of what the
FDR runtime should be writing and what the logical FDR event log
structures are. We use this fairly extensively to reason about why some
non-trivial traces we're generating with FDR mode runtimes fail to
convert or fail to parse correctly.
One of these failures we've found in manual debugging of some of the
traces we've seen involve an inconsistency between the buffer extents (a
record indicating how many bytes to follow are part of a logical
thread's event log) and the record of the bytes written into the log --
sometimes it turns out the data could be garbage, due to buffers being
recycled, but sometimes we're seeing the buffer extent indicating a log
is "shorter" than the actual records associated with the buffer. This
case happens particularly with function entry records with a call
argument.
This change for now updates the FDR mode runtime to write the bytes for
the function call and arg record before updating the buffer extents
atomically, allowing multiple threads to see a consistent view of the
data in the buffer using the atomic counter associated with a buffer.
What we're trying to prevent here is partial updates where we see the
intermediary updates to the buffer extents (function record size then
call argument record size) becoming observable from another thread, for
instance, one doing the serialization/flushing.
To do both diagnose this issue properly, we need to be able to honour
the extents being set in the `BufferExtents` records marking the
beginning of the logical buffers when reading an FDR trace. Since LLVM
doesn't use C++'s RTTI mechanism, we instead follow the advice in the
documentation for LLVM Style RTTI
(https://llvm.org/docs/HowToSetUpLLVMStyleRTTI.html). We then rely on
this RTTI feature to ensure that our file-based record producer (our
streaming "deserializer") can honour the extents of individual buffers
as we interpret traces.
This also sets us up to be able to eventually do smart
skipping/continuation of FDR logs, seeking instead to find BufferExtents
records in cases where we find potentially recoverable errors. In the
meantime, we make this change to operate in a strict mode when reading
logical buffers with extent records.
Reviewers: mboerger
Subscribers: hiraditya, llvm-commits, jfb
Differential Revision: https://reviews.llvm.org/D54201
llvm-svn: 346473
2018-11-09 14:26:48 +08:00
|
|
|
CurrentBufferBytes = BE->size();
|
|
|
|
return std::move(R);
|
|
|
|
}
|
|
|
|
|
|
|
|
//
|
2018-08-31 16:04:56 +08:00
|
|
|
// At the top level, we read one byte to determine the type of the record to
|
|
|
|
// create. This byte will comprise of the following bits:
|
|
|
|
//
|
|
|
|
// - offset 0: A '1' indicates a metadata record, a '0' indicates a function
|
|
|
|
// record.
|
|
|
|
// - offsets 1-7: For metadata records, this will indicate the kind of
|
|
|
|
// metadata record should be loaded.
|
|
|
|
//
|
|
|
|
// We read first byte, then create the appropriate type of record to consume
|
|
|
|
// the rest of the bytes.
|
|
|
|
auto PreReadOffset = OffsetPtr;
|
|
|
|
uint8_t FirstByte = E.getU8(&OffsetPtr);
|
2018-11-02 06:57:50 +08:00
|
|
|
if (OffsetPtr == PreReadOffset)
|
|
|
|
return createStringError(
|
|
|
|
std::make_error_code(std::errc::executable_format_error),
|
2019-08-06 18:49:40 +08:00
|
|
|
"Failed reading one byte from offset %" PRId64 ".", OffsetPtr);
|
2018-11-02 06:57:50 +08:00
|
|
|
|
2018-08-31 16:04:56 +08:00
|
|
|
// For metadata records, handle especially here.
|
[XRay] Improve FDR trace handling and error messaging
Summary:
This change covers a number of things spanning LLVM and compiler-rt,
which are related in a non-trivial way.
In LLVM, we have a library that handles the FDR mode even log loading,
which uses C++'s runtime polymorphism feature to better faithfully
represent the events that are written down by the FDR mode runtime. We
do this by interpreting a trace that's serliased in a common format
agreed upon by both the trace loading library and the FDR mode runtime.
This library is under active development, which consists of features
allowing us to reconstitute a higher-level event log.
This event log is used by the conversion and visualisation tools we have
for interpreting XRay traces.
One of the tools we have is a diagnostic tool in llvm-xray called
`fdr-dump` which we've been using to debug our expectations of what the
FDR runtime should be writing and what the logical FDR event log
structures are. We use this fairly extensively to reason about why some
non-trivial traces we're generating with FDR mode runtimes fail to
convert or fail to parse correctly.
One of these failures we've found in manual debugging of some of the
traces we've seen involve an inconsistency between the buffer extents (a
record indicating how many bytes to follow are part of a logical
thread's event log) and the record of the bytes written into the log --
sometimes it turns out the data could be garbage, due to buffers being
recycled, but sometimes we're seeing the buffer extent indicating a log
is "shorter" than the actual records associated with the buffer. This
case happens particularly with function entry records with a call
argument.
This change for now updates the FDR mode runtime to write the bytes for
the function call and arg record before updating the buffer extents
atomically, allowing multiple threads to see a consistent view of the
data in the buffer using the atomic counter associated with a buffer.
What we're trying to prevent here is partial updates where we see the
intermediary updates to the buffer extents (function record size then
call argument record size) becoming observable from another thread, for
instance, one doing the serialization/flushing.
To do both diagnose this issue properly, we need to be able to honour
the extents being set in the `BufferExtents` records marking the
beginning of the logical buffers when reading an FDR trace. Since LLVM
doesn't use C++'s RTTI mechanism, we instead follow the advice in the
documentation for LLVM Style RTTI
(https://llvm.org/docs/HowToSetUpLLVMStyleRTTI.html). We then rely on
this RTTI feature to ensure that our file-based record producer (our
streaming "deserializer") can honour the extents of individual buffers
as we interpret traces.
This also sets us up to be able to eventually do smart
skipping/continuation of FDR logs, seeking instead to find BufferExtents
records in cases where we find potentially recoverable errors. In the
meantime, we make this change to operate in a strict mode when reading
logical buffers with extent records.
Reviewers: mboerger
Subscribers: hiraditya, llvm-commits, jfb
Differential Revision: https://reviews.llvm.org/D54201
llvm-svn: 346473
2018-11-09 14:26:48 +08:00
|
|
|
if (isMetadataIntroducer(FirstByte)) {
|
2018-08-31 16:04:56 +08:00
|
|
|
auto LoadedType = FirstByte >> 1;
|
|
|
|
auto MetadataRecordOrErr = metadataRecordType(Header, LoadedType);
|
|
|
|
if (!MetadataRecordOrErr)
|
|
|
|
return joinErrors(
|
|
|
|
MetadataRecordOrErr.takeError(),
|
|
|
|
createStringError(
|
|
|
|
std::make_error_code(std::errc::executable_format_error),
|
2019-08-06 18:49:40 +08:00
|
|
|
"Encountered an unsupported metadata record (%d) "
|
|
|
|
"at offset %" PRId64 ".",
|
2018-08-31 16:04:56 +08:00
|
|
|
LoadedType, PreReadOffset));
|
|
|
|
R = std::move(MetadataRecordOrErr.get());
|
|
|
|
} else {
|
2019-08-15 23:54:37 +08:00
|
|
|
R = std::make_unique<FunctionRecord>();
|
2018-08-31 16:04:56 +08:00
|
|
|
}
|
|
|
|
RecordInitializer RI(E, OffsetPtr);
|
|
|
|
|
|
|
|
if (auto Err = R->apply(RI))
|
|
|
|
return std::move(Err);
|
|
|
|
|
[XRay] Improve FDR trace handling and error messaging
Summary:
This change covers a number of things spanning LLVM and compiler-rt,
which are related in a non-trivial way.
In LLVM, we have a library that handles the FDR mode even log loading,
which uses C++'s runtime polymorphism feature to better faithfully
represent the events that are written down by the FDR mode runtime. We
do this by interpreting a trace that's serliased in a common format
agreed upon by both the trace loading library and the FDR mode runtime.
This library is under active development, which consists of features
allowing us to reconstitute a higher-level event log.
This event log is used by the conversion and visualisation tools we have
for interpreting XRay traces.
One of the tools we have is a diagnostic tool in llvm-xray called
`fdr-dump` which we've been using to debug our expectations of what the
FDR runtime should be writing and what the logical FDR event log
structures are. We use this fairly extensively to reason about why some
non-trivial traces we're generating with FDR mode runtimes fail to
convert or fail to parse correctly.
One of these failures we've found in manual debugging of some of the
traces we've seen involve an inconsistency between the buffer extents (a
record indicating how many bytes to follow are part of a logical
thread's event log) and the record of the bytes written into the log --
sometimes it turns out the data could be garbage, due to buffers being
recycled, but sometimes we're seeing the buffer extent indicating a log
is "shorter" than the actual records associated with the buffer. This
case happens particularly with function entry records with a call
argument.
This change for now updates the FDR mode runtime to write the bytes for
the function call and arg record before updating the buffer extents
atomically, allowing multiple threads to see a consistent view of the
data in the buffer using the atomic counter associated with a buffer.
What we're trying to prevent here is partial updates where we see the
intermediary updates to the buffer extents (function record size then
call argument record size) becoming observable from another thread, for
instance, one doing the serialization/flushing.
To do both diagnose this issue properly, we need to be able to honour
the extents being set in the `BufferExtents` records marking the
beginning of the logical buffers when reading an FDR trace. Since LLVM
doesn't use C++'s RTTI mechanism, we instead follow the advice in the
documentation for LLVM Style RTTI
(https://llvm.org/docs/HowToSetUpLLVMStyleRTTI.html). We then rely on
this RTTI feature to ensure that our file-based record producer (our
streaming "deserializer") can honour the extents of individual buffers
as we interpret traces.
This also sets us up to be able to eventually do smart
skipping/continuation of FDR logs, seeking instead to find BufferExtents
records in cases where we find potentially recoverable errors. In the
meantime, we make this change to operate in a strict mode when reading
logical buffers with extent records.
Reviewers: mboerger
Subscribers: hiraditya, llvm-commits, jfb
Differential Revision: https://reviews.llvm.org/D54201
llvm-svn: 346473
2018-11-09 14:26:48 +08:00
|
|
|
// If we encountered a BufferExtents record, we should record the remaining
|
|
|
|
// bytes for the current buffer, to determine when we should start ignoring
|
|
|
|
// potentially malformed data and looking for buffer extents records.
|
|
|
|
if (auto BE = dyn_cast<BufferExtents>(R.get())) {
|
|
|
|
CurrentBufferBytes = BE->size();
|
|
|
|
} else if (Header.Version >= 3) {
|
|
|
|
if (OffsetPtr - PreReadOffset > CurrentBufferBytes)
|
|
|
|
return createStringError(
|
|
|
|
std::make_error_code(std::errc::executable_format_error),
|
2019-08-06 18:49:40 +08:00
|
|
|
"Buffer over-read at offset %" PRId64 " (over-read by %" PRId64
|
|
|
|
" bytes); Record Type = %s.",
|
[XRay] Improve FDR trace handling and error messaging
Summary:
This change covers a number of things spanning LLVM and compiler-rt,
which are related in a non-trivial way.
In LLVM, we have a library that handles the FDR mode even log loading,
which uses C++'s runtime polymorphism feature to better faithfully
represent the events that are written down by the FDR mode runtime. We
do this by interpreting a trace that's serliased in a common format
agreed upon by both the trace loading library and the FDR mode runtime.
This library is under active development, which consists of features
allowing us to reconstitute a higher-level event log.
This event log is used by the conversion and visualisation tools we have
for interpreting XRay traces.
One of the tools we have is a diagnostic tool in llvm-xray called
`fdr-dump` which we've been using to debug our expectations of what the
FDR runtime should be writing and what the logical FDR event log
structures are. We use this fairly extensively to reason about why some
non-trivial traces we're generating with FDR mode runtimes fail to
convert or fail to parse correctly.
One of these failures we've found in manual debugging of some of the
traces we've seen involve an inconsistency between the buffer extents (a
record indicating how many bytes to follow are part of a logical
thread's event log) and the record of the bytes written into the log --
sometimes it turns out the data could be garbage, due to buffers being
recycled, but sometimes we're seeing the buffer extent indicating a log
is "shorter" than the actual records associated with the buffer. This
case happens particularly with function entry records with a call
argument.
This change for now updates the FDR mode runtime to write the bytes for
the function call and arg record before updating the buffer extents
atomically, allowing multiple threads to see a consistent view of the
data in the buffer using the atomic counter associated with a buffer.
What we're trying to prevent here is partial updates where we see the
intermediary updates to the buffer extents (function record size then
call argument record size) becoming observable from another thread, for
instance, one doing the serialization/flushing.
To do both diagnose this issue properly, we need to be able to honour
the extents being set in the `BufferExtents` records marking the
beginning of the logical buffers when reading an FDR trace. Since LLVM
doesn't use C++'s RTTI mechanism, we instead follow the advice in the
documentation for LLVM Style RTTI
(https://llvm.org/docs/HowToSetUpLLVMStyleRTTI.html). We then rely on
this RTTI feature to ensure that our file-based record producer (our
streaming "deserializer") can honour the extents of individual buffers
as we interpret traces.
This also sets us up to be able to eventually do smart
skipping/continuation of FDR logs, seeking instead to find BufferExtents
records in cases where we find potentially recoverable errors. In the
meantime, we make this change to operate in a strict mode when reading
logical buffers with extent records.
Reviewers: mboerger
Subscribers: hiraditya, llvm-commits, jfb
Differential Revision: https://reviews.llvm.org/D54201
llvm-svn: 346473
2018-11-09 14:26:48 +08:00
|
|
|
OffsetPtr, (OffsetPtr - PreReadOffset) - CurrentBufferBytes,
|
|
|
|
Record::kindToString(R->getRecordType()).data());
|
|
|
|
|
|
|
|
CurrentBufferBytes -= OffsetPtr - PreReadOffset;
|
|
|
|
}
|
2018-08-31 16:04:56 +08:00
|
|
|
assert(R != nullptr);
|
|
|
|
return std::move(R);
|
|
|
|
}
|
|
|
|
|
|
|
|
} // namespace xray
|
|
|
|
} // namespace llvm
|