service/dap: allow expression evaluation in log messages (#2747)

From the DAP spec:

If this attribute exists and is non-empty, the backend must not 'break' (stop) but log the message instead.
Expressions within {} are interpolated.
This change parses the log messages and stores the parsed values as a format string and list of expressions to evaluate and get the string value of.

Updates golang/vscode-go#123

service/dap/server.go

@@ -1355,9 +1355,10 @@ func (s *Session) setBreakpoints(prefix string, totalBps int, metadataFunc func(
 		} else {
 			got.Cond = want.condition
 			got.HitCond = want.hitCondition
-			got.Tracepoint = want.logMessage != ""
+			err = setLogMessage(got, want.logMessage)
-			got.UserData = want.logMessage
+			if err == nil {
-			err = s.debugger.AmendBreakpoint(got)
+				err = s.debugger.AmendBreakpoint(got)
+			}
 		}
 		createdBps[want.name] = struct{}{}
 		s.updateBreakpointsResponse(breakpoints, i, err, got)
@@ -1380,19 +1381,20 @@ func (s *Session) setBreakpoints(prefix string, totalBps int, metadataFunc func(
 			if _, ok := createdBps[want.name]; ok {
 				err = fmt.Errorf("breakpoint already exists")
 			} else {
-				// Create new breakpoints.
+				bp := &api.Breakpoint{
-				got, err = s.debugger.CreateBreakpoint(
+					Name:    want.name,
-					&api.Breakpoint{
+					File:    wantLoc.file,
-						Name:       want.name,
+					Line:    wantLoc.line,
-						File:       wantLoc.file,
+					Addr:    wantLoc.addr,
-						Line:       wantLoc.line,
+					Addrs:   wantLoc.addrs,
-						Addr:       wantLoc.addr,
+					Cond:    want.condition,
-						Addrs:      wantLoc.addrs,
+					HitCond: want.hitCondition,
-						Cond:       want.condition,
+				}
-						HitCond:    want.hitCondition,
+				err = setLogMessage(bp, want.logMessage)
-						Tracepoint: want.logMessage != "",
+				if err == nil {
-						UserData:   want.logMessage,
+					// Create new breakpoints.
-					})
+					got, err = s.debugger.CreateBreakpoint(bp)
+				}
 			}
 		}
 		createdBps[want.name] = struct{}{}
@@ -1401,6 +1403,18 @@ func (s *Session) setBreakpoints(prefix string, totalBps int, metadataFunc func(
 	return breakpoints
 }
 
+func setLogMessage(bp *api.Breakpoint, msg string) error {
+	tracepoint, userdata, err := parseLogPoint(msg)
+	if err != nil {
+		return err
+	}
+	bp.Tracepoint = tracepoint
+	if userdata != nil {
+		bp.UserData = *userdata
+	}
+	return nil
+}
+
 func (s *Session) updateBreakpointsResponse(breakpoints []dap.Breakpoint, i int, err error, got *api.Breakpoint) {
 	breakpoints[i].Verified = (err == nil)
 	if err != nil {
@@ -3601,8 +3615,8 @@ func (s *Session) logBreakpointMessage(bp *api.Breakpoint, goid int) bool {
 	if !bp.Tracepoint {
 		return false
 	}
-	// TODO(suzmue): allow evaluate expressions within log points.
+	if lMsg, ok := bp.UserData.(logMessage); ok {
-	if msg, ok := bp.UserData.(string); ok {
+		msg := lMsg.evaluate(s, goid)
 		s.send(&dap.OutputEvent{
 			Event: *newEvent("output"),
 			Body: dap.OutputEventBody{
@@ -3618,6 +3632,19 @@ func (s *Session) logBreakpointMessage(bp *api.Breakpoint, goid int) bool {
 	return true
 }
 
+func (msg *logMessage) evaluate(s *Session, goid int) string {
+	evaluated := make([]interface{}, len(msg.args))
+	for i := range msg.args {
+		exprVar, err := s.debugger.EvalVariableInScope(goid, 0, 0, msg.args[i], DefaultLoadConfig)
+		if err != nil {
+			evaluated[i] = fmt.Sprintf("{eval err: %e}", err)
+			continue
+		}
+		evaluated[i] = s.convertVariableToString(exprVar)
+	}
+	return fmt.Sprintf(msg.format, evaluated...)
+}
+
 func (s *Session) toClientPath(path string) string {
 	if len(s.args.substitutePathServerToClient) == 0 {
 		return path
@@ -3639,3 +3666,64 @@ func (s *Session) toServerPath(path string) string {
 	}
 	return serverPath
 }
+
+type logMessage struct {
+	format string
+	args   []string
+}
+
+// parseLogPoint parses a log message according to the DAP spec:
+//   "Expressions within {} are interpolated."
+func parseLogPoint(msg string) (bool, *logMessage, error) {
+	// Note: All braces *must* come in pairs, even those within an
+	// expression to be interpolated.
+	// TODO(suzmue): support individual braces in string values in
+	// eval expressions.
+	var args []string
+
+	var isArg bool
+	var formatSlice, argSlice []rune
+	braceCount := 0
+	for _, r := range msg {
+		if isArg {
+			switch r {
+			case '}':
+				if braceCount--; braceCount == 0 {
+					argStr := strings.TrimSpace(string(argSlice))
+					if len(argStr) == 0 {
+						return false, nil, fmt.Errorf("empty evaluation string")
+					}
+					args = append(args, argStr)
+					formatSlice = append(formatSlice, '%', 's')
+					isArg = false
+					continue
+				}
+			case '{':
+				braceCount += 1
+			}
+			argSlice = append(argSlice, r)
+			continue
+		}
+
+		switch r {
+		case '}':
+			return false, nil, fmt.Errorf("invalid log point format, unexpected '}'")
+		case '{':
+			if braceCount++; braceCount == 1 {
+				isArg, argSlice = true, []rune{}
+				continue
+			}
+		}
+		formatSlice = append(formatSlice, r)
+	}
+	if isArg {
+		return false, nil, fmt.Errorf("invalid log point format")
+	}
+	if len(formatSlice) == 0 {
+		return false, nil, nil
+	}
+	return true, &logMessage{
+		format: string(formatSlice),
+		args:   args,
+	}, nil
+}

service/dap/server_test.go

@@ -3126,7 +3126,7 @@ func TestLogPoints(t *testing.T) {
 				execute: func() {
 					checkStop(t, client, 1, "main.main", 23)
 					bps := []int{6, 25, 27, 16}
-					logMessages := map[int]string{6: "in callme!", 16: "in callme2!"}
+					logMessages := map[int]string{6: "{i*2}: in callme!", 16: "in callme2!"}
 					client.SetBreakpointsRequestWithArgs(fixture.Source, bps, nil, nil, logMessages)
 					client.ExpectSetBreakpointsResponse(t)
 
@@ -3142,7 +3142,7 @@ func TestLogPoints(t *testing.T) {
 
 						client.ContinueRequest(1)
 						client.ExpectContinueResponse(t)
-						checkLogMessage(t, client.ExpectOutputEvent(t), 1, "in callme!", fixture.Source, 6)
+						checkLogMessage(t, client.ExpectOutputEvent(t), 1, fmt.Sprintf("%d: in callme!", i*2), fixture.Source, 6)
 					}
 					se := client.ExpectStoppedEvent(t)
 					if se.Body.Reason != "breakpoint" || se.Body.ThreadId != 1 {
@@ -6528,6 +6528,83 @@ func TestBadlyFormattedMessageToServer(t *testing.T) {
 	})
 }
 
+func TestParseLogPoint(t *testing.T) {
+	tests := []struct {
+		name           string
+		msg            string
+		wantTracepoint bool
+		wantFormat     string
+		wantArgs       []string
+		wantErr        bool
+	}{
+		// Test simple log messages.
+		{name: "simple string", msg: "hello, world!", wantTracepoint: true, wantFormat: "hello, world!"},
+		{name: "empty string", msg: "", wantTracepoint: false, wantErr: false},
+		// Test parse eval expressions.
+		{
+			name:           "simple eval",
+			msg:            "{x}",
+			wantTracepoint: true,
+			wantFormat:     "%s",
+			wantArgs:       []string{"x"},
+		},
+		{
+			name:           "type cast",
+			msg:            "hello {string(x)}",
+			wantTracepoint: true,
+			wantFormat:     "hello %s",
+			wantArgs:       []string{"string(x)"},
+		},
+		{
+			name:           "multiple eval",
+			msg:            "{x} {y} {z}",
+			wantTracepoint: true,
+			wantFormat:     "%s %s %s",
+			wantArgs:       []string{"x", "y", "z"},
+		},
+		{
+			name:           "eval expressions contain braces",
+			msg:            "{interface{}(x)} {myType{y}} {[]myType{{z}}}",
+			wantTracepoint: true,
+			wantFormat:     "%s %s %s",
+			wantArgs:       []string{"interface{}(x)", "myType{y}", "[]myType{{z}}"},
+		},
+		// Test parse errors.
+		{name: "empty evaluation", msg: "{}", wantErr: true},
+		{name: "empty space evaluation", msg: "{   \n}", wantErr: true},
+		{name: "open brace missing closed", msg: "{", wantErr: true},
+		{name: "closed brace missing open", msg: "}", wantErr: true},
+		{name: "open brace in expression", msg: `{m["{"]}`, wantErr: true},
+		{name: "closed brace in expression", msg: `{m["}"]}`, wantErr: true},
+	}
+	for _, tt := range tests {
+		t.Run(tt.name, func(t *testing.T) {
+			gotTracepoint, gotLogMessage, err := parseLogPoint(tt.msg)
+			if gotTracepoint != tt.wantTracepoint {
+				t.Errorf("parseLogPoint() tracepoint = %v, wantTracepoint %v", gotTracepoint, tt.wantTracepoint)
+				return
+			}
+			if (err != nil) != tt.wantErr {
+				t.Errorf("parseLogPoint() error = %v, wantErr %v", err, tt.wantErr)
+				return
+			}
+			if !tt.wantTracepoint {
+				return
+			}
+			if gotLogMessage == nil {
+				t.Errorf("parseLogPoint() gotLogMessage = nil, want log message")
+				return
+			}
+			if gotLogMessage.format != tt.wantFormat {
+				t.Errorf("parseLogPoint() gotFormat = %v, want %v", gotLogMessage.format, tt.wantFormat)
+			}
+			if !reflect.DeepEqual(gotLogMessage.args, tt.wantArgs) {
+				t.Errorf("parseLogPoint() gotArgs = %v, want %v", gotLogMessage.args, tt.wantArgs)
+			}
+		})
+	}
+}
+
 func TestDisassemble(t *testing.T) {
 	runTest(t, "increment", func(client *daptest.Client, fixture protest.Fixture) {
 		runDebugSessionWithBPs(t, client, "launch",