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: detach leaves the delve or the debugee hang (remote) #497

Closed
leggettc18 opened this issue Aug 8, 2020 · 15 comments
Closed

debug: detach leaves the delve or the debugee hang (remote) #497

leggettc18 opened this issue Aug 8, 2020 · 15 comments
Labels
debug/legacy legacy debug adapter related issues - new issues won't be fixed Debug Issues related to the debugging functionality of the extension. FrozenDueToAge WaitingForInfo Issue is not actionable because of missing required information, which needs to be provided.

Comments

@leggettc18
Copy link

Please direct general questions to:

Please review the documentation before filing an issue.
Helpful pages include:

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
    • 1.14.4
  • Run code -v or code-insiders -v to get version of VS Code or VS Code Insiders
    • 1.47.3
  • Check your installed extensions to get the version of the VS Code Go extension
    • 0.16.1
  • Run go env to get the go development environment details

GOARCH="amd64"
GOBIN=""
GOCACHE="/home/chris/.cache/go-build"
GOENV="/home/chris/.config/go/env"
GOEXE=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GOINSECURE=""
GONOPROXY=""
GONOSUMDB=""
GOOS="linux"
GOPATH="/home/chris/go"
GOPRIVATE=""
GOPROXY="https://proxy.golang.org,direct"
GOROOT="/usr/local/go"
GOSUMDB="sum.golang.org"
GOTMPDIR=""
GOTOOLDIR="/usr/local/go/pkg/tool/linux_amd64"
GCCGO="gccgo"
AR="ar"
CC="gcc"
CXX="g++"
CGO_ENABLED="1"
GOMOD=""
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-build060961081=/tmp/go-build -gno-record-gcc-switches"

Also using Delve version 1.5.0

Share the Go related settings you have added/edited

Run Preferences: Open Settings (JSON) command to open your settings.json file.
Share all the settings with the go. or ["go"] or gopls prefixes.

Describe the bug

I have a couple of weird issues with the vscode debugger attaching to a headless delve instance. One or both of these may be delve instances, but I'm pretty sure they are vscode debugging issues.

First off, here is my launch.json file

{
    // Use IntelliSense to learn about possible attributes.
    // Hover to view descriptions of existing attributes.
    // For more information, visit: https://go.microsoft.com/fwlink/?linkid=830387
    "version": "0.2.0",
    "configurations": [

        {
            "name": "Connect to Delve",
            "type": "go",
            "request": "attach",
            "remotePath": "${workspaceRoot}",
            "mode": "remote",
            "port": 2345,
            "host": "127.0.0.1",
            "apiVersion": 2,
            "showLog": true,
            "trace": "verbose"
        }
    ]
}

I build my code with go build -o $GOPATH/bin/devmarks -i (which you can find here) and run the server with devmarks serve. Then in another terminal I run delve in headless mode dlv attach --headless --listen=:2345 --api-version=2 $(pgrep devmarks) Then I run the debugger, put in some breakpoints, and make an API request to my server. That's when the odd stuff starts.

Firstly whenever my breakpoint is in any of the files (out of the ones I've tried so far at least) in the api folder (api/bookmark.go for example, I can't see the variables in the side window. I also do not see them in the debug console. If I put the breakpoint in the app folder somewhere (for example in app/bookmark.go, I can see the variables just fine, and can also see them in the debug log (although I may need to hide and unhide the variables pane to make it show up, if I do that in the api folder I get the Local and Global headers but it just spins).

To add to that, if I stop VSCode's Debugger for whatever reason, I can't reconnect to it without quitting my server's process and restarting both it and delve. Delve's logs don't appear to indicate any errors or crashes.

Steps to reproduce the behavior:

  1. Run my server with devmarks serve
  2. Start a headless delve instance with dlv attach --headless --listen=:2345 --api-version=2 $(pgrep devmarks)
  3. Connect VSCode's debugger to the delve instance with my above launch.json
  4. Add Breakpoints and make API requests, see how sometimes the variables are not seen.
  5. Quit the VSCode debugger and attempt to reconnect to Delve, see it hang until you restart the delve instance (which also requires restarting my api server),

Screenshots or recordings

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

@leggettc18
Copy link
Author

To add to this, I realized I was a couple of minor versions behind for go so I updated and rebuilt my server and I still cannot see the variables for certain breakpoints. My go version is now 1.14.7

Also because I did not specify I am on Pop!_OS 20.04.

@hyangah
Copy link
Contributor

hyangah commented Aug 10, 2020

@leggettc18 Can you please compile the go code with the flags as described in https:/golang/vscode-go/blob/master/docs/debugging.md#try-building-your-binary-without-compiler-optimizations (or see https://golang.org/doc/gdb#Introduction)
For debugging dlv needs extra debugging information.

@hyangah hyangah added the WaitingForInfo Issue is not actionable because of missing required information, which needs to be provided. label Aug 10, 2020
@leggettc18
Copy link
Author

Yeah I can try that tonight, not able to get in front of my computer at the moment.

@leggettc18
Copy link
Author

leggettc18 commented Aug 10, 2020

So I tried the command listed at the first link and got this:

go build -gcflags="all=-N -l" -o $GOPATH/bin/devmarks -i

go build unicode/utf8: copying /tmp/go-build143356859/b025/_pkg_.a: open /usr/local/go/pkg/linux_amd64/unicode/utf8.a: permission denied
go build internal/race: copying /tmp/go-build143356859/b014/_pkg_.a: open /usr/local/go/pkg/linux_amd64/internal/race.a: permission denied
go build runtime/internal/sys: copying /tmp/go-build143356859/b012/_pkg_.a: open /usr/local/go/pkg/linux_amd64/runtime/internal/sys.a: permission denied
go build math/bits: copying /tmp/go-build143356859/b023/_pkg_.a: open /usr/local/go/pkg/linux_amd64/math/bits.a: permission denied
go build crypto/internal/subtle: copying /tmp/go-build143356859/b060/_pkg_.a: open /usr/local/go/pkg/linux_amd64/crypto/internal/subtle.a: permission denied
go build crypto/subtle: copying /tmp/go-build143356859/b061/_pkg_.a: open /usr/local/go/pkg/linux_amd64/crypto/subtle.a: permission denied
go build container/list: copying /tmp/go-build143356859/b057/_pkg_.a: open /usr/local/go/pkg/linux_amd64/container/list.a: permission denied
go build unicode/utf16: copying /tmp/go-build143356859/b070/_pkg_.a: open /usr/local/go/pkg/linux_amd64/unicode/utf16.a: permission denied
go build internal/nettrace: copying /tmp/go-build143356859/b090/_pkg_.a: open /usr/local/go/pkg/linux_amd64/internal/nettrace.a: permission denied
go build runtime/internal/atomic: copying /tmp/go-build143356859/b010/_pkg_.a: open /usr/local/go/pkg/linux_amd64/runtime/internal/atomic.a: permission denied
go build vendor/golang.org/x/crypto/cryptobyte/asn1: copying /tmp/go-build143356859/b085/_pkg_.a: open /usr/local/go/pkg/linux_amd64/vendor/golang.org/x/crypto/cryptobyte/asn1.a: permission denied
go build internal/cpu: copying /tmp/go-build143356859/b008/_pkg_.a: open /usr/local/go/pkg/linux_amd64/internal/cpu.a: permission denied
go build sync/atomic: copying /tmp/go-build143356859/b015/_pkg_.a: open /usr/local/go/pkg/linux_amd64/sync/atomic.a: permission denied
go build vendor/golang.org/x/crypto/internal/subtle: copying /tmp/go-build143356859/b095/_pkg_.a: open /usr/local/go/pkg/linux_amd64/vendor/golang.org/x/crypto/internal/subtle.a: permission denied
go build encoding: copying /tmp/go-build143356859/b129/_pkg_.a: open /usr/local/go/pkg/linux_amd64/encoding.a: permission denied
go build unicode: copying /tmp/go-build143356859/b026/_pkg_.a: open /usr/local/go/pkg/linux_amd64/unicode.a: permission denied
go build runtime/cgo: copying /tmp/go-build143356859/b092/_pkg_.a: open /usr/local/go/pkg/linux_amd64/runtime/cgo.a: permission denied

After that I tried just go build -gcflags="-N -l" -o $GOPATH/bin/devmarks -i and it built, but gave me the same result as without the flags, no variables shown when the breakpoint is in certain files.

@hyangah
Copy link
Contributor

hyangah commented Aug 10, 2020

@leggettc18 drop the -i flag. You need -gcflags="all=-N -l".

@leggettc18
Copy link
Author

Ah I see, so the -i and the all from -gcflags was giving me the issues because it was trying to install dependencies without the compiler optimizations then? Makes enough sense I suppose, so I guess if I introduce new dependencies I build once with the -i flag and then if I need to debug build again with the line removing compiler optimizations? I can work with that I suppose.

@leggettc18
Copy link
Author

So that's the variable issue solved, there is still the other issue though, where if I detach from the delve instance, I can't reconnect. I can work around that by restarting the delve instance, but I would prefer not to if I can help it.

@hyangah hyangah changed the title Couple of issues with delve debugging debug: detach leaves the delve or the debugee hang Aug 11, 2020
@hyangah hyangah added Debug Issues related to the debugging functionality of the extension. NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. labels Aug 11, 2020
@hyangah
Copy link
Contributor

hyangah commented Aug 11, 2020

@leggettc18 can you please add logging (instruction: https:/golang/vscode-go/blob/master/docs/debugging.md#enable-logging) and share the trace when you detach?

/cc @polinasok @quoctruong

@leggettc18
Copy link
Author

From my terminal where the dlv instance is running:

API server listening at: [::]:2345
2020-08-10T18:55:18-04:00 info layer=debugger attaching to pid 88759
2020-08-10T18:55:21-04:00 info layer=debugger created breakpoint: &api.Breakpoint{ID:1, Name:"", Addr:0xb36847, Addrs:[]uint64{0xb36847}, File:"/home/chris/Projects/devmarks/api/api/bookmark.go", Line:119, FunctionName:"leggett.dev/devmarks/api/api.(*API).UpdateBookmarkById", Cond:"", Tracepoint:false, TraceReturn:false, Goroutine:false, Stacktrace:0, Variables:[]string(nil), LoadArgs:(*api.LoadConfig)(0xc00176a180), LoadLocals:(*api.LoadConfig)(0xc00176a1b0), HitCount:map[string]uint64{}, TotalHitCount:0x0}
2020-08-10T18:55:21-04:00 debug layer=debugger continuing
2020-08-10T19:02:29-04:00 debug layer=debugger continuing
2020-08-10T19:18:30-04:00 error layer=rpc writing response:write tcp 127.0.0.1:2345->127.0.0.1:45186: use of closed network connection
Process 88759 has exited with status 0
chris@pop-os:~/Projects/devmarks/api$ dlv attach --headless --listen=:2345 --log --api-version=2 $(pgrep devmarks) --log-output=rpc
API server listening at: [::]:2345
2020-08-11T20:59:03-04:00 debug layer=rpc API server pid = 98747
2020-08-11T20:59:12-04:00 debug layer=rpc <- RPCServer.GetVersion(api.GetVersionIn{})
2020-08-11T20:59:12-04:00 debug layer=rpc -> *api.GetVersionOut{"DelveVersion":"Version: 1.5.0\nBuild: $Id: ca5318932770ca063fc9885b4764c30bfaf8a199 $","APIVersion":2,"Backend":"native","TargetGoVersion":"Go cmd/compile go1.14.7","MinSupportedVersionOfGo":"1.12.0","MaxSupportedVersionOfGo":"1.15.0"} error: ""
2020-08-11T20:59:12-04:00 debug layer=rpc (async 2) <- RPCServer.State(rpc2.StateIn{"NonBlocking":true})
2020-08-11T20:59:12-04:00 debug layer=rpc (async 2) -> rpc2.StateOut{"State":{"Running":false,"Recording":false,"currentThread":{"id":98681,"pc":4653139,"file":"/usr/local/go/src/runtime/sys_linux_amd64.s","line":568,"function":{"name":"runtime.futex","value":4653104,"type":0,"goType":0,"optimized":true},"goroutineID":0,"ReturnValues":null},"Threads":[{"id":98682,"pc":4653139,"file":"/usr/local/go/src/runtime/sys_linux_amd64.s","line":568,"function":{"name":"runtime.futex","value":4653104,"type":0,"goType":0,"optimized":true},"goroutineID":0,"ReturnValues":null},{"id":98683,"pc":4653139,"file":"/usr/local/go/src/runtime/sys_linux_amd64.s","line":568,"function":{"name":"runtime.futex","value":4653104,"type":0,"goType":0,"optimized":true},"goroutineID":0,"ReturnValues":null},{"id":98684,"pc":4653568,"file":"/usr/local/go/src/runtime/sys_linux_amd64.s","line":705,"function":{"name":"runtime.epollwait","value":4653536,"type":0,"goType":0,"optimized":true},"goroutineID":0,"ReturnValues":null},{"id":98685,"pc":4653139,"file":"/usr/local/go/src/runtime/sys_linux_amd64.s","line":568,"function":{"name":"runtime.futex","value":4653104,"type":0,"goType":0,"optimized":true},"goroutineID":0,"ReturnValues":null},{"id":98686,"pc":4653139,"file":"/usr/local/go/src/runtime/sys_linux_amd64.s","line":568,"function":{"name":"runtime.futex","value":4653104,"type":0,"goType":0,"optimized":true},"goroutineID":0,"ReturnValues":null},{"id":98688,"pc":4653139,"file":"/usr/local/go/src/runtime/sys_linux_amd64.s","line":568,"function":{"name":"runtime.futex","value":4653104,"type":0,"goType":0,"optimized":true},"goroutineID":18,"ReturnValues":null},{"id":98689,"pc":4653139,"file":"/usr/local/go/src/runtime/sys_linux_amd64.s","line":568,"function":{"name":"runtime.futex","value":4653104,"type":0,"goType":0,"optimized":true},"goroutineID":0,"ReturnValues":null},{"id":98681,"pc":4653139,"file":"/usr/local/go/src/runtime/sys_linux_amd64.s","line":568,"function":{"name":"runtime.futex","value":4653104,"type":0,"goType":0,"optimized":true},"goroutineID":0,"ReturnValues":null}],"NextInProgress":false,"exited":false,"exitStatus":0,"When":""}} error: ""
2020-08-11T20:59:12-04:00 debug layer=rpc (async 3) <- RPCServer.Command(api.DebuggerCommand{"name":"continue","ReturnInfoLoadConfig":null})
2020-08-11T20:59:43-04:00 debug layer=rpc (async 4) <- RPCServer.State(rpc2.StateIn{"NonBlocking":true})
2020-08-11T20:59:43-04:00 debug layer=rpc (async 4) -> rpc2.StateOut{"State":{"Running":true,"Recording":false,"Threads":null,"NextInProgress":false,"exited":false,"exitStatus":0,"When":""}} error: ""

VSCode debug log

Verbose logs are written to:
/tmp/vscode-go-debug.txt
2020-8-12, 00:59:11.915 UTC
From client: initialize({"clientID":"vscode","clientName":"Visual Studio Code","adapterID":"go","pathFormat":"path","linesStartAt1":true,"columnsStartAt1":true,"supportsVariableType":true,"supportsVariablePaging":true,"supportsRunInTerminalRequest":true,"locale":"en-us","supportsProgressReporting":true})
InitializeRequest
To client: {"seq":0,"type":"response","request_seq":1,"command":"initialize","success":true,"body":{"supportsConfigurationDoneRequest":true,"supportsSetVariable":true}}
InitializeResponse
From client: attach({"name":"Connect to Delve","type":"go","request":"attach","remotePath":"/home/chris/Projects/devmarks/api","mode":"remote","port":2345,"host":"127.0.0.1","apiVersion":2,"showLog":true,"trace":"verbose","logOutput":"rpc","packagePathToGoModPathMap":{"/home/chris/Projects/devmarks/api/app":"/home/chris/Projects/devmarks/api","/home/chris/Projects/devmarks/api/api":"/home/chris/Projects/devmarks/api","/home/chris/Projects/devmarks/api/.vscode":"/home/chris/Projects/devmarks/api","/home/chris/Projects/devmarks/api/cmd":"/home/chris/Projects/devmarks/api","/home/chris/Projects/devmarks/api/db":"/home/chris/Projects/devmarks/api","/home/chris/Projects/devmarks/api/migrations":"/home/chris/Projects/devmarks/api","/home/chris/Projects/devmarks/api":"/home/chris/Projects/devmarks/api",".":"","/home/chris/Projects/devmarks/api/model":"/home/chris/Projects/devmarks/api"},"env":{"GOPATH":"/home/chris/go","ELECTRON_RUN_AS_NODE":"1","GJS_DEBUG_TOPICS":"JS ERROR;JS LOG","USER":"chris","LANGUAGE":"en_US:en","LC_TIME":"en_US.UTF-8","SSH_AGENT_PID":"2142","XDG_SESSION_TYPE":"x11","SHLVL":"0","HOME":"/home/chris","QT4_IM_MODULE":"ibus","DESKTOP_SESSION":"pop","GIO_LAUNCHED_DESKTOP_FILE":"/usr/share/applications//code.desktop","GTK_MODULES":"gail:atk-bridge:appmenu-gtk-module","GNOME_SHELL_SESSION_MODE":"pop","LC_MONETARY":"en_US.UTF-8","MANAGERPID":"1895","DBUS_SESSION_BUS_ADDRESS":"unix:path=/run/user/1000/bus","GOROOT":"/usr/local/go","GIO_LAUNCHED_DESKTOP_FILE_PID":"5405"[...]
AttachRequest
Start remote debugging: connecting 127.0.0.1:2345
To client: {"seq":0,"type":"event","event":"initialized"}
InitializeEvent
To client: {"seq":0,"type":"response","request_seq":2,"command":"attach","success":true}
From client: configurationDone(undefined)
ConfigurationDoneRequest
ContinueRequest
To client: {"seq":0,"type":"response","request_seq":3,"command":"configurationDone","success":true}
ContinueResponse
From client: threads(undefined)
To client: {"seq":0,"type":"response","request_seq":4,"command":"threads","success":true,"body":{"threads":[{"id":1,"name":"Dummy"}]}}
From client: disconnect({"restart":false})
DisconnectRequest
HaltRequest

@hyangah
Copy link
Contributor

hyangah commented Sep 18, 2020

@leggettc18 I just noticed there is a breakpoint setup (not sure how it happened because I don't see it from the VSCODE debug log, but see from your terminal log).

I just encountered a similar issue but realized I detached without clearing the breakpoints, and wondered if uncleared breakpoints left the debugee hang.

@polinasok
Copy link
Contributor

polinasok commented Sep 29, 2020

@leggettc18
Could you please relate the logs you posted to your steps to reproduce? I am having a hart time seeing how they map to each other. For example, why did process 88759 exit in the middle of this?
Could you please use --log-output=rpc,debugger to get more logging from delve?
Does everything work as expected if you do not set breakpoints and issue any API requests or issue different sets of those? Does it matter if you are paused or running when you disconnect the debug session?

@polinasok
Copy link
Contributor

Start a headless delve instance with dlv attach --headless --listen=:2345 --api-version=2 $(pgrep devmarks)
if I detach from the delve instance, I can't reconnect

You cannot reconnect to a dlv server if it is not running in a mode that supports multiple client connections (--accept-multiclient). Without that mode, the server is a single-use server and should exit when you exit the debug session. The existing adapter doesn't handle this correctly and lets an unresponsive server keep running (see #748), but if you use dlv connect <host:port> instead you will observe this behavior.

@polinasok
Copy link
Contributor

polinasok commented Mar 8, 2021

The issue title ("detach leaves the delve or the debugee hang") suggests two problems.

  1. Hung delve. I addressed this issue in the comment above.
  2. Hung debuggee. This would be a separate issue, but I am unable to reproduce it. Please note that we have logic to issue a continue request before disconnecting from a remote debugging server
    if (this.delve.isRemoteDebugging) {
    if (!(await this.isDebuggeeRunning())) {
    log("Issuing a continue command before closing Delve's connection as the debuggee is not running.");
    this.continue();

    However, while the process should continue running after the debug session is over, because an unresponsive debugger is already attached (due to (1)), another attempt to dlv-attach to it would fail. If you kill the unresponsive debugger, you should be able to dlv-attach to it again.

@polinasok polinasok added DlvDAP and removed NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. WaitingForInfo Issue is not actionable because of missing required information, which needs to be provided. labels Mar 8, 2021
@polinasok polinasok changed the title debug: detach leaves the delve or the debugee hang debug: detach leaves the delve or the debugee hang (remote) Mar 8, 2021
@polinasok polinasok added the WaitingForInfo Issue is not actionable because of missing required information, which needs to be provided. label Mar 23, 2021
@polinasok
Copy link
Contributor

polinasok commented Mar 23, 2021

@leggettc18 @hyangah

  1. Hung delve. I addressed this issue in the comment above.
  2. Hung debuggee. This would be a separate issue, but I am unable to reproduce it. Please note that we have logic to issue a continue request before disconnecting from a remote debugging server

As I have not heard a confirmation that 2 was indeed a known (as opposed to suspected) problem, I propose closing this as per 1 as a duplicate of #748.

@hyangah
Copy link
Contributor

hyangah commented Mar 23, 2021

@polinasok thanks for the followup.
@leggettc18 please file a new issue if you are still having the same issue. --accept-multiclient and make sure no breakpoint set up hanging (check delve script, etc...) And -i flag from go command is officially deprecated from go1.16 (https://golang.org/doc/go1.16#go-command)

@polinasok polinasok added the debug/legacy legacy debug adapter related issues - new issues won't be fixed label Jul 16, 2021
@golang golang locked and limited conversation to collaborators Jul 16, 2022
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
debug/legacy legacy debug adapter related issues - new issues won't be fixed Debug Issues related to the debugging functionality of the extension. FrozenDueToAge WaitingForInfo Issue is not actionable because of missing required information, which needs to be provided.
Projects
None yet
Development

No branches or pull requests

4 participants