Breakpoints added when debug session is not in a paused state, results in debug process not ending

[iamdanielyin]

Steps to Reproduce:

Every time I add a new breakpoint, the process will not be killed after restarting the debug.

macOS 10.13.6
vscode 1.28.0
vscode-go 0.6.91.

[ramya-rao-a]

Can you provide a small sample code where I can try to reproduce this issue?

[iamdanielyin]

package main

import "github.com/gin-gonic/gin"

func main() {
	r := gin.Default()
	r.GET("/", func(c *gin.Context) {
		c.String(200, "hello")
	})
	r.Run()
}

[ramya-rao-a]

I followed all the steps as in the video on the sample code, but I dont see the same error.
I am on Windows, using VS Code 1.28.2, Go version 1.11 and the latest VS Code Go extension.

Can you share your set up information? OS, VS Code version, Go version and the Go extension version.

[iamdanielyin]

I have provided version information in the first comment:

• macOS 10.13.6
• vscode 1.28.0
• vscode-go 0.6.91
• go version go1.11 darwin/amd64

[ramya-rao-a]

Thanks @yinfxs

I see this on Mac, but on Windows.
Will look into it.

[iamdanielyin]

Thanks.

[bihe]

Can confirm the exact same behavior on

• Ubuntu 18.10 x86_64
• vscode 1.28.2
• vscode-go 0.7.0
• go version go1.11 linux/amd64

The problem only occurs if one adds/removes breakpoints during a debug-session.

[mbanzon]

I also see this on all current versions:

• macOS 10.14.1
• VS Code 1.28.2
• vscode-go 0.7.0
• Go 1.11.2
• Delve 1.1.0

[ericpitcher]

I'm having the same problem right now on mac, first time testing delve with go extension and after hitting the stop button the debug process is still alive

[ramya-rao-a]

@yinfxs I am trying to reproduce this issue again with your sample code, but the video in your comment is no longer available (its just a snapshot now). Can you re-share the steps?

The problem only occurs if one adds/removes breakpoints during a debug-session.

@bihe Adding a breakpoint is only possible either before a debug session starts or when another breakpoint is hit. Are you seeing this issue when trying to add a breakpoint when another breakpoint is hit or when the program is running?

@ericpitcher, @mbanzon If you are seeing this issue with the sample code @yinfxs has shared in
#2002 (comment), can you provide me the exact steps?

[bihe]

@ramya-rao-a I have used the godoc example of a http handler as the testing-code (https://golang.org/pkg/net/http/#example_ListenAndServe). Using this I can reproduce/show the behavior.

The process only hangs if I change breakpoints "outside" of debug sessions.

1. start debug session with breakpoint in handler
2. call the handler
3. breakpoint hits (next)
4. remove the breakpoint
5. call the handler again
6. breaks at breakpoint location - even no breakpoint is set
7. stop debug session
8. dlv process is not terminated

I've created a video showing the behavior above:
https://s3.eu-central-1.amazonaws.com/bihe.share/vscode_golang_debug.webm

If I change the breakpoint only during a active debug session the behavior is normal/expected.

1. start debug session with breakpoint in handler
2. call the handler
3. breakpoint hits -> remove the breakpoint
4. call the handler again
5. breakpoint does not hit
6. stop debug session
7. dlv process (and child process) is terminated

Again short video shwoing this behavior:
https://s3.eu-central-1.amazonaws.com/bihe.share/vscode_golang_debug_OK.webm

Adding a breakpoint is only possible either before a debug session starts or when another breakpoint is hit

If this is the case (the example above shows it) I was not really aware of this. I could not find anything in the docs (https://github.com/Microsoft/vscode-go/wiki/Debugging-Go-code-using-VS-Code). Compared with the debugging experience of other vscode extensions (e.g. omnisharp-vscode) this is a rather non-standard-behavior.

Update of my environment:

• Ubuntu 18.10 x86_64
• vscode 1.29.1
• vscode-go 0.7.0
• go version go1.11 linux/amd64

[ramya-rao-a]

Thanks for the details @bihe.

The issue of breakpoints getting added successfully only before a debug session or when another breakpoint is hit is a limitation on delve's side which doesn't allow interacting with the target process when it is running.

You are right, this isn't documented well even though it has come up multiple times as issues in this repo. I have updated the wiki on debugging Go code with this extension appropriately

The fact that the debug process itself doesn't get cleaned up properly and so further debug sessions fail due to the "listen tcp :8080: bind: address already in use" is an issue that we can look into.

[mbanzon]

This description matches what I am seeing as well. I have tried on macOS (latest, 10.14.1) and Windows 10 - it is only on macOS I see the error where the process is kept hanging.

[ramya-rao-a]

I am a little pressed for time at the moment. If anyone is interested in investigating the cause for the debug process not ending properly, here are a few pointers

• Add "trace": "verbose" to your debug configuration. This will print logs from the debug adapter and you can see each step executed by the debug adapter.
• If the above doesn't provide any hints, then add "showLog": true, "logOutput": "rpc" to your debug configuration as well. This will print logs from delve corresponding to each request/response between the debug adapter and delve.

[ericpitcher]

@ramya-rao-a

I added the trace: verbose.

What I have found is that if I create the breakpoints before I launch debugging, then debugging works, the breakpoints are hit and when I hit stop the debug process is killed.

It is when I click to launch debugging with no breakpoints in place and I add them afterward is when they are not hit and when I click on the stop button the debug process does not get killed. I have the debug log for each case below, I perform the same debug steps in each case below, refresh the browser only once to trigger breakpoint on web server response, then I stop debugging, again only difference is at what point breakpoints are added. This is the code I am debugging https://github.com/ericpitcher/go-vs-code-debugging

When debugging is failing, breakpoints not hit, debug process does not die when stopped - Breakpoints are created after debug launch

Verbose logs are written to:
/var/folders/m5/dt184yv95sd55pgqzw8q3mkm0000gn/T/vscode-go-debug.txt
10:15:33 AM, 1/16/2019
InitializeRequest
InitializeResponse
Using GOPATH: /Users/eric/go
Current working directory: /Users/eric/go/src/myserve
Running: /Users/eric/go/bin/dlv debug myserve --headless=true --listen=127.0.0.1:32083 --api-version=2 --
API server listening at: 127.0.0.1:32083
InitializeEvent
ConfigurationDoneRequest
ContinueRequest
ContinueResponse
SetBreakPointsRequest
All cleared
Creating on: /Users/eric/go/src/myserve/main.go:10
DisconnectRequest
HaltRequest

When debugging is successful, breakpoints are hit, debug process does die when stopped - Breakpoints are created before debug launch

Verbose logs are written to:
/var/folders/m5/dt184yv95sd55pgqzw8q3mkm0000gn/T/vscode-go-debug.txt
10:19:05 AM, 1/16/2019
InitializeRequest
InitializeResponse
Using GOPATH: /Users/eric/go
Current working directory: /Users/eric/go/src/myserve
Running: /Users/eric/go/bin/dlv debug myserve --headless=true --listen=127.0.0.1:24297 --api-version=2 --
API server listening at: 127.0.0.1:24297
InitializeEvent
SetBreakPointsRequest
All cleared
Creating on: /Users/eric/go/src/myserve/main.go:10
All set:[{"id":1,"name":"","addr":19842861,"file":"/Users/eric/go/src/myserve/main.go","line":10,"functionName":"main.handle","Cond":"","continue":false,"traceReturn":false,"goroutine":false,"stacktrace":0,"LoadArgs":{"FollowPointers":true,"MaxVariableRecurse":1,"MaxStringLen":64,"MaxArrayValues":64,"MaxStructFields":-1},"LoadLocals":{"FollowPointers":true,"MaxVariableRecurse":1,"MaxStringLen":64,"MaxArrayValues":64,"MaxStructFields":-1},"hitCount":{},"totalHitCount":0}]
SetBreakPointsResponse
ConfigurationDoneRequest
ContinueRequest
ContinueResponse
continue state {"Running":false,"currentThread":{"id":267440,"pc":19842861,"file":"/Users/eric/go/src/myserve/main.go","line":10,"function":{"name":"main.handle","value":19842832,"type":0,"goType":0,"optimized":false},"goroutineID":5,"breakPoint":{"id":1,"name":"","addr":19842861,"file":"/Users/eric/go/src/myserve/main.go","line":10,"functionName":"main.handle","Cond":"","continue":false,"traceReturn":false,"goroutine":false,"stacktrace":0,"LoadArgs":{"FollowPointers":true,"MaxVariableRecurse":1,"MaxStringLen":64,"MaxArrayValues":64,"MaxStructFields":-1},"LoadLocals":{"FollowPointers":true,"MaxVariableRecurse":1,"MaxStringLen":64,"MaxArrayValues":64,"MaxStructFields":-1},"hitCount":{"5":1},"totalHitCount":1},"breakPointInfo":{"arguments":[{"name":"r","addr":824634366528,"onlyAddr":false,"type":"*net/http.Request","realType":"*net/http.Request","flags":8,"kind":22,"value":"","len":1,"cap":0,"children":[{"name":"","addr":824634745088,"onlyAddr":false,"type":"net/http.Request","realType":"net/http.Request","flags":0,"kind":25,"value":"","len":22,"cap":0,"children":[{"name":"Method","addr":824634745088,"onlyAddr":false,"type":"string","realType":"string","flags":0,"kind":24,"value":"GET","len":3,"cap":0,"children":[],"base":824633820400,"unreadable":"","LocationExpr":"","DeclLine":0},{"name":"URL","addr":824634745104,"onlyAddr":false,"type":"*net/url.URL","realType":"*net/url.URL","flags":0,"kind":22,"value":"","len":1,"cap":0,"children":[{"name":"","addr":824634720640,"onlyAddr"[...]
StoppedEvent("breakpoint")
ThreadsRequest
goroutines [{"id":1,"currentLoc":{"pc":16982420,"file":"/usr/local/go/src/runtime/proc.go","line":303,"function":{"name":"runtime.gopark","value":16982208,"type":0,"goType":0,"optimized":true}},"userCurrentLoc":{"pc":16960270,"file":"/usr/local/go/src/runtime/netpoll.go","line":173,"function":{"name":"internal/poll.runtime_pollWait","value":16960176,"type":0,"goType":0,"optimized":true}},"goStatementLoc":{"pc":17156411,"file":"/usr/local/go/src/runtime/asm_amd64.s","line":201,"function":{"name":"runtime.rt0_go","value":17156112,"type":0,"goType":0,"optimized":true}},"startLoc":{"pc":16980976,"file":"/usr/local/go/src/runtime/proc.go","line":110,"function":{"name":"runtime.main","value":16980976,"type":0,"goType":0,"optimized":true}},"threadID":0,"unreadable":""},{"id":2,"currentLoc":{"pc":16982420,"file":"/usr/local/go/src/runtime/proc.go","line":303,"function":{"name":"runtime.gopark","value":16982208,"type":0,"goType":0,"optimized":true}},"userCurrentLoc":{"pc":16982420,"file":"/usr/local/go/src/runtime/proc.go","line":303,"function":{"name":"runtime.gopark","value":16982208,"type":0,"goType":0,"optimized":true}},"goStatementLoc":{"pc":16981845,"file":"/usr/local/go/src/runtime/proc.go","line":240,"function":{"name":"runtime.init.4","value":16981792,"type":0,"goType":0,"optimized":true}},"startLoc":{"pc":16981872,"file":"/usr/local/go/src/runtime/proc.go","line":243,"function":{"name":"runtime.forcegchelper","value":16981872,"type":0,"goType":0,"optimized":true}},"threadID"[...]
ThreadsResponse [{"id":1,"name":"internal/poll.runtime_pollWait"},{"id":2,"name":"runtime.gopark"},{"id":3,"name":"runtime.gopark"},{"id":4,"name":"runtime.gopark"},{"id":5,"name":"main.handle"},{"id":6,"name":"internal/poll.runtime_pollWait"},{"id":7,"name":"internal/poll.(*FD).Read"}]
StackTraceRequest
locations [{"pc":19842861,"file":"/Users/eric/go/src/myserve/main.go","line":10,"function":{"name":"main.handle","value":19842832,"type":0,"goType":0,"optimized":false},"Locals":[],"Arguments":[{"name":"r","addr":824634366528,"onlyAddr":false,"type":"*net/http.Request","realType":"*net/http.Request","flags":8,"kind":22,"value":"","len":1,"cap":0,"children":[{"name":"","addr":824634745088,"onlyAddr":false,"type":"net/http.Request","realType":"net/http.Request","flags":0,"kind":25,"value":"","len":22,"cap":0,"children":[{"name":"Method","addr":824634745088,"onlyAddr":false,"type":"string","realType":"string","flags":0,"kind":24,"value":"GET","len":3,"cap":0,"children":[],"base":824633820400,"unreadable":"","LocationExpr":"","DeclLine":0},{"name":"URL","addr":824634745104,"onlyAddr":false,"type":"*net/url.URL","realType":"*net/url.URL","flags":0,"kind":22,"value":"","len":1,"cap":0,"children":[{"name":"","addr":824634720640,"onlyAddr":false,"type":"net/url.URL","realType":"net/url.URL","flags":0,"kind":25,"value":"","len":9,"cap":0,"children":[{"name":"Scheme","addr":824634720640,"onlyAddr":false,"type":"string","realType":"string","flags":0,"kind":24,"value":"","len":0,"cap":0,"children":[],"base":0,"unreadable":"","LocationExpr":"","DeclLine":0},{"name":"Opaque","addr":824634720656,"onlyAddr":false,"type":"string","realType":"string","flags":0,"kind":24,"value":"","len":0,"cap":0,"children":[],"base":0,"unreadable":"","LocationExpr":"","DeclLine":0},{"name":"User","addr":82463[...]
StackTraceResponse
ThreadsRequest
goroutines [{"id":1,"currentLoc":{"pc":16982420,"file":"/usr/local/go/src/runtime/proc.go","line":303,"function":{"name":"runtime.gopark","value":16982208,"type":0,"goType":0,"optimized":true}},"userCurrentLoc":{"pc":16960270,"file":"/usr/local/go/src/runtime/netpoll.go","line":173,"function":{"name":"internal/poll.runtime_pollWait","value":16960176,"type":0,"goType":0,"optimized":true}},"goStatementLoc":{"pc":17156411,"file":"/usr/local/go/src/runtime/asm_amd64.s","line":201,"function":{"name":"runtime.rt0_go","value":17156112,"type":0,"goType":0,"optimized":true}},"startLoc":{"pc":16980976,"file":"/usr/local/go/src/runtime/proc.go","line":110,"function":{"name":"runtime.main","value":16980976,"type":0,"goType":0,"optimized":true}},"threadID":0,"unreadable":""},{"id":2,"currentLoc":{"pc":16982420,"file":"/usr/local/go/src/runtime/proc.go","line":303,"function":{"name":"runtime.gopark","value":16982208,"type":0,"goType":0,"optimized":true}},"userCurrentLoc":{"pc":16982420,"file":"/usr/local/go/src/runtime/proc.go","line":303,"function":{"name":"runtime.gopark","value":16982208,"type":0,"goType":0,"optimized":true}},"goStatementLoc":{"pc":16981845,"file":"/usr/local/go/src/runtime/proc.go","line":240,"function":{"name":"runtime.init.4","value":16981792,"type":0,"goType":0,"optimized":true}},"startLoc":{"pc":16981872,"file":"/usr/local/go/src/runtime/proc.go","line":243,"function":{"name":"runtime.forcegchelper","value":16981872,"type":0,"goType":0,"optimized":true}},"threadID"[...]
ThreadsResponse [{"id":1,"name":"internal/poll.runtime_pollWait"},{"id":2,"name":"runtime.gopark"},{"id":3,"name":"runtime.gopark"},{"id":4,"name":"runtime.gopark"},{"id":5,"name":"main.handle"},{"id":6,"name":"internal/poll.runtime_pollWait"},{"id":7,"name":"internal/poll.(*FD).Read"}]
ScopesRequest
locals []
functionArgs [{"name":"r","addr":824634366528,"onlyAddr":false,"type":"*net/http.Request","realType":"*net/http.Request","flags":8,"kind":22,"value":"","len":1,"cap":0,"children":[{"name":"","addr":824634745088,"onlyAddr":false,"type":"net/http.Request","realType":"net/http.Request","flags":0,"kind":25,"value":"","len":22,"cap":0,"children":[{"name":"Method","addr":824634745088,"onlyAddr":false,"type":"string","realType":"string","flags":0,"kind":24,"value":"GET","len":3,"cap":0,"children":[],"base":824633820400,"unreadable":"","LocationExpr":"","DeclLine":0},{"name":"URL","addr":824634745104,"onlyAddr":false,"type":"*net/url.URL","realType":"*net/url.URL","flags":0,"kind":22,"value":"","len":1,"cap":0,"children":[{"name":"","addr":824634720640,"onlyAddr":false,"type":"net/url.URL","realType":"net/url.URL","flags":0,"kind":25,"value":"","len":9,"cap":0,"children":[{"name":"Scheme","addr":824634720640,"onlyAddr":false,"type":"string","realType":"string","flags":0,"kind":24,"value":"","len":0,"cap":0,"children":[],"base":0,"unreadable":"","LocationExpr":"","DeclLine":0},{"name":"Opaque","addr":824634720656,"onlyAddr":false,"type":"string","realType":"string","flags":0,"kind":24,"value":"","len":0,"cap":0,"children":[],"base":0,"unreadable":"","LocationExpr":"","DeclLine":0},{"name":"User","addr":824634720672,"onlyAddr":false,"type":"*net/url.Userinfo","realType":"*net/url.Userinfo","flags":0,"kind":22,"value":"","len":1,"cap":0,"children":[{"name":"","addr":0,"onlyAddr":false,"[...]
global vars [{"name":"statictmp_0","addr":20796992,"onlyAddr":false,"type":"string","realType":"string","flags":0,"kind":24,"value":"ListenAndServe: ","len":16,"cap":0,"children":[],"base":20456460,"unreadable":"","LocationExpr":"[block] DW_OP_addr 0x13d5640 ","DeclLine":0}]
ScopesResponse
VariablesRequest
VariablesResponse [
 {
  "name": "r",
  "value": "<*net/http.Request>(0xc0000fa100)",
  "evaluateName": "r",
  "variablesReference": 1002
 },
 {
  "name": "w",
  "value": "<net/http.ResponseWriter>",
  "evaluateName": "w",
  "variablesReference": 1003
 }
]
VariablesRequest
VariablesResponse [
 {
  "name": "statictmp_0",
  "value": "\"ListenAndServe: \"",
  "evaluateName": ".statictmp_0",
  "variablesReference": 0
 }
]
ContinueRequest
ContinueResponse
DisconnectRequest
HaltRequest
continue state {"Running":false,"currentThread":{"id":267440,"pc":140735162476510,"file":"","line":0,"goroutineID":0,"ReturnValues":null},"Threads":[{"id":267440,"pc":140735162476510,"file":"","line":0,"goroutineID":0,"ReturnValues":null},{"id":267474,"pc":140735162476510,"file":"","line":0,"goroutineID":0,"ReturnValues":null},{"id":267475,"pc":140735162488598,"file":"","line":0,"goroutineID":0,"ReturnValues":null},{"id":267476,"pc":140735162476510,"file":"","line":0,"goroutineID":0,"ReturnValues":null},{"id":267477,"pc":140735162476510,"file":"","line":0,"goroutineID":0,"ReturnValues":null},{"id":267478,"pc":140735162476510,"file":"","line":0,"goroutineID":0,"ReturnValues":null}],"NextInProgress":false,"exited":false,"exitStatus":0,"When":""}
HaltResponse
DetachRequest
DisconnectRequest to parent

[ramya-rao-a]

Thanks @ericpitcher!

From your logs its clear that the call to delve to create the breakpoint at https://github.com/Microsoft/vscode-go/blob/latest/src/debugAdapter/goDebug.ts#L722 never actually returns. I guess at this point, any further requests to delve doesnt get responded to which is why the eventual Halt request doesnt reach it and so it is unable to gracefully close the program.

We have #2128 to fix the issue of adding breakpoints when the program is running. Once that fix is in, we shouldnt be having this issue anymore.

[ericpitcher]

@ramya-rao-a Great thanks a lot! Let me know if you want me to test anything else out on my Mac.

[ramya-rao-a]

Adding/Removing breakpoints when the program is running is now possible in the latest update (0.9.0) to the Go extension.

Huge thanks to the amazing @xiphon who made this happen! And @muravjov for his observations that lead to the fix.