runtime/pprof: support OS X CPU profiling

Work around profiling kernel bug with signal masks.
Still broken on 64-bit Snow Leopard kernel,
but I think we can ignore that one and let people
upgrade to Lion.

Add new trivial tools addr2line and objdump to take
the place of the GNU tools of the same name, since
those are not installed on OS X.

Adapt pprof to invoke 'go tool addr2line' and
'go tool objdump' if the system tools do not exist.

Clean up disassembly of base register on amd64.

Fixes #2008.

R=golang-dev, bradfitz, mikioh.mikioh, r, iant
CC=golang-dev
https://golang.org/cl/5697066

misc/pprof

@@ -1234,6 +1234,13 @@ sub Disassemble {
   my $cmd = sprintf("$objdump -C -d -l --no-show-raw-insn " .
                     "--start-address=0x$start_addr " .
                     "--stop-address=0x$end_addr $prog");
+
+  if (system("$objdump --help >/dev/null 2>&1") != 0) {
+    # objdump must not exist.  Fall back to go tool objdump.
+    $objdump = "go tool objdump";
+    $cmd = "$objdump $prog 0x$start_addr 0x$end_addr";
+  }
+
   open(OBJDUMP, "$cmd |") || error("$objdump: $!\n");
   my @result = ();
   my $filename = "";
@@ -4391,6 +4398,12 @@ sub MapToSymbols {
     $cmd = "$addr2line --demangle -f -C -e $image";
   }
 
+  if (system("$addr2line --help >/dev/null 2>&1") != 0) {
+    # addr2line must not exist.  Fall back to go tool addr2line.
+    $addr2line = "go tool addr2line";
+    $cmd = "$addr2line $image";
+  }
+
   # If "addr2line" isn't installed on the system at all, just use
   # nm to get what info we can (function names, but not line numbers).
   if (system("$addr2line --help >/dev/null 2>&1") != 0) {
@@ -4434,7 +4447,7 @@ sub MapToSymbols {
   if ($debug) {
     print("----\n");
     system("cat $main::tmpfile_sym");
-    print("----\n");
+    print("---- $cmd\n");
     system("$cmd <$main::tmpfile_sym");
     print("----\n");
   }
@@ -4544,7 +4557,7 @@ sub ShortFunctionName {
 # Trim overly long symbols found in disassembler output
 sub CleanDisassembly {
   my $d = shift;
-  while ($d =~ s/(?<!\.)\([^()%]*\)(\s*const)?//g) { } # Argument types, not (%rax)
+  while ($d =~ s/(?<!\.)\([^()%A-Z]*\)(\s*const)?//g) { } # Argument types, not (%rax)
   while ($d =~ s/(\w+)<[^<>]*>/$1/g)  { }       # Remove template arguments
   return $d;
 }

src/cmd/addr2line/main.c

@@ -0,0 +1,68 @@
+// Copyright 2012 The Go Authors. All rights reserved.
+// Use of this source code is governed by a BSD-style
+// license that can be found in the LICENSE file.
+
+/*
+ * addr2line simulation - only enough to make pprof work on Macs
+ */
+
+#include <u.h>
+#include <libc.h>
+#include <bio.h>
+#include <mach.h>
+
+void
+usage(void)
+{
+	fprint(2, "usage: addr2line binary\n");
+	fprint(2, "reads addresses from standard input and writes two lines for each:\n");
+	fprint(2, "\tfunction name\n");
+	fprint(2, "\tfile:line\n");
+	exits("usage");
+}
+
+void
+main(int argc, char **argv)
+{
+	int fd;
+	char *p;
+	uvlong pc;
+	Symbol s;
+	Fhdr fhdr;
+	Biobuf bin, bout;
+	char file[1024];
+
+	ARGBEGIN{
+	default:
+		usage();
+	}ARGEND
+
+	if(argc != 1)
+		usage();
+
+	fd = open(argv[0], OREAD);
+	if(fd < 0)
+		sysfatal("open %s: %r", argv[0]);
+	if(crackhdr(fd, &fhdr) <= 0)
+		sysfatal("crackhdr: %r");
+	machbytype(fhdr.type);
+	if(syminit(fd, &fhdr) <= 0)
+		sysfatal("syminit: %r");
+
+	Binit(&bin, 0, OREAD);
+	Binit(&bout, 1, OWRITE);
+	for(;;) {
+		p = Brdline(&bin, '\n');
+		if(p == nil)
+			break;
+		p[Blinelen(&bin)-1] = '\0';
+		pc = strtoull(p, 0, 16);
+		if(!findsym(pc, CTEXT, &s))
+			s.name = "??";
+		if(!fileline(file, sizeof file, pc))
+			strcpy(file, "??:0");
+		Bprint(&bout, "%s\n%s\n", s.name, file);
+	}
+	Bflush(&bout);
+	exits(0);
+}

src/cmd/dist/build.c

@@ -1073,8 +1073,10 @@ static char *buildorder[] = {
 
 	"misc/pprof",
 
+	"cmd/addr2line",
 	"cmd/cov",
 	"cmd/nm",
+	"cmd/objdump",
 	"cmd/pack",
 	"cmd/prof",
 
@@ -1122,12 +1124,12 @@ static char *buildorder[] = {
 	"pkg/go/scanner",
 	"pkg/go/ast",
 	"pkg/go/parser",
-	"pkg/go/build",
 	"pkg/os/exec",
 	"pkg/net/url",
 	"pkg/text/template/parse",
 	"pkg/text/template",
 	"pkg/go/doc",
+	"pkg/go/build",
 	"cmd/go",
 };
 
@@ -1147,11 +1149,13 @@ static char *cleantab[] = {
 	"cmd/8c",
 	"cmd/8g",
 	"cmd/8l",
+	"cmd/addr2line",
 	"cmd/cc",
 	"cmd/cov",
 	"cmd/gc",
 	"cmd/go",
 	"cmd/nm",
+	"cmd/objdump",
 	"cmd/pack",
 	"cmd/prof",
 	"lib9",

src/cmd/objdump/main.c

@@ -0,0 +1,68 @@
+// Copyright 2012 The Go Authors. All rights reserved.
+// Use of this source code is governed by a BSD-style
+// license that can be found in the LICENSE file.
+
+/*
+ * objdump simulation - only enough to make pprof work on Macs
+ */
+
+#include <u.h>
+#include <libc.h>
+#include <bio.h>
+#include <mach.h>
+
+void
+usage(void)
+{
+	fprint(2, "usage: objdump binary start stop\n");
+	fprint(2, "Disassembles binary from PC start up to stop.\n");
+	exits("usage");
+}
+
+void
+main(int argc, char **argv)
+{
+	int fd, n;
+	uvlong pc, start, stop;
+	Fhdr fhdr;
+	Biobuf bout;
+	char buf[1024];
+	Map *text;
+
+	ARGBEGIN{
+	default:
+		usage();
+	}ARGEND
+
+	if(argc != 3)
+		usage();
+	start = strtoull(argv[1], 0, 16);
+	stop = strtoull(argv[2], 0, 16);
+
+	fd = open(argv[0], OREAD);
+	if(fd < 0)
+		sysfatal("open %s: %r", argv[0]);
+	if(crackhdr(fd, &fhdr) <= 0)
+		sysfatal("crackhdr: %r");
+	machbytype(fhdr.type);
+	if(syminit(fd, &fhdr) <= 0)
+		sysfatal("syminit: %r");
+	text = loadmap(nil, fd, &fhdr);
+	if(text == nil)
+		sysfatal("loadmap: %r");
+
+	Binit(&bout, 1, OWRITE);
+	for(pc=start; pc<stop; ) {
+		if(fileline(buf, sizeof buf, pc))
+			Bprint(&bout, "%s\n", buf);
+		buf[0] = '\0';
+		machdata->das(text, pc, 0, buf, sizeof buf);
+		Bprint(&bout, " %llx: %s\n", pc, buf);
+		n = machdata->instsize(text, pc);
+		if(n <= 0)
+			break;
+		pc += n;
+	}
+	Bflush(&bout);
+	exits(0);
+}

src/libmach/8db.c

@@ -2088,18 +2088,23 @@ immediate(Instr *ip, vlong val)
 static void
 pea(Instr *ip)
 {
+	int base;
+
+	base = ip->base;
+	if(base >= 0 && (ip->rex & REXB))
+		base += 8;
+
 	if (ip->mod == 3) {
 		if (ip->osize == 'B')
 			bprint(ip, (ip->rex & REXB? breg64: breg)[(uchar)ip->base]);
-		else if(ip->rex & REXB)
-			bprint(ip, "%s%s", ANAME(ip), reg[ip->base+8]);
 		else
-			bprint(ip, "%s%s", ANAME(ip), reg[(uchar)ip->base]);
+			bprint(ip, "%s%s", ANAME(ip), reg[base]);
 		return;
 	}
+
 	if (ip->segment)
 		bprint(ip, ip->segment);
-	if (ip->asize == 'E' && ip->base == SP)
+	if (ip->asize == 'E' && base == SP)
 		plocal(ip);
 	else {
 		if (ip->base < 0)

src/pkg/runtime/lock_futex.c

@@ -118,8 +118,12 @@ runtime·notewakeup(Note *n)
 void
 runtime·notesleep(Note *n)
 {
+	if(m->profilehz > 0)
+		runtime·setprof(false);
 	while(runtime·atomicload(&n->key) == 0)
 		runtime·futexsleep(&n->key, 0, -1);
+	if(m->profilehz > 0)
+		runtime·setprof(true);
 }
 
 void
@@ -135,14 +139,18 @@ runtime·notetsleep(Note *n, int64 ns)
 	if(runtime·atomicload(&n->key) != 0)
 		return;
 
+	if(m->profilehz > 0)
+		runtime·setprof(false);
 	deadline = runtime·nanotime() + ns;
 	for(;;) {
 		runtime·futexsleep(&n->key, 0, ns);
 		if(runtime·atomicload(&n->key) != 0)
-			return;
+			break;
 		now = runtime·nanotime();
 		if(now >= deadline)
-			return;
+			break;
 		ns = deadline - now;
 	}
+	if(m->profilehz > 0)
+		runtime·setprof(true);
 }

src/pkg/runtime/lock_sema.c

@@ -154,7 +154,11 @@ runtime·notesleep(Note *n)
 		return;
 	}
 	// Queued.  Sleep.
+	if(m->profilehz > 0)
+		runtime·setprof(false);
 	runtime·semasleep(-1);
+	if(m->profilehz > 0)
+		runtime·setprof(true);
 }
 
 void
@@ -178,12 +182,16 @@ runtime·notetsleep(Note *n, int64 ns)
 		return;
 	}
 
+	if(m->profilehz > 0)
+		runtime·setprof(false);
 	deadline = runtime·nanotime() + ns;
 	for(;;) {
 		// Registered.  Sleep.
 		if(runtime·semasleep(ns) >= 0) {
 			// Acquired semaphore, semawakeup unregistered us.
 			// Done.
+			if(m->profilehz > 0)
+				runtime·setprof(true);
 			return;
 		}
 
@@ -196,6 +204,9 @@ runtime·notetsleep(Note *n, int64 ns)
 		ns = deadline - now;
 	}
 
+	if(m->profilehz > 0)
+		runtime·setprof(true);
+
 	// Deadline arrived.  Still registered.  Semaphore not acquired.
 	// Want to give up and return, but have to unregister first,
 	// so that any notewakeup racing with the return does not

src/pkg/runtime/os_darwin.h

@@ -38,4 +38,7 @@ void	runtime·raisesigpipe(void);
 
 #define	NSIG 32
 #define	SI_USER	0  /* empirically true, but not what headers say */
+#define	SIG_BLOCK 1
+#define	SIG_UNBLOCK 2
 #define	SIG_SETMASK 3
+

src/pkg/runtime/os_freebsd.h

@@ -9,7 +9,6 @@ struct	sigaction;
 void	runtime·sigaction(int32, struct sigaction*, struct sigaction*);
 void	runtime·sigprocmask(Sigset *, Sigset *);
 void	runtime·setsig(int32, void(*)(int32, Siginfo*, void*, G*), bool);
-void	runtiem·setitimerval(int32, Itimerval*, Itimerval*);
 void	runtime·setitimer(int32, Itimerval*, Itimerval*);
 int32	runtime·sysctl(uint32*, uint32, byte*, uintptr*, byte*, uintptr);
 

src/pkg/runtime/os_netbsd.h

@@ -12,7 +12,6 @@ void	runtime·sigaltstack(Sigaltstack*, Sigaltstack*);
 void	runtime·sigaction(int32, struct sigaction*, struct sigaction*);
 void	runtime·setsig(int32, void(*)(int32, Siginfo*, void*, G*), bool);
 void	runtime·sighandler(int32 sig, Siginfo *info, void *context, G *gp);
-void	runtime·setitimerval(int32, Itimerval*, Itimerval*);
 void	runtime·setitimer(int32, Itimerval*, Itimerval*);
 int32	runtime·sysctl(uint32*, uint32, byte*, uintptr*, byte*, uintptr);
 

src/pkg/runtime/os_openbsd.h

@@ -12,7 +12,6 @@ void	runtime·sigaltstack(Sigaltstack*, Sigaltstack*);
 void	runtime·sigaction(int32, struct sigaction*, struct sigaction*);
 void	runtime·setsig(int32, void(*)(int32, Siginfo*, void*, G*), bool);
 void	runtime·sighandler(int32 sig, Siginfo *info, void *context, G *gp);
-void	runtime·setitimerval(int32, Itimerval*, Itimerval*);
 void	runtime·setitimer(int32, Itimerval*, Itimerval*);
 int32	runtime·sysctl(uint32*, uint32, byte*, uintptr*, byte*, uintptr);
 

src/pkg/runtime/pprof/pprof.go

@@ -20,8 +20,8 @@ import (
 	"text/tabwriter"
 )
 
-// BUG(rsc): CPU profiling is broken on OS X, due to an Apple kernel bug.
-// For details, see http://code.google.com/p/go/source/detail?r=35b716c94225.
+// BUG(rsc): A bug in the OS X Snow Leopard 64-bit kernel prevents
+// CPU profiling from giving accurate results on that system.
 
 // A Profile is a collection of stack traces showing the call sequences
 // that led to instances of a particular event, such as allocation.

src/pkg/runtime/pprof/pprof_test.go

@@ -7,6 +7,7 @@ package pprof_test
 import (
 	"bytes"
 	"hash/crc32"
+	"os/exec"
 	"runtime"
 	. "runtime/pprof"
 	"strings"
@@ -17,8 +18,15 @@ import (
 func TestCPUProfile(t *testing.T) {
 	switch runtime.GOOS {
 	case "darwin":
-		// see Apple Bug Report #9177434 (copied into change description)
-		return
+		out, err := exec.Command("uname", "-a").CombinedOutput()
+		if err != nil {
+			t.Fatal(err)
+		}
+		vers := string(out)
+		t.Logf("uname -a: %v", vers)
+		if strings.Contains(vers, "Darwin Kernel Version 10.8.0") && strings.Contains(vers, "root:xnu-1504.15.3~1/RELEASE_X86_64") {
+			t.Logf("skipping test on known-broken kernel (64-bit Snow Leopard)")
+		}
 	case "plan9":
 		// unimplemented
 		return

src/pkg/runtime/proc.c

@@ -728,7 +728,6 @@ runtime·mstart(void)
 	// so other calls can reuse this stack space.
 	runtime·gosave(&m->g0->sched);
 	m->g0->sched.pc = (void*)-1;  // make sure it is never used
-
 	runtime·asminit();
 	runtime·minit();
 	schedule(nil);
@@ -916,6 +915,9 @@ runtime·entersyscall(void)
 {
 	uint32 v;
 
+	if(m->profilehz > 0)
+		runtime·setprof(false);
+
 	// Leave SP around for gc and traceback.
 	runtime·gosave(&g->sched);
 	g->gcsp = g->sched.sp;
@@ -979,6 +981,9 @@ runtime·exitsyscall(void)
 		// Garbage collector isn't running (since we are),
 		// so okay to clear gcstack.
 		g->gcstack = nil;
+
+		if(m->profilehz > 0)
+			runtime·setprof(true);
 		return;
 	}
 

src/pkg/runtime/runtime.h

@@ -730,3 +730,13 @@ bool	runtime·showframe(Func*);
 void	runtime·ifaceE2I(struct InterfaceType*, Eface, Iface*);
 
 uintptr	runtime·memlimit(void);
+
+// If appropriate, ask the operating system to control whether this
+// thread should receive profiling signals.  This is only necessary on OS X.
+// An operating system should not deliver a profiling signal to a
+// thread that is not actually executing (what good is that?), but that's
+// what OS X prefers to do.  When profiling is turned on, we mask
+// away the profiling signal when threads go to sleep, so that OS X
+// is forced to deliver the signal to a thread that's actually running.
+// This is a no-op on other systems.
+void	runtime·setprof(bool);

src/pkg/runtime/signal_darwin_386.c

@@ -40,6 +40,7 @@ runtime·sighandler(int32 sig, Siginfo *info, void *context, G *gp)
 	r = &mc->ss;
 
 	if(sig == SIGPROF) {
+		if(gp != m->g0 && gp != m->gsignal)
 			runtime·sigprof((uint8*)r->eip, (uint8*)r->esp, nil, gp);
 		return;
 	}

src/pkg/runtime/signal_darwin_amd64.c

@@ -48,6 +48,7 @@ runtime·sighandler(int32 sig, Siginfo *info, void *context, G *gp)
 	r = &mc->ss;
 
 	if(sig == SIGPROF) {
+		if(gp != m->g0 && gp != m->gsignal)
 			runtime·sigprof((uint8*)r->rip, (uint8*)r->rsp, nil, gp);
 		return;
 	}

src/pkg/runtime/signal_unix.c

@@ -59,13 +59,13 @@ runtime·resetcpuprofiler(int32 hz)
 	runtime·memclr((byte*)&it, sizeof it);
 	if(hz == 0) {
 		runtime·setitimer(ITIMER_PROF, &it, nil);
-		runtime·setsig(SIGPROF, SIG_IGN, true);
+		runtime·setprof(false);
 	} else {
-		runtime·setsig(SIGPROF, runtime·sighandler, true);
 		it.it_interval.tv_sec = 0;
 		it.it_interval.tv_usec = 1000000 / hz;
 		it.it_value = it.it_interval;
 		runtime·setitimer(ITIMER_PROF, &it, nil);
+		runtime·setprof(true);
 	}
 	m->profilehz = hz;
 }

src/pkg/runtime/sys_darwin_386.s

@@ -107,7 +107,7 @@ TEXT runtime·nanotime(SB), 7, $32
 	RET
 
 TEXT runtime·sigprocmask(SB),7,$0
-	MOVL	$48, AX
+	MOVL	$329, AX  // pthread_sigmask (on OS X, sigprocmask==entire process)
 	INT	$0x80
 	JAE	2(PC)
 	CALL	runtime·notok(SB)

src/pkg/runtime/sys_darwin_amd64.s

@@ -96,7 +96,7 @@ TEXT runtime·sigprocmask(SB),7,$0
 	MOVL	8(SP), DI
 	MOVQ	16(SP), SI
 	MOVQ	24(SP), DX
-	MOVL	$(0x2000000+48), AX	// syscall entry
+	MOVL	$(0x2000000+329), AX  // pthread_sigmask (on OS X, sigprocmask==entire process)
 	SYSCALL
 	JCC	2(PC)
 	CALL	runtime·notok(SB)

src/pkg/runtime/thread_darwin.c

@@ -11,6 +11,7 @@ extern SigTab runtime·sigtab[];
 
 static Sigset sigset_all = ~(Sigset)0;
 static Sigset sigset_none;
+static Sigset sigset_prof = 1<<(SIGPROF-1);
 
 static void
 unimplemented(int8 *name)
@@ -23,7 +24,14 @@ unimplemented(int8 *name)
 int32
 runtime·semasleep(int64 ns)
 {
-	return runtime·mach_semacquire(m->waitsema, ns);
+	int32 v;
+
+	if(m->profilehz > 0)
+		runtime·setprof(false);
+	v = runtime·mach_semacquire(m->waitsema, ns);
+	if(m->profilehz > 0)
+		runtime·setprof(true);
+	return v;
 }
 
 void
@@ -98,7 +106,11 @@ runtime·minit(void)
 	// Initialize signal handling.
 	m->gsignal = runtime·malg(32*1024);	// OS X wants >=8K, Linux >=2K
 	runtime·signalstack(m->gsignal->stackguard - StackGuard, 32*1024);
+
+	if(m->profilehz > 0)
 		runtime·sigprocmask(SIG_SETMASK, &sigset_none, nil);
+	else
+		runtime·sigprocmask(SIG_SETMASK, &sigset_prof, nil);
 }
 
 // Mach IPC, to get at semaphores
@@ -434,3 +446,34 @@ runtime·memlimit(void)
 	// the limit.
 	return 0;
 }
+
+// NOTE(rsc): On OS X, when the CPU profiling timer expires, the SIGPROF
+// signal is not guaranteed to be sent to the thread that was executing to
+// cause it to expire.  It can and often does go to a sleeping thread, which is
+// not interesting for our profile.  This is filed Apple Bug Report #9177434,
+// copied to http://code.google.com/p/go/source/detail?r=35b716c94225.
+// To work around this bug, we disable receipt of the profiling signal on
+// a thread while in blocking system calls.  This forces the kernel to deliver
+// the profiling signal to an executing thread.
+//
+// The workaround fails on OS X machines using a 64-bit Snow Leopard kernel.
+// In that configuration, the kernel appears to want to deliver SIGPROF to the
+// sleeping threads regardless of signal mask and, worse, does not deliver
+// the signal until the thread wakes up on its own.
+//
+// If necessary, we can switch to using ITIMER_REAL for OS X and handle
+// the kernel-generated SIGALRM by generating our own SIGALRMs to deliver
+// to all the running threads.  SIGALRM does not appear to be affected by
+// the 64-bit Snow Leopard bug.  However, as of this writing Mountain Lion
+// is in preview, making Snow Leopard two versions old, so it is unclear how
+// much effort we need to spend on one buggy kernel.
+
+// Control whether profiling signal can be delivered to this thread.
+void
+runtime·setprof(bool on)
+{
+	if(on)
+		runtime·sigprocmask(SIG_UNBLOCK, &sigset_prof, nil);
+	else
+		runtime·sigprocmask(SIG_BLOCK, &sigset_prof, nil);
+}

src/pkg/runtime/thread_freebsd.c

@@ -189,3 +189,9 @@ runtime·memlimit(void)
 
 	return rl.rlim_cur - used;
 }
+
+void
+runtime·setprof(bool on)
+{
+	USED(on);
+}

src/pkg/runtime/thread_linux.c

@@ -249,3 +249,9 @@ runtime·memlimit(void)
 
 	return rl.rlim_cur - used;
 }
+
+void
+runtime·setprof(bool on)
+{
+	USED(on);
+}

src/pkg/runtime/thread_netbsd.c

@@ -207,3 +207,9 @@ runtime·memlimit(void)
 {
 	return 0;
 }
+
+void
+runtime·setprof(bool on)
+{
+	USED(on);
+}

src/pkg/runtime/thread_openbsd.c

@@ -207,3 +207,9 @@ runtime·memlimit(void)
 {
 	return 0;
 }
+
+void
+runtime·setprof(bool on)
+{
+	USED(on);
+}

src/pkg/runtime/thread_plan9.c

@@ -241,3 +241,9 @@ runtime·memlimit(void)
 {
 	return 0;
 }
+
+void
+runtime·setprof(bool on)
+{
+	USED(on);
+}

src/pkg/runtime/thread_windows.c

@@ -431,3 +431,9 @@ runtime·memlimit(void)
 {
 	return 0;
 }
+
+void
+runtime·setprof(bool on)
+{
+	USED(on);
+}