Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

debug: toggling breakpoints hangs while focus is on an ephemeral goroutine #1648

Closed
lucky-wolf opened this issue Jul 26, 2021 · 24 comments
Closed
Labels
Debug Issues related to the debugging functionality of the extension. FrozenDueToAge upstream-vscode Issues that are by problems in VS Code itself.

Comments

@lucky-wolf
Copy link

lucky-wolf commented Jul 26, 2021

For asking questions, see:

Before filing an issue, please review our troubleshooting guides

Please answer these questions before submitting your issue. Thanks!

What version of Go, VS Code & VS Code Go extension are you using?

  • Run go version to get version of Go from the VS Code integrated terminal.
    • go version go1.16.5 linux/amd64
  • Run gopls -v version to get version of Gopls from the VS Code integrated terminal.
    • Build info
    golang.org/x/tools/gopls v0.7.0
    golang.org/x/tools/gopls@v0.7.0 h1:JQBHW81Gsyim6iDjUwGoPeSpXrSqwen3isPJLfDfaYU=
    github.com/BurntSushi/toml@v0.3.1 h1:WXkYYl6Yr3qBf1K79EBnL4mak0OimBfB0XUf9Vl28OQ=
    github.com/google/go-cmp@v0.5.5 h1:Khx7svrCpmxxtHBq5j2mp/xVjsi8hQMfNLvJFAlrGgU=
    github.com/sergi/go-diff@v1.1.0 h1:we8PVUC3FE2uYfodKH/nBHMSetSfHDR6scGdBi+erh0=
    golang.org/x/mod@v0.4.2 h1:Gz96sIWK3OalVv/I/qNygP42zyoKp3xptRVCWRFEBvo=
    golang.org/x/sync@v0.0.0-20210220032951-036812b2e83c h1:5KslGYwFpkhGh+Q16bwMP3cOontH8FOep7tGV86Y7SQ=
    golang.org/x/sys@v0.0.0-20210510120138-977fb7262007 h1:gG67DSER+11cZvqIMb8S8bt0vZtiN6xWYARwirrOSfE=
    golang.org/x/tools@v0.1.3-0.20210608163600-9ed039809d4c h1:Pv9gNyJFYVdpUAVZYJ1BDSU4eGgXQ+0f3DIGAdolO5s=
    golang.org/x/xerrors@v0.0.0-20200804184101-5ec99f83aff1 h1:go1bK/D/BFZV2I8cIQd1NKEZ+0owSTG1fDTci4IqFcE=
    honnef.co/go/tools@v0.2.0 h1:ws8AfbgTX3oIczLPNPCu5166oBg9ST2vNs0rcht+mDE=
    mvdan.cc/gofumpt@v0.1.1 h1:bi/1aS/5W00E2ny5q65w9SnKpWEF/UIOqDYBILpo9rA=
    mvdan.cc/xurls/v2@v2.2.0 h1:NSZPykBXJFCetGZykLAxaL6SIpvbVy/UFEniIfHAa8A=
  • Run code -v or code-insiders -v to get version of VS Code or VS Code Insiders.
    • 1.58.2
      c3f126316369cd610563c75b1b1725e0679adfb3
      x64
  • Check your installed extensions to get the version of the VS Code Go extension
    • N/A
  • Run Ctrl+Shift+P (Cmd+Shift+P on Mac OS) > Go: Locate Configured Go Tools command.
    • Checking configured tools....
GOBIN: undefined
toolsGopath: 
gopath: /home/swolf/go
GOROOT: /home/swolf/go-sdk
PATH: /home/swolf/go-sdk/bin:/home/swolf/go/bin:/home/swolf/.local/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/games:/usr/local/games:/snap/bin:/home/swolf/protobuf/bin

   gopkgs: /home/swolf/go/bin/gopkgs installed
   go-outline: /home/swolf/go/bin/go-outline installed
   gotests: /home/swolf/go/bin/gotests installed
   gomodifytags: /home/swolf/go/bin/gomodifytags installed
   impl: /home/swolf/go/bin/impl installed
   goplay: /home/swolf/go/bin/goplay installed
   dlv: /home/swolf/go/bin/dlv installed
   dlv-dap: /home/swolf/go/bin/dlv-dap installed
   staticcheck: /home/swolf/go/bin/staticcheck installed
   gopls: /home/swolf/go/bin/gopls installed

go env
Workspace Folder (pb): /home/swolf/Projects/pb
	GO111MODULE=""
	GOARCH="amd64"
	GOBIN=""
	GOCACHE="/home/swolf/.cache/go-build"
	GOENV="/home/swolf/.config/go/env"
	GOEXE=""
	GOFLAGS=""
	GOHOSTARCH="amd64"
	GOHOSTOS="linux"
	GOINSECURE=""
	GOMODCACHE="/home/swolf/go/pkg/mod"
	GONOPROXY="github.com/luckypointlabs,github.com/Arkadia-tech"
	GONOSUMDB="github.com/luckypointlabs,github.com/Arkadia-tech"
	GOOS="linux"
	GOPATH="/home/swolf/go"
	GOPRIVATE="github.com/luckypointlabs,github.com/Arkadia-tech"
	GOPROXY="https://proxy.golang.org,direct"
	GOROOT="/home/swolf/go-sdk"
	GOSUMDB="sum.golang.org"
	GOTMPDIR=""
	GOTOOLDIR="/home/swolf/go-sdk/pkg/tool/linux_amd64"
	GOVCS=""
	GOVERSION="go1.16.5"
	GCCGO="gccgo"
	AR="ar"
	CC="gcc"
	CXX="g++"
	CGO_ENABLED="1"
	GOMOD="/home/swolf/Projects/pb/go.mod"
	CGO_CFLAGS="-g -O2"
	CGO_CPPFLAGS=""
	CGO_CXXFLAGS="-g -O2"
	CGO_FFLAGS="-g -O2"
	CGO_LDFLAGS="-g -O2"
	PKG_CONFIG="pkg-config"
	GOGCCFLAGS="-fPIC -m64 -pthread -fmessage-length=0 -fdebug-prefix-map=/tmp/go-build2546632551=/tmp/go-build -gno-record-gcc-switches"

Share the Go related settings you have added/edited

Nothing very interesting...

Describe the bug

When I set a breakpoint in a running session using dlv-dap, the process hangs (assuming it wasn't paused when I set the BP).

When I clear a BP in a paused session using dlv-dap, I thrown into src/runtime/sigqueue.go:168

Eitherway - unable to change BPs in an active debug session. I can change them if I exit the process first, and start a new session.

Steps to reproduce the behavior:

launch a go server
to set a BP on something you know will trigger in a moment / after an action
do that action to trigger that code
nothing will ever happen (the process is frozen)

Screenshots or recordings

If applicable, add screenshots or recordings to help explain your problem.

@gopherbot gopherbot added this to the Untriaged milestone Jul 26, 2021
@lucky-wolf
Copy link
Author

I'd give you more logging info - but I've always found selecting text & copying from output to be nigh-impossible (linux mint / cinnamon vm, if that matters).

@lucky-wolf
Copy link
Author

Note: I was informed that using dlv-dap the behavior of setting a BP causes the process to be paused. Simply resuming the process after setting the BP does appear to work.

@lucky-wolf
Copy link
Author

lucky-wolf commented Jul 26, 2021

Hmm... having that "jumps to runtime/sema.go" over and over bug (similar to #1617).

I simply set a BP - started a session - after it trapped into debugger - stepped a few lines, then stepped into something - and it began happening on each new step...

@hyangah
Copy link
Contributor

hyangah commented Jul 26, 2021

@lucky-wolf Seems like you already figured out how to handle the original issue - resuming after changing breakpoints - and now you are experiencing a different issue - jumping to runtime/sema.go. Am I understanding it correctly?

Re: #1648 (comment)
What is the dlv-dap version (go version -m /home/swolf/go/bin/dlv-dap)? Do you reproduce the issue if you update dlv-dap ("Go: Install/Update Tools" -> choose dlv-dap)?

@hyangah hyangah added Debug Issues related to the debugging functionality of the extension. DlvDAPDA labels Jul 26, 2021
@hyangah hyangah changed the title toggling breakpoints hangs or breaks a dlv-dap debug session debug: toggling breakpoints hangs or breaks a dlv-dap debug session Jul 26, 2021
@lucky-wolf
Copy link
Author

@hyangah apologies for the swerve - but yes, I was asked on #1648 to start another report for the toggling BP issues - but for the most part those are just not automatic anymore - if I manually resume the debug process after toggling one, it does appear to work as expected. So that could be said to be "working as intended"

However, while using the debugger yesterday - I did run into essentially that same bug (well, nearly same behavior, if the same cause or simply something like it) - where each step over / step into would flash over to a go runtime file - seemingly to do with goroutine state assessment?

in 1648 it was a different file - this time it jumps into sema.go.

there's a lot of context switching in the debug output from dlv-dap - but nothing more interesting than that. screenshots might be easier than copying the text from the debug output window - not sure why that is so user-unfriendly - but I cannot find a good way to simply select multiple lines & copy them out - it refuses to allow me to select them properly and becomes impossible to interface to when I do have a selection...

@polinasok
Copy link
Contributor

@lucky-wolf

Setting breakpoints while the program is running

Just to confirm the expected behavior (which you already seem to have figured out):

  1. When setting a breakpoint during one of the "step" operations,
    Legacy: halts execution as if you clicked pause first, sets breakpoint, user must resume manually
    Dlv-dap: halts execution as if you clicked pause first, sets breakpoint, user must resume manually
  2. When setting a breakpoint during "continue"
    Legacy: halts execution, sets breakpoint, execution is resumed automatically (can be flaky due to concurrency issues)
    Dlv-dap: halts execution as if you clicked pause first, sets breakpoint, user must resume manually
    So yes, for now this is working as intended. We will continue looking into automating program execution after setting a breakpoint (tricky), but in the meantime we can make this behavior more clear with additional user messages.

Jumping goroutines/files while stepping

This is likely caused by the same underlying issues as #1617 and #1647. Since everybody's goroutine set up iss differemt, it is not surprising that flickering files are not always the same. We have submitted an additional fixes for the issue since it was reported, so please do make sure that you are using the most recent version of dlv-dap.

Coping logs

You should be able to right click on the Debug Console and choose Copy All. You can also use logDest in launch.json to redirect to a file. From dlv help log:

--log-dest can be used to specify where the logs should be written. 
If the argument is a number it will be interpreted as a file descriptor,
otherwise as a file path.

@lucky-wolf
Copy link
Author

@polinasok thanks for the feedback!
I just fixed the font-size issue in debug-console - so that helps. And yes - copy all will be my goto from now on. It would be nice to be able to click to set a cursor position, and shift click on a new position to select between those!

Similarly, if I could drag above / below the current window so it scrolled while selecting - that'd be useful.

But neither of those exist, so selecting a chunk is nigh-impossible.

All will work (and I can edit that in another text editor after that).

Any improvements to make the setting of a BP during "running" state auto-resume would be nice. Messaging me to say "app paused to set new BP - press continue to resume..." would be helpful. Thanks.

@lucky-wolf
Copy link
Author

Since I've got a platform to make some comments, I'll add one more:

It would be nice if the dlv-dap captured the remaining debug output once I hit "stop".

I think you disconnect before the app is actually shut down? So any final log output is missed from the debug console.

That or dlv-dap still only kills dlv and fails to send a stop interrupt to the underlying debug process? My graceful shutdown code (which triggers on such an interrupt) is not visible in the debug console, but I am certain works if I send a stop from some other mechanism (e.g. a rest call that issues it against itself).

Preferrable to have dlv-dap send a terminate / stop interrupt rather than just hard killing the process immediately. Or for that to be a configurable option anyway (in the launch settings + user + project defaults?)

@hyangah
Copy link
Contributor

hyangah commented Jul 28, 2021

@lucky-wolf you can access equivalent tracing info from "Go Debug" output channel which in my opinion is a bit easier to select/copy/paste than the Debug Console where various javascript runs because it's primarily targeted for repl use.
https://github.com/golang/vscode-go/blob/master/docs/dlv-dap.md#testing

I think you disconnect before the app is actually shut down? So any final log output is missed from the debug console.

Triaging and inspecting the issue will be much easier if you can share the trace/log.

That or dlv-dap still only kills dlv and fails to send a stop interrupt to the underlying debug process? My graceful shutdown code (which triggers on such an interrupt) is not visible in the debug console, but I am certain works if I send a stop from some other mechanism (e.g. a rest call that issues it against itself).

For graceful shutdown, there is an open issue #120 I believe dlv-dap has the same issue.

@polinasok
Copy link
Contributor

polinasok commented Jul 28, 2021

@lucky-wolf Just to add to what @hyangah wrote. The logging in Go Debug output channel is enabled with "trace" in your launch.json. It is true that after things start shutting down the Debug Console stops logging. Its life span is associated with the interactive user portion of the debug session, which is truncated, comparing to the life span of all the moving parts involved in setting up and shutting down this debug session. That's why we also send logging to Go Debug output channel. But it would not have the output from your application. We do not do anything special to shut it down, just whatever delve normally does (e.g. what you would get with dlv on the command-line). You can see exactly what gets triggered by running the dlv dap server externally and connecting to it from the editor. Then all the logging from dlv-dap and from your process will go to your terminal window.

dlv dap --listen=:12345 --log --log-output=dap,debugger

Then add "debugServer" to your launch configuration to tell vscode to connect to the above server instead of launching a new one.

Edit: recommend using debugServer to attach to debug server.

@polinasok
Copy link
Contributor

polinasok commented Jul 28, 2021

Just to add about shutdown. Dlv-dap is supposed to shut down gracefully if it receives an explicit disconnect request from the editor or is killed with SIGTERM or SIGINT (which is what we do to force-kill it from the extension if the server becomes unresponsive). If target was launched, it should be taken down by default as well (unless you toggle the stop/disconnect option in the client to change the default). If you attached to an application, it should keep running (unless you toggle stop/disconnect option in the client to change the default).

@suzmue suzmue added the WaitingForInfo Issue is not actionable because of missing required information, which needs to be provided. label Aug 9, 2021
@zzjin
Copy link

zzjin commented Aug 17, 2021

I'm facing same issue with uncheck breakpoint.
As described below, when setting one breakpoint ,the process show paused status, and I can click Continue(F5) correctly.
But after debug and some steps, uncheck this breakpoint, the process bar still shows Pause(F6) and the whole process is under paused status so I cannot manual resume by click Continue(F5) as setting BP can.
Is this a debug bar UI bug?

The whole action chain:
start debug -> trigger http connect -> ok response ✔️
-> setting one breakpoint -> process paused (as except) -> manual click 'Continue' -> trigger http connect -> break at breakpoint -> step continue -> process continues ✔️
-> unset one breakpoint -> process paused (as except?) -> cannot manual resume process here

@oxycoder
Copy link

It is anoying whenever we place breakpoint during debug, it pause all debug instance.
Example If we are debuging 10 process, place any breakpoint will cause all process paused, even the breakpoin didn't trigger yet. So we have to press F5 10 times to continue debug.

Please have a setting that do not pause on place breakpoint during debug (if it didn't trigger intemediately)

@polinasok
Copy link
Contributor

@zzjin We either need a reproducible test case or a client-side log to see what requests the client processed to be able to diagnose this. Please also share if any warnings were printed to Debug Console.

process continues ✔️
-> unset one breakpoint -> process paused (as except?)

At this point, whenever you make any changes to breakpoints (set or unset) while the process is running, we will pause and print a message to the Debug Console requesting that you continue manually. Do you see such a message?

@polinasok
Copy link
Contributor

@oxycoder Thank you for your input, we realize that the behavior of pausing to set a breakpoint is unideal. Continuing automatically is work in progress. Thank you for your patience.

@gopherbot
Copy link
Collaborator

Timed out in state WaitingForInfo. Closing.

(I am just a bot, though. Please speak up if this is a mistake or you have the requested information.)

@hyangah
Copy link
Contributor

hyangah commented Sep 17, 2021

The issue is not fixed. Reopening.

@hyangah hyangah reopened this Sep 17, 2021
@hyangah hyangah modified the milestones: Untriaged, Backlog Sep 17, 2021
@hyangah hyangah removed the WaitingForInfo Issue is not actionable because of missing required information, which needs to be provided. label Sep 17, 2021
@hyangah hyangah reopened this Sep 17, 2021
@polinasok
Copy link
Contributor

Which specific problem are we trying to address under this bug? We should rename the title to say so.

Users are rightfully unhappy that we have to pause and request manual Continue when (un)setting breakpoints while the process is running. We also filed #1676 for that. But there are also reports of other odd behavior in here. For example @
zzjin wrote -> unset one breakpoint -> process paused (as except?) -> cannot manual resume process here ❌ although we did not get more details beyond that.

@zzjin
Copy link

zzjin commented Sep 18, 2021

Reproduceable minimal code with log:

main.go:

package main

import (
	"fmt"
	"net/http"
)

func main() {
	http.HandleFunc("/hello", func(w http.ResponseWriter, _ *http.Request) {
		fmt.Fprint(w, "Hello, world!") // set breakline here.
	})
	http.ListenAndServe(":8080", nil)
}

.vscode/launch.json:

{
	"version": "0.2.0",
	"configurations": [
		{
			"name": "Debug",
			"type": "go",
			"request": "launch",
			"mode": "auto",
			"program": "${workspaceFolder}",
			"showLog": true,
			"logOutput": "debugger,dap",
		}
	]
}
  1. set breakpoint at line 10, then start debug session:
Starting: /go/bin/dlv-dap dap --check-go-version=false --listen=127.0.0.1:33019 --log=true --log-output=debugger,dap --log-dest=3 from /projects/breakpoint_test
DAP server listening at: 127.0.0.1:33019
2021-09-18T11:19:37+08:00 debug layer=dap DAP server pid = 8869
2021-09-18T11:19:37+08:00 debug layer=dap [<- from client]{"seq":1,"type":"request","command":"initialize","arguments":{"clientID":"vscode","clientName":"Visual Studio Code - Insiders","adapterID":"go","locale":"en-us","linesStartAt1":true,"columnsStartAt1":true,"pathFormat":"path","supportsVariableType":true,"supportsVariablePaging":true,"supportsRunInTerminalRequest":true,"supportsMemoryReferences":true,"supportsProgressReporting":true,"supportsInvalidatedEvent":true}}
2021-09-18T11:19:37+08:00 debug layer=dap [-> to client]{"seq":0,"type":"response","request_seq":1,"success":true,"command":"initialize","body":{"supportsConfigurationDoneRequest":true,"supportsFunctionBreakpoints":true,"supportsConditionalBreakpoints":true,"supportsEvaluateForHovers":true,"supportsSetVariable":true,"supportsExceptionInfoRequest":true,"supportTerminateDebuggee":true,"supportsDelayedStackTraceLoading":true,"supportsClipboardContext":true}}
2021-09-18T11:19:37+08:00 debug layer=dap [<- from client]{"seq":2,"type":"request","command":"launch","arguments":{"name":"Debug","type":"go","request":"launch","mode":"debug","program":".","showLog":true,"logOutput":"debugger,dap","__configurationTarget":5,"packagePathToGoModPathMap":{"/projects/breakpoint_test":"/projects/breakpoint_test"},"debugAdapter":"dlv-dap","apiVersion":2,"dlvLoadConfig":{"followPointers":true,"maxVariableRecurse":1,"maxStringLen":64,"maxArrayValues":64,"maxStructFields":-1},"showGlobalVariables":true,"substitutePath":[],"dlvToolPath":"/go/bin/dlv-dap","env":{},"__buildDir":"/projects/breakpoint_test","__sessionId":"2bce936d-4178-434b-8943-4ccefc4c43aa"}}
2021-09-18T11:19:37+08:00 debug layer=dap debug backend is 'default'
2021-09-18T11:19:37+08:00 debug layer=dap building program '.' in '/projects/breakpoint_test' with flags ''
2021-09-18T11:19:38+08:00 debug layer=dap running binary '/projects/breakpoint_test/__debug_bin' in '/projects/breakpoint_test'
2021-09-18T11:19:38+08:00 info layer=debugger launching process with args: [/projects/breakpoint_test/__debug_bin]
2021-09-18T11:19:38+08:00 debug layer=dap [-> to client]{"seq":0,"type":"event","event":"initialized"}
2021-09-18T11:19:38+08:00 debug layer=dap [-> to client]{"seq":0,"type":"response","request_seq":2,"success":true,"command":"launch"}
2021-09-18T11:19:38+08:00 debug layer=dap [<- from client]{"seq":3,"type":"request","command":"setBreakpoints","arguments":{"source":{"name":"main.go","path":"/projects/breakpoint_test/main.go"},"breakpoints":[{"line":10}],"lines":[10]}}
2021-09-18T11:19:38+08:00 info layer=debugger created breakpoint: &api.Breakpoint{ID:1, Name:"sourceBp Path=\"/projects/breakpoint_test/main.go\"  Line=10 Column=0", Addr:0x6e1145, Addrs:[]uint64{0x6e1145}, File:"/projects/breakpoint_test/main.go", Line:10, FunctionName:"main.main.func1", Cond:"", HitCond:"", Tracepoint:false, TraceReturn:false, Goroutine:false, Stacktrace:0, Variables:[]string(nil), LoadArgs:(*api.LoadConfig)(nil), LoadLocals:(*api.LoadConfig)(nil), WatchExpr:"", WatchType:0x0, VerboseDescr:[]string(nil), HitCount:map[string]uint64{}, TotalHitCount:0x0, Disabled:false}
2021-09-18T11:19:38+08:00 debug layer=dap [-> to client]{"seq":0,"type":"response","request_seq":3,"success":true,"command":"setBreakpoints","body":{"breakpoints":[{"id":1,"verified":true,"source":{"name":"main.go","path":"/projects/breakpoint_test/main.go"},"line":10}]}}
2021-09-18T11:19:38+08:00 debug layer=dap [<- from client]{"seq":4,"type":"request","command":"setFunctionBreakpoints","arguments":{"breakpoints":[]}}
2021-09-18T11:19:38+08:00 debug layer=dap [-> to client]{"seq":0,"type":"response","request_seq":4,"success":true,"command":"setFunctionBreakpoints","body":{"breakpoints":[]}}
2021-09-18T11:19:38+08:00 debug layer=dap [<- from client]{"seq":5,"type":"request","command":"configurationDone","arguments":{}}
2021-09-18T11:19:38+08:00 debug layer=dap [-> to client]{"seq":0,"type":"response","request_seq":5,"success":true,"command":"configurationDone"}
2021-09-18T11:19:38+08:00 debug layer=debugger continuing
2021-09-18T11:19:38+08:00 debug layer=dap [<- from client]{"seq":6,"type":"request","command":"threads"}
2021-09-18T11:19:38+08:00 debug layer=dap [-> to client]{"seq":0,"type":"response","request_seq":6,"success":true,"command":"threads","body":{"threads":[{"id":-1,"name":"Current"}]}}
  1. make one http request:
2021-09-18T11:20:42+08:00 debug layer=dap "continue" command stopped - reason "breakpoint", location /projects/breakpoint_test/main.go:10
2021-09-18T11:20:42+08:00 debug layer=dap [-> to client]{"seq":0,"type":"event","event":"stopped","body":{"reason":"breakpoint","threadId":6,"allThreadsStopped":true,"hitBreakpointIds":[1]}}
2021-09-18T11:20:42+08:00 debug layer=dap [<- from client]{"seq":7,"type":"request","command":"threads"}
2021-09-18T11:20:42+08:00 debug layer=dap [-> to client]{"seq":0,"type":"response","request_seq":7,"success":true,"command":"threads","body":{"threads":[{"id":1,"name":"[Go 1] internal/poll.runtime_pollWait"},{"id":2,"name":"[Go 2] runtime.gopark"},{"id":3,"name":"[Go 3] runtime.gopark"},{"id":4,"name":"[Go 4] runtime.gopark"},{"id":5,"name":"[Go 5] runtime.gopark"},{"id":6,"name":"* [Go 6] main.main.func1 (Thread 9052)"},{"id":7,"name":"[Go 7] syscall.Syscall (Thread 9060)"}]}}
2021-09-18T11:20:42+08:00 debug layer=dap [<- from client]{"seq":8,"type":"request","command":"stackTrace","arguments":{"threadId":6,"levels":1,"format":{}}}
2021-09-18T11:20:42+08:00 debug layer=dap [-> to client]{"seq":0,"type":"response","request_seq":8,"success":true,"command":"stackTrace","body":{"stackFrames":[{"id":1000,"name":"main.main.func1","source":{"name":"main.go","path":"/projects/breakpoint_test/main.go"},"line":10,"column":0}],"totalFrames":51}}
2021-09-18T11:20:42+08:00 debug layer=dap [<- from client]{"seq":9,"type":"request","command":"stackTrace","arguments":{"threadId":6,"startFrame":1,"levels":19,"format":{}}}
2021-09-18T11:20:42+08:00 debug layer=dap [-> to client]{"seq":0,"type":"response","request_seq":9,"success":true,"command":"stackTrace","body":{"stackFrames":[{"id":1001,"name":"net/http.HandlerFunc.ServeHTTP","source":{"name":"server.go","path":"/usr/local/go/src/net/http/server.go"},"line":2046,"column":0},{"id":1002,"name":"net/http.(*ServeMux).ServeHTTP","source":{"name":"server.go","path":"/usr/local/go/src/net/http/server.go"},"line":2424,"column":0},{"id":1003,"name":"net/http.serverHandler.ServeHTTP","source":{"name":"server.go","path":"/usr/local/go/src/net/http/server.go"},"line":2878,"column":0},{"id":1004,"name":"net/http.(*conn).serve","source":{"name":"server.go","path":"/usr/local/go/src/net/http/server.go"},"line":1929,"column":0},{"id":1005,"name":"net/http.(*Server).Serve·dwrap·82","source":{"name":"server.go","path":"/usr/local/go/src/net/http/server.go"},"line":3033,"column":0},{"id":1006,"name":"runtime.goexit","source":{"name":"asm_amd64.s","path":"/usr/local/go/src/runtime/asm_amd64.s","presentationHint":"deemphasize"},"line":1581,"column":0}],"totalFrames":7}}
2021-09-18T11:20:42+08:00 debug layer=dap [<- from client]{"seq":10,"type":"request","command":"scopes","arguments":{"frameId":1000}}
2021-09-18T11:20:42+08:00 debug layer=dap [-> to client]{"seq":0,"type":"response","request_seq":10,"success":true,"command":"scopes","body":{"scopes":[{"name":"Arguments","variablesReference":1000,"expensive":false,"source":{}},{"name":"Locals","variablesReference":1001,"expensive":false,"source":{}},{"name":"Globals (package main)","variablesReference":1002,"expensive":false,"source":{}}]}}
2021-09-18T11:20:42+08:00 debug layer=dap [<- from client]{"seq":11,"type":"request","command":"variables","arguments":{"variablesReference":1000,"format":{}}}
2021-09-18T11:20:42+08:00 debug layer=dap [-> to client]{"seq":0,"type":"response","request_seq":11,"success":true,"command":"variables","body":{"variables":[{"name":"w","value":"net/http.ResponseWriter(*net/http.response) *{conn: *net/http.conn {server: *(*\"net/http.Server\")(0xc0000ea000), cancelCtx: context.WithCancel.func1, rwc: net.Conn(*net.TCPConn) ..., remoteAddr: \"127.0.0.1:53736\", tlsState: *crypto/tls.ConnectionState nil,...","type":"net/http.ResponseWriter","presentationHint":{},"evaluateName":"w","variablesReference":1003}]}}

with debugger stopped at breakpoint as except.

  1. continue by click F5:
2021-09-18T11:21:00+08:00 debug layer=dap [<- from client]{"seq":12,"type":"request","command":"evaluate","arguments":{"expression":"import","frameId":1000,"context":"hover","format":{}}}
2021-09-18T11:21:00+08:00 debug layer=dap Unable to evaluate expression: 1:1: expected operand, found 'import'
2021-09-18T11:21:00+08:00 debug layer=dap [-> to client]{"seq":0,"type":"response","request_seq":12,"success":false,"command":"evaluate","message":"Unable to evaluate expression","body":{"error":{"id":2009,"format":"Unable to evaluate expression: 1:1: expected operand, found 'import'"}}}
2021-09-18T11:21:06+08:00 debug layer=dap [<- from client]{"seq":13,"type":"request","command":"continue","arguments":{"threadId":6}}
2021-09-18T11:21:06+08:00 debug layer=dap [-> to client]{"seq":0,"type":"response","request_seq":13,"success":true,"command":"continue","body":{"allThreadsContinued":true}}
2021-09-18T11:21:06+08:00 debug layer=debugger continuing
  1. unset breakpoint:
2021-09-18T11:22:46+08:00 debug layer=dap [<- from client]{"seq":14,"type":"request","command":"setBreakpoints","arguments":{"source":{"name":"main.go","path":"/projects/breakpoint_test/main.go"}}}
2021-09-18T11:22:46+08:00 debug layer=dap halting execution to set breakpoints
2021-09-18T11:22:46+08:00 debug layer=debugger halting
2021-09-18T11:22:46+08:00 debug layer=dap "continue" command stopped - reason "manual", location /usr/local/go/src/runtime/sys_linux_amd64.s:520
2021-09-18T11:22:46+08:00 debug layer=dap [-> to client]{"seq":0,"type":"event","event":"stopped","body":{"reason":"pause","allThreadsStopped":true}}
2021-09-18T11:22:46+08:00 debug layer=dap [-> to client]{"seq":0,"type":"event","event":"output","body":{"category":"console","output":"Execution halted to set breakpoints - please resume execution manually\n","source":{}}}
Execution halted to set breakpoints - please resume execution manually
2021-09-18T11:22:46+08:00 info layer=debugger cleared breakpoint: []*api.Breakpoint{(*api.Breakpoint)(0xc000d08900)}
2021-09-18T11:22:46+08:00 debug layer=dap [-> to client]{"seq":0,"type":"response","request_seq":14,"success":true,"command":"setBreakpoints","body":{"breakpoints":[]}}
2021-09-18T11:22:46+08:00 debug layer=dap [<- from client]{"seq":15,"type":"request","command":"threads"}
2021-09-18T11:22:46+08:00 debug layer=dap [-> to client]{"seq":0,"type":"response","request_seq":15,"success":true,"command":"threads","body":{"threads":[{"id":1,"name":"[Go 1] internal/poll.runtime_pollWait"},{"id":2,"name":"[Go 2] runtime.gopark"},{"id":3,"name":"[Go 3] runtime.gopark"},{"id":4,"name":"[Go 4] runtime.gopark"},{"id":5,"name":"[Go 5] runtime.gopark"}]}}
  1. Cannot call to 8080 anymore with no debug output.
    QQ20210918112426
    the debug bar show like this and cannot hit any Continue or F5. the process seems hang and cannot accept any new http req.

@hyangah hyangah changed the title debug: toggling breakpoints hangs or breaks a dlv-dap debug session debug: toggling breakpoints hangs while focus is on an ephemeral goroutine Sep 22, 2021
@hyangah
Copy link
Contributor

hyangah commented Sep 22, 2021

Thanks @zzjin for the repro. @suzmue located a bug in VS Code that caused this misbehavior. She is following up the issue by reporting the issue upstream (microsoft/vscode#133623). My understanding is that the pause/continue button in the debug toolbox lost track of the debugger's state because the goroutine (the http handler goroutine in the example) that was on focus is gone after continue.

This problem should be present in the legacy debug adapter, but users encounter this bug more frequently in dlv dap because of the change in how it handles setting/unsetting breakpoints while the debug target is running.

While we track the general UX improvement (i.e. auto-resume after changing breakpoints) in #1676, let's use this issue to track the specific issue around working with short-lived goroutines.

EDIT: I am guessing the legacy debug adapter avoids this issue by always sending the current goroutine id in StoppedEvent. If there is no current goroutine, it also picks up the first goroutine from the goroutine list.

@hyangah hyangah added upstream-vscode Issues that are by problems in VS Code itself. and removed DlvDAPDA labels Sep 22, 2021
@hyangah
Copy link
Contributor

hyangah commented Sep 22, 2021

@suzmue Is it a possibility that dlv-dap returns a thread id with the stopped event to workaround this issue?

@lkarlslund
Copy link

If you're not aware this problem also exists when you do dual debugging under VS Code. One is running delve with the Go webservice, and another is using the Firefox debugger.

Setting a breakpoint in Javascript then pauses the Go side of things, and you have to switch to the other session in the dropdown menu and press F5 to continue.

So fixing this is very welcome :-)

@suzmue
Copy link
Contributor

suzmue commented Dec 21, 2021

This should be fixed in the latest version of VS Code (verified with 1.63.0). If you are still experiencing this issue, please reopen.

@suzmue suzmue closed this as completed Dec 21, 2021
@steveheyman
Copy link

What did I do

Recreated the test case that @zzjin posted on September 17, 2021

What did I expect

Setting the breakpoint on line 10 would not cause execution to be suspended.

What did I see instead

The message "Execution halted to set breakpoints - please resume execution manually" appeared in the logs. The debugger was stopped and F5 was required to resume execution. Although @suzme said that this was fixed in VSCode 1.63.0, there may be a regression or another issue.

Output logs:

Starting: C:\Users\compuser\go\bin\dlv.exe dap --check-go-version=false --log=true --log-output=debugger,dap --listen=127.0.0.1:1074 from C:\Users\compuser\Documents\test\gosimplehttp
DAP server listening at: 127.0.0.1:1074
2022-01-27T19:45:30-08:00 debug layer=dap DAP server pid = 62856
2022-01-27T19:45:30-08:00 debug layer=dap [<- from client]{"seq":1,"type":"request","command":"initialize","arguments":{"clientID":"vscode","clientName":"Visual Studio Code","adapterID":"go","locale":"en-us","linesStartAt1":true,"columnsStartAt1":true,"pathFormat":"path","supportsVariableType":true,"supportsVariablePaging":true,"supportsRunInTerminalRequest":true,"supportsMemoryReferences":true,"supportsProgressReporting":true,"supportsInvalidatedEvent":true}}
2022-01-27T19:45:30-08:00 debug layer=dap [-> to client]{"seq":0,"type":"response","request_seq":1,"success":true,"command":"initialize","body":{"supportsConfigurationDoneRequest":true,"supportsFunctionBreakpoints":true,"supportsConditionalBreakpoints":true,"supportsEvaluateForHovers":true,"supportsSetVariable":true,"supportsExceptionInfoRequest":true,"supportTerminateDebuggee":true,"supportsDelayedStackTraceLoading":true,"supportsClipboardContext":true}}
2022-01-27T19:45:30-08:00 debug layer=dap [<- from client]{"seq":2,"type":"request","command":"launch","arguments":{"name":"Debug","type":"go","request":"launch","mode":"debug","program":".","showLog":true,"logOutput":"debugger,dap","__configurationTarget":5,"packagePathToGoModPathMap":{"c:\\Users\\compuser\\Documents\\test\\gosimplehttp":"c:\\Users\\compuser\\Documents\\test\\gosimplehttp"},"debugAdapter":"dlv-dap","showRegisters":false,"showGlobalVariables":false,"substitutePath":[],"dlvFlags":[],"hideSystemGoroutines":false,"dlvToolPath":"C:\\Users\\compuser\\go\\bin\\dlv.exe","env":{"GOPATH":"C:\\Users\\compuser\\go"},"__buildDir":"C:\\Users\\compuser\\Documents\\test\\gosimplehttp","__sessionId":"7436fda7-6643-41dc-ab8d-576e1ba30ae6"}}
2022-01-27T19:45:30-08:00 debug layer=dap debug backend is 'default'
2022-01-27T19:45:30-08:00 debug layer=dap building program '.' in 'C:\Users\compuser\Documents\test\gosimplehttp' with flags ''
2022-01-27T19:45:31-08:00 debug layer=dap running binary 'C:\Users\compuser\Documents\test\gosimplehttp\__debug_bin.exe' in 'C:\Users\compuser\Documents\test\gosimplehttp'
2022-01-27T19:45:31-08:00 info layer=debugger launching process with args: [C:\Users\compuser\Documents\test\gosimplehttp\__debug_bin.exe]
2022-01-27T19:45:32-08:00 debug layer=dap [-> to client]{"seq":0,"type":"event","event":"initialized"}
2022-01-27T19:45:32-08:00 debug layer=dap [-> to client]{"seq":0,"type":"response","request_seq":2,"success":true,"command":"launch"}
2022-01-27T19:45:32-08:00 debug layer=dap [<- from client]{"seq":3,"type":"request","command":"setFunctionBreakpoints","arguments":{"breakpoints":[]}}
2022-01-27T19:45:32-08:00 debug layer=dap [-> to client]{"seq":0,"type":"response","request_seq":3,"success":true,"command":"setFunctionBreakpoints","body":{"breakpoints":[]}}
2022-01-27T19:45:32-08:00 debug layer=dap [<- from client]{"seq":4,"type":"request","command":"configurationDone","arguments":{}}
2022-01-27T19:45:32-08:00 debug layer=dap [-> to client]{"seq":0,"type":"response","request_seq":4,"success":true,"command":"configurationDone"}
2022-01-27T19:45:32-08:00 debug layer=debugger continuing
2022-01-27T19:45:32-08:00 debug layer=dap [<- from client]{"seq":5,"type":"request","command":"threads"}
2022-01-27T19:45:32-08:00 debug layer=dap [-> to client]{"seq":0,"type":"response","request_seq":5,"success":true,"command":"threads","body":{"threads":[{"id":-1,"name":"Current"}]}}
2022-01-27T19:45:34-08:00 debug layer=dap [<- from client]{"seq":6,"type":"request","command":"setBreakpoints","arguments":{"source":{"name":"main.go","path":"c:\\Users\\compuser\\Documents\\test\\gosimplehttp\\main.go"},"breakpoints":[{"line":10}],"lines":[10]}}
2022-01-27T19:45:34-08:00 debug layer=dap halting execution to set breakpoints
2022-01-27T19:45:34-08:00 debug layer=debugger halting
2022-01-27T19:45:34-08:00 debug layer=dap "continue" command stopped - reason "manual", location :0
2022-01-27T19:45:34-08:00 debug layer=dap [-> to client]{"seq":0,"type":"event","event":"stopped","body":{"reason":"pause","allThreadsStopped":true}}
2022-01-27T19:45:34-08:00 debug layer=dap [-> to client]{"seq":0,"type":"event","event":"output","body":{"category":"console","output":"Execution halted to set breakpoints - please resume execution manually\n","source":{}}}
Execution halted to set breakpoints - please resume execution manually
2022-01-27T19:45:34-08:00 info layer=debugger created breakpoint: &api.Breakpoint{ID:1, Name:"sourceBp Path=\"c:\\\\Users\\\\compuser\\\\Documents\\\\test\\\\gosimplehttp\\\\main.go\"  Line=10 Column=0", Addr:0x8d6605, Addrs:[]uint64{0x8d6605}, File:"C:/Users/compuser/Documents/test/gosimplehttp/main.go", Line:10, FunctionName:"main.main.func1", Cond:"", HitCond:"", Tracepoint:false, TraceReturn:false, Goroutine:false, Stacktrace:0, Variables:[]string(nil), LoadArgs:(*api.LoadConfig)(nil), LoadLocals:(*api.LoadConfig)(nil), WatchExpr:"", WatchType:0x0, VerboseDescr:[]string(nil), HitCount:map[string]uint64{}, TotalHitCount:0x0, Disabled:false}
2022-01-27T19:45:34-08:00 debug layer=dap [-> to client]{"seq":0,"type":"response","request_seq":6,"success":true,"command":"setBreakpoints","body":{"breakpoints":[{"id":1,"verified":true,"source":{"name":"main.go","path":"c:\\Users\\compuser\\Documents\\test\\gosimplehttp\\main.go"},"line":10}]}}
2022-01-27T19:45:34-08:00 debug layer=dap [<- from client]{"seq":7,"type":"request","command":"threads"}
2022-01-27T19:45:34-08:00 debug layer=dap [-> to client]{"seq":0,"type":"response","request_seq":7,"success":true,"command":"threads","body":{"threads":[{"id":1,"name":"[Go 1] internal/poll.runtime_pollWait"},{"id":2,"name":"[Go 2] runtime.gopark"},{"id":18,"name":"[Go 18] runtime.gopark"},{"id":19,"name":"[Go 19] runtime.gopark"},{"id":20,"name":"[Go 20] runtime.gopark"}]}}

Version Information:

go version go1.17.6 windows/amd64

go extension version:
Name: Go
Id: golang.go
Description: Rich Go language support for Visual Studio Code
Version: 0.31.0
Publisher: Go Team at Google
VS Marketplace Link: https://marketplace.visualstudio.com/items?itemName=golang.Go

code -v
1.63.2
899d46d82c4c95423fb7e10e68eba52050e30ba3
x64

gopls -v version

Build info
----------
golang.org/x/tools/gopls v0.7.5
    golang.org/x/tools/gopls@v0.7.5 h1:8Az52YwcFXTWPvrRomns1C0N+zlgTyyPKWvRazO9GG8=
    github.com/BurntSushi/toml@v0.4.1 h1:GaI7EiDXDRfa8VshkTj7Fym7ha+y8/XxIgD2okUIjLw=
    github.com/google/go-cmp@v0.5.6 h1:BKbKCqvP6I+rmFHt06ZmyQtvB8xAkWdhFyr0ZUNZcxQ=
    github.com/sergi/go-diff@v1.1.0 h1:we8PVUC3FE2uYfodKH/nBHMSetSfHDR6scGdBi+erh0=
    golang.org/x/mod@v0.5.1 h1:OJxoQ/rynoF0dcCdI7cLPktw/hR2cueqYfjm43oqK38=
    golang.org/x/sync@v0.0.0-20210220032951-036812b2e83c h1:5KslGYwFpkhGh+Q16bwMP3cOontH8FOep7tGV86Y7SQ=
    golang.org/x/sys@v0.0.0-20211019181941-9d821ace8654 h1:id054HUawV2/6IGm2IV8KZQjqtwAOo2CYlOToYqa0d0=
    golang.org/x/text@v0.3.7 h1:olpwvP2KacW1ZWvsR7uQhoyTYvKAupfQrRGBFM352Gk=
    golang.org/x/tools@v0.1.9-0.20220114220130-fd7798718afd h1:lTnuArxJC+n54TyvWUPyHhrnGxYvhSi13/aM2Ndr4bs=
    golang.org/x/xerrors@v0.0.0-20200804184101-5ec99f83aff1 h1:go1bK/D/BFZV2I8cIQd1NKEZ+0owSTG1fDTci4IqFcE=
    honnef.co/go/tools@v0.2.1 h1:/EPr//+UMMXwMTkXvCCoaJDq8cpjMO80Ou+L4PDo2mY=
    mvdan.cc/gofumpt@v0.1.1 h1:bi/1aS/5W00E2ny5q65w9SnKpWEF/UIOqDYBILpo9rA=
    mvdan.cc/xurls/v2@v2.3.0 h1:59Olnbt67UKpxF1EwVBopJvkSUBmgtb468E4GVWIZ1I=

dlv-dap version -v

Delve Debugger
Version: 1.7.2
Build: $Id: a06f0b8c273325e2160bfd35972c12eda410077c $
Build Details: go1.17.3
 mod    github.com/go-delve/delve       v1.7.3-0.20211109082426-9013a121d8bc    h1:W/nYlpoFw1KtHtNzPnZ6N8OoVm8734cWSwhMnXGrc/4=
 dep    github.com/cilium/ebpf  v0.7.0  h1:1k/q3ATgxSXRdrmPfH8d7YK0GfqVsEKZAX9dQZvs56k=
 dep    github.com/cosiner/argv v0.1.0  h1:BVDiEL32lwHukgJKP87btEPenzrrHUjajs/8yzaqcXg=
 dep    github.com/cpuguy83/go-md2man/v2        v2.0.0  h1:EoUDS0afbrsXAZ9YQ9jdu/mZ2sXgT1/2yyNng4PGlyM=
 dep    github.com/derekparker/trie     v0.0.0-20200317170641-1fdf38b7b0e9      h1:G765iDCq7bP5opdrPkXk+4V3yfkgV9iGFuheWZ/X/zY=
 dep    github.com/google/go-dap        v0.6.0  h1:Y1RHGUtv3R8y6sXq2dtGRMYrFB2hSqyFVws7jucrzX4=
 dep    github.com/hashicorp/golang-lru v0.5.4  h1:YDjusn29QI/Das2iO9M0BHnIbxPeyuCHsjMW+lJfyTc=
 dep    github.com/inconshreveable/mousetrap    v1.0.0  h1:Z8tu5sraLXCXIcARxBp/8cbvlwVa7Z1NHg9XEKhtSvM=
 dep    github.com/konsorten/go-windows-terminal-sequences      v1.0.3  h1:CE8S1cTafDpPvMhIxNJKvHsGVBgn1xWYf1NbHQhywc8=
 dep    github.com/mattn/go-colorable   v0.0.9  h1:UVL0vNpWh04HeJXV0KLcaT7r06gOH2l4OW6ddYRUIY4=
 dep    github.com/mattn/go-isatty      v0.0.3  h1:ns/ykhmWi7G9O+8a448SecJU3nSMBXJfqQkl0upE1jI=
 dep    github.com/mattn/go-runewidth   v0.0.3  h1:a+kO+98RDGEfo6asOGMmpodZq4FNtnGP54yps8BzLR4=
 dep    github.com/peterh/liner v1.2.1  h1:O4BlKaq/LWu6VRWmol4ByWfzx6MfXc5Op5HETyIy5yg=
 dep    github.com/russross/blackfriday/v2      v2.0.1  h1:lPqVAte+HuHNfhJ/0LC98ESWRz8afy9tM/0RK8m9o+Q=
 dep    github.com/shurcooL/sanitized_anchor_name       v1.0.0  h1:PdmoCO6wvbs+7yrJyMORt4/BmY5IYyJwS/kOiWx8mHo=
 dep    github.com/sirupsen/logrus      v1.6.0  h1:UBcNElsrwanuuMsnGSlYmtmgbb23qDR5dG+6X6Oo89I=
 dep    github.com/spf13/cobra  v1.1.3  h1:xghbfqPkxzxP3C/f3n5DdpAbdKLj4ZE4BWQI362l53M=
 dep    github.com/spf13/pflag  v1.0.5  h1:iy+VFUOCP1a+8yFto/drg2CJ5u0yRoB7fZw3DKv/JXA=
 dep    go.starlark.net v0.0.0-20200821142938-949cc6f4b097      h1:YiRMXXgG+Pg26t1fjq+iAjaauKWMC9cmGFrtOEuwDDg=
 dep    golang.org/x/arch       v0.0.0-20190927153633-4e8777c89be4      h1:QlVATYS7JBoZMVaf+cNjb90WD/beKVHnIxFKT4QaHVI=
 dep    golang.org/x/sys        v0.0.0-20211019181941-9d821ace8654      h1:id054HUawV2/6IGm2IV8KZQjqtwAOo2CYlOToYqa0d0=
 dep    gopkg.in/yaml.v2        v2.4.0  h1:D8xgwECY7CYvx+Y2n4sBz93Jn9JRvxdiyyo8CTfuKaY=

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
Debug Issues related to the debugging functionality of the extension. FrozenDueToAge upstream-vscode Issues that are by problems in VS Code itself.
Projects
None yet
Development

No branches or pull requests

9 participants