search

golang / vscode-go

Go extension for Visual Studio Code
https://marketplace.visualstudio.com/items?itemName=golang.Go
Other
3.89k stars 751 forks source link

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

Closed lucky-wolf closed 2 years ago

lucky-wolf commented 3 years ago

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?

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.
lucky-wolf commented 3 years ago

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 commented 3 years ago

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 commented 3 years ago

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 commented 3 years ago

@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: https://github.com/golang/vscode-go/issues/1648#issuecomment-886957881 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)?

lucky-wolf commented 3 years ago

@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 commented 3 years ago

@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 commented 3 years ago

@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 commented 3 years ago

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 commented 3 years ago

@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 https://github.com/golang/vscode-go/issues/120 I believe dlv-dap has the same issue.

polinasok commented 3 years ago

@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 commented 3 years ago

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).

zzjin commented 3 years ago

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 :heavy_check_mark: -> setting one breakpoint -> process paused (as except) -> manual click 'Continue' -> trigger http connect -> break at breakpoint -> step continue -> process continues :heavy_check_mark: -> unset one breakpoint -> process paused (as except?) -> cannot manual resume process here :x:

oxycoder commented 3 years ago

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 commented 3 years ago

@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 commented 3 years ago

@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 commented 3 years ago

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 commented 3 years ago

The issue is not fixed. Reopening.

polinasok commented 3 years ago

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 :x: although we did not get more details beyond that.

zzjin commented 3 years ago

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"}]}}

  2. 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.

  3. 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

  4. 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"}]}}

  5. 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 commented 3 years ago

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 commented 3 years ago

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

lkarlslund commented 3 years ago

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 commented 2 years ago

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.

steveheyman commented 2 years ago

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=