-
Notifications
You must be signed in to change notification settings - Fork 1.7k
dart debug session slow to start. #60252
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
Comments
its perhaps worth noting that I'm not seeing the same issue when debugging flutter (on the same machine) using the dart vm that comes with flutter. |
running (as opposed to debugging) my shelf server works fine from within vscode. |
FYI as well, @DanTup |
One first thing to note is that the command contains The VSCode slowness is unexpected though, so I'll continue looking into that. |
Do you mean you see it take a few minutes - or is it possible it never completes. When running at the terminal with Is it possible you could capture a log file using the Dart: Capture Debugging Logs command from VS Code (using the brand new sample project)? Run the command before starting the debug session, then wait for the app to load and exit, and then click Cancel to stop logging and open the log. Edit: I don't have easy access to Ubuntu, but I've not been able to reproduce similar on Windows Edit2: Actually, I have WSL Ubuntu, but I tried there with 3.7.1 but also could not repro. |
I also could not reproduce this on Debian with |
sorry for the late reply, github wasn't sending me notifications for some reason.
it does start after a few minutes.
so ignore the terminal startup issue. Here is a capture using the brand new sample project.
|
and I accidently closed the issue :< |
I think you should be able to reopen it since you, the author, closed it 🤔 If you can't, someone from the team will be able to do that for you. |
I've reopened - just needed to refresh the page. |
Just a couple of additional notes. If I (attempt to) start one debug session the call stack window in vs code shows 'running' but no process name. If I start a second debug session, it also doesn't connect but then both of the processes show up in the 'call stack' window. The call stack window will let me stop them or restart them but no pause them. |
@bsutton it seems that there's a long pause (around 170s?) in the log where we ask VS Code to run the process in the terminal. If you remove Do you see any delay if you create a new terminal manually inside VS Code? (for example both of these probably trigger your terminal startup scripts to run - although I think you'd probably have noticed if those scripts added 170s). |
For the testing I didn't have a launch.json I was just running from the 'run | debug' menu in slow_debug.dart.
not certain what you are asking here. Each of the below runs uses the same vs-code terminal (bash) instance so has the output from the last run. I've just tried creating a launch.json with: {
// 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": "slow_debug",
"request": "launch",
"type": "dart",
"console": "terminal"
}
]
} This is slow to start. So as requested I've removed the 'console":"terminal" {
// 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": "slow_debug",
"request": "launch",
"type": "dart",
}
]
} This is also slow to launch. I then tried using the debugConsole explicitly: {
// 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": "slow_debug",
"request": "launch",
"type": "dart",
"console": "debugConsole"
}
]
} I waited about five minutes and this launch simply didn't complete. I've attached the debug logs from when using 'debugConsole' (log.debugconsole.txt). Flipping back to 3.6.0 and the launch runs/completes immediately. As a comparison I've included the debug logs from a 3.6.0 launch. |
here is a recording showing switching between dart 3.6 and 3.7. Screencast.From.2025-03-13.08-28-57.webm |
FYI: i've just tried dart 3.7.2 with the same slow to start results. |
So I'm not positive it is specific to dart 3.7. I have another project ( money2 as published on pub.dev) that exhibits the same issue whether I run it with 3.6 or 3.7. On the smaller project 'slow_debug' we have been testing on moving between 3.6 and 3.7 gives very predictable results (works on 3.6 fails on 3.7). |
Sorry, I wasn't very clear. I wanted you to run without using the terminal (eg. in the debug console) however since the usual reason to run in the terminal is because you read from In any case, the log you provided for running in the debug console provided what I was after, which is a single DAP log that doesn't delegate spawning the process to VS Code (to eliminate that from the possible issues). In your new log, I see the delay here:
The code that emits these two messages is here: sdk/pkg/dds/lib/src/dap/adapters/dart_cli_adapter.dart Lines 90 to 102 in f25a2b4
The gap between them is the time waiting for the file passed to I will try to extract the relevant code here into something you can run as a standalone script (that spawns the process with the same flags and watches for that file to appear) to see if it can be reproduced without VS Code and DAP in the way, which might help narrow it down. |
@bsutton I've extracted what I think are the relevant parts of the debug adapter to try and reproduce this outside of VS Code/DAP: https://gist.github.com/DanTup/9a6461192fb96ae4c4c9f800ce36a23e If you update the You'll need to run this script using the VM version you want to test with (or change Assuming the issue reproduces with this, try removing the |
So If i run the code from a terminal started outside of vs code, it starts
immediately:
```bash
dart bin/adaptor.dart
[ 0] Progress: Starting…
[ 22] Ignoring error parsing vm-service-info file:
PathNotFoundException: Cannot open file, path =
'/tmp/dart-vm-serviceSTANNF/vm.json' (OS Error: No such file or directory,
errno = 2)
[ 25] Spawning
/home/bsutton/.dswitch/channels/stable/versions/3.7.2/dart-sdk/bin/dart
with [--no-serve-devtools, --enable-vm-service=0, -DSILENT_VM_SERVICE=true,
--write-service-info=file:///tmp/dart-vm-serviceSTANNF/vm.json,
--pause_isolates_on_exit, --pause_isolates_on_start,
/home/bsutton/git/slow_debug/bin/slow_debug.dart] in
/home/bsutton/git/slow_debug
[ 428] Progress: Fake connecting debugger…
[ 428] Terminating process
[ 439] Process exited (-15)
```
If I start the code within a vs-code terminal it hangs on the spawn
```bash
dart bin/adaptor.dart
[ 0] Progress: Starting…
[ 23] Ignoring error parsing vm-service-info file:
PathNotFoundException: Cannot open file, path =
'/tmp/dart-vm-serviceSTLBOV/vm.json' (OS Error: No such file or directory,
errno = 2)
[ 27] Spawning
/home/bsutton/.dswitch/channels/stable/versions/3.7.2/dart-sdk/bin/dart
with [--no-serve-devtools, --enable-vm-service=0, -DSILENT_VM_SERVICE=true,
--write-service-info=file:///tmp/dart-vm-serviceSTLBOV/vm.json,
--pause_isolates_on_exit, --pause_isolates_on_start,
/home/bsutton/git/slow_debug/bin/slow_debug.dart] in
/home/bsutton/git/slow_debug
```
It also tried creating a second terminal with vs-code (incase there was
some issue with the default terminal the vs-code opens) but alas we get the
same hang.
Edit: for clarity
|
removing the pause isoaltes improves the results. We see that the program
now runs (hello world is printed immediately) but then hangs waiting for
the exit code.
I made some changes to the code to print a few more progress steps - I
tested before I made the code changes and saw the hang so added the
additional log points to identify the point of failure.
```dart
process.stdout.listen(_handleStdout);
process.stderr.listen(_handleStderr);
printTime('wait for exit');
await process.exitCode.then(_handleExitCode);
printTime('exited launch');
}
```
```bash
dart bin/adaptor.dart
[ 0] Progress: Starting…
[ 25] Ignoring error parsing vm-service-info file: PathNotFoundException: Cannot open file, path = '/tmp/dart-vm-servicePKLFYB/vm.json' (OS Error: No such file or directory, errno = 2)
[ 28] Spawning /home/bsutton/.dswitch/channels/stable/versions/3.7.2/dart-sdk/bin/dart with [--no-serve-devtools, --enable-vm-service=0, -DSILENT_VM_SERVICE=true, --write-service-info=file:///tmp/dart-vm-servicePKLFYB/vm.json, /home/bsutton/git/slow_debug/bin/slow_debug.dart] in /home/bsutton/git/slow_debug
[ 57] wait for exit
[ 791] stdout: Hello world: 42!
```
Edit: for clarity.
|
just for a comparison point, I also tried directly launching ' dart slow_debug.dart' from the adaptor and the call exited normally. Future<void> launchAndRespond() async {
File? vmServiceInfoFile;
Settings().setVerbose(enabled: true);
final executable = normalizePath(Platform.resolvedExecutable);
printTime('Spaning slow_debug directly $cwd');
await launchAsProcess(executable, ['bin/slow_debug.dart'],
workingDirectory: cwd);
return; dart bin/adaptor.dart
[ 0] Spawning slow_debug directly /home/bsutton/git/slow_debug
[ 3] Spawning /home/bsutton/.dswitch/channels/stable/versions/3.7.2/dart-sdk/bin/dart with [bin/slow_debug.dart] in /home/bsutton/git/slow_debug
[ 62] wait for exit
[ 228] stdout: Hello world: 42!
[ 255] Process exited (0)
[ 255] exited launch
|
This is probably the thing I'm most interested in. Assuming these are the same SDKs being used here, what is the difference here? You're using the terminal so there's no DAP or anything involved. Does it hang indefinitely, or is it just slow? Are you using the same kind of terminal inside/outside VS Code? (on Windows at least, we can choose between CMD, PowerShell, etc.). If it's just slow, can you use a file explorer or something to see when the service info file actually exists on disk? (if it appears immediately, then perhaps this is a watcher issue, and if not, a VM issue).
This makes sense, but probably isn't a good test alone. The program will immediately start running and terminate but it's not clear whether the service info file is being written to disk quickly in this case.
Looking at your code, this makes sense - since it's being spawned without writing (or waiting for) the service info file. |
@bsutton I've slightly updated my test script here: https://gist.github.com/DanTup/9a6461192fb96ae4c4c9f800ce36a23e It should print a little more information now. Could you test this in both external and VS Code terminal and capture the output (I expect the behaviour is the same, it will work outside of VS Code and fail inside). Then could you try uncommenting the 1s pause on line 46 and see whether that changes the behaviour (besides it taking 1s extra)? |
results from the unadulterated version: run from a vs-code terminal.
run from a bash terminal
The 1 second delay made no difference.
|
@bsutton thanks! The one second delay was to ensure the file system watcher had plenty of time to be initialized before we spawned the process. In this case, we set up the watcher, wait one second, spawn the program, and then wait for the watcher event showing that the VM wrote that file. In this case, it still seems like there is a 160s delay between spawning the VM and the watcher event:
This leads me to the question of whether the file exists on disk during those 160s and the watcher event is delayed (or being processed slowly by Dart), or whether the file does not exist on disk (in which case the issue is in the program we are spawning). Is it possible you could re-run your last test, and during that 160s delay, check whether the filename that is printed in the output ("Attempting to read file...") actually appears to exist on your disk, or whether it only appears after the 160s? This will help narrow down whether the issue is in the spawned VM side, or the "debug adapter" side. Thanks! |
as requested I checked for the files existings during the 160 s wait and NO the file does not exist.
|
I've just an additional test and the directory however does exist, just not the file. |
|
I don't know if this helps, but if I delete the watched directory during the 160 second wait I see an additional watch event reported:
The watch event 4: occurs immediately after I delete the directory. |
@bsutton thanks for testing! Based on this:
It seems that the problem is probably with the spawned program. For some reason, when spawned from within VS Code, it's taking a very long time to write that file. It would be useful to try and eliminate the Dart script that's spawning the VM to see if the issue persists (I suspect it will). Could you try running that script directly (inside a VS Code window) using exactly the same command:
And see if the file Note: The script itself will appear to just hang, because of the pauses, but you can just terminate it afterwards. All we're interested in knowing here is whether the service info file is being written immediately, or after the same delay. |
Not certain how useful this is but its a list of open files whilst I wait for the json file to be created:
|
and the contents of ptyhost.log cat /home/bsutton/.config/Code/logs/20250326T184802/ptyhost.log |
so interesting observation.. If I run the command with sudo from the vs-code terminal the my-vm-service-info.json file is created immediately. without sudo it doesn't appear to ever create the json file (I waited 15min). So I tried running with strace. When running without sudo
|
strace output of both runs. |
@bsutton could you produce full traces without |
@mraleph
|
Thanks @bsutton - that explains the hang. You seem to have a very high limit set for When you run under root The code in question tries to fight what is arguably a POSIX design issue: file descriptors are inherited on fork and remain open across I think we should rewrite this code to check whats in |
Thanks for the effort on this one, particularly since it seems somewhat peculiar to my system. I've actually just been doing a deep dive and can't actually find where the default limits have been changed (.bashrc, .profile, logind.conf, systemd.conf, limits.conf). It may be worth noting for other readers that vs-code changes the soft limit to be equal to the hard limit when it launches. https://stackoverflow.com/questions/72542581/maximum-file-descriptors-used-by-visual-code In a vs-code terminal I get:
outside of vs-code
I'm about to add a reduced hard limit to logind.conf (from gnome sessions) and systemd.conf for services. Will report back after I reboot. I should note that this is a system which is probably 6 years old and has been through multiple OS upgrades (without a re-install). |
so for the record the changes to systemd.conf and logind.conf made no difference. What did work is that I created a file /etc/security/limits.d/custom.conf with:
I now have a working debugger. Once again, thanks for all of the assistance. |
UPD: the nofile thing worked for me as well. Hi there. So is there any workaround? Looks like I'm facing exactly the same issue but there is another thing I can add: this issue also happens when I run tests with Constantly reproducible on both of my PCs with Ubuntu 25.04:
I've tried switching to older versions of flutter/dart - no luck even with a year-old releases. |
The work-around right now is to reduce the fd limit to something smaller. cc @a-siva for visibility. |
@mraleph there is a counter proposal from @rmacnak-google that maybe we delete this entire 'for loop of closing file descriptors' as files opened by 'dart:io' always have FD_CLOEXEC set which would take care of closing these files. There could be situations |
Yes, that's an option, though there is a catch here. I do think that force closing fds is overall safer. Especially if third party native code is considered. That's what other languages tend to do (I checked at least JVM and Python). It seems on Linux there is https://man7.org/linux/man-pages/man2/close_range.2.html which might mean that a simpler implementation is possible which does not require meddling with |
The current implementation of File::Open in file_linux.cc and file_macos.cc and Socket::Create already seem to set this flag. |
FWIW we still have a bunch of places where we call |
TEST=ci Bug: #60252 Change-Id: Ide6d156d8a7c569984d4fa702dc32ac08f9ee9e1 Reviewed-on: https://dart-review.googlesource.com/c/sdk/+/426580 Reviewed-by: Brian Quinlan <[email protected]> Reviewed-by: Siva Annamalai <[email protected]> Commit-Queue: Ryan Macnak <[email protected]>
I've recently upgraded to dart 3.7.0 (I have a separate flutter install).
Going back to a shelf web server project I tried to start it in debug mode in vs code.
The problem is that the debug launch times now takes 2min+ as opposed to less than 10 seconds previously.
I should note that the app does eventually launch and run to completion.
I thought this might related to my project so I created a brand new dart project with:
dart create slow_debug
Opened that project with dart code and see the same slow start times.
I have now upgraded to dart 3.7.1 but I'm see the same slow start times.
If I run the command directly from (a non vscode) terminal I see the same results.
.../3.7.1/dart-sdk/bin/dart --no-serve-devtools --enable-vm-service=0 -DSILENT_VM_SERVICE=true --write-service-info=file:///tmp/dart-vm-serviceJANFKU/vm.json --pause_isolates_on_exit --pause_isolates_on_start --enable-asserts slow_debug/bin/slow_debug.dart
I've now installed dart 3.6.0 and the problem goes away (i.e. fast debug start times are back).
I've rolled back and forth (between versions) a couple of times and can reproduce the results.
I'm running dart code 3.106.0
I'm running ubuntu 24.10 (I've only upgraded in the last week).
I've restarted my system.
dart info
The text was updated successfully, but these errors were encountered: