Could this have something to do with turning on frame pointers?

CC @aclements

This has nothing to do with frame pointers, as it doesn't work in 1.6.1 as well.
Also go1 is a leaf function, so it doesn't save/restore BP anyway.

I'm able to fix this by changing the alignment padding between functions from 0xcc (INT $3) to 0x00. I'm not sure why 0xcc makes dtrace fail, but there you go. Padding with 0x90 instead also works. Maybe we could change our padding back to 0x00.

https://go-review.googlesource.com/#/c/16102/ changed from 0x00 to 0xcc padding.

@TocarIP

Failing due to valid, never executed instructions sounds wrong. Is there an open Dtrace bug? Even if Go reverts back to 0x00 for OS X, everything built with 1.6 will still be affected, so I'm interested in Dtrace's team opinion.

I agree. I sent an email to dtrace-discuss@lists.dtrace.org to ask about this problem. I have not heard back yet.

In the version of go I'm looking at (1.6.2) main.go1 is compiled (efficiently) into simply retq. DTrace is failing to identify that instruction as a return site.

Agreed that the null -> int 3 change raised an eyebrow, but it's merely a red herring.

This is a DTrace bug; I'd suggest you close out this golang issue.

It's not a red herring, in that it really does change the behavior of dtrace. Agreed, it looks like a dtrace bug. My email to dtrace-discuss@lists.dtrace.org seems to have gone to /dev/null. Here's what I sent:

In Go, we switched our padding between functions from 0x00 to 0xcc (int3). It seems to have caused a bad interaction with dtrace, where function returns are no longer picked up by dtrace. Is this known? Expected?

A small c/asm program to reproduce is below (for OSX).

a.c:

#include <unistd.h>

void f();

int main() {
    for(;1;) {
        f();
        sleep(1);
    }
}

a.s:

    .globl  _f
_f:
    retq
    //int3

> gcc a.c a.s
> ./a.out

ctrl-T to get the pid. Then in another window:

> sudo dtrace -n 'pid$1::f:' 80480
CPU     ID                    FUNCTION:NAME
  0 198785                          f:entry 
  0 198786                              f:0 
  0 198784                         f:return 
  0 198785                          f:entry 
  0 198786                              f:0 
  0 198784                         f:return 
  0 198785                          f:entry 
  0 198786                              f:0 
  0 198784                         f:return 

If I uncomment the int3 instruction and try again, I get:

CPU     ID                    FUNCTION:NAME
  0 197903                          f:entry 
  0 197903                          f:entry 
  0 197903                          f:entry 

Note the f:0 and f:return trace items are gone.

The Go bug is #15969 if you're interested.

Thanks for the clarification; indeed your mail to the DTrace list didn't make it to me.

DTrace disassembles functions to determine the return (and offset) probe points. If it encounters something that looks fishy it bails out. In particular if it finds a 0xcc (int 3) it figures that either a debugger is already in there (in which case there's no telling the identity of the original instruction) or that this an offset for a jump table. We're particularly paranoid about interpreting data as code since doing so would cause DTrace to dramatically (and hopefully fatally) change the operation of the program.

I noticed that the int 3 padding is within the bounds of the symbol. Is that necessary? DTrace only look at the range of the function symbol. Is there a reason that the size needs to encompass the padding? Could the padding be beyond the range of the function?

I understand the rationale behind using the int 3 as padding though I haven't seen other compilers do this.

I'm not sure how we would fix this in DTrace without adding some special golang-specific workaround to ignore 0xcc trailing padding. And while I could get this into illumos and FreeBSD the processes around Mac OS X and Oracle Linux are a mystery.

I will look into shortening the bounds of the symbol. It may just be easier to revert to 0x00 padding.

CL https://golang.org/cl/24040 mentions this issue.

CL 24040 changes the padding so it lies outside the range of the function symbols. It may fix this bug. Could someone test on darwin? I don't have access to my darwin machine at the moment.

I just tested this on Darwin. With CL24040:

sudo dtrace -n 'pid$1::main.go1:' 55567
dtrace: description 'pid$1::main.go1:' matched 11 probes
CPU     ID                    FUNCTION:NAME
  0 227928                   main.go1:entry 
  0 227929                       main.go1:0 
  0 227927                  main.go1:return 
  0 227928                   main.go1:entry 
  0 227929                       main.go1:0 
  0 227927                  main.go1:return 
  0 227928                   main.go1:entry 
  0 227929                       main.go1:0 
  0 227927                  main.go1:return 
  0 227928                   main.go1:entry 
  0 227929                       main.go1:0 

without:

sudo dtrace -n 'pid$1::main.go1:' 55623
dtrace: description 'pid$1::main.go1:' matched 1 probe
CPU     ID                    FUNCTION:NAME
  0   3186                   main.go1:entry 
  0   3186                   main.go1:entry 
  0   3186                   main.go1:entry 
  0   3186                   main.go1:entry 
  0   3186                   main.go1:entry 

So, happy?

Yes, thanks.