:* Improve trace subcommand output (#3091)

This patch improves the output of the trace subcommand by
adding better line breaks, adding goroutine info to the
return statement, and removing unnecessary output.

_fixtures/goroutines-trace.go

@@ -0,0 +1,32 @@
+package main
+
+import (
+	"fmt"
+	"sync"
+)
+
+func callme(i int, s string) int {
+	fmt.Println(s)
+	return i * i
+}
+
+func dostuff(wg *sync.WaitGroup, lbl string) {
+	defer wg.Done()
+	var j int
+	for i := 0; i < 10; i++ {
+		j += callme(i, lbl)
+	}
+	println(lbl, j)
+}
+
+func main() {
+	var wg sync.WaitGroup
+
+	for _, lbl := range []string{"one", "two", "three", "four", "five"} {
+		for i := 0; i < 10; i++ {
+			wg.Add(1)
+			go dostuff(&wg, lbl)
+		}
+	}
+	wg.Wait()
+}

cmd/dlv/cmds/commands.go

@@ -685,6 +685,7 @@ func traceCmd(cmd *cobra.Command, args []string) {
 		}
 		cmds := terminal.DebugCommands(client)
 		t := terminal.New(client, nil)
+		t.SetTraceNonInteractive()
 		t.RedirectTo(os.Stderr)
 		defer t.Close()
 		if traceUseEBPF {
@@ -724,7 +725,11 @@ func traceCmd(cmd *cobra.Command, args []string) {
 				}
 			}()
 		}
-		cmds.Call("continue", t)
+		err = cmds.Call("continue", t)
+		if err != nil {
+			fmt.Fprintln(os.Stderr, err)
+			return 1
+		}
 		return 0
 	}()
 	os.Exit(status)

cmd/dlv/dlv_test.go

@@ -993,7 +993,7 @@ func TestTrace(t *testing.T) {
 	dlvbin, tmpdir := getDlvBin(t)
 	defer os.RemoveAll(tmpdir)
 
-	expected := []byte("> goroutine(1): main.foo(99, 9801) => (9900)\n")
+	expected := []byte("> goroutine(1): main.foo(99, 9801)\n>> goroutine(1): => (9900)\n")
 
 	fixtures := protest.FindFixturesDir()
 	cmd := exec.Command(dlvbin, "trace", "--output", filepath.Join(tmpdir, "__debug"), filepath.Join(fixtures, "issue573.go"), "foo")
@@ -1014,6 +1014,38 @@ func TestTrace(t *testing.T) {
 	cmd.Wait()
 }
 
+func TestTraceMultipleGoroutines(t *testing.T) {
+	dlvbin, tmpdir := getDlvBin(t)
+	defer os.RemoveAll(tmpdir)
+
+	// TODO(derekparker) this test has to be a bit vague to avoid flakyness.
+	// I think a future improvement could be to use regexp captures to match the
+	// goroutine IDs at function entry and exit.
+	expected := []byte("main.callme(0, \"five\")\n")
+	expected2 := []byte("=> (0)\n")
+
+	fixtures := protest.FindFixturesDir()
+	cmd := exec.Command(dlvbin, "trace", "--output", filepath.Join(tmpdir, "__debug"), filepath.Join(fixtures, "goroutines-trace.go"), "callme")
+	rdr, err := cmd.StderrPipe()
+	assertNoError(err, t, "stderr pipe")
+	defer rdr.Close()
+
+	cmd.Dir = filepath.Join(fixtures, "buildtest")
+
+	assertNoError(cmd.Start(), t, "running trace")
+
+	output, err := ioutil.ReadAll(rdr)
+	assertNoError(err, t, "ReadAll")
+
+	if !bytes.Contains(output, expected) {
+		t.Fatalf("expected:\n%s\ngot:\n%s", string(expected), string(output))
+	}
+	if !bytes.Contains(output, expected2) {
+		t.Fatalf("expected:\n%s\ngot:\n%s", string(expected), string(output))
+	}
+	cmd.Wait()
+}
+
 func TestTracePid(t *testing.T) {
 	if runtime.GOOS == "linux" {
 		bs, _ := ioutil.ReadFile("/proc/sys/kernel/yama/ptrace_scope")
@@ -1026,7 +1058,7 @@ func TestTracePid(t *testing.T) {
 	dlvbin, tmpdir := getDlvBin(t)
 	defer os.RemoveAll(tmpdir)
 
-	expected := []byte("goroutine(1): main.A()\n => ()\n")
+	expected := []byte("goroutine(1): main.A()\n>> goroutine(1): => ()\n")
 
 	// make process run
 	fix := protest.BuildFixture("issue2023", 0)

pkg/proc/threads.go

@@ -2,7 +2,6 @@ package proc
 
 import (
 	"errors"
-
 	"github.com/go-delve/delve/pkg/dwarf/op"
 )
 

pkg/terminal/command.go

@@ -2469,6 +2469,17 @@ func printStack(t *Term, out io.Writer, stack []api.Stackframe, ind string, offs
 }
 
 func printcontext(t *Term, state *api.DebuggerState) {
+	if t.IsTraceNonInteractive() {
+		// If we're just running the `trace` subcommand there isn't any need
+		// to print out the rest of the state below.
+		for i := range state.Threads {
+			if state.Threads[i].Breakpoint != nil {
+				printcontextThread(t, state.Threads[i])
+			}
+		}
+		return
+	}
+
 	for i := range state.Threads {
 		if (state.CurrentThread != nil) && (state.Threads[i].ID == state.CurrentThread.ID) {
 			continue
@@ -2659,10 +2670,7 @@ func printBreakpointInfo(t *Term, th *api.Thread, tracepointOnNewline bool) {
 
 func printTracepoint(t *Term, th *api.Thread, bpname string, fn *api.Function, args string, hasReturnValue bool) {
 	if th.Breakpoint.Tracepoint {
-		fmt.Fprintf(t.stdout, "> goroutine(%d): %s%s(%s)", th.GoroutineID, bpname, fn.Name(), args)
+		fmt.Fprintf(t.stdout, "> goroutine(%d): %s%s(%s)\n", th.GoroutineID, bpname, fn.Name(), args)
-		if !hasReturnValue {
-			fmt.Fprintln(t.stdout)
-		}
 		printBreakpointInfo(t, th, !hasReturnValue)
 	}
 	if th.Breakpoint.TraceReturn {
@@ -2670,7 +2678,7 @@ func printTracepoint(t *Term, th *api.Thread, bpname string, fn *api.Function, a
 		for _, v := range th.ReturnValues {
 			retVals = append(retVals, v.SinglelineString())
 		}
-		fmt.Fprintf(t.stdout, " => (%s)\n", strings.Join(retVals, ","))
+		fmt.Fprintf(t.stdout, ">> goroutine(%d): => (%s)\n", th.GoroutineID, strings.Join(retVals, ","))
 	}
 	if th.Breakpoint.TraceReturn || !hasReturnValue {
 		if th.BreakpointInfo != nil && th.BreakpointInfo.Stacktrace != nil {

pkg/terminal/terminal.go

@@ -75,6 +75,8 @@ type Term struct {
 
 	quittingMutex sync.Mutex
 	quitting      bool
+
+	traceNonInteractive bool
 }
 
 type displayEntry struct {
@@ -140,6 +142,14 @@ func New(client service.Client, conf *config.Config) *Term {
 	return t
 }
 
+func (t *Term) SetTraceNonInteractive() {
+	t.traceNonInteractive = true
+}
+
+func (t *Term) IsTraceNonInteractive() bool {
+	return t.traceNonInteractive
+}
+
 // Close returns the terminal to its previous mode.
 func (t *Term) Close() {
 	t.line.Close()