[XRay] Custom event logging intrinsic

[dberris]

Summary

This patch introduces an LLVM intrinsic and a target opcode for custom event logging in XRay. Initially, its use case will be to allow users of XRay to log some type of string ("poor man's printf"). The target opcode compiles to a noop sled large enough to enable calling through to a runtime-determined relative function call. At runtime, when X-Ray is enabled, the sled is replaced by compiler-rt with a trampoline to the logic for creating the custom log entries.

Future patches will implement the compiler-rt parts and clang-side support for emitting the IR corresponding to this intrinsic.

[dberris]

Thanks for this louis!

I think you can start getting a bit more advice from @echristo about the handling that's appropriate here. I've added some thoughts below but I'm not very familiar yet with the higher level LLVM IR functionality that would facilitate what we're trying to achieve here.

lib/Target/X86/X86ISelLowering.cpp

18649–18654

At this point I think you can check first whether the arg is a constant in the first place (and handle that appropriately). Here you can emit the pseudo instruction and use virtual registers (or other mechanisms for the operands) to pass the information through.

[lrl]

I think I might be a little closer. Now it doesn't get optimized out but it fails on the second round of combine for legalize types. I replaced uses of the original intrinsic operand with the target opcode instruction.

Other examples seem to be doing chian/glue though so I figure I still need to do this for it to work out

[dberris]

Can you post the legalization error somewhere, or on this patch as well?

I have to admit to not knowing very much about the SelectionDAG business... probably need to read more to understand it myself. Maybe @echristo can redirect to someone who might know more there?

[lrl]

This comment was removed by lrl.

[lrl]

Note: I'm planning to hack on it some more this week, probably Thursday. I haven't had time to play around too much after the legalization error. I suspect the current way of explicitly setting the use might be wrong because all the other lowerings don't explicitly set the use. But I'm not really sure...

➜  llvmninja bin/llc -debug -view-dag-combine2-dags -filetype=asm -o - -mtriple=x86_64-unknown-linux-gnu playground.ll
Args: bin/llc -debug -view-dag-combine2-dags -filetype=asm -o - -mtriple=x86_64-unknown-linux-gnu playground.ll
	.text
	.file	"playground.ll"

Features:+64bit,+sse2
CPU:generic

Subtarget features: SSELevel 2, 3DNowLevel 0, 64bit 1
********** Begin Constant Hoisting **********
********** Function: caller
********** End Constant Hoisting **********
*** Interleaved Access Pass: caller
[SafeStack] Function: caller
[SafeStack]     safestack is not requested for this function
---- Branch Probability Info : caller ----

Computing probabilities for



=== caller
Initial selection DAG: BB#0 'caller:'
SelectionDAG has 8 nodes:
  t1: i64 = FrameIndex<0>
    t0: ch = EntryToken
  t6: ch,glue = CopyToReg t0, Register:i32 %EAX, Constant:i32<0>
  t7: ch = X86ISD::RET_FLAG t6, TargetConstant:i32<0>, Register:i32 %EAX, t6:1



Combining: t7: ch = X86ISD::RET_FLAG t6, TargetConstant:i32<0>, Register:i32 %EAX, t6:1

Combining: t6: ch,glue = CopyToReg t0, Register:i32 %EAX, Constant:i32<0>

Combining: t5: i32 = Register %EAX

Combining: t4: i32 = TargetConstant<0>

Combining: t3: i32 = Constant<0>

Combining: t2: ch = PATCHABLE_LOG_CALL t2

Combining: t0: ch = EntryToken
Optimized lowered selection DAG: BB#0 'caller:'
SelectionDAG has 7 nodes:
    t0: ch = EntryToken
  t6: ch,glue = CopyToReg t0, Register:i32 %EAX, Constant:i32<0>
  t7: ch = X86ISD::RET_FLAG t6, TargetConstant:i32<0>, Register:i32 %EAX, t6:1


Legally typed node: t5: i32 = Register %EAX

Legally typed node: t4: i32 = TargetConstant<0>

Legally typed node: t3: i32 = Constant<0>

Legally typed node: t0: ch = EntryToken

Legally typed node: t6: ch,glue = CopyToReg t0, Register:i32 %EAX, Constant:i32<0>

Legally typed node: t7: ch = X86ISD::RET_FLAG t6, TargetConstant:i32<0>, Register:i32 %EAX, t6:1

Legally typed node: t65535: ch = handlenode t7

Unanalyzed node not noticed?
t2: ch = PATCHABLE_LOG_CALL t2

UNREACHABLE executed at /Users/louisli/branches/llvm/lib/CodeGen/SelectionDAG/LegalizeTypes.cpp:456!
0  libLLVMSupport.dylib     0x000000010da30275 llvm::sys::PrintStackTrace(llvm::raw_ostream&) + 101
1  libLLVMSupport.dylib     0x000000010da308b9 PrintStackTraceSignalHandler(void*) + 25
2  libLLVMSupport.dylib     0x000000010da2c8b9 llvm::sys::RunSignalHandlers() + 425
3  libLLVMSupport.dylib     0x000000010da30ce2 SignalHandler(int) + 354
4  libsystem_platform.dylib 0x00007fff9d84852a _sigtramp + 26
Stack dump:
0.	Program arguments: bin/llc -debug -view-dag-combine2-dags -filetype=asm -o - -mtriple=x86_64-unknown-linux-gnu playground.ll
1.	Running pass 'Function Pass Manager' on module 'playground.ll'.
2.	Running pass 'X86 DAG->DAG Instruction Selection' on function '@caller'
[1]    6623 abort      bin/llc -debug -view-dag-combine2-dags -filetype=asm -o -  playground.ll

[dberris]

Today I spent a bit of time having a read through the CodeGenerator docs (http://llvm.org/docs/CodeGenerator.html) which allowed me a bit of insight into how we might want to think about this or at least ask the right questions (hopefully). :)

Please see below. :D

include/llvm/IR/Intrinsics.td

765

You might also consider marking the argument as explicitly ReadOnly`. So this might look like:

[IntrReadMem, IntrArgMemOnly, ReadOnly<1>]

As far as naming goes, I'm not sure how this looks like in practice... but it seems we'd want to give this an "experimental" namespace of sorts, so something like llvm.experimental.xray_customlog(...). I understand that's a bit verbose, but that's fine we can work with that.

include/llvm/Target/Target.td

1003

Having read a little about this, we probably want to provide a specific type here for the register. For custom logging, we may have to make sure that we preserve the value of %r10d before the instruction, and restore it afterwards so we might need to indicate that somehow (that we're implicitly using that register, so the code generator can work around that). Note though that this only makes sense if we ever want to associate custom log entries to function ids (which we do currently), but we can change our minds on that at any point.

Since we're doing this as a generic target-agnostic instruction, we're probably unable to enforce that at this level. So we may have to do something in the SelectionDAG time to say that we're using the R10D register implicitly. Something to think about.

One potential thing we might want to think about is whether this should behave as if it was a "call" instruction anyway, so we may also need to add:

let isCall = 1;

This introduces a wrinkle, since the custom log instruction/intrinsic may inhibit some ordering optimisations that might happen (since it already has hasSideEffects = 1), so it may act as a barrier for code moving before it. I don't know enough of the re-orderings that happen post-SelectionDAG scheduling. Whether that's a concern in practice is less of an issue I think, since we assume that the front-end generated the call to the intrinsic anyway, which means we can treat it as if it were a function call.

lib/CodeGen/SelectionDAG/SelectionDAGBuilder.cpp

5741–5752

I think most of this code is unnecessary (or a red herring) -- what I think might be worth doing at this point is just looking at the LogEntry value, which is an llvm::Value. We want to make sure this is the correct type, and when selecting the operands of the PATCHABLE_LOG_CALL, and provide that list of operands (which should contain a single operand really). So I found that you might be able to do this transparently this way:

SDLoc dl = getCurSDLoc();
Value *LogEntry = I.getArgOperand(0);
// assert(LogEntry->getType()->isPointerTy() && "I need a pointer!");
setValue(&I, DAG.getMachineNode(TargetOpcode::..., dl, NodeTys, getValue(LogEntry)));
return nullptr;

At this point the lowering code should take care of the thing we actually want to see.

There's still the question of how to make sure that before the call the value of the %r10d register is preserved somewhere, and after the call gets restored. I don't have an answer to this just yet (maybe there's a way to explicitly define a "use these registers" here), but that's likely something that's more important in the lowering bits (i.e. we can work around that ourselves there if we can't find a good way of expressing that here).

lib/Target/X86/X86MCInstLower.cpp

1039–1041

I think we can do better here, that instead of pushing the pointer onto the stack, I think we're allowed by the X86 calling conventions to use %edi or similar. If we're going to lower this differently though, say if we took the length of the string as an argument to the intrinsic then we ought to think about this a little more -- i.e. we may need a bit more bytes in the sled for custom log calls. But it's a little too early for us to think about these things. :)

test/CodeGen/X86/xray-custom-log.ll

5

So to make this less weird, you can probably make it so that you have a string that you allocate either as a global (recommended for a test) or taken from a function that will have an i8* pointer argument.

To inform our design of the intrinsic, we ought to think about whether we also need the length of the data on the other side of the pointer. If we know this statically, this is fine -- but if this was something that was taken as an argument to the function, then we ought to be able to handle that too. Sample code might look like:

define i32 @caller2(i8* %str, i8 %len) {
  call void @llvm.xray.customlog_str(i8* %str, i8 %len)
  ret i32 0
}

Note that this allows us to make sure that the length fits within 8 bits (so that limits the amount of data we're willing to write to the log).

[lrl]

lib/CodeGen/SelectionDAG/SelectionDAGBuilder.cpp

5741–5752

This is roughly what it looked like in the previous patch I think -- the assertion does pass, so it seems like the type works. With the above approach, the node gets optimized out, so I believe the next step is to replace the uses. The example I'm trying to use is the PATCHPOINT intrinsic which seems to follow roughly what we've done above by calling setValue() and then replaceUsesWith (I don't understand every line of its implementation -- still looking)

[timshen]

I cannot reproduce the playground.ll crash with close-to-trunk revision. Have you rebased your patch recently?

Also, it might be helpful to add a "; RUN:" line for the .ll files. See http://llvm.org/docs/CommandGuide/FileCheck.html

[lrl]

In D27503#647796, @timshen wrote:

I cannot reproduce the playground.ll crash with close-to-trunk revision. Have you rebased your patch recently?

Also, it might be helpful to add a "; RUN:" line for the .ll files. See http://llvm.org/docs/CommandGuide/FileCheck.html

Let me add the ;RUN: line. Thanks.

The playground.ll crash was for an earlier version of the patch I think. Now it's on the revision where it just gets optimized out. The playground.ll patch will happen if I try to replace uses of the old intrinsic with the new MachineSDNode -- let me know if you want to see that version and I can upload a commit.

[timshen]

In D27503#648524, @lrl wrote:

The playground.ll patch will happen if I try to replace uses of the old intrinsic with the new MachineSDNode -- let me know if you want to see that version and I can upload a commit.

I'm not sure I understand this?

[rSerge]

As I understood, this patch starts adding a possibility to pass custom events to the XRay logging mechanism. So isn't it more logical to call it "custom event" rather than "custom log"? Another reason, I saw some terms similar to "custom log" somewhere in @dberris 's commits, perhaps in FDR. So I think it's desirable to avoid confusion.
And a general question: how are you going to pass these custom events to XRay logging, if currently the handler callback is not designed to take a pointer argument? It currently takes the function id and call reason code as arguments. Are you going to add the 3rd parameter like void* Data to the handler function? Trampolines may need adjustment in that case on some platforms.

[timshen]

lib/CodeGen/SelectionDAG/SelectionDAGBuilder.cpp

5748

NodeTys seems wrong to me, it should be MVT::Other. It indicates the return type, aka void, not the parameter types.

5752

You need to call DAG.setRoot(patchableNode), otherwise the succeeding nodes are not reached from patchableNode, ending up with patchableNode gets garbage-collected.

[dberris]

In D27503#653620, @rSerge wrote:

As I understood, this patch starts adding a possibility to pass custom events to the XRay logging mechanism. So isn't it more logical to call it "custom event" rather than "custom log"? Another reason, I saw some terms similar to "custom log" somewhere in @dberris 's commits, perhaps in FDR. So I think it's desirable to avoid confusion.

Indeed, it will be confusing when we think about how in the FDR change we're allowing for a custom logging mechanism. In this case though we're really talking about a user-driven event being inserted into the XRay log. I think custom events seem to make a bit more sense for this functionality.

And a general question: how are you going to pass these custom events to XRay logging, if currently the handler callback is not designed to take a pointer argument? It currently takes the function id and call reason code as arguments. Are you going to add the 3rd parameter like void* Data to the handler function? Trampolines may need adjustment in that case on some platforms.

Yes, this is currently an exploratory patch -- we will need to handle these differently in the runtime. That should come later.

The intent here is to have a different trampoline for these custom events, with a different extension point in the log implementation. The API being introduced in the FDR change allows us to add different kinds of handlers too.

There's also work being done by @pelikan that should implement the first argument logging implementation, which will also require changes to the runtime. We're doing it incrementally though to unblock progress, and allow XRay to be usable even in its current form.

[timshen]

lib/Target/X86/X86MCInstLower.cpp

1041

Is PATCHABLE_LOG_CALL allowed to be inserted in arbitrary place inside the function?

If so, the callee must not clobber any register at all. This is unlike \_\_xray_FunctionEntry, which just need to save and restore callee-saved, parameter passing registers; or unlike \_\_xray_FunctionExit, which just need to save and restore return value register.

[dberris]

lib/Target/X86/X86MCInstLower.cpp

1041

Yes, we're going to have to treat this as if it's a normal function call, on a cross-platform basis. The only difference would be that the call will be guarded by a jump over that could be patched at runtime.

[timshen]

lib/Target/X86/X86MCInstLower.cpp

1041

That requires larger instrumentation pass changes, right? It's going to be moved before at least frame lowering, Or even earlier. Or even changed to an IR pass. :P

[dberris]

lib/Target/X86/X86MCInstLower.cpp

1041

Not really, at least I don't think so -- this is something that users write in their code (something like __xray_custom_log(...)) that turns into an intrinsic instruction function call in the IR. We're lowering that intrinsic call, which by definition really happens in the function body (after stack adjustments, after the prologue). The intent is to guard the function call with a "jump over" just like normal sleds (and have it compute the offset to the trampoline at runtime).

[timshen]

lib/Target/X86/X86MCInstLower.cpp

1041

which by definition really happens in the function body (after stack adjustments, after the prologue).

That is true. I was not worrying about that, and I ignored that we do have an IR intrinsic for it. During the lowering, the call sequence is there, providing proper amount of space reserved for saving live,callee-saved registers. These are good. The problem is that currently the sled doesn't save any live registers (according to LowerPATCHABLE_LOG_CALL, the function we are commenting on).

Either the caller or the callee needs to save the live registers. If it's implemented in a way that registers saved by callee (__xray_custom_log), the problem is it doesn't know which registers are alive; since custom logging may happen at any point in the function, __xray_custom_log'd better save all callee-saved registers.

If it's implemented in the way that registers are saved by the caller, great, the caller knows which registers to save - but it knows only at compile time, as opposed to patch time. The current LowerPATCHABLE_LOG_CALL, which is at compile time, doesn't emit register saving and restoring code.

Ideally, I prefer just lowering the intrinsic to a normal function call C function __xray_custom_log, instead of a pseudo instruction PATCHABLE_LOG_CALL. In the instrumentation pass, the pass scans for calls to __xray_custom_log, and add branch overs before those calls. The advantage is that all register saving/restoring code is handled by common llvm infrastructure. In this approach, adding an IR intrinsic is optional, because the user can directly call the C function __xray_custom_log, knowing that the compiler is going to add the branch over around it.

[dberris]

lib/Target/X86/X86MCInstLower.cpp

1041

Ideally, I prefer just lowering the intrinsic to a normal function call C function xray_custom_log, instead of a pseudo instruction PATCHABLE_LOG_CALL. In the instrumentation pass, the pass scans for calls to xray_custom_log, and add branch overs before those calls.

That makes sense, although I haven't quite worked out how to do this from the MachineFunction pass, since the register restoration code after the call might be arbitrarily long. From the IR level I don't think we have a means of marking sections of code yet that could be explicitly branched over statically but preserved in codegen (i.e. if it's possible to inhibit dead-code removal).

Even if it's possible to do caller-saved register stashing and have the back-end generate the jumps (similar to how we have the sleds now), the differences amongst the intrinsic call-sites could be substantial (i.e. register allocation could get messed up by treating the intrinsic call to be a "normal function call"). The advantage of making the trampoline do the caller- and callee-saved register stashing/restoring is that the patch points all look the same (matters especially in x86) and the trampoline also does the same thing and has a fixed cost.

[timshen]

lib/Target/X86/X86MCInstLower.cpp

1041

Even if it's possible to do caller-saved register stashing and have the back-end generate the jumps (similar to how we have the sleds now), the differences amongst the intrinsic call-sites could be substantial (i.e. register allocation could get messed up by treating the intrinsic call to be a "normal function call"). The advantage of making the trampoline do the caller- and callee-saved register stashing/restoring is that the patch points all look the same (matters especially in x86) and the trampoline also does the same thing and has a fixed cost.

That's a good point, since adding normal function calls may significantly change the shape of the normal code. Maybe we should just save and restore *all* registers and see how slow it is - I'm not quite optimistic, since xray logs hot functions.

While we shouldn't worry too much about the performance until we have numbers, a random thought on making this faster can be: when calling __xray_set_handler, require the passed in handler function to be marked with a special ABI attribute, that's essentially saying all registers are callee-saved.

[dberris]

lib/Target/X86/X86MCInstLower.cpp

1041

This has so far been the assumption for all the XRay sleds -- that the trampolines do save all callee and caller-saved registers. This is going to be a bit different too (the trampoline for the custom logging) since it has to store even the scratch registers in x86. Note that this only happens though when the user asks for custom event logging -- the logging implementation is going to be the bottleneck anyway, and our fixed costs in the trampolines will be "constant" modulo interference effects.

So far too we haven't had to do special annotations of the ABI, since we do the patching at runtime anyway.

[dberris]

@lrl Please let us know when this is ready again for another look (given the feedback and recent discussions).

[lrl]

Hullo! I've now updated the patch.

• renamed things to custom event
• add a single unit test -- taking suggestions for more (due to lack of domain knowledge, would love suggestions about what types of cases need to be tested)
• followed x86 calling conventions before/after the trampoline

[dberris]

Cool stuff, thanks @lrl -- just one thing and I think we can land soon after unless @timshen or @echristo have other thoughts.

lib/Target/X86/X86MCInstLower.cpp

1042–1051

We can reduce this a bit, now that we don't really need to put the function id in %r10 anymore.

[lrl]

In D27503#673151, @dberris wrote:

Cool stuff, thanks @lrl -- just one thing and I think we can land soon after unless @timshen or @echristo have other thoughts.

done

[dberris]

Couple more things you might want to address. If @timshen or @echristo don't get to land it or have more comments, I'll land it tomorrow. :)

lib/Target/X86/X86MCInstLower.cpp

1046

We don't need the function id here anymore, so really the jump will just become a 2-byte nop.

1073–1080

You can MI.getNumOperands() and use that to do a reverse index, using MI.getOperand(...)?

test/CodeGen/X86/xray-custom-log.ll

23

You can probably look for the entry in the instrumentation map that will contain the correct reference to the sled, with the correct type associated with it. See other adjacent tests that do similar things?

[timshen]

lib/Target/X86/X86MCInstLower.cpp

1065

I thought we want save & restore all registers at the callee side?

Besides, this might be in a middle of a function, so any register could be alive, not just the caller-saved ones. That include all 16 generic registers, 16 xmm registers, 8 mmx registers, 8 "k" registers, 8 st registers, mxcsr, x87 SW, x87 CW, 4 bnd registers. And I don't even know what are some these weirdo registers. :)

[timshen]

lib/Target/X86/X86MCInstLower.cpp

1065

Sorry, I was wrong about this. Only caller-saved registers need to be saved.

However, there are more registers then these three. See https://github.com/llvm-mirror/compiler-rt/blob/master/lib/xray/xray_trampoline_x86_64.S "SAVE_REGISTERS".

Still, I think it's better to save and restore them on the callee side, to minimize the change on the caller sidde.

[dberris]

lib/Target/X86/X86MCInstLower.cpp

1065

The implementation of the trampoline will do more of the register saving. That will be in the compiler-rt side of things. This is first introducing the intrinsic, and the compiler-rt changes will happen later. I think we're doing the right things at this point, and can do more in the trampoline.

[timshen]

lib/Target/X86/X86MCInstLower.cpp

1065

I was confused by doing some of the register saving at the caller side (naturally it should be all or none).

If that's the right thing then go ahead and check in.

[dberris]

Thanks @timshen for having a look. I'll land this now and improve the tests while @lrl is out on vacation.

lib/Target/X86/X86MCInstLower.cpp

1065

I was confused by doing some of the register saving at the caller side (naturally it should be all or none).

The register saving is really because the trampoline needs those things as arguments -- so the caller side needs to put the data in the stack anyway, and restore those registers on the caller side after the function (in this case the trampoline) call returns. This is just normal x86 function calling semantics. Since this can occur in the body of the function, we don't necessarily know what the registers hold at that point and therefore need to stash them caller-side so we can use those for the function call.

The trampoline will then use the arguments to be passed into the logging implementation, setting the stack up appropriately there too. To do that correctly, the trampoline has to store the state of all registers that the logging implementation might use in its execution (including the scratch registers), call the logging implementation, then restore the state of the registers before returning to the caller.

The caller (the function from which the custom event logging was called) will then restore the caller-saved registers so the function can proceed as-if the instrumentation never happened in the first place. :)

[dberris]

Adding llvm-commits, will upload an updated patch for posterity.

[dberris]

Taking this on while @lrl is on vacation.

[dberris]

Rebase

[echristo]

One inline nit, I'd like to take a closer look at this though. Can you give an example of use case and lowering?

Thanks :)

lib/Target/X86/X86MCInstLower.cpp

1086

No named fixme.

[dberris]

• Fixups

[dberris]

Can you give an example of use case and lowering?

The high-level idea is to translate something like this in C++:

[[clang::xray_always_instrument]] void foo() {
  static constexpr char kPhase[] = "Foo phase."
  __xray_customevent(kPhase, strlen(kPhase));
}

Into the lowered form in llvm IR calling llvm.experimental.customevent(...). The intent is to emit the sled, such that we can at runtime embed the correct call to a relative offset, to the trampoline that will invoke the custom event handler

Does that help?

[dberris]

Actually, now that I think about it more, it seems that we can get away with just always precisely pushing the values in the arguments (the pointer value and the size) and not worrying about the x86 calling convention -- since we in theory control what the trampoline does anyway in compiler-rt. I'm working on some local changes to reflect this. We also want to change the type of the size argument so that it reflects what 'size_t' might be for the platform.

[dberris]

• fixup: simplify and shrink sled code

[dberris]

This is now ready for another look @timshen / @echristo

[dberris]

Actually, while working on the compiler-rt side of things it turns out the sleds aren't quite that simple to nail down. I have some local changes and am iterating, mostly based on trying it out and hitting different roadblocks.

However, if you have feedback on the following issues, it would be most appreciated:

• Fixing up the size of the sleds in all situations. It seems the initial assumptions in the comments are different (it largely depends on which registers are being pushed in, and the encoding of the push operations will vary in x86 if the arguments are passed in following a specific ABI).
• Whether we can enforce a specific ABI for an intrinsic so that, say, we always have the first and second arguments to the trampoline be in %rdi and %rsi (as in the System V ABI).

Cheers

[dberris]

Re-did to make lowering of arguments simpler, and be jumped over (no impact to caller code when off).

[dberris]

Much simpler now, although I'm not sure why calls to the intrinsic don't automatically lower the arguments to the call according to the sysv64 calling convention -- perhaps I'm missing an explicit calling convention spec in the front-end in D30018? Will that help?

[dberris]

Ping @echristo or @timshen ?

[dberris]

Hi @rSerge -- do you have time to have a look at this?

[rSerge]

@dberris , I've reviewed it, but I'm not sufficiently qualified for this as I am not familiar with some parts of LLVM touched...
To the extent of my knowledge, this looks good.

[dberris]

thanks @rSerge

ping @echristo on the new intrinsics, apis, etc.

also @rnk in case there's anything that jumps out here.

[dberris]

ping @timshen

[timshen]

Other than some nits and questions, looks good. :)

include/llvm/IR/Intrinsics.td

779

Is the length going to be i8 forever? What if the strings are getting longer? Would it be better to use a word-size length variable?

lib/CodeGen/SelectionDAG/FastISel.cpp

885 ↗

(On Diff #91274)

I thought It's not necessary to have a FastISel implementation for this, because if FastISel doesn't work, the execution falls back to SelectionDAG.

Now that you already have this, I'm not object to keeping it though. :)

lib/Target/X86/X86MCInstLower.cpp

1047

I believe that before at symbol, all caller-saved registers are actually saved?

1070

Maybe jump to an "exit" symbol, and emit that symbol at the end of the sled?

See: https://github.com/llvm-mirror/llvm/blob/288180ac40ab050711298f42340233bd47916634/lib/Target/PowerPC/PPCAsmPrinter.cpp#L1076

[dberris]

Update test and address comments

[dberris]

include/llvm/IR/Intrinsics.td

779

good point -- i32 is definitely better for future proofing.

lib/CodeGen/SelectionDAG/FastISel.cpp

885 ↗

(On Diff #91274)

Ah, cool. That's good to know. :)

lib/Target/X86/X86MCInstLower.cpp

1047

I thought that too, except the calling convention for the intrinsic seems to be the C calling convention (default) as opposed to the SysV64 calling convention that I'd like it to be. This is where the question of whether it's possible (or whether it makes sense) for us to actually provide the calling convention for the intrinsic (or whether the front-end has to explicitly state this).

Any suggestions on how to force the calling convention here?

1070

That doesn't quite work for x86 because the jump instruction emitted can vary (i.e. it's not always 2 bytes). The runtime requires us to be able to write two bytes atomically to enable/disable the jump. Since there's no way yet for us to force a specific jump instruction that will be preserved when the relaxation pass runs, for now we need to hard-code this static relative jump ourselves.

[timshen]

lib/Target/X86/X86MCInstLower.cpp

1047

Why do you want SysV64 calling convention?

I was trying to confirm that no registers will be clobbered unexpectedly, causing correctness issues.

1070

I'm not quite following - it's AsmPrinter, and there shouldn't be any lowering after that, is it right?

What is the "relaxation pass" you mentioned? Is it BranchRelaxation pass? But I think it runs before AsmPrinter?

[dberris]

lib/Target/X86/X86MCInstLower.cpp

1047

I thought that was the default calling convention for x86_64 on Linux, and it would greatly simplify the code in the sled to not have to put the registers in the correct registers expected by the function we are calling (__xray_CustomEvent is a trampoline). In my testing, for some reason the arguments we need might be placed in random registers. Like in the test, you will see that we need to move arguments around from the C calling convention, using different registers for the arguments, than the SysV64 calling convention (which the __xray_CustomEvent trampoline requires).

I was trying to confirm that no registers will be clobbered unexpectedly, causing correctness issues.

Ah, yes -- AFAICT, the lowering of MachineInst's that are considered "call" instructions will preserve caller-saved registers before the call. Is there a way for me to verify that in the test more explicitly?

1070

So the integrated assembler has an option (-mrelax-all) which will look for jmp instructions and attempt to relax those. The integrated assembler will run after all assembly is emitted. This works around that until we can flag certain jump instructions to never be relaxed.

[timshen]

lib/Target/X86/X86MCInstLower.cpp

1047

As long as it's correct, I'm fine.

1070

\facepalm that's good to know. Thanks!

include/llvm/CodeGen/AsmPrinter.h

public:
   // XRay instrumentation implementation.
   //===------------------------------------------------------------------===//
 public:
   // This describes the kind of sled we're storing in the XRay table.
   enum class SledKind : uint8_t {
     FUNCTION_ENTER = 0,
     FUNCTION_EXIT = 1,
     TAIL_CALL = 2,
+    CUSTOM_EVENT = 3,
   };
 
   // The table will contain these structs that point to the sled, the function
   // containing the sled, and what kind of sled (and whether they should always
   // be instrumented).
   struct XRayFunctionEntry {
     const MCSymbol *Sled;
     const MCSymbol *Function;

include/llvm/IR/Intrinsics.td

 def int_masked_compressstore: Intrinsic<[],
                                      [llvm_anyvector_ty,
                                       LLVMPointerToElt<0>,
                                       LLVMVectorSameWidth<0, llvm_i1_ty>],
                                      [IntrArgMemOnly]>;
 
 // Test whether a pointer is associated with a type metadata identifier.
 def int_type_test : Intrinsic<[llvm_i1_ty], [llvm_ptr_ty, llvm_metadata_ty],
                               [IntrNoMem]>;
 
 // Safely loads a function pointer from a virtual table pointer using type metadata.
 def int_type_checked_load : Intrinsic<[llvm_ptr_ty, llvm_i1_ty],
                                       [llvm_ptr_ty, llvm_i32_ty, llvm_metadata_ty],
                                       [IntrNoMem]>;
 
 def int_load_relative: Intrinsic<[llvm_ptr_ty], [llvm_ptr_ty, llvm_anyint_ty],
                                  [IntrReadMem, IntrArgMemOnly]>;
 
+// Xray intrinsics
+//===----------------------------------------------------------------------===//
+// Custom event logging for x-ray.
+// Takes a pointer to a string and the length of the string.
+def int_xray_customevent : Intrinsic<[], [llvm_ptr_ty, llvm_i8_ty],
+                                   [IntrReadMem, IntrArgMemOnly]>;
+//===----------------------------------------------------------------------===//
+
 //===------ Memory intrinsics with element-wise atomicity guarantees ------===//
 //
 
 def int_memcpy_element_atomic  : Intrinsic<[],
                                            [llvm_anyptr_ty, llvm_anyptr_ty,
                                             llvm_i64_ty, llvm_i32_ty],
                                  [IntrArgMemOnly, NoCapture<0>, NoCapture<1>,
                                   WriteOnly<0>, ReadOnly<1>]>;

include/llvm/Target/Target.td

 def PATCHABLE_TAIL_CALL : Instruction {
   let OutOperandList = (outs unknown:$dst);
   let InOperandList = (ins variable_ops);
   let AsmString = "# XRay Tail Call Exit.";
   let usesCustomInserter = 1;
   let hasSideEffects = 1;
   let isReturn = 1;
 }
+def PATCHABLE_EVENT_CALL : Instruction {
+  let OutOperandList = (outs);
+  let InOperandList = (ins unknown:$event, i8imm:$size);
+  let AsmString = "# XRay Custom Event Log.";
+  let usesCustomInserter = 1;
+  let isCall = 1;
+  let mayLoad = 1;
+  let mayStore = 1;
+  let hasSideEffects = 1;
+}
 def FENTRY_CALL : Instruction {
   let OutOperandList = (outs unknown:$dst);
   let InOperandList = (ins variable_ops);
   let AsmString = "# FEntry call";
   let usesCustomInserter = 1;
   let mayLoad = 1;
   let mayStore = 1;
   let hasSideEffects = 1;

include/llvm/Target/TargetOpcodes.def

 /// call it, it does the tracing, preserves the stack and returns.
 HANDLE_TARGET_OPCODE(PATCHABLE_FUNCTION_EXIT)
 
 /// Wraps a tail call instruction and its operands to enable adding nop sleds
 /// either before or after the tail exit. We use this as a disambiguation from
 /// PATCHABLE_RET which specifically only works for return instructions.
 HANDLE_TARGET_OPCODE(PATCHABLE_TAIL_CALL)
 
+/// Wraps a logging call and its arguments with nop sleds. At runtime, this can be
+/// patched to insert instrumentation instructions.
+HANDLE_TARGET_OPCODE(PATCHABLE_EVENT_CALL)
+
 /// The following generic opcodes are not supposed to appear after ISel.
 /// This is something we might want to relax, but for now, this is convenient
 /// to produce diagnostics.
 
 /// Generic ADD instruction. This is an integer add.
 HANDLE_TARGET_OPCODE(G_ADD)
 HANDLE_TARGET_OPCODE_MARKER(PRE_ISEL_GENERIC_OPCODE_START, G_ADD)
 

lib/CodeGen/SelectionDAG/SelectionDAGBuilder.cpp

for (unsigned Idx = 0, E = I.getNumArgOperands(); Idx < E; ++Idx) {
              "can only escape static allocas");
       int FI = FuncInfo.StaticAllocaMap[Slot];
       MCSymbol *FrameAllocSym =
           MF.getMMI().getContext().getOrCreateFrameAllocSymbol(
               GlobalValue::getRealLinkageName(MF.getName()), Idx);
       BuildMI(*FuncInfo.MBB, FuncInfo.InsertPt, dl,
               TII->get(TargetOpcode::LOCAL_ESCAPE))
           .addSym(FrameAllocSym)
           .addFrameIndex(FI);
     }
 
     return nullptr;
   }
 
   case Intrinsic::localrecover: {
     // i8* @llvm.localrecover(i8* %fn, i8* %fp, i32 %idx)
     MachineFunction &MF = DAG.getMachineFunction();
     MVT PtrVT = TLI.getPointerTy(DAG.getDataLayout(), 0);
 
     // Get the symbol that defines the frame offset.
     auto *Fn = cast<Function>(I.getArgOperand(0)->stripPointerCasts());
     auto *Idx = cast<ConstantInt>(I.getArgOperand(2));
     unsigned IdxVal = unsigned(Idx->getLimitedValue(INT_MAX));
     MCSymbol *FrameAllocSym =
         MF.getMMI().getContext().getOrCreateFrameAllocSymbol(
             GlobalValue::getRealLinkageName(Fn->getName()), IdxVal);
 
     // Create a MCSymbol for the label to avoid any target lowering
case Intrinsic::eh_exceptioncode: {
     unsigned VReg = FuncInfo.getCatchPadExceptionPointerVReg(CPI, PtrRC);
     SDValue N =
         DAG.getCopyFromReg(DAG.getEntryNode(), getCurSDLoc(), VReg, PtrVT);
     if (Intrinsic == Intrinsic::eh_exceptioncode)
       N = DAG.getZExtOrTrunc(N, getCurSDLoc(), MVT::i32);
     setValue(&I, N);
     return nullptr;
   }
+  case Intrinsic::xray_customevent: {
+    SDLoc dl = getCurSDLoc();
+    SmallVector<SDValue, 8> Ops;
+    SDValue LogEntryVal = getValue(I.getArgOperand(0));
+    SDValue StrSizeVal = getValue(I.getArgOperand(1));
     
+    SDVTList NodeTys = DAG.getVTList(MVT::Other, MVT::Glue);
+    SDValue Chain = getRoot();
+    Ops.push_back(LogEntryVal);
+    Ops.push_back(StrSizeVal);
+    Ops.push_back(Chain);
+    MachineSDNode *MN = DAG.getMachineNode(TargetOpcode::PATCHABLE_EVENT_CALL, dl, NodeTys, Ops);
+    SDValue patchableNode = SDValue(MN, 0);
+    DAG.setRoot(patchableNode);
+    setValue(&I, patchableNode);
+    return nullptr;
+  }
   case Intrinsic::experimental_deoptimize:
     LowerDeoptimizeCall(&I);
     return nullptr;
   }
 }
 
 void SelectionDAGBuilder::visitConstrainedFPIntrinsic(const CallInst &I,
                                                       unsigned Intrinsic) {

lib/Target/X86/X86AsmPrinter.h

class LLVM_LIBRARY_VISIBILITY X86AsmPrinter : public AsmPrinter {
 
   void LowerTlsAddr(X86MCInstLower &MCInstLowering, const MachineInstr &MI);
 
   // XRay-specific lowering for X86.
   void LowerPATCHABLE_FUNCTION_ENTER(const MachineInstr &MI,
                                      X86MCInstLower &MCIL);
   void LowerPATCHABLE_RET(const MachineInstr &MI, X86MCInstLower &MCIL);
   void LowerPATCHABLE_TAIL_CALL(const MachineInstr &MI, X86MCInstLower &MCIL);
+  void LowerPATCHABLE_EVENT_CALL(const MachineInstr &MI, X86MCInstLower &MCIL);
 
   void LowerFENTRY_CALL(const MachineInstr &MI, X86MCInstLower &MCIL);
 
   // Helper function that emits the XRay sleds we've collected for a particular
   // function.
   void EmitXRayTable();
 
 public:

lib/Target/X86/X86ISelLowering.cpp

static SDValue getTargetVShiftNode(unsigned Opc, const SDLoc &dl, MVT VT,
   // | i64             | Yes, No    | Use ShAmt as lowest elt               |
   // | i32             | Yes        | zero-extend in-reg                    |
   // | (i32 zext(i16)) | Yes        | zero-extend in-reg                    |
   // | i16/i32         | No         | v4i32 build_vector(ShAmt, 0, ud, ud)) |
   // +=================+============+=======================================+
 
   if (SVT == MVT::i64)
     ShAmt = DAG.getNode(ISD::SCALAR_TO_VECTOR, SDLoc(ShAmt), MVT::v2i64, ShAmt);
   else if (Subtarget.hasSSE41() && ShAmt.getOpcode() == ISD::ZERO_EXTEND &&
            ShAmt.getOperand(0).getSimpleValueType() == MVT::i16) {
     ShAmt = ShAmt.getOperand(0);
     ShAmt = DAG.getNode(ISD::SCALAR_TO_VECTOR, SDLoc(ShAmt), MVT::v8i16, ShAmt);
     ShAmt = DAG.getNode(X86ISD::VZEXT, SDLoc(ShAmt), MVT::v2i64, ShAmt);
   } else if (Subtarget.hasSSE41() &&
              ShAmt.getOpcode() == ISD::EXTRACT_VECTOR_ELT) {
     ShAmt = DAG.getNode(ISD::SCALAR_TO_VECTOR, SDLoc(ShAmt), MVT::v4i32, ShAmt);
     ShAmt = DAG.getNode(X86ISD::VZEXT, SDLoc(ShAmt), MVT::v2i64, ShAmt);
   } else {
     SmallVector<SDValue, 4> ShOps = {ShAmt, DAG.getConstant(0, dl, SVT),
                                      DAG.getUNDEF(SVT), DAG.getUNDEF(SVT)};
     ShAmt = DAG.getBuildVector(MVT::v4i32, dl, ShOps);
   }
X86TargetLowering::EmitInstrWithCustomInserter(MachineInstr &MI,
   case TargetOpcode::STATEPOINT:
     // As an implementation detail, STATEPOINT shares the STACKMAP format at
     // this point in the process.  We diverge later.
     return emitPatchPoint(MI, BB);
 
   case TargetOpcode::STACKMAP:
   case TargetOpcode::PATCHPOINT:
     return emitPatchPoint(MI, BB);
     
+  case TargetOpcode::PATCHABLE_EVENT_CALL:
+    // Do nothing here, handle in xray instrumentation pass.
+    return BB;
+
   case X86::LCMPXCHG8B: {
     const X86RegisterInfo *TRI = Subtarget.getRegisterInfo();
     // In addition to 4 E[ABCD] registers implied by encoding, CMPXCHG8B
     // requires a memory operand. If it happens that current architecture is
     // i686 and for current function we need a base pointer
     // - which is ESI for i686 - register allocator would not be able to
     // allocate registers for an address in form of X(%reg, %reg, Y)
     // - there never would be enough unreserved registers during regalloc

lib/Target/X86/X86MCInstLower.cpp

void X86AsmPrinter::LowerPATCHPOINT(const MachineInstr &MI,
   unsigned NumBytes = opers.getNumPatchBytes();
   assert(NumBytes >= EncodedBytes &&
          "Patchpoint can't request size less than the length of a call.");
 
   EmitNops(*OutStreamer, NumBytes - EncodedBytes, Subtarget->is64Bit(),
            getSubtargetInfo());
 }
 
+void X86AsmPrinter::LowerPATCHABLE_EVENT_CALL(const MachineInstr &MI,
+                                              X86MCInstLower &MCIL) {
+  // We want to emit the following pattern, which follows the x86 calling
+  // convention to prepare for the trampoline call to be patched in.
+  //
+  //   .p2align 1, ...
+  // .Lxray_event_sled_N:
+  //   jmp .tmpN # 2 bytes
+  //   [3 times] push <caller-saved register>  (15 bytes = 3 registers * 5
+  //   bytes) push <reg containing arg 1 of intrinsic> (5 bytes) push <reg
+  //   containing arg 0 of intrinsic> (5 bytes) # 5 bytes of noops (reserve
+  //   space for call) addq, $8, esp (9 bytes, clean parameters) [3 times] pop
+  //   <caller-saved register> (15 bytes)
+  // .tmpN
+  //
+  // The relative jump needs to jump forward 45 bytes:
+  // 15 (caller-saved) + 10 (args) + 5 (nops) + 9 + 15
+  //
+  // After patching, it would look something like:
+  //
+  //   <push instructions for calling convention>
+  //   push <reg containing pointer to log entry> // 5 bytes
+  //   call <relative offset, 32-bits>   // 5 bytes
+  //   <instructions for calling convention cleanup>
+  //
+  auto CurSled = OutContext.createTempSymbol("xray_event_sled_", true);
+  OutStreamer->EmitCodeAlignment(2);
+  OutStreamer->EmitLabel(CurSled);
+  auto Target = OutContext.createTempSymbol();
+
+  // Use a two-byte `jmp`. This version of JMP takes an 8-bit relative offset as
+  // an operand (computed as an offset from the jmp instruction).
+  // FIXME: Find another less hacky way do force the relative jump.
+  OutStreamer->EmitBytes("\xeb\x2d");
+
+  // Push caller-saved registers per x86 calling convention.
+  static const unsigned CallerSavedReg[3] = {X86::EAX, X86::ECX, X86::EDX};
+  for (auto Reg : CallerSavedReg)
+    OutStreamer->EmitInstruction(
+        MCInstBuilder(X86::PUSH64r).addOperand(MCOperand::createReg(Reg)),
+        getSubtargetInfo());
+
+  // Push the arguments in reverse order per x86 calling convention.
+  for (auto &MO : reverse(MI.operands()))
+    if (auto MaybeOperand = MCIL.LowerMachineOperand(&MI, MO))
+      OutStreamer->EmitInstruction(
+          MCInstBuilder(X86::PUSH64r).addOperand(MaybeOperand.getValue()),
+          getSubtargetInfo());
+
+  // nops to be patched with a trampoline call.
+  EmitNops(*OutStreamer, 5, Subtarget->is64Bit(), getSubtargetInfo());
+
+  // ESP - (2 parameters * 4 bytes)
+  MCInst RemoveParameters = MCInstBuilder(X86::ADD64ri8)
+                                .addOperand(MCOperand::createReg(X86::ESP))
+                                .addOperand(MCOperand::createReg(X86::ESP))
+                                .addOperand(MCOperand::createImm(8));
+  OutStreamer->EmitInstruction(RemoveParameters, getSubtargetInfo());
+
+  // Restore caller saved registers (popping in reverse order)
+  for (auto Reg : reverse(CallerSavedReg))
+    OutStreamer->EmitInstruction(
+        MCInstBuilder(X86::POP64r).addOperand(MCOperand::createReg(Reg)),
+        getSubtargetInfo());
+
+  OutStreamer->EmitLabel(Target);
+  recordSled(CurSled, MI, SledKind::CUSTOM_EVENT);
+}
+
 void X86AsmPrinter::LowerPATCHABLE_FUNCTION_ENTER(const MachineInstr &MI,
                                                   X86MCInstLower &MCIL) {
   // We want to emit the following pattern:
   //
   //   .p2align 1, ...
   // .Lxray_sled_N:
   //   jmp .tmpN
   //   # 9 bytes worth of noops
void X86AsmPrinter::EmitInstruction(const MachineInstr *MI) {
   case TargetOpcode::PATCHABLE_FUNCTION_ENTER:
     return LowerPATCHABLE_FUNCTION_ENTER(*MI, MCInstLowering);
 
   case TargetOpcode::PATCHABLE_RET:
     return LowerPATCHABLE_RET(*MI, MCInstLowering);
 
   case TargetOpcode::PATCHABLE_TAIL_CALL:
     return LowerPATCHABLE_TAIL_CALL(*MI, MCInstLowering);
     
+  case TargetOpcode::PATCHABLE_EVENT_CALL:
+    return LowerPATCHABLE_EVENT_CALL(*MI, MCInstLowering);
+
   case X86::MORESTACK_RET:
     EmitAndCountInstruction(MCInstBuilder(getRetOpcode(*Subtarget)));
     return;
 
   case X86::MORESTACK_RET_RESTORE_R10:
     // Return, then restore R10.
     EmitAndCountInstruction(MCInstBuilder(getRetOpcode(*Subtarget)));
     EmitAndCountInstruction(MCInstBuilder(X86::MOV64rr)

test/CodeGen/X86/xray-custom-log.ll

+; RUN: llc -filetype=asm -o - -mtriple=x86_64-unknown-linux-gnu < %s | FileCheck %s
+
+define i32 @fn() nounwind noinline uwtable "function-instrument"="xray-always" {
+    %eventptr = alloca i8
+    %eventsize = alloca i8
+    store i8 3, i8* %eventsize
+    %val = load i8, i8* %eventsize
+    call void @llvm.xray.customevent(i8* %eventptr, i8 %val)
+    ; CHECK-LABEL: .Lxray_event_sled_0:
+    ; CHECK-NEXT:  .ascii "\353-"
+    ; CHECK-NEXT:  pushq %eax
+    ; CHECK-NEXT:  pushq %ecx
+    ; CHECK-NEXT:  pushq %edx
+    ; CHECK-NEXT:  pushq %al
+    ; CHECK-NEXT:  pushq %rcx
+    ; CHECK-NEXT:  nopl 8(%rax,%rax)
+    ; CHECK-NEXT:  addq $8, %esp
+    ; CHECK-NEXT:  popq %edx
+    ; CHECK-NEXT:  popq %ecx
+    ; CHECK-NEXT:  popq %eax
+    ret i32 0
+}
+; CHECK:       .section {{.*}}xray_instr_map
+; CHECK-LABEL: Lxray_synthetic_0:
+; CHECK:       .quad {{.*}}xray_event_sled_0
+
+declare void @llvm.xray.customevent(i8*, i8)
+