Skip to content
This repository has been archived by the owner on Jul 15, 2023. It is now read-only.

debugging hangs with no error message #473

Closed
jgimenez opened this issue Sep 12, 2016 · 34 comments
Closed

debugging hangs with no error message #473

jgimenez opened this issue Sep 12, 2016 · 34 comments
Assignees
Labels

Comments

@jgimenez
Copy link

Could be related to #240 but since a long time has passed since then, could also be a new issue.

When I press the "play" button a progress indication appears but nothing happens.

I'm working with:

  • Visual Studio Code Version 1.5.1 (1.5.1)
  • Go extension 0.6.43
  • go version go1.6.2 darwin/amd64
  • Delve Debugger Version: 0.11.0-alpha Build: v0.11.0

I can confirm running dlv debug, then continue on my console works.

I can not say it's a regression, since this is the first time I try it in this machine.

If I type anything in the debug console, an error message appears:

TypeError: Cannot read property 'currentGoroutine' of null\n    at GoDebugSession.evaluateRequest (/Users/gimix/.vscode/extensions/lukehoban.Go-0.6.43/out/src/debugAdapter/goDebug.js:595:45)\n    at GoDebugSession.DebugSession.dispatchRequest (/Users/gimix/.vscode/extensions/lukehoban.Go-0.6.43/node_modules/vscode-debugadapter/lib/debugSession.js:354:22)\n    at GoDebugSession.ProtocolServer._handleData (/Users/gimix/.vscode/extensions/lukehoban.Go-0.6.43/node_modules/vscode-debugadapter/lib/protocol.js:78:38)\n    at Socket.<anonymous> (/Users/gimix/.vscode/extensions/lukehoban.Go-0.6.43/node_modules/vscode-debugadapter/lib/protocol.js:23:60)\n    at emitOne (events.js:90:13)\n    at Socket.emit (events.js:182:7)\n    at readableAddChunk (_stream_readable.js:153:18)\n    at Socket.Readable.push (_stream_readable.js:111:10)\n    at Pipe.onread (net.js:531:20)
@svanas
Copy link

svanas commented Dec 16, 2016

I seem to have the same problem. I'm working with:

  • Visual Studio Code 1.8.0
  • Go extension 0.6.51
  • go version go1.7.3 darwin/amd64
  • Delve 0.11.0-alpha

Every so often, nexting (F10) in de IDE hangs. I then see this in the debug console:

TypeError: Cannot read property 'currentGoroutine' of null
    at GoDebugSession.evaluateRequest (/Users/svanas/.vscode/extensions/lukehoban.Go-0.6.51/out/src/debugAdapter/goDebug.js:595:45)
    at GoDebugSession.DebugSession.dispatchRequest (/Users/svanas/.vscode/extensions/lukehoban.Go-0.6.51/node_modules/vscode-debugadapter/lib/debugSession.js:424:22)
    at GoDebugSession.ProtocolServer._handleData (/Users/svanas/.vscode/extensions/lukehoban.Go-0.6.51/node_modules/vscode-debugadapter/lib/protocol.js:104:38)
    at Socket.<anonymous> (/Users/svanas/.vscode/extensions/lukehoban.Go-0.6.51/node_modules/vscode-debugadapter/lib/protocol.js:24:60)
    at emitOne (events.js:96:13)
    at Socket.emit (events.js:188:7)
    at readableAddChunk (_stream_readable.js:176:18)
    at Socket.Readable.push (_stream_readable.js:134:10)
    at Pipe.onread (net.js:543:20)

@ramya-rao-a
Copy link
Contributor

@roblourens Could you take a look at this?

@roblourens
Copy link
Member

This would imply that Delve returned a state of null when telling it to step. I'm not sure why that would happen. @ramya-rao-a I could add a null check, in case it's an error that can be recovered from?

@roblourens
Copy link
Member

roblourens commented Jan 11, 2017

"evaluateRequest" is in the callstack, which implies that you either have a watch, or you typed something in the console. Did you do one of those?

Separate issue but I noticed that evaluateRequest assumes that you have hit a breakpoint when it's run, and it errors if you have a watch or eval something in the console before the first time a breakpoint is hit. We could do something about that.

@svanas
Copy link

svanas commented Jan 13, 2017

"evaluateRequest" is in the callstack, which implies that you either have a watch, or you typed something in the console. Did you do one of those?

@roblourens No, but VSCode does watch all local variables in a VARIABLES panel -- could that be related to this problem?

@roblourens
Copy link
Member

roblourens commented Jan 13, 2017

It doesn't send an evaluateRequest for that, so I'm not sure where else it would have come from.

@svanas
Copy link

svanas commented Jan 14, 2017

@roblourens could command-line arguments be related to that, maybe? I get the impression a CLI-with-command-line-args is making nexting (F10) more unstable than a debug session without them.

@cyc115
Copy link

cyc115 commented May 31, 2017

Same error occurred for me
Visual Studio Code 1.12.2
Go extension 0.6.61
go version go1.8.3 darwin/amd64
Delve 1.0.0-rc.1

2017/05/31 14:12:37 server.go:73: Using API v1
2017/05/31 14:12:37 debugger.go:97: launching process with args: [./debug.test -test.v -test.run TestKeyRotation]
API server listening at: 127.0.0.1:2345
2017/05/31 14:12:39 debugger.go:505: continuing
=== RUN   TestKeyRotation
continue
TypeError: Cannot read property 'currentGoroutine' of null
    at GoDebugSession.evaluateRequest (/Users/xjqw46/.vscode/extensions/lukehoban.go-0.6.61/out/src/debugAdapter/goDebug.js:681:45)
    at GoDebugSession.DebugSession.dispatchRequest (/Users/xjqw46/.vscode/extensions/lukehoban.go-0.6.61/node_modules/vscode-debugadapter/lib/debugSession.js:430:22)
    at GoDebugSession.ProtocolServer._handleData (/Users/xjqw46/.vscode/extensions/lukehoban.go-0.6.61/node_modules/vscode-debugadapter/lib/protocol.js:104:38)
    at Socket.<anonymous> (/Users/xjqw46/.vscode/extensions/lukehoban.go-0.6.61/node_modules/vscode-debugadapter/lib/protocol.js:24:60)
    at emitOne (events.js:96:13)
    at Socket.emit (events.js:188:7)
    at readableAddChunk (_stream_readable.js:176:18)
    at Socket.Readable.push (_stream_readable.js:134:10)
    at Pipe.onread (net.js:551:20)

@ramya-rao-a
Copy link
Contributor

@derekparker Looks like delve is sending null state when the next command is executed. How do you suggest editors treat null state from delve. Can this be a bug in delve?

@ramya-rao-a
Copy link
Contributor

@cyc115 If you are able to repro consistently, then can you try to use delve from the command line and share if that works?

@cyc115
Copy link

cyc115 commented Jun 1, 2017

@ramya-rao-a it indeed does

➜  dlv test
Type 'help' for list of commands.
(dlv) break main.main
Breakpoint 1 set at 0x1673fa3 for main.main() xxxx.go:220
(dlv)

@cyc115
Copy link

cyc115 commented Jun 1, 2017

@ramya-rao-a Any idea how this bug can be bypassed at least for now? :)

@ramya-rao-a
Copy link
Contributor

Does next work as well in command line delve?

The thing is we are getting null state from delve and so the issue. We would be in a better state to fix this if we know why delve does so

@cyc115
Copy link

cyc115 commented Jun 5, 2017

@ramya-rao-a yes next and c works.

@ramya-rao-a
Copy link
Contributor

Can you share a sample code where this repress consistently?

@cyc115
Copy link

cyc115 commented Jun 5, 2017

@ramya-rao-a The docker/notary project seems to be failing.

@ahmedjafri
Copy link

ahmedjafri commented Jun 8, 2017

@ramya-rao-a Here is an example: https://github.com/willseward/delve-crash which I cannot debug from VsCode but I can with the command dlv connect 127.0.0.1:2345 and then using the dlv command line.

/var/folders/gm/fb6sb_5n6s19dyjpvqtmq_jh0000gn/T/vscode-go-debug.txt
10:06:03 PM, 6/7/2017
InitializeRequest
InitializeResponse
InitializeEvent
ConfigurationDoneRequest
ContinueRequest
ContinueResponse
ThreadsRequest
  • VSCode 1.12.2
  • vscode-go 0.6.61 (also tried building extension from HEAD - same issue)
  • delve 1.0.0-rc.1

#941, #360

@ramya-rao-a
Copy link
Contributor

@ahmedjafri I am using the same version of VS Code, the Go extension and delve as you

  • I did a go get -u github.com/willseward/delve-crash/app
  • opened the app folder in VS Code, opened main.go
  • Added breakpoint in the fmt.Println line
  • Hit F5

I am able to hit the breakpoint, step in/out/next etc.

screen shot 2017-06-07 at 10 05 13 pm

Are you on Mac, linux or Windows?

@ahmedjafri
Copy link

ahmedjafri commented Jun 8, 2017

@ramya-rao-a I'm on OSX 10.11.6. Is this remote debugging?

I cloned https://github.com/willseward/delve-crash and launched the docker container with docker-compose up --build at the root of the repo

@cyc115
Copy link

cyc115 commented Jun 8, 2017

Local debugging on https://github.com/willseward/delve-crash does not work either:
image

@ramya-rao-a
Copy link
Contributor

@ahmedjafri Not remote debugging, I tried local.

@cyc115 Can you set showLog to true and try again? This will show logs from delve in the debug console. Maybe that can help us in figuring out why delve is returning null`

@ahmedjafri
Copy link

As a point of reference, I can debug locally if I set a breakpoint initially and launch the debug session from vscode. After I hit the first breakpoint, I remove that breakpoint and hit continue. If I try to set that breakpoint again, it becomes unverified.

vscodegodebugging720

vscode-go-debug.txt

@ramya-rao-a
Copy link
Contributor

ramya-rao-a commented Jun 8, 2017

@ahmedjafri I can repro that.

The delve call here https://github.com/Microsoft/vscode-go/blob/master/src/debugAdapter/goDebug.ts#L510 doesnt seem to be returning at all.

Nothing after https://github.com/Microsoft/vscode-go/blob/master/src/debugAdapter/goDebug.ts#L508 gets printed to the logs.

Can you try the same with command line delve and see what you get?

  • Start delve
  • set breakpoint
  • remove breakpoint
  • let the program run for a while and add breakpoint again

@ahmedjafri
Copy link

Working as expected through dlv command line

[ajafri:~/external/delve-crash]$ dlv debug app/main.go
Type 'help' for list of commands.
(dlv) break main.go:13
Breakpoint 1 set at 0x2145 for main.main() ./app/main.go:13
(dlv) continue
> main.main() ./app/main.go:13 (hits goroutine(1):1 total:1) (PC: 0x2145)
     8:	func main() {
     9:	        ticker := time.NewTicker(time.Second)
    10:	        defer ticker.Stop()
    11:
    12:	        for _ = range ticker.C {
=>  13:	                fmt.Println("Hello! I'm going to sleep for 1 second.")
    14:	                time.Sleep(time.Second)
    15:	        }
    16:	}
(dlv) clear 1
Breakpoint 1 cleared at 0x2145 for main.main() ./app/main.go:13
(dlv) continue
Hello! I'm going to sleep for 1 second.
Hello! I'm going to sleep for 1 second.
Hello! I'm going to sleep for 1 second.
Hello! I'm going to sleep for 1 second.
Hello! I'm going to sleep for 1 second.
received SIGINT, stopping process (will not forward signal)> runtime.mach_semaphore_timedwait() /usr/local/go/src/runtime/sys_darwin_amd64.s:428 (PC: 0x52e13)
   423:		MOVL	sema+0(FP), DI
   424:		MOVL	sec+4(FP), SI
   425:		MOVL	nsec+8(FP), DX
   426:		MOVL	$(0x1000000+38), AX	// semaphore_timedwait_trap
   427:		SYSCALL
=> 428:		MOVL	AX, ret+16(FP)
   429:		RET
   430:
   431:	// func mach_semaphore_signal(sema uint32) int32
   432:	TEXT runtime·mach_semaphore_signal(SB),NOSPLIT,$0
   433:		MOVL	sema+0(FP), DI
(dlv) break main.go:13
Breakpoint 2 set at 0x2145 for main.main() ./app/main.go:13
(dlv) continue
> main.main() ./app/main.go:13 (hits goroutine(1):1 total:1) (PC: 0x2145)
     8:	func main() {
     9:	        ticker := time.NewTicker(time.Second)
    10:	        defer ticker.Stop()
    11:
    12:	        for _ = range ticker.C {
=>  13:	                fmt.Println("Hello! I'm going to sleep for 1 second.")
    14:	                time.Sleep(time.Second)
    15:	        }
    16:	}
(dlv) clear 2
Breakpoint 2 cleared at 0x2145 for main.main() ./app/main.go:13
(dlv) continue
Hello! I'm going to sleep for 1 second.
Hello! I'm going to sleep for 1 second.
Hello! I'm going to sleep for 1 second.
Hello! I'm going to sleep for 1 second.
Hello! I'm going to sleep for 1 second.
Hello! I'm going to sleep for 1 second.
received SIGINT, stopping process (will not forward signal)> runtime.mach_semaphore_timedwait() /usr/local/go/src/runtime/sys_darwin_amd64.s:428 (PC: 0x52e13)
   423:		MOVL	sema+0(FP), DI
   424:		MOVL	sec+4(FP), SI
   425:		MOVL	nsec+8(FP), DX
   426:		MOVL	$(0x1000000+38), AX	// semaphore_timedwait_trap
   427:		SYSCALL
=> 428:		MOVL	AX, ret+16(FP)
   429:		RET
   430:
   431:	// func mach_semaphore_signal(sema uint32) int32
   432:	TEXT runtime·mach_semaphore_signal(SB),NOSPLIT,$0
   433:		MOVL	sema+0(FP), DI
(dlv) ^C
(dlv) exit

@ramya-rao-a
Copy link
Contributor

ramya-rao-a commented Jun 9, 2017

That was very helpful @ahmedjafri Thanks! I can repro the exact same thing

received SIGINT, stopping process (will not forward signal)

I am guessing you did a ctrl+c at this point.

Looking at the steps followed by the debugger, this is what is missing I believe.
I wonder if our debugger is failing to interrupt the running process and ask to set a breakpoint

@roblourens Does that make sense? ( I might be way off here)

@roblourens
Copy link
Member

Yes, I think in general we don't handle setting BPs while the process is active very well. The solution might be that when a breakpoint is set and Delve isn't paused, we send a SIGINT first, set the bps, and continue. Would have to experiment to say for sure.

@ahmedjafri
Copy link

@ramya-rao-a

received SIGINT, stopping process (will not forward signal)

Yep that is me hitting ctrl+c

@byron70
Copy link

byron70 commented Jul 21, 2017

I am having this exact issue when I have any parameters in the "buildFlags" the the launch.json.

    "version": "0.2.0",
    "configurations": [
        {
            "stopOnEntry": false,
            "name": "test account",
            "type": "go",
            "request": "launch",
            "mode": "test",
            "cwd": "${workspaceRoot}/lib/ssm/account",
            "program": "${workspaceRoot}/lib/ssm/account",
            "args": [
                "-test.v",
                "-test.run",
                "TestCreate"
            ],
            "buildFlags": "-x -v -tags 'unit'",
            "port": 2345,
            "host": "127.0.0.1",
            "trace": "verbose",
            "showLog": true
        }
    ]
}

After banging on this for some time, I found increasing the pause in the following line to something like 500+ ms before the RPC connection attempt seems to alleviate the issue and things continue as expected.

https://github.com/Microsoft/vscode-go/blob/0.6.62/src/debugAdapter/goDebug.ts#L296

If I remove the buildFlags from the launch configuration things work just fine. The code doesn't have to build in that instance. The code is fairly simple and compiles fairly quickly.

Here is a dump of a trace with the build flags. I've removed some things for privacy sake.

Verbose logs are written to:
C:\Users\mannb\AppData\Local\Temp\vscode-go-debug.txt
3:29:28 PM, 7/21/2017
InitializeRequest
InitializeResponse
Using dlv at: D:\projects\cdn\go\bin\dlv.exe
["test","--headless=true","--listen=127.0.0.1:2345"]
WORK=C:\Users\mannb\AppData\Local\Temp\go-build948495966
mkdir -p $WORK\{....}\lib\ssm\account\_test\{....}\lib\ssm\
mkdir -p $WORK\{....}\lib\ssm\account\_test\_obj_test\
cd D:\projects\cdn\go\src\{....}\lib\ssm\account
"D:\\Go\\pkg\\tool\\windows_amd64\\compile.exe" -o "C:\\Users\\mannb\\AppData\\Local\\Temp\\go-build948495966\\{....}lib\\ssm\\account\\_test\\{....}lib\\ssm\\account.a" -trimpath "C:\\Users\\mannb\\AppData\\Local\\Temp\\go-build948495966" -N -l -p {....}/lib/ssm/account -complete -buildid 172609513b0df491632e99722f5926d2bbdf0a62 -D _/D_/projects/cdn/go/src/{....}/lib/ssm/account -I "C:\\Users\\mannb\\AppData\\Local\\Temp\\go-build948495966" -I "D:\\projects\\cdn\\go\\pkg\\windows_amd64" -pack "D:\\projects\\cdn\\go\\src\\{....}lib\\ssm\\account\\account.go" "D:\\projects\\cdn\\go\\src\\{....}lib\\ssm\\account\\account_test.go"
mkdir -p $WORK\{....}\lib\ssm\account\_test\
cd $WORK\{....}\lib\ssm\account\_test
"D:\\Go\\pkg\\tool\\windows_amd64\\compile.exe" -o "C:\\Users\\mannb\\AppData\\Local\\Temp\\go-build948495966\\{....}lib\\ssm\\account\\_test\\main.a" -trimpath "C:\\Users\\mannb\\AppData\\Local\\Temp\\go-build948495966" -N -l -p main -complete -D "" -I "C:\\Users\\mannb\\AppData\\Local\\Temp\\go-build948495966\\{....}lib\\ssm\\account\\_test" -I "C:\\Users\\mannb\\AppData\\Local\\Temp\\go-build948495966" -pack "C:\\Users\\mannb\\AppData\\Local\\Temp\\go-build948495966\\{....}lib\\ssm\\account\\_test\\_testmain.go"
cd .
"D:\\Go\\pkg\\tool\\windows_amd64\\link.exe" -o "C:\\Users\\mannb\\AppData\\Local\\Temp\\go-build948495966\\{....}lib\\ssm\\account\\_test\\account.test.exe" -L "C:\\Users\\mannb\\AppData\\Local\\Temp\\go-build948495966\\{....}lib\\ssm\\account\\_test" -L "C:\\Users\\mannb\\AppData\\Local\\Temp\\go-build948495966" -L "D:\\projects\\cdn\\go\\pkg\\windows_amd64" -extld=gcc -buildmode=exe "C:\\Users\\mannb\\AppData\\Local\\Temp\\go-build948495966\\{....}lib\\ssm\\account\\_test\\main.a"
mkdir -p d:\projects\cdn\go\src\{....}\lib\ssm\account\
cp $WORK\{....}\lib\ssm\account\_test\account.test.exe d:\projects\cdn\go\src\{....}\lib\ssm\account\debug.test
2017/07/21 15:29:30 server.go:73: Using API v1
2017/07/21 15:29:30 debugger.go:97: launching process with args: [./debug.test -test.v -test.run TestCreate]
API server listening at: 127.0.0.1:2345

This is where things stop. If I hit enter 2 times on the debug console, I receive the following. Also, if I don't hit enter a couple of times, Ctl+Shift+F5 (debug restart) won't work... but a debug stop does.

Please start a debug session to evaluate
TypeError: Cannot read property 'currentGoroutine' of null
    at GoDebugSession.evaluateRequest (C:\Users\mannb\.vscode\extensions\lukehoban.go-0.6.62\out\src\debugAdapter\goDebug.js:669:45)
    at GoDebugSession.DebugSession.dispatchRequest (C:\Users\mannb\.vscode\extensions\lukehoban.go-0.6.62\node_modules\vscode-debugadapter\lib\debugSession.js:430:22)
    at GoDebugSession.ProtocolServer._handleData (C:\Users\mannb\.vscode\extensions\lukehoban.go-0.6.62\node_modules\vscode-debugadapter\lib\protocol.js:104:38)
    at Socket.<anonymous> (C:\Users\mannb\.vscode\extensions\lukehoban.go-0.6.62\node_modules\vscode-debugadapter\lib\protocol.js:24:60)
    at emitOne (events.js:96:13)
    at Socket.emit (events.js:188:7)
    at readableAddChunk (_stream_readable.js:176:18)
    at Socket.Readable.push (_stream_readable.js:134:10)
    at Pipe.onread (net.js:551:20)
EvaluateRequest

@byron70
Copy link

byron70 commented Jul 21, 2017

Guess I should note for anyone wanting to test this possible fix locally. For Windows just update that line in your local file... probably here for Windows. Linux might have a similar path.

%USERPROFILE%\.vscode\extensions\lukehoban.go-0.6.62\out\src\debugAdapter\goDebug.js

@ramya-rao-a
Copy link
Contributor

@byron70 Yours is a different issue in that you want to increase the time before the connecting so that there is enough time for build.

cc @roblourens for increasing the time interval int he setTimeout

This current issue on the other hand is about the ability to add breakpoints when the Go program is already running.

@roblourens
Copy link
Member

roblourens commented Jul 24, 2017

Other debug adapters allow you to override the timeout, and it would be easy to do that (I don't know whether there's a smarter way to detect when the build is complete)

@EdwinCloud101
Copy link

I'm having the same issue running from VS Code running a simple hello world using fmt.Scanf

@primalmotion
Copy link
Contributor

primalmotion commented Oct 7, 2017

I think this is an issue with delve. I opened a reduction here derekparker/delve#982

It seems the headless rpc server get stuck for some reason. I've noticed that you can send various commands, they leave VSCode without problem and never get any response back. Then if you brutally kill the debugger, you see one error in the VSCode debug console about "connection closed" or something for each command that never got response.

@ramya-rao-a
Copy link
Contributor

Multiple issues are being talked abt here, I'll try to address them here

@jgimenez @svanas I dont have the details if you used -v in the buildflags or -test.v in the args. If you did, then the latest update to the Go extension has the fix. If you didnt, and can still repro this issue, please log a new issue.

All,
I am locking this thread as it is getting hard to maintain the different threads in a single issue.
Feel free to log a new issue.

@microsoft microsoft locked and limited conversation to collaborators Nov 27, 2017
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
Projects
None yet
Development

No branches or pull requests

9 participants