This is an archive of the discontinued LLVM Phabricator instance.

[XRay] Improve FDR trace handling and error messaging
ClosedPublic

Authored by dberris on Nov 7 2018, 2:08 AM.

Details

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.

Diff Detail

Repository
rL LLVM

Event Timeline

dberris created this revision.Nov 7 2018, 2:08 AM
mboerger added inline comments.Nov 7 2018, 9:57 PM
llvm/include/llvm/XRay/FDRRecords.h
129 ↗(On Diff #172910)

This is a weird interface. You basically want to associate a type enum with a class type. But here you do it in a kind of inverse way. Since you don't really use it, I don't know what better to do though.

llvm/lib/XRay/FDRRecordProducer.cpp
80 ↗(On Diff #172910)

Please reword this

84 ↗(On Diff #172910)

one would expect the external 'OffsetPtr' to stay unaffected and instead of 'PreReadOffset' having a 'CurrentOffset' or so variable. Please clarify or change.

91 ↗(On Diff #172910)

comment what this check does, or even better provide a static helper function that is used everywhere you do this

llvm/lib/XRay/FDRRecords.cpp
34 ↗(On Diff #172910)

this screams for using a macro :-)

llvm/lib/XRay/FDRTraceWriter.cpp
46 ↗(On Diff #172910)

so this should probably also get a helper function

dberris updated this revision to Diff 173266.Nov 8 2018, 8:32 PM
dberris marked 2 inline comments as done.

Address some comments by @mboerger.

dberris added inline comments.Nov 8 2018, 8:32 PM
llvm/include/llvm/XRay/FDRRecords.h
129 ↗(On Diff #172910)

We use it in LLVM's own RTTI implementation (see https://llvm.org/docs/HowToSetUpLLVMStyleRTTI.html).

llvm/lib/XRay/FDRRecordProducer.cpp
84 ↗(On Diff #172910)

The API for the DataExtractor documents the semantics of these get*(...) functions, which says that the offset pointer is updated only if there were no errors encountered while reading the data. This is why we need to check against whether the offset we got before reading the data is the same, and if so deal with the error condition.

llvm/lib/XRay/FDRRecords.cpp
34 ↗(On Diff #172910)

Haha -- or a language feature. :(

llvm/lib/XRay/FDRTraceWriter.cpp
46 ↗(On Diff #172910)

This is only done here, where we're synthesising the record being serialised. There's no other place AFAICT where we're doing this particular operation in the LLVM side of the project.

In compiler-rt, we do this serialization but using bitfields.

mboerger accepted this revision.Nov 8 2018, 10:01 PM
This revision is now accepted and ready to land.Nov 8 2018, 10:01 PM
This revision was automatically updated to reflect the committed changes.