PowerShell 7 preview 5 takes way too long to launch, far too slow

[JasonFossen]

PROBLEM:
When opening PowerShell 7 Preview 5, it takes 6-10 seconds before the prompt/cursor appears so that commands may be entered. This is embarrassingly slow. If it is not some quirk of my VM, this must be fixed before GA.

REPRODUCE:
Fresh install of Windows Server 2019 Datacenter, version 1809, OS build 17763.737.
Network adapter enabled inside the VM.
VM is on an isolated virtual segment, no outside LAN access.
This Windows Server VM is its own DNS server.
Set POWERSHELL_TELEMETRY_OPTOUT = 1 as a system environment variable.
Install PowerShell Core 7.0.0-preview.5 x64.
Reboot and log on as Administrator.
Run App: pwsh.exe -noprofile
Must wait 6-9 seconds.
Confirm that POWERSHELL_TELEMETRY_OPTOUT = 1 is correctly set in pwsh.
Disable the VM network adapter inside the VM.
Run App: pwsh.exe -noprofile
Launches normally, less than 1 second delay.

NOTES:
PowerShell appears to be doing DNS lookups for ctldl.windowsupdate.com and api.github.com, possibly for telemetry spying, even though POWERSHELL_TELEMETRY_OPTOUT has been set to 1 in the Control Panel System app. The shell is blocking until the DNS lookups fail.

The telemetry spying is bad enough by itself, but the 8-second delay makes it unshippable, especially when telemetry opt out is configured. Many networks, like for the DoD, must run air-gapped.

[SteveL-MSFT]

What you are seeing is calls for update notification as detailed in this RFC: https://github.com/PowerShell/PowerShell-RFC/pull/162/files which includes instructions on how to disable it. Please don't state or imply any "spying" is going on. We deliberately publish RFCs being completely transparent on all data that is sent from the product. Since PowerShell is Open Source, you can see exactly what is being sent and where.

Also, the first cold start of PowerShell, it spends time building the module analysis cache so it knows what commands and cmdlets are available. This is only on the first cold start.

GitHub

Support notification on `pwsh` startup when a new update is available by daxian-dbw · Pull Request #162 · PowerShell/PowerShell-RFC

Support notification on pwsh startup when a new update is available. Today, to find out whether a new version of PowerShell is available, one has to check the release page of the PowerShell\PowerSh...

[JasonFossen]

Thanks for the quick response.

However, setting POWERSHELL_UPDATECHECK to "Off" as a system environment variable does not decrease the startup time of pwsh, it's still about 8 seconds. Disabling the VM's network interface reduces launch time to less than 1 second. Is it a different setting? Am I reading the RFC correctly?

(Regarding telemetry on non-beta products: if it's opt-in, it's feedback; if it's out-out, it's spying. But this isn't the place for another debate on the issue, I'm only interested here in the startup delay.)

[SteveL-MSFT]

Looks like the code currently expects POWERSHELL_UPDATECHECK_OPTOUT=1 to disable. However, that check is supposed to run on a background thread not impact startup perf. cc @daxian-dbw

[xsoheilalizadeh]

Also it getting worse when you load some modules such as posh-git in the profile.

[daxian-dbw]

@JasonFossen The RFC was updated after preview.5 to make the update check behavior more than just on and off, but the code in preview.5 was using POWERSHELL_UPDATECHECK_OPTOUT similar as the telemetry, so you can set POWERSHELL_UPDATECHECK_OPTOUT to 1 to disable the update notification functionality.

But at any rate, the network query to GitHub.com happens on a background thread and shouldn't affect the startup time. I will setup the environment as you described and try to repro the issue. At the same time, hopefully setting POWERSHELL_UPDATECHECK_OPTOUT to 1 can help you work around the problem.

[JasonFossen]

@daxian-dbw Thank you. Btw, setting POWERSHELL_UPDATECHECK_OPTOUT to 1 as a system environment variable makes no difference on my VM. However, disabling recursion on my DNS service in my VM (DNS properties > Advanced tab) also reduces the pwsh startup delay to less than 1 second. My VM is a DNS client to itself. Disabling the VM's network interface has the same effect.

[iSazonov]

@JasonFossen Please share follow information after you run pwsh:

 [environment]::GetEnvironmentVariables()

[environment]::GetEnvironmentVariable("POWERSHELL_UPDATECHECK_OPTOUT")
[environment]::GetEnvironmentVariable("POWERSHELL_TELEMETRY_OPTOUT")

Also you could enable tracing on DNS and catch the slow request - what is a dns name in the request?

[JasonFossen]

@iSazonov

Hello Ilya, these are the names being queried most consistently after launching "pwsh.exe -noprofile":

• ctldl.windowsupdate.com
• checkappexec.microsoft.com
• az764295.vo.msecnd.net

However, when I disable recursion support on the DNS server, only the first name is queried (ctldl.windowsupdate.com), then, when the DNS server refuses to resolve it, pwsh immediately displays a working cursor/prompt, no delay. When recursion support is enabled on the DNS server again, ctldl.windowsupdate.com is queried repeatedly until lookup failure, and then pwsh displays a working cursor/prompt. The other two names are not as consistently queried. Earlier, I saw a query for api.github.com too, but I don't see that anymore.

The DNS server is the local VM on which pwsh is running. The VM is air-gapped from the physical LAN. Queries were captured with Wireshark on the VM. The VM is running Windows Server 2019 Datacenter Evaluation v1809, OS build 17763.737, installed on 3-Nov.2019 as a VM in VirtualBox 6.0.14.

[environment]::GetEnvironmentVariables() | Select *

NUMBER_OF_PROCESSORS : 4
HOMEPATH : UsersAdministrator
DriverData : C:WindowsSystem32DriversDriverData
FPS_BROWSER_APP_PROFILE_STRING : Internet Explorer
USERNAME : Administrator
windir : C:Windows
CommonProgramFiles(x86) : C:Program Files (x86)Common Files
PROCESSOR_REVISION : 3c03
PROCESSOR_IDENTIFIER : Intel64 Family 6 Model 60 Stepping 3, GenuineIntel
USERDNSDOMAIN : TESTING.LOCAL
POWERSHELL_UPDATECHECK_OPTOUT : 1
FPS_BROWSER_USER_PROFILE_STRING : Default
PUBLIC : C:UsersPublic
POWERSHELL_DISTRIBUTION_CHANNEL : MSI:Windows Server 2019 Datacenter Evaluation
PATHEXT : .COM;.EXE;.BAT;.CMD;.VBS;.VBE;.JS;.JSE;.WSF;.WSH;.MSC;.CPL
ProgramFiles : C:Program Files
PROCESSOR_ARCHITECTURE : AMD64
SystemRoot : C:Windows
COMPUTERNAME : WIN-F8ANUMHVJH5
LOGONSERVER : \WIN-F8ANUMHVJH5
HOMEDRIVE : C:
TMP : C:UsersADMINI~1AppDataLocalTemp
ProgramFiles(x86) : C:Program Files (x86)
APPDATA : C:UsersAdministratorAppDataRoaming
PROCESSOR_LEVEL : 6
CommonProgramW6432 : C:Program FilesCommon Files
ProgramData : C:ProgramData
LOCALAPPDATA : C:UsersAdministratorAppDataLocal
SystemDrive : C:
PsNotificationPreference : Off
ProgramW6432 : C:Program Files
POWERSHELL_TELEMETRY_OPTOUT : 1
USERDOMAIN_ROAMINGPROFILE : TESTING
CommonProgramFiles : C:Program FilesCommon Files
OS : Windows_NT
TEMP : C:UsersADMINI1AppDataLocalTemp
PSModulePath : C:UsersAdministratorDocumentsPowerShellModules;C:Program FilesPowerShellModules;c:program filespowershell7-previewModules;C:Windowssystem32WindowsPowerShellv1.0Modules
USERPROFILE : C:UsersAdministrator
ALLUSERSPROFILE : C:ProgramData
Path : C:Windowssystem32;C:Windows;C:WindowsSystem32Wbem;C:WindowsSystem32WindowsPowerShellv1.0;C:WindowsSystem32OpenSSH;C:Program FilesPowerShell7-previewpreview;C:Program FilesMicrosoft VS Codebin;C:UsersAdministratorAppDataLocalMicrosoftWindowsApps
ComSpec : C:Windowssystem32cmd.exe
USERDOMAIN : TESTING

[iSazonov]

ctldl.windowsupdate.com

This site is used for updating root certificates.

I guess there are three issue:

1. DNS. If you enable recursion your DNS service does all work itself. Perhaps you need to update root DNS site list. Or you get a broken response from a stolen DNS.
2. You could look logs (CAPI) to discover why your server has not an updated root certificate list.
3. I don't know why pwsh causes the request every time. I guess it could be third-party AV soft. You could remove the AV and look a result.

[SteveL-MSFT]

pwsh calls into AMSI API (anti-malware) to validate scripts which calls into the AV software that's installed. This is probably triggering the attempt to see if there's new certs for @iSazonov's 3rd point.

[JasonFossen]

Note that, in the VM, the only AV is the built-in Windows Defender and its realtime scanning had been disabled with:

Set-MpPreference -DisableRealtimeMonitoring $True -Force

PowerShell Core is being launched with "pwsh.exe -noprofile" and no third-party modules are installed.

DNS is the symptom, not the cause, of the startup delay. Like Dongbo mentioned, it's probably a thread in pwsh launch/init that is supposed to be running in the background, but is blocking instead. I assume this is what Dongbo is looking into now.

[daxian-dbw]

What I was looking into was whether the updates notification query to GitHub.com, which happens on a background thread, could be the cause.
However, given that the long delay remains after you opt'ed out the update notification (pwsh won't query for GitHub.com at all in this case), the notification update feature is likely not the cause of the symptom.

I did a bit research, ctldl.windowsupdate.com is for updating certificate revocation lists; checkappexec.microsoft.com has something to do with Windows Defender SmartScreen; az764295.vo.msecnd.net is also for detecting malicious code.

Like @SteveL-MSFT mentioned above, the AMSI APIs are hooked up with Windows Defender by default, and could be the trigger of those queries. /cc @TravisEz13 for some insights.

@JasonFossen Can you please try using the 7.0.0-preview.4 version of pwsh on the same VM and see if it has the same problem?

[JasonFossen]

@daxian-dbw Unfortunately, no luck, 7.0.0-preview.4 also shows the same startup delay.

Note that I didn't uninstall preview5 and then install preview4, I started with a fresh VM snapshot, no pwsh at all, then installed preview4.

Btw, in case it makes a difference, the way I'm installing pwsh is from within ISE as local admin:

msiexec.exe /i C:\Full\Path\PowerShell-7.0.0-preview.4-win-x64.msi /qn

And the Windows Server installation ISO was downloaded on 3.Nov.2019: 17763.737.190906-2324.rs5_release_svc_refresh_SERVER_EVAL_x64FRE_en-us_1.iso

No patches or updates have been applied. No third-party software installed. The VM has never had outside network access. If I uninstall the DNS role, or if the VM is configured with no DNS servers at all as a client, then there's no pwsh startup delay because all DNS queries are failing immediately.

I also set Windows Defender back to the default realtime monitoring with the following, but it didn't help:

Set-MpPreference -DisableRealtimeMonitoring $False -Force

[TravisEz13]

I don't think that disables smartscreen. You would have to do this:
https://www.maketecheasier.com/disable-smartscreen-filter-windows10/

Make Tech Easier

How to Disable SmartScreen Filter in Windows 10 - Make Tech Easier

The SmartScreen filter in Windows helps protect your PC from malicious apps and files. Don't like how the SmartScreen filter works? Disable it in Windows 10

[JasonFossen]

@TravisEz13 Thanks Travis, I used all three methods described in that article, at least as far as Windows Server 2019 goes, rebooted, but it didn't help: pwsh-preview4 still opens with an 8-second delay as it waits on recursive DNS queries. Presumably preview5 would do the same. Thank you though.

[TravisEz13]

How about this?
https://blogs.msdn.microsoft.com/winsdk/2015/02/10/reducing-the-time-to-perform-a-crl-check-on-isolated-networks/

Windows SDK Support Team Blog

Reducing the time to perform a CRL check on isolated networks

    Hi everyone,   Writing today to pass along a solution to reduce the time for performing certificate revocation list processing (CRL checking).   This topic has been covered in other blogs in length in ways to lock down servers to prevent outgoing calls for CRL processing and delays.  Here are a few for example:...

[JasonFossen]

Thanks @TravisEz13, it might help, I didn't try it, but the fundamental problem is not that CRL checking is slow, the problem is that the pwsh process launch likely has an init/launch/createrunspace/etc thread which should be running parallel in the background to the other threads, but instead is blocking the whole shell. Launching a new pwsh shell should present a cursor to the user as quickly as possible, even if pwsh is doing other housekeeping in the background. Performing _any_ kind of DNS query for any purpose whatsoever should not be in the "critical path", so to speak, of launching a new "pwsh.exe -noprofile" shell with only generic default modules installed.

[TravisEz13]

@JasonFossen Please provide a stack trace showing what you are saying. Base on the information you have provided so far, I am assume that it is critical path security code.

[TravisEz13]

This article talk about the specific problem. It can happen when we validate any local certificate, and is a WINDOWS function:
https://support.microsoft.com/en-us/help/2677070/an-automatic-updater-of-untrusted-certificates-is-available-for-window

[JasonFossen]

Thanks @TravisEz13 for the links, but you are not seeing the pwsh startup delay as described above? This is on a fresh, air-gapped Windows Server VM, no updates applied, NIC enabled in the isolated VM, DNS role installed in the VM, the VM is a DNS client to itself in the NIC properties, and a clean install of pwsh7-preview5. No stack trace is needed to see the pwsh startup delay of 8 seconds. As the old joke goes, if the problem can't be reproduced, it's not really a problem... ;-)

[JasonFossen]

Interesting, if the OpenSSH service is installed and pwsh7-preview4 is configured as an OpenSSH "subsystem" in the sshd_config file, then there is no startup or connection delay when connecting with:

Enter-PSSession -HostName localhost -SSHTransport -UserName administrator

When pwsh is run by the sshd.exe service, is there something different about running "pwsh.exe -sshs" by the service that avoids the launch delay? Different launch code path? System SID?

[TravisEz13]

My guess is that the call that cause the delay is deferred in the SSH scenario. Something like PSReadLine would run very differently in this scenario

[daxian-dbw]

It looks to me the certificate revocation list (CRL) request is triggered by loading PSReadLine module. PSReadLine.psm1 contains a signature block and the content of the file is scanned by the AMSI API.
In the ssh ssh server mode, PSReadLine will not be loaded at all, so you don't see the CRL request.

[daxian-dbw]

We possibly can move the PSConsoleHostReadLine function from PSReadLine to a C# cmdlet to avoid the delay in the pwsh -noprofile scenario, but it doesn't solve the problem. As soon as you load another script module with a signature in it, you will see the delay again.

[SteveL-MSFT]

PSReadLine is already catalog signed, perhaps we should stop individually signing the psm1 file.

[daxian-dbw]

we should individually signing the psm1 file.

@SteveL-MSFT do you mean skip individually signing the psm1 file? That probably work too, but it just pushes off the problem, not solving it, which might be fine depending on how pwsh is used in such an air-gapped environment. If no other modules with signature block will be used, then maybe the delay issue will never happen.

[SteveL-MSFT]

@daxian-dbw yeah, a word was missing there :)

If other modules the user installs have sig blocks, then that's not something we can solve. We can remediate it for modules we own.

[TravisEz13]

@SteveL-MSFT Catalog signing is not a valid for of authenticode signing for non-windows components. Meaning the module would not work in allSigned.
cc @rkeithhill
The Microsoft SDL requires non-windows components to embed signatures where possible.

[rkeithhill]

Meaning the module would not work in allSigned.

Well, obviously that is not acceptable. :-) The bummer here is that PSRL is 99.9% a binary module. The only script requiring signing is this one function:

function PSConsoleHostReadLine
{
    Microsoft.PowerShell.Core\Set-StrictMode -Off
    [Microsoft.PowerShell.PSConsoleReadLine]::ReadLine($host.Runspace, $ExecutionContext)
}

As @daxian-dbw says "can move the PSConsoleHostReadLine function from PSReadLine to a C# cmdlet to avoid the delay in the pwsh -noprofile scenario"`. While it doesn't solve the issue for other modules, ~I don't see any other modules in a new session that require sig-checking other than PSRL. So in a way, this would solve the PowerShell startup time problem.~ Strike that - the Management & Utility modules have their psd1 files signed. I'm not sure how/when catalog sigs are checked.

@JasonFossen what startup perf do you get with pwsh -nop -noni? That will avoid loading PSRL.

[iSazonov]

If I uninstall the DNS role, or if the VM is configured with no DNS servers at all as a client, then there's no pwsh startup delay because all DNS queries are failing immediately.

What if you assign Google DNS 4.4.4.4 on the network interface?

[JasonFossen]

Hi @rkeithhill, thanks for the useful tip, there is no startup delay when running 'pwsh -noprofile -noninteractive.' However, what I'm actually concerned about in posting this issue to GitHub is PowerShell Core's market share, not my own testing VMs.

As the 'good word' spreads about pwsh7's compatibility and performance, more people will try it out for the first time, especially in comparison to prior versions of pwsh. Thousands of these people, however, will be in air gaps (like half the DoD), or using isolated testing VMs, or sitting at training computers, or otherwise installing pwsh7 on systems that are clients to DNS servers which do not respond correctly or fast enough. These people are not going to blame DNS, AMSI, Windows Defender, Authenticode or CRLs for pwsh's slow startup speed. Every time they launch pwsh and have to wait 8 seconds, they are going to think, "PowerShell Core sucks." Then some of them will tell their friends and post on social media how "PowerShell Core sucks." And for Linux admins in particular, who are accustomed to terminals opening more-or-less instantaneously, an 8-second delay is an _eternity_. When they figure out that it's because pwsh is querying DNS to "phone home" back to Microsoft (the reason why won't matter), it's not going to improve their opinion of PowerShell or Microsoft, to put it mildly. So, overall, I know we're talking about a small percentage of potential pwsh7 users, but why have this unnecessary, self-imposed issue at all?

[rkeithhill]

Could you try this right after you've started with pwsh -nop -noni:

measure-command { ipmo Microsoft.PowerShell.Management }

How long does that take? Then restart with pwsh -nop -noni and run:

measure-command { ipmo PSReadLine }

You mention this being an issue on Linux. I don't think any of the Authenticode cert checking applies to Linux. In fact, execution policy (AllSigned, RemoteSigned, etc) does not apply at all on non-Windows OSs AFAICT.

[JasonFossen]

measure-command { ipmo Microsoft.PowerShell.Management }

9.95 milliseconds avg in 3 new shells

measure-command { ipmo PSReadLine }

9.52 seconds avg in 3 new shells (recursion enabled on DNS server)
83.1 milliseconds avg in 3 new shells (recursion disabled on DNS server)

Good point about Linux, I've only been testing pwsh7 on Windows so far, I'll try it out!

[TravisEz13]

@rkeithhill The catalog signatures on modules are checked when you upload to the gallery.
We really need to move to nuget package signing which theoretically can work cross platform.

[rkeithhill]

@JasonFossen One last test if you don't mind. Go into C:\Program Files\PowerShell\7-preview\Modules\PSReadLine and make a backup copy of PSReadLine.psm1. Then open the original PSReadLine.psm1 and rip out the signature block from beginning to end and save that file. Then run pwsh -nop -noni followed by measure-command { ipmo PSReadLine }. In theory, that should be fast. Note that this would fail if your execution policy were set to AllSigned.

[JasonFossen]

@rkeithhill It was fun to try, but no luck: 9.39 seconds avg, 3 tests, execution policy = bypass. :-

[rkeithhill]

Thanks. Then perhaps it's not the module signature but the Authenticode signature on Microsoft.PowerShell.PSReadLine2.dll. That kind of makes sense because the Management & Utility modules (their psd1 files), which load fast, are also module signed. Not sure how to verify that though.

We had a similar issue on a licensing project I worked on 12 years ago. It was checking the calling assembly's Authenticode signature and on air-gapped systems (never connected to the internet - common for some of our DoD subcontractor customers), there would be this ~30 delay in that code. I don't remember exactly how we addressed that. Seems like it involved us installing a root cert on these machines.

[JasonFossen]

@rkeithhill Fortunately there is no startup delay, as you suggested, for pwsh7-preview5 on Ubuntu 18.04 on the same isolated network using the same DNS server that has recursion enabled. There were DNS queries for api.github.com and dc.services.visualstudio.com, but these were in the background and did not block the shell. No OPTOUT environment variables were set and PSReadLine loaded normally.

[SteveL-MSFT]

It seems that we should minimally provide some information to the user if there is a delay on startup with an aka.ms link to documentation explaining what is happening and what options they have

[daxian-dbw]

That kind of makes sense because the Management & Utility modules (their psd1 files), which load fast, are also module signed.

@rkeithhill There is an optimization to the psd1 files. If the psd1 file contains a pure Hashtable expression and it's considered safe (by using the IsSafeValueVisitor), then the security check is skipped for the psd1 file. The psd1 files for Management & Utility modules are skipped because of this. But you are right, from what @JasonFossen described, loading Utility module still triggers the query, and that suggests the dll signature is playing a role here.

[TravisEz13]

@JasonFossen I profiled this and verified this is a security check of code we are actually running and if you would like to speed up this check, please adjust the settings as described here:
https://github.com/PowerShell/PowerShell/issues/10983#issuecomment-551976417

[JasonFossen]

@TravisEz13 Thank you Travis, that is useful. Unfortunately, it will only be useful to new pwsh users who research the issue (maybe finding it here). I think most people who encounter the problem will simply blame PowerShell Core and go back to Windows PowerShell, which has no startup delay.

[TravisEz13]

@JasonFossen We are considering mitigations. Currently, the best fix, without changes to Windows or removing features is to notify uses of the situation.

[TravisEz13]

Here is the profile:

[iSazonov]

For reference #10309

[TravisEz13]

https://github.com/PowerShell/PowerShell/issues/10983#issuecomment-553759588 this wasn't CDXML related.

[TravisEz13]

@jasonfossen The changes to fix this would be significant. Some possible mitigations would require an RFC. I've opened as discussion issue it to get feedback before we write a detailed RFC on whatever is chosen to go forward with: https://github.com/PowerShell/PowerShell/issues/11074
I'm going to close this issue as the discussion should track this going forward.

[iSazonov]

#10983 (comment) this wasn't CDXML related.

The same GetSaferPolicy() is used.

[msftbot[bot]]

This issue has been marked as answered and has not had any activity for 1 day. It has been closed for housekeeping purposes.