Debugging goes into proc.go at every step

[mmcmm]

I'm using go modules, and every debug step into or step over goes into a proc.go file gopark function and then goes back. You can see it in this gif. https://gyazo.com/adb4a54cc467ce372a4b5595b72d150f

Steps to Reproduce:

Have some test and try to debug them.

launch.json

{ "name": "Test", "type": "go", "mode": "test", "request": "launch", "remotePath": "", "port": 2346, "host": "127.0.0.1", "program": "${workspaceRoot}/test", "env": { "GOPATH": "/Users/user/golang" }, "args": ["-test.short"], "showLog": false }

[ramya-rao-a]

Can you try running dlv from the command line, debug the same test and see if the step into/over in that case does something similar?

[stffabi]

We are seeing the same behaviour on different machines in our company. I'll try to test dlv from the command line later this day.

[virtuald]

I'm seeing the same issue, on go version go1.10.4 darwin/amd64

Delve Debugger
Version: 1.1.0
Build: $Id: 1990ba12450cab9425a2ae62e6ab988725023d5c $

[virtuald]

Is there a way to easily obtain the commandline that vscode is providing to dlv? That seems like it would be useful.

[ramya-rao-a]

@virtuald Of course. I just added a note on it at https://github.com/Microsoft/vscode-go/wiki/Debugging-Go-code-using-VS-Code#try-using-dlv-from-the-terminalcommand-line

[stffabi]

@ramya-rao-a I've tried running dlv from the command line. An attach from vscode to the running dlv leads to the same behaviour. Stepping into/out goes into proc.go gopark. Furthermore I've now even seen some assembler files popup during the debugging.

[ramya-rao-a]

@stffabi I didn't mean attaching vscode to a running dlv instance. I meant using the dlv client directly. Run dlv debug on the folder that has your file. That will open an interactive session where you can add break points, step into/over code using commands

[anphung]

Same here, and it's very slow for it to Step into/over, or showing Variables in the debug tab.
I try with using dlv debug, and use interactive session b, c, n, it's quite fast there.

$ go version
go version go1.11 darwin/amd64
$ dlv version
Delve Debugger
Version: 1.1.0
Build: $Id: 1990ba12450cab9425a2ae62e6ab988725023d5c
$ code --version
1.29.1
bc24f98b5f70467bc689abf41cc5550ca637088e
x64

[anphung]

Inspecting the vscode-go-debug.txt from the debug, global vars request is huge for me, I guess thats the reason. Is there anyway to disable global vars?

[ramya-rao-a]

@anphung Is your problem also about every step in going into the proc.go file or is it just about slowness?

[anphung]

It's both. Actually, it jumps into proc.go for around several seconds (the time varies). If just wait for several seconds then it'll jump back to the next line that it supposed to jump in the first place.
I guess it jumps like that because of the slowness, and the slowness is because of loading all global vars.

[ramya-rao-a]

Inspecting the vscode-go-debug.txt from the debug, global vars request is huge for me, I guess thats the reason. Is there anyway to disable global vars?

Thats an interesting find. There is no official way to disable global vars, but can you try the below

• Open the file ~/.vscode/extensions/ms-vscode.go-0.7.0/out/src/debugAdapter/goDebug.js. If you are using Insiders then use .vscode-insiders. If you are not on the latest version of VS Code (0.7.0), then use the appropriate version
• Find the function getPackageInfo, and add return Promise.resolve(null); to the first line inside the function. This will return null for package and consequently the global vars call will not be made.
• Reload VS Code

Check if this solves the problem of slowness

[anphung]

That's faster. It still jumps into proc.go sometime, but jumps out immediately (not several seconds anymore).

[anphung]

Digging a little deeper, most responses from delve are too much for vscode-go (vscode-go only extracts part of the responses), such as ListGoroutines, StackTraceRequest, it takes lots of bandwidth, hence the slowness.

[mmcmm]

@ramya-rao-a I can concur, is also very slow to step over, and I tried to reinstall dlv to no avail, I remember getting slow suddenly, months ago, I think it was an update.

[ramya-rao-a]

Is this only with certain code bases or even a simple hello world program? If you can provide a sample code that I can try this on, I can look deeper into what is causing the slowness as well as the jump to proc.go

I try with using dlv debug, and use interactive session b, c, n, it's quite fast there.

@anphung When you used dlv debug, did you see the jump to proc.go there as well?

[mmcmm]

@ramya-rao-a here it is with a hello world, https://gyazo.com/a90e25806cbbf6013d4af25a1c0220c2 it doesn't seem that slow actually, but still flashes into proc.go, but it flashes, on the normal codebase it would just stop into proc.go and you need to step over it.

[anphung]

With dlv debug, the speed is just like "native", no proc.go jump, pretty fast.
With vscode, in normal code base, sometime it stops in proc.go for long, some time several seconds, it's up to whether I'm running some other heavy programs in my machine.

Delve RPCs give out much information, in exchange vscode only uses part of it. For example, ListGoroutines, vscode only extract id, function name from goroutines.

I guess vscode can't do much here, unless people build a more lightweight RPCs in delve project.

Here is a sample: Set breakpoint at line 19, if you can't see the slowness or jumping to proc.go, try increase n.
https://play.golang.org/p/nYkRp-yG1aK

[ramya-rao-a]

Thanks @mxxcx and @anphung

@derekparker, @aarzilli Any thoughts on this?

[aarzilli]

A while ago we added two parameters to ListGoroutines that allow retrieving goroutines in smaller chunks (there is however a bug, see related PR).
Same PR will also improve the speed of Eval, ListLocalVars and ListFunctionArgs.
I think calling ListPackageVars at every step is probably a bad idea. If I were you I'd nix the globals view entirely (evaluating expressions is more useful anyway). An alternative is only showing variables for the current package, by calling ListPackageVars(Filter="^[curpkg]") (however vendored packages will be a pain).
I don't know why it's showing proc.go at every step, that looks more like a problem on your side.

[leesjensen]

For me the debug performance is fine, but the constant flipping to proc.go is really annoying.

[ori-saporta83]

I experience the exact same behavior with the debugger jumping to the function "gopark" in proc.go every step I make.
Is there any estimation for a fix?

[mhr3]

I can confirm the same jumping into gopark, in a codebase not using go modules. Also the jump is super fast... but also super distracting.

[tcagan]

I am experiencing the same behavior.
The jump is sometimes very quick and sometimes slower. Quite a bad experience debugging now...

My setup:
Mac (High Sierra)
go version go1.10.2 darwin/amd64
VS Code Version 1.29.1 (1.29.1) bc24f98b5f70467bc689abf41cc5550ca637088e

If there's something I can do to help - let me know. It is really annoying :-|

[ramya-rao-a]

I tried with older versions of the Go extension and I can still see the issue which tells me that this is not due to any recent changes in the extension.

If somebody here can try with older versions of dlv, then we can at least narrow down or eliminate recent changes to dlv as the reason.

[mikecowgill]

Inspecting the vscode-go-debug.txt from the debug, global vars request is huge for me, I guess thats the reason. Is there anyway to disable global vars?

Thats an interesting find. There is no official way to disable global vars, but can you try the below

• Open the file ~/.vscode/extensions/ms-vscode.go-0.7.0/out/src/debugAdapter/goDebug.js. If you are using Insiders then use .vscode-insiders. If you are not on the latest version of VS Code (0.7.0), then use the appropriate version
• Find the function getPackageInfo, and add return Promise.resolve(null); to the first line inside the function. This will return null for package and consequently the global vars call will not be made.
• Reload VS Code

Check if this solves the problem of slowness

I've been experiencing slowness (sometimes extreme) and the proc.go jump while debugging for the past month or so. Using the above adjustment to disable package info, the speed is back to normal and fast and I have yet to have the proc.go jump but will continue to experiment.

What are the side-effects of having this disabled?

[segevfiner]

It seems that the extension is responsible for providing a log of the adapter protocol (VS Code doesn't supply a mechanism to log on its side)

Maybe we should integrate LoggingDebugSession from the adapter module so that we can produce such a log which might help reveal the cause, if it's in the debug adapter that is.

[segevfiner]

@ramya-rao-a It got auto closed by GitHub. This should be reopened.

[ramya-rao-a]

@segevfiner The master branch now uses the LoggingDebugSession.

[segevfiner]

With the more verbose logging, it seems that the trigger for this is a scopes request on the currently debugged thread taking a long time, and while it's still not finished (The response is sent) a next (or step, etc.) request and response goes through. Immediately after that VS Code shifts it's focus to the next thread (You see a stacktrace request for it), and the next time you do next/step/etc. the focus will jump to that thread. I wonder if this is a bug in VS Code itself...

(The scopes request is the one that does the large local/global variables query that is slow)

[segevfiner]

Debugging VS Code a bit, it seems to me we are hitting this line in VS Code: vscode/src/vs/workbench/parts/debug/electron-browser/debugService.ts:496 and that call to focusStackFrame is selecting to focus some other thread than the one currently being debugged, and that thread is, more often than not, stopped on gopark.

We really shouldn't be reaching a code path where VS Code selects some arbitrary thread to focus, that seems like a bug in VS Code.

The code there is a bit weird too, like vscode/src/vs/workbench/parts/debug/electron-browser/debugService.ts:773 with that shift... selecting the second stopped thread...? 😕

I launched VS Code (Git build) with --remote-debugging-port=9222 and the extension installed (--extensionDevelopmentPath or just install it), used the "Attach to VS Code" launch configuration in VS Code's repository, and then conditional breakpoints to stop when it's requesting a stackTrace on threadId === 2.

[ramya-rao-a]

All,

I have added a new property showGlobalVariables to the debug configuration which will control the showing of the global variables. It is false by default. Try the latest beta version of this extension to get the fix. This reverts the feature introduced in 0.6.89.

@aarzilli We already pass the current package as filter when calling ListPackageVars

@segevfiner Great insights!
Can you log an issue in the VS Code repo for your findings? Mention me there and I can rope in the right people who can help us. Log the issue with enough details so that we don't have to point folks back to this issue.

[vscodebot]

This issue has been closed automatically because it needs more information and has not had recent activity. Thank you for your contributions.

[jogly]

before @ramya-rao-a 's beta (was using v0.8.0), I experienced this issue (slow-down and proc jumping between steps). I also noticed that while experiencing the slowdown, the dlv process was churning through system memory, at one point asking for 11GB at 100% CPU util. I was able to mitigate the problem by changing the dlv configuration to ask for very small inspection limits:

        "dlvLoadConfig": {
            "followPointers": true,
            "maxVariableRecurse": 2,   // <--
            "maxStringLen": 64,
            "maxArrayValues": 64,
            "maxStructFields": 2       // <--
        }

but that made the inspection useless 😞

then I reverted to API version 1:

"go.delveConfig": {
  "apiVersion": 1,
  ...
}

which fixed it entirely, but was less than ideal.

The beta fixed the issue entirely for me. I've reverted to the default go.delveConfig settings and it still flies. <3 <3 @ramya-rao-a

[ramya-rao-a]

Hello all,

The jumping to proc.go issue has been fixed upstream in VS Code. Therefore, please use the latest Insiders which has the fix. For reference, microsoft/vscode#65920 was the upstream issue, and a big shout-out to @segevfiner who drilled down on the root cause and helped the VS Code team in coming up with a fix.

The slowness issue is due to the recent feature of showing global variables in the variables pane. In the beta releases, I added a setting (by default: false) to control that feature and most of you saw improvements. @jhendrixMSFT figured out that this was due to a caching problem which we have now fixed. I am retaining the setting, but turning its default value to true.

So, please install the latest beta version of this extension in VS Code Insiders and you should see improvements.

If you still see the slowness, try adding "showGlobalVariables": false to your debug config and see if that solves the problem and let me know here, so that we can take a call if this setting should be true or false by default

[ramya-rao-a]

Hello again!

Turns out we didnt really turn the showGlobalVariables feature back on in the beta version 0.8.1-beta.10 :(

So folks (@joegilley, @anphung, @tcagan, @mikecowgill, @stffabi, @seanstrickland-wf, @egorse ), who saw the slowness and then saw the slowness go away (either with the beta version, or by using the workaround I mentioned in #2133 (comment)), can you please update to the latest beta version (the version should be 0.8.1-beta.11) and let me know if you still see the slowness?

I really need this feedback before releasing the next update, so thanks a ton in advance!

[stffabi]

@ramya-rao-a I've just tried 0.8.1-beta.12 with vscode insiders. The jumps to proc.go have gone 🎉 , that's awesome...

Regarding the slowness, I think it has gotten faster, but it's still slower than before 0.6.89. Disabling the global variables with showGlobalVariables works like a charm and the debugging is fast as with older versions.

[ramya-rao-a]

Regarding the slowness, I think it has gotten faster, but it's still slower than before 0.6.89. Disabling the global variables with showGlobalVariables works like a charm and the debugging is fast as with older versions.

Thanks for that feedback @stffabi!
If any of the others (@joegilley, @anphung, @tcagan, @mikecowgill, @seanstrickland-wf, @egorse ) can confirm the same, then I will go ahead disable the showGlobalVariables feature by default

[jhendrixMSFT]

If there's a repro available that demonstrates the slowness it would help, maybe there's a better way we can implement this feature.

[mmcmm]

@ramya-rao-a I just got the new update, and yes it is slower with global variables ON, I had it off, using the workaround you posted with return null, you can see bellow, it can take up to 1 second to step over, and those are simple if statements in a big codebase albeit.

https://gyazo.com/b24bebc3b90c48b2ffd1f8e70fd501cf

In my opinion is not unbearable slow, initially it was much slower.

[ramya-rao-a]

@mxxcx
Did you get the update for both VS Code (1.31) and the Go extension (0.9.1)?
If you are on the latest Go extension, then instead of the workaround that changes the code, you can add "showGlobalVariables": false in your debug configuration.

[mmcmm]

@ramya-rao-a yes, got the update for both, hence it overwrite the workaround I did when you initially posted it, thanks for the config tip. No proc.go btw, so I guess this can be closed.

[ramya-rao-a]

Thanks @mxxcx!

Conclusion:

• The jump to proc.go is fixed in VS Code. Get the latest version of 1.31
• The slowness is fixed in the latest version of the Go extension (0.9.1). If you still see slowness, then add "showGlobalVariables": "false" in your debug configuration