microsoft
Repeated SSH disconnects/reconnects that eventually stabilizes (large folder)
- VSCode Version: 1.37.1
- Local OS Version: macOS 10.14.6
- Remote OS Version: Debian 4.19.37-5rodete4 (in-house Google Debian distro)
- Remote Extension/Connection Type: SSH
Steps to Reproduce:
- Open workspace using "Remote - SSH" connection w/ large folder open (a remote checkout of fuchsia.googlesource.com/fuchsia, in this case)
- Connection initially succeeds, then disconnects or times out and I get into a loop of "Attempting to reconnect...". See logs.
- Eventually, after a number of disconnects/time outs and reconnects, it stabilizes and works mostly fine (at least as far as I can tell, I haven't used VSCode much yet since it's mostly unusable for me while this is unresolved)
Logs from Output > "Remote - SSH" panel on local end: https://gist.github.com/sbrocket/fc7f94588538a1de0ac7055c555d6df8
Notes:
- I work over SSH, using tmux+vim, fairly regularly and my connection is always stable, so I don't believe this is a general connection stability issue.
- Note that my SSH configuration uses (and requires) a ProxyCommand for the host I'm connecting to, which handles authentication and relaying the SSH connection through to our internal network. (But again, I use this regularly and it is stable.)
- I normally use SSH multiplexing (i.e. ControlMaster, ControlPath, etc. in the ssh config), and when VSCode disconnects/times out it also kills any connections that I have open in a separate terminal that are multiplexed over the same control socket.
- I uninstalled all extensions on the remote end, and that seemed to help it go through less disconnections, though not zero.
- The extensions panel that shows remote extensions doesn't update to say "No extensions found" (or to list the installed extensions, before I had uninstalled them) until the connection finally stabilizes.
Does this issue occur when you try this locally?: No (N/A) Does this issue occur when you try this locally and all extensions are disabled?: No (N/A)
Happy to collect logs to help diagnose, but couldn't immediately find any more interesting logs than what was attached below from the local client.
Thanks for the detailed report. I think that what you are describing sounds consistent with issues like https://github.com/microsoft/vscode-remote-release/issues/1087 which are probably caused by the remote extension host getting stuck doing lots of work and not responding to messages fast enough which makes the frontend think it has lost the connection.
Not sure about
[02:24:33.275] > F0826 19:24:33.273471 61705 helper.go:233] read tcp 192.168.1.198:60832->216.239.45.151:443: read: operation timed out
[02:24:33.286] > mux_client_request_session: read from master failed: Broken pipe
guessing this is from your proxy.
Can you see what error messages are in the devtools after reconnection happens? It should be some hint as to why vscode thought it lost the connection.
How are the specs on the host? You could run code --status or just top to see if a vscode process is using all of your cpu/memory before we get disconnected.
Yes those logs you called out are from the SSH ProxyCommand.
Console log attached. It's not clear to me if the log is indicating why VSCode thinks it lost the connection the first few times, but I'm not sure what I'm looking for. However, on the last connection attempt or two - and once it finally stabilized - I see some worrying messages about a file watcher dying.
The host specs are very high, so I doubt that's the issue (or if it is an issue then it would be an issue for most or all users). It's an HP Z840 workstation, 2x Xeon E5-2690 v4 (56 logical cores), 132GB RAM, etc.
One thing I'll mention again: The directory I have open is relatively large, since it's a checkout of Fuchsia (from fuchsia.googlesource.com), so if this is a "remote extension host is stuck doing lots of work" and failing to respond in time type issue, it's possible that the large project directory is part of the cause.
Probably the real problem:
log.ts:173 ERR Error: [File Watcher (chokidar)] terminated unexpectedly and is restarted again...
log.ts:173 ERR Error: [File Watcher (chokidar)] terminated unexpectedly and is restarted again...
log.ts:173 ERR Error: [File Watcher (chokidar)] terminated unexpectedly and is restarted again...
log.ts:173 ERR Error: [File Watcher (chokidar)] terminated unexpectedly and is restarted again...
log.ts:173 ERR Error: [File Watcher (chokidar)] terminated unexpectedly and is restarted again...
log.ts:173 ERR Error: [File Watcher (chokidar)] failed to start after retrying for some time, giving up. Please report this as a bug report!
FYI @Tyriar, any ideas?
You could try excluding some folders with files.watcherExclude to check whether that helps.
Looks related to https://github.com/microsoft/vscode-remote-release/issues/735 and https://github.com/microsoft/vscode/issues/79152
Do you have a lot of changes in your repo? Does https://code.visualstudio.com/docs/setup/linux#_visual-studio-code-is-unable-to-watch-for-file-changes-in-this-large-workspace-error-enospc help?
I already have fs.inotify.max_user_watches=524288 set from something previous. Do you mean changes as in modifications to files vs. the Git HEAD? If so, then no; it happens even with zero changes against HEAD.
I tried adding a files.watcherExclude config for my build output directory, for both "${workspaceFolder}/out/" and "/out/**" (since I wasn't sure if workspaceFolder worked there) but that didn't seem to help. I'll have to see if I can dig up whether there are any other large directories to ignore, because I still see errors about reaching the inotify limit.
I noticed some new logs in the Developer Tools console now, I'm guessing these were added in a recent update. Attaching new logs, since now you can see the reconnection attempts. Is there some way I can enable the trace logs that are referenced? I still don't see anything logged as far as a cause for most of the reconnections.
Also, VSCode version is now 1.38.0 and the Remote - SSH extension is at 0.46.0.
You can run the "Set Log Level" command to see some more logs but I'm not sure there will be anything useful there.
ERR Error: [File Watcher (chokidar)] Inotify limit reached (ENOSPC sure sounds like the error from my link above but sounds like you have already addressed that.
I'm coming from https://github.com/microsoft/vscode/issues/79152
Since updating to 1.38.0 on MacOS, I have the same Inotify limit reached error in the remoteagent.log every time my remote SSH disconnects, but now it just asks me to close my session instead of trying to reconnect automatically.
I also have fs.inotify.max_user_watches=524288 and put **/build/** in the files.watcherExclude setting. I don't know of any other large directories.
I tried Set Log Level and enabled all the levels it offered when taking the logs attached above, but it didn’t have an option for trace logs.
Yes, my inotify limit is set as high as possible. I’m not convinced that this is a problem with the file watcher. I think this is a deeper issue with how the extension is handling or monitoring disconnects. Is there some way I can gather other logs or data to support or disprove that?
There are a number of others on my team that are prospective VSCode users and who are hitting similar issues, and I’m encouraging them to chime in here (gbbosak is one). It’s also possible that there is some interaction between our SSH proxy helper and the extension.
I experienced similar issues recently. Also working on the large Fuchsia codebase.
I notice that apparently heavy server-side operations seem to correlate with disconnects.
One thing that seems to have dramatically improved remote connection stability is removing the Microsoft C++ extension from the server and using vscode-clangd instead. I don't know much about how the Microsoft C++ extension operates in the server environment, but I do know that vscode-clangd uses the external clangd binary to do the heavy lifting.
This difference in stability might support the suspicion that server response time is related to the disconnect -- supposing that doing the heavy lifting in a separate process makes the overall server more concurrent and responsive.
How does the remote extension determine connection liveliness? Is there some sort of response timeout? If so, is it a short duration?
If the remote extension host stops responding (like if some extension code is in a busy loop) then the frontend will think it disconnected. Also talking about that issue in https://github.com/microsoft/vscode-remote-release/issues/1087. @alexandrudima I saw that you had added that one to the milestone, are you planning to do anything there?
Then it seems like there is a set of users specifically seeing file watcher-related errors right before connection is lost, which seems related.
I can try to repro this in the Fuchsia repo, can anyone tell me which other extensions you are using or how the C++ extension is configured?
I personally have a c_cpp_properties.json file in the Zircon folder, and usually open that directory (I mainly work on Zircon) instead of the root Fuchsia folder. The c_cpp_properties.json file refers to include directories generated by the build process in the out/ directory at the root of the Fuchsia checkout. Many people here open the root of the Fuchsia directory, and either select a compile_commands.json file or leave it unconfigured (using fuzzy IntelliSense only). The compile_commands.json file often doesn't work particularly well with Fuchsia, so I think as far as the C++ extension goes it's more common to leave it unconfigured than it is to point it at a compile_commands.json file. This disconnect problem doesn't seem to occur as frequently when using clangd instead of the default C++ extension.
I operate from the root of the Fuchsia repo. The only server extensions I have installed are vscode-clangd, Clang-Format, and FIDL Language Support.
I have vscode-clangd configured to use the aggregate compile_commands.json in the root directory. The aggregate file is created using the fx compdb command after a build.
VS Code Server 'node' generates a lot of core dumps to a point it fills up my entire disk space rendering the VM completely unusable. Here is the stack trace:
next2020@vivija1:~/source>gdb ~/.vscode-server/bin/6ab598523be7a800d7f3eb4d92d7ab9a66069390/node core.10832
GNU gdb (GDB) Red Hat Enterprise Linux (7.2-92.el6)
Copyright (C) 2010 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law. Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-redhat-linux-gnu".
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>...
Reading symbols from /home/next2020/.vscode-server/bin/6ab598523be7a800d7f3eb4d92d7ab9a66069390/node...done.
[New Thread 10832]
[New Thread 10843]
[New Thread 10835]
[New Thread 10869]
[New Thread 10836]
[New Thread 10837]
[New Thread 10838]
[New Thread 10839]
[New Thread 10866]
[New Thread 10867]
[New Thread 10868]
Reading symbols from /lib64/libdl.so.2...(no debugging symbols found)...done.
Loaded symbols for /lib64/libdl.so.2
Reading symbols from /lib64/librt.so.1...(no debugging symbols found)...done.
Loaded symbols for /lib64/librt.so.1
Reading symbols from /usr/lib64/libstdc++.so.6...(no debugging symbols found)...done.
Loaded symbols for /usr/lib64/libstdc++.so.6
Reading symbols from /lib64/libm.so.6...(no debugging symbols found)...done.
Loaded symbols for /lib64/libm.so.6
Reading symbols from /lib64/libgcc_s.so.1...(no debugging symbols found)...done.
Loaded symbols for /lib64/libgcc_s.so.1
Reading symbols from /lib64/libpthread.so.0...(no debugging symbols found)...done.
[Thread debugging using libthread_db enabled]
Loaded symbols for /lib64/libpthread.so.0
Reading symbols from /lib64/libc.so.6...(no debugging symbols found)...done.
Loaded symbols for /lib64/libc.so.6
Reading symbols from /lib64/ld-linux-x86-64.so.2...(no debugging symbols found)...done.
Loaded symbols for /lib64/ld-linux-x86-64.so.2
Core was generated by `/home/next2020/.vscode-server/bin/6ab598523be7a800d7f3eb4d92d7ab9a66069390/node'.
Program terminated with signal 6, Aborted.
#0 0x00000030e9a359d9 in raise () from /lib64/libc.so.6
Missing separate debuginfos, use: debuginfo-install glibc-2.17-55.el6.x86_64 libgcc-4.4.7-23.el6.x86_64 libstdc++-4.8.2-16.3.el6.x86_64
(gdb) where
#0 0x00000030e9a359d9 in raise () from /lib64/libc.so.6
#1 0x00000030e9a370e8 in abort () from /lib64/libc.so.6
#2 0x00000000008d20e1 in node::Abort() ()
#3 0x00000000008d211c in node::OnFatalError(char const*, char const*) ()
#4 0x0000000000b02b6e in v8::Utils::ReportOOMFailure(v8::internal::Isolate*, char const*, bool) ()
#5 0x0000000000b02da4 in v8::internal::V8::FatalProcessOutOfMemory(v8::internal::Isolate*, char const*, bool) ()
#6 0x0000000000ef02e2 in v8::internal::Heap::FatalProcessOutOfMemory(char const*) ()
#7 0x0000000000ef03e8 in v8::internal::Heap::CheckIneffectiveMarkCompact(unsigned long, double) ()
#8 0x0000000000efc512 in v8::internal::Heap::PerformGarbageCollection(v8::internal::GarbageCollector, v8::GCCallbackFlags) ()
#9 0x0000000000efce44 in v8::internal::Heap::CollectGarbage(v8::internal::AllocationSpace, v8::internal::GarbageCollectionReason, v8::GCCallbackFlags)
()
#10 0x0000000000effab1 in v8::internal::Heap::AllocateRawWithRetryOrFail(int, v8::internal::AllocationSpace, v8::internal::AllocationAlignment) ()
#11 0x0000000000ec8fd4 in v8::internal::Factory::NewFillerObject(int, bool, v8::internal::AllocationSpace) ()
#12 0x000000000116846e in v8::internal::Runtime_AllocateInNewSpace(int, v8::internal::Object**, v8::internal::Isolate*) ()
#13 0x00002cf2df55c01d in ?? ()
#14 0x000035c90cb026f1 in ?? ()
#15 0x00002cf2df55bf81 in ?? ()
#16 0x00007ffe73325c50 in ?? ()
#17 0x0000000000000006 in ?? ()
#18 0x00007ffe73325cb0 in ?? ()
#19 0x00002cf2df511146 in ?? ()
#20 0x0000002000000000 in ?? ()
#21 0x00002b13652e2f89 in ?? ()
#22 0x00007ffe73325c80 in ?? ()
#23 0x0000000000000013 in ?? ()
#24 0x0000000600000000 in ?? ()
#25 0x0000000000000016 in ?? ()
#26 0x00007ffe73325d30 in ?? ()
#27 0x00002cf2df5b975a in ?? ()
#28 0x0000000000000000 in ?? ()
(gdb)
My VSCode version:
Version: 1.39.2 (user setup)
Commit: 6ab598523be7a800d7f3eb4d92d7ab9a66069390
Date: 2019-10-15T15:35:18.241Z
Electron: 4.2.10
Chrome: 69.0.3497.128
Node.js: 10.11.0
V8: 6.9.427.31-electron.0
OS: Windows_NT x64 10.0.18362
A number of us use VS Code with remote and can have up to 10-12 core dumps in a single day and all similar to what @vivekvjn listed. Each core dump is generally at least 2GB each. I hope this "little" feature can be investigated and fix soon.
IMHO I think this has to do with the file watcher. Has anyone here attempted to use exclusion rules to limit what is being watched and check if that helps?
e.g.
"files.watcherExclude": {
"**/.git/objects/**": true,
"**/.git/subtree-cache/**": true,
"**/node_modules/*/**": true
},
@bpasero Do you have any tips how to troubleshoot watcher process crashes?
Ideally try to reproduce with the watcher itself. Is this a watcher crashing locally or in the server?
For those who are looking for a workaround to continue working (it took me half a day to find it), I don't have this issue anymore by putting a new pattern / in workplace settings - Watcher Exclude.
Go to vscode settings (ctrl + p or cmd + p), search for "watcher exclude" and "Add Pattern" /.
Mr. @marcosandri-dev, are you referring to doing following:
"files.watcherExclude": {
"**/.git/objects/**": true,
"**/.git/subtree-cache/**": true,
"/": true,
},
Isn't that going to exclude all files and folders from being watched?
The * were lost, should be **/** but yeah that would exclude everything. If there is a part of the workspace tree that you are not actively working on, maybe you can just exclude that part.
I still have this issue.
Version: 1.40.2 Commit: f359dd69833dd8800b54d458f6d37ab7c78df520 Date: 2019-11-25T14:52:45.129Z Electron: 6.1.5 Chrome: 76.0.3809.146 Node.js: 12.4.0 V8: 7.6.303.31-electron.0 OS: Darwin x64 18.7.0
Here's what the vscode-server log says:
*
* Visual Studio Code Server
*
* Reminder: You may only use this software with Visual Studio family products,
* as described in the license https://aka.ms/vscode-remote/license
*
IP Address: 10.116.100.150
Extension host agent listening on 32811
[09:43:43] Extension host agent started.
[09:43:43] [127.0.0.1][cad68fb1][ManagementConnection] New connection established.
[09:43:43] [127.0.0.1][e933f1ea][ExtensionHostConnection] New connection established.
bash: cannot set terminal process group (-1): Inappropriate ioctl for device
bash: no job control in this shell
[09:43:43] [127.0.0.1][e933f1ea][ExtensionHostConnection] <1996> Launched Extension Host Process.
EXTHOST-STDOUT::::::::
<--- Last few GCs --->
[1996:0x43d53a0] 90528 ms: Mark-sweep 2115.7 (2126.7) -> 2063.9 (2072.4) MB, 1734.7 / 0.0 ms (+ 0.0 ms in 24 steps since start of marking, biggest step 0.0 ms, walltime since start of marking 1744 ms) (average mu = 0.113, current mu = 0.076) allocatio[1996:0x43d53a0] 91446 ms: Mark-sweep 2065.5 (2072.4) -> 2064.7 (2071.4) MB, 819.2 / 0.0 ms (+ 72.5 ms in 17 steps since start of marking, biggest step 14.6 ms, walltime since start of marking 918 ms) (average mu = 0.079, current mu = 0.029) allocatio
<--- JS stacktrace --->
==== JS stack trace =========================================
0: ExitFrame [pc: 0x19fe126]
Security context: 0x0a29a671a2f1 <JSObject>
1: /* anonymous */ [0x28ddaba545f9] [/home/user/.vscode-server/bin/f359dd69833dd8800b54d458f6d37ab7c78df520/out/vs/server/remoteExtensionHostProcess.js:~790] [pc=0x11b0511f9fd2](this=0x28ddaba54671 <Socket map = 0x1b977c4d3bf9>,0x227000b9e831 <Uint8Array map = 0x3f1b81825899>)
2: emit [0xa29a67536f1] [events.js:~149] [pc=0x11b0511f3df5](this=0x28ddaba54...
EXTHOST-STDERR::::::::FATAL ERROR: Ineffective mark-compacts near heap limit Allocation failed - JavaScript heap out of memory
EXTHOST-STDERR:::::::: 1: 0x98edf0 node::Abort() [/home/user/.vscode-server/bin/f359dd69833dd8800b54d458f6d37ab7c78df520/node]
EXTHOST-STDERR:::::::: 2: 0x98fe56 node::OnFatalError(char const*, char const*) [/home/user/.vscode-server/bin/f359dd69833dd8800b54d458f6d37ab7c78df520/node]
EXTHOST-STDERR:::::::: 3: 0xb1552e v8::Utils::ReportOOMFailure(v8::internal::Isolate*, char const*, bool) [/home/user/.vscode-server/bin/f359dd69833dd8800b54d458f6d37ab7c78df520/node]
EXTHOST-STDERR:::::::: 4: 0xb158a9 v8::internal::V8::FatalProcessOutOfMemory(v8::internal::Isolate*, char const*, bool) [/home/user/.vscode-server/bin/f359dd69833dd8800b54d458f6d37ab7c78df520/node]
EXTHOST-STDERR:::::::: 5: 0xf20105 [/home/user/.vscode-server/bin/f359dd69833dd8800b54d458f6d37ab7c78df520/node]
EXTHOST-STDERR:::::::: 6: 0xf2aa6b v8::internal::Heap::PerformGarbageCollection(v8::internal::GarbageCollector, v8::GCCallbackFlags) [/home/user/.vscode-server/bin/f359dd69833dd8800b54d458f6d37ab7c78df520/node]
EXTHOST-STDERR:::::::: 7: 0xf2b787 v8::internal::Heap::CollectGarbage(v8::internal::AllocationSpace, v8::internal::GarbageCollectionReason, v8::GCCallbackFlags) [/home/user/.vscode-server/bin/f359dd69833dd8800b54d458f6d37ab7c78df520/node]
EXTHOST-STDERR:::::::: 8: 0xf2e225 v8::internal::Heap::AllocateRawWithRetryOrFail(int, v8::internal::AllocationType, v8::internal::AllocationAlignment) [/home/user/.vscode-server/bin/f359dd69833dd8800b54d458f6d37ab7c78df520/node]
EXTHOST-STDERR:::::::: 9: 0xef7f9b [/home/user/.vscode-server/bin/f359dd69833dd8800b54d458f6d37ab7c78df520/node]
EXTHOST-STDERR::::::::10: 0xeff74b v8::internal::Factory::NewRawOneByteString(int, v8::internal::PretenureFlag) [/home/user/.vscode-server/bin/f359dd69833dd8800b54d458f6d37ab7c78df520/node]
EXTHOST-STDERR::::::::11: 0xeff9eb v8::internal::Factory::NewStringFromOneByte(v8::internal::Vector<unsigned char const>, v8::internal::PretenureFlag) [/home/user/.vscode-server/bin/f359dd69833dd8800b54d458f6d37ab7c78df520/node]
EXTHOST-STDERR::::::::12: 0xf0068d v8::internal::Factory::NewStringFromUtf8(v8::internal::Vector<char const>, v8::internal::PretenureFlag) [/home/user/.vscode-server/bin/f359dd69833dd8800b54d458f6d37ab7c78df520/node]
EXTHOST-STDERR::::::::13: 0xb2e749 v8::String::NewFromUtf8(v8::Isolate*, char const*, v8::NewStringType, int) [/home/user/.vscode-server/bin/f359dd69833dd8800b54d458f6d37ab7c78df520/node]
EXTHOST-STDERR::::::::14: 0xa469d0 node::StringDecoder::DecodeData(v8::Isolate*, char const*, unsigned long*) [/home/user/.vscode-server/bin/f359dd69833dd8800b54d458f6d37ab7c78df520/node]
EXTHOST-STDERR::::::::15: 0xa46b5c [/home/user/.vscode-server/bin/f359dd69833dd8800b54d458f6d37ab7c78df520/node]
EXTHOST-STDERR::::::::16: 0x19fe126 [/home/user/.vscode-server/bin/f359dd69833dd8800b54d458f6d37ab7c78df520/node]
[09:45:16] [127.0.0.1][e933f1ea][ExtensionHostConnection] <1996> Extension Host Process exited with code: null, signal: SIGABRT.
Last EH closed, waiting before shutting down
[09:45:16] Last EH closed, waiting before shutting down
[09:45:21] [127.0.0.1][e933f1ea][ExtensionHostConnection] Unknown reconnection token.
Got delay-shutdown request while in shutdown timeout, delaying
[09:45:26] Got delay-shutdown request while in shutdown timeout, delaying
Cancelling previous shutdown timeout
[09:45:26] Cancelling previous shutdown timeout
[09:45:26] [127.0.0.1][8f302c5a][ManagementConnection] New connection established.
[09:45:26] [127.0.0.1][b7e4cd89][ExtensionHostConnection] New connection established.
[09:45:26] [127.0.0.1][b7e4cd89][ExtensionHostConnection] <2941> Launched Extension Host Process.
Error: write EPIPE
at WriteWrap.onWriteComplete [as oncomplete] (internal/stream_base_commons.js:83:16) {
errno: 'EPIPE',
code: 'EPIPE',
syscall: 'write'
}
Error: Unexpected SIGPIPE
at process.<anonymous> (/home/user/.vscode-server/bin/f359dd69833dd8800b54d458f6d37ab7c78df520/out/bootstrap.js:5:192)
at process.emit (events.js:200:13)
Error: Unexpected SIGPIPE
at process.<anonymous> (/home/user/.vscode-server/bin/f359dd69833dd8800b54d458f6d37ab7c78df520/out/bootstrap.js:5:192)
at process.emit (events.js:200:13)
[09:45:31] [127.0.0.1][cad68fb1][ManagementConnection] The client has disconnected, will wait for reconnection 3h before disposing...
Still having the issue described in #1686. Core.# files end up filling up the drive and causing a number of problems. Any way to disable these dumps?
Any way to disable these dumps?
If you just want to disable the core dumps, you can set ulimit -c 0 which sets the core dump size to zero. But beware this affects all core dumps on the system.
Is there a way to reduce the 3h delay before disposing?
"The client has disconnected, will wait for reconnection 3h before disposing..."
