[compiler-rt][XRay] Support tail call sleds

[dberris]

Summary

This change depends on D23986 which adds tail call-specific sleds. For
now we treat them first as normal exits, and in the future leave room
for implementing this as a different kind of log entry.

The reason for deferring the change is so that we can keep the naive
logging implementation more accurate without additional complexity for
reading the log. The accuracy is gained in effectively interpreting call
stacks like:

A()
  B()
    C()

Which when tail-call merged will end up not having any exit entries for
A() nor B(), but effectively in turn can be reasoned about as:

A()
B()
C()

Although we lose the fact that A() had called B() then had called C()
with the naive approach, a later iteration that adds the explicit tail
call entries would be a change in the log format and thus necessitate a
version change for the header. We can do this later to have a chance at
releasing some tools (in D21987) that are able to handle the naive log
format, then support higher version numbers of the log format too.

[dberris]

Ping?

[rSerge]

In D23988#548335, @dberris wrote:

Ping?

I'm reviewing it, though not ready to say something because I haven't yet understood the implementation for tail calls.

[rSerge]

I have another question in https://reviews.llvm.org/D23986 .

lib/xray/xray_interface.cc

266

The comment says about a jump to the exit sled, but the code below uses CallOpCode. Which one is wrong?

[rSerge]

So in this implementation the handler doesn't receive XRayEntryType::TAIL type of event, but instead receives XRayEntryType::EXIT, right? Is it also intended for now?

[rSerge]

I've tried seemingly the same approach on ARM with the following program:

#include <cstdio>
#include <cassert>
#include <xray/xray_interface.h>

[[clang::xray_always_instrument]] void __attribute__ ((noinline)) fC() { 
  std::printf("In fC()\n");
}

[[clang::xray_always_instrument]] void __attribute__ ((noinline)) fB() { 
  std::printf("In fB()\n");
  fC();
}

[[clang::xray_always_instrument]] void __attribute__ ((noinline)) fA() { 
  std::printf("In fA()\n");
  fB();
}

// Avoid infinite recursion in case the logging function is instrumented (so calls logging
//   function again).
[[clang::xray_never_instrument]] void simplyPrint(int32_t functionId, XRayEntryType xret)
{
  printf("XRay: functionId=%d type=%d.\n", int(functionId), int(xret));
}

int main(int argc, char* argv[]) {
  __xray_set_handler(simplyPrint);

  printf("Patching...\n");
  __xray_patch();
  fA();

  printf("Unpatching...\n");
  __xray_unpatch();       
  fA();

  return 0;
}

For me it gives the following results

Patching...
XRay: functionId=3 type=0.
In fA()
XRay: functionId=3 type=1.
XRay: functionId=2 type=0.
In fB()
XRay: functionId=2 type=1.
XRay: functionId=1 type=0.
XRay: functionId=1 type=1.
In fC()
Unpatching...
In fA()
In fB()
In fC()

So for function fC() the exit sled seems to be called too much before function exit: before printing In fC(). I compiled with the following generic flags: -O3 -g -fxray-instrument -Wall -std=c++14 -ffunction-sections -fdata-sections (this list doesn't include my specific flags like --target=armv7-linux-gnueabihf etc.).

Does the code snippet work correctly for you on x86_64? Or is the above output expected?

[dberris]

In D23988#553965, @rSerge wrote:

So in this implementation the handler doesn't receive XRayEntryType::TAIL type of event, but instead receives XRayEntryType::EXIT, right? Is it also intended for now?

Yes, this is intended for now.

In D23988#554292, @rSerge wrote:

I've tried seemingly the same approach on ARM with the following program:

[snipped]

So for function fC() the exit sled seems to be called too much before function exit: before printing In fC(). I compiled with the following generic flags: -O3 -g -fxray-instrument -Wall -std=c++14 -ffunction-sections -fdata-sections (this list doesn't include my specific flags like --target=armv7-linux-gnueabihf etc.).

Does the code snippet work correctly for you on x86_64? Or is the above output expected?

It's certainly not expected, but I think I can explain this.

Since printf isn't instrumented, this means the implementation of fC() could be tail-calling into printf (which is a perfectly good optimisation to make). Of course this mis-accounts the time but we really can't do anything about that yet, unless we know that we're tail-calling into something else, which will come later when we have different records for tail calls. We should probably do that when we have a more substantial change in the format once some of the stuff I'm working on (to support richer records into the log) goes upstream and increment the file version number.

Does that make sense?

[rSerge]

Debugging for me has shown that the above happens because printf from fC is also called as a tail call. So first the exit sled of fC is executed, and only then printf is jumped into. So it seems we can't do anything about this with the current approach.

[dberris]

In D23988#555375, @rSerge wrote:

Debugging for me has shown that the above happens because printf from fC is also called as a tail call. So first the exit sled of fC is executed, and only then printf is jumped into. So it seems we can't do anything about this with the current approach.

This isn't such a bad thing though, given the following construction:

f1()
  f2()
    f3()

If we get f2() tail-calling into f3() and f3() tail calling into something else that isn't instrumented (not shown here), then we will still see:

f1()
  f2()
  f3()
  ... missing ...

However, since f1() is instrumented, we will see that time spent outside of f3() will be attributed to f1().

This is predicated though on having an enclosing function that is instrumented. To see this in your example, you can wrap the call to fA() with another function that will not tail-call into fA().

[dberris]

lib/xray/xray_interface.cc

266

The comment is inaccurate -- it should say "call to the exit sled instead". We need to call the exit sled so that it returns to the calling function just before the jump to the tail-called function. Let me update that.

[dberris]

• Rebased and redone

[dberris]

• Rebase

[dberris]

• Fix bad merge

[dberris]

Ping?

[dberris]

Ping again? @echristo or @rSerge?

[rSerge]

Sorry, it's apparently too easy to miss activity on Phabricator. The emails get filtered together with LLVM mailing list piles.

include/xray/xray_interface.h

 //===----------------------------------------------------------------------===//
 #ifndef XRAY_XRAY_INTERFACE_H
 #define XRAY_XRAY_INTERFACE_H
 
 #include <cstdint>
 
 extern "C" {
 
-enum XRayEntryType { ENTRY = 0, EXIT = 1 };
+enum XRayEntryType { ENTRY = 0, EXIT = 1, TAIL = 2 };
 
 // Provide a function to invoke for when instrumentation points are hit. This is
 // a user-visible control surface that overrides the default implementation. The
 // function provided should take the following arguments:
 //
 //   - function id: an identifier that indicates the id of a function; this id
 //                  is generated by xray; the mapping between the function id
 //                  and the actual function pointer is available through

lib/xray/xray_interface.cc

if (Sled.Kind == XRayEntryType::EXIT) {
             std::memory_order_release);
       } else {
         std::atomic_store_explicit(
             reinterpret_cast<std::atomic<uint8_t> *>(Sled.Address), RetOpCode,
             std::memory_order_release);
         // FIXME: Write out the nops still?
       }
     }
+
+    if (Sled.Kind == XRayEntryType::TAIL) {
+      // FIXME: Implement this in a more extensible manner, per-platform.
+      // Here we do the dance of replacing the tail call sled with a similar
+      // sequence as the entry sled, but jump to the exit sled instead, so we
+      // can treat tail call exits as if they were normal exits. In the future
+      // we'd need to distinguish between non-tail exits and tail exits for
+      // better information preservation.
+      int64_t TrampolineOffset = reinterpret_cast<int64_t>(__xray_FunctionExit) - (static_cast<int64_t>(Sled.Address) + 11);
+      if (TrampolineOffset < MinOffset || TrampolineOffset > MaxOffset) {
+        Report("XRay Exit trampoline (%p) too far from sled (%p); distance = "
+               "%ld\n",
+               __xray_FunctionExit, reinterpret_cast<void *>(Sled.Address),
+               TrampolineOffset);
+        continue;
+      }
+      if (Enable) {
+        *reinterpret_cast<uint32_t *>(Sled.Address + 2) = FuncId;
+        *reinterpret_cast<uint8_t *>(Sled.Address + 6) = CallOpCode;
+        *reinterpret_cast<uint32_t *>(Sled.Address + 7) = TrampolineOffset;
+        std::atomic_store_explicit(
+            reinterpret_cast<std::atomic<uint16_t> *>(Sled.Address), MovR10Seq,
+            std::memory_order_release);
+      } else {
+        std::atomic_store_explicit(
+            reinterpret_cast<std::atomic<uint16_t> *>(Sled.Address), Jmp9Seq,
+            std::memory_order_release);
+        // FIXME: Write out the nops still?
+      }
+    }
+
   }
   XRayPatching.store(false, std::memory_order_release);
   PatchingSuccess = true;
   return XRayPatchingStatus::SUCCESS;
 }
 
 XRayPatchingStatus __xray_patch() { return ControlPatching(true); }
 
 XRayPatchingStatus __xray_unpatch() { return ControlPatching(false); }