Rebuild times consistently take quite long in Build Task

[dkolas]

Describe the bug Re-building the project always takes a long time (30ish seconds) when done from Build task, but not from terminal (both without changing any files). This is somewhat painful when running tests - rerunning the test takes a long time to start.

If I run the build via the build task repeatedly, it always takes approximately 30s:

 *  Executing task: swift build --build-tests 

Building for debugging...
Build complete! (29.70s)
 *  Terminal will be reused by tasks, press any key to close it. 

 *  Executing task: swift build --build-tests 

Building for debugging...
Build complete! (29.46s)
 *  Terminal will be reused by tasks, press any key to close it. 

 *  Executing task: swift build --build-tests 

Building for debugging...
Build complete! (28.35s)
 *  Terminal will be reused by tasks, press any key to close it.

Note that the entire time is spent on some hidden step (no messages about compiling particular files are emitted).

If I simply run the build from a Terminal window within VSCode:

dkolas@terra:~/projects/nludb$ swift build --build-tests
Building for debugging...
Build complete! (29.50s)
dkolas@terra:~/projects/nludb$ swift build --build-tests
Building for debugging...
Build complete! (0.37s)
dkolas@terra:~/projects/nludb$ swift build --build-tests
Building for debugging...
Build complete! (0.36s)
dkolas@terra:~/projects/nludb$ swift build --build-tests
Building for debugging...
Build complete! (0.37s)
dkolas@terra:~/projects/nludb$ 

Note that after the first build, it takes less than 1s per build, which is more in line with expectations

I played around with various swift compiler options (--force-resolved-versions, --skip-update) but these didn't seem to have any effect, and it doesn't look like it's doing that stuff anyway since it's not in the output.

To Reproduce I suspect this has something to do with either the number of files in the project or the number of dependencies, so it's unclear to me how to strip this down to an example without our code in it.

Expected behavior Rebuilds (at least within some short wall-clock timeframe) should take nearly 0 time

Environment

• OS: Windows 11 (vscode) connected to WSL Ubuntu 22.04.2
• Swift version 5.9 (swift-5.9-RELEASE)
• Visual Studio Code version: 1.83.1
• vscode-swift version: 1.5.2

Thanks again for all your work on the project.

[adam-fowler]

Yeah I've heard this being reported on Windows before. Do you have any other language extensions installed in your VSCode?

[dkolas]

Nope. The following things are installed in WSL: Ubuntu:

GitLens CodeLLDB Swift

What I don't understand is what would be different about the environment of running the build task and running the same command in the VSCode bash terminal view.

[dkolas]

Can confirm that building with the same project on MacOS does not experience the same build warm-up issue.

[adam-fowler]

The pause appears to be in VSCode. You get a slight pause on macOS, but nowhere near what you are describing

[dkolas]

Hm. But if the pause is happening in/because of VSCode, it's still happening AFTER the swift build process is launched, right? Or else the Build complete! (29.70s) would not include the time. Maybe I will try it on a raw Ubuntu machine, to see if related to Windows/WSL or just the linux toolchain.

[adam-fowler]

Ok that's interesting. I'm not sure why that is at all.

[dkolas]

Digging in a little more / rubber ducking.

In a new/empty project, no dependencies, building / rebuilding takes < 1s consistently, so I don't think it's that VSCode is taking a long time to kick off the process.

In my real project, If I run the builds with -v for verbose output, the difference between a re-build that takes ~30s and a rebuild that takes 0.3s (both with no project files changed) is that in the former case it is rerunning the linker on the project and all its individual dependencies.

I don't yet understand:

• Why the compiler decides it needs to rerun the linker on all of the dependencies after some amount of time has passed, even if Package.resolved hasn't changed and none of the source files have been modified
• Why in the terminal the 2nd rebuild manages to skip this step, whereas in the VSCode build task it does not

My working theory is that something is touched with every VSCode build that is not touched when building from bash, and the compiler is deciding conservatively that it needs to rerun those processes even though it does not.

[dkolas]

Nope, that turned out to be a red herring. I tracked all the files touched by both builds and they were the same. Also, I have one build than ran from command line in ~2s and did all of those same linking steps as the build that takes ~30s. The verbose output is nearly identical, modulo tmp directory paths, so I'm back to wondering what could be different about the environment of the swift build Task in vscode and the terminal.

[dkolas]

Further down the rabbit hole.

I've now installed on vanilla Ubuntu 20.04, on a different machine, same swift 5.9 toolchain.

The behavior is the same in one aspect, which is that there is sometimes a hidden step during re-build that takes a long time, that happens before Building for debugging... is output. This happens sometimes when jumping from building on the bash terminal to buildng in vs code, or vice versa, for reasons I cannot predict. I cannot find any difference in build output, even with -v or -vv, to justify this OOM difference, nor in the build artifacts.

The behavior is different however in that unlike in the Windows / WSL install, the hidden, long step does not happen every time the build task is run.

[adam-fowler]

Ok. Are you in a position to build the extension? See CONTRIBUTING.md.

If so one thing you could try is edit src/SwiftTaskProvider.ts and change all instances of ProcessExecution to ShellExecution.

The first runs the task in the shell that vscode runs in. The second creates a new shell to run the task. This might make a difference. I've seen other things that appear to be different when run within a vscode task and a normal shell.

[dkolas]

@adam-fowler I tested this theory in a slightly different way. I added a new Task in task.json that just ran swift build --build-tests, but as a shell task instead of a process task. Interestingly, this does not change / fix the behavior.

This lead me to test something else; could it be the fact that it's a NEW shell/process every time that is making the difference? And indeed, even outside the context of VSCode, if I run swift build --build-tests in one bash shell, and then run it again immediately in a NEW bash shell, I get the long build time.

I wonder, then, if there's something about the way the VSCode WSL remote server creates / destroys processes that is fundamentally different than VSCode is running in the host OS, that results in a file system cache being destroyed instead of retained every time.

[dkolas]

It seems like this may all come down to something related to spawning new shells versus existing ones or subprocesses.

The following (running on straight, non-WSL ubuntu 20.04) shows the difference:

dkolas@bernard:~/projects/project-name$ swift build --build-tests
Building for debugging...
Build complete! (72.35s)
dkolas@bernard:~/projects/project-name$ swift build --build-tests
Building for debugging...
Build complete! (1.58s)
dkolas@bernard:~/projects/project-name$ bash
dkolas@bernard:~/projects/project-name$ swift build --build-tests
Building for debugging...
Build complete! (75.55s)

Rebuilding in the SAME shell costs nearly no time at all; rebuilding in a DIFFERENT shell is much slower.

However, it does not seem to necessarily be that the filesystem contents are no longer cached, using vmtouch shows nearly the whole directory being in memory even when I open a new shell.

So far I have found VSCode settings for allowing tasks to run reusing a terminal window, but not that seem to reuse an open terminal process.

[adam-fowler]

This might be something to ask about in the swift repo.

[dkolas]

Agreed. I posted this yesterday: https://forums.swift.org/t/rebuild-times-in-new-shell-significantly-slower/68012

No responses there yet. Please let me know if you happen to have any other suggestions.

[dkolas]

@adam-fowler

I got an answer here: https://forums.swift.org/t/rebuild-times-in-new-shell-significantly-slower/68054/3 that really pinned it down. The gist is that the big swing in build times happens if there are ANY differences in env vars, which invalidates the build's manifest cache.

In the VSCode / WSL context, the culprit env var, which is different every time the build task runs, is:

VSCODE_IPC_HOOK_CLI

which includes a UUID in a socket path.

By creating a local custom task, I was able to verify that by overwriting that env var before invoking swift build, I can get the short rebuild times consistently.

in tasks.json:

        "label": "swift-build-tests",
        "type": "shell",
        "command": "VSCODE_IPC_HOOK_CLI= swift build --build-tests",
        "group": "build"
    },

Would it be possible to incorporate this env var override into the tasks that are generated by the plugin? I think it would be a pretty huge quality of life increase for anyone with a Windows / WSL setup. Happy to put up a PR myself if you can give me a pointer.

[adam-fowler]

Nice catch

There is a CONTRIBUTING.md that details development setup. Before I accepted this change I would like to see what this env var does. I'll look through the vscode source code.

[tomerd]

cc @neonichu @MaxDesiatov

[dkolas]

Nice catch

There is a CONTRIBUTING.md that details development setup. Before I accepted this change I would like to see what this env var does. I'll look through the vscode source code.

From what I've seen so far, it's what's providing the socket for the remote process in WSL to write back to so that the CLI output of it can be piped back to the terminal window in VSCode on the Windows side. So on the Linux side, the VSCode host process needs that env var to know what socket to pipe back to, but the swift build process should not care.

[dkolas]

Apologies if this is a dumb question. Followed the instructions in CONTRIBUTING.md, forked the repo, and tried to run the tests out of the box to establish a baseline.

I get a few failures, which all seem to be related to initializing the workspace in the child/test VSCode:

rejected promise not handled within 1 second: Error: Activating extension 'sswg.swift-lang' failed: Cannot find module '/home/dkolas/projects/vscode-swift/dist/extension.js'

and indeed, the dist directory doesn't exist at all. Am I missing a step in the setup or build process?

[dkolas]

Nevermind, looks like I just needed to manually run the build task first. Sorry for TS ignorance.

[adam-fowler]

https://github.com/apple/swift-package-manager/pull/7056

[dkolas]

Can confirm that using the nightly development build of 5.10 that includes the fix above resolves this issue.

[adam-fowler]

I think we can close this now

[dkolas]

Agreed! Thanks for all the help connecting the dots 😃