GV

GeezerVison

The World Wide Web, restored to 800 pixels of glory.

Home|About|Gaming cabinet|Archives|How it works|Starter sites

On this site

  • Sign in
  • ActionsCI/CD and automation
  • CodespacesCloud development environments
  • All Features
  • Documentation
  • Training
  • Certifications
  • Build with Copilot
  • Customize Copilot
  • Integrations
  • Trending repos
  • GitHub Sponsors
  • Developer articles
  • Enterprises

This view

  • Original page
  • New address

GeezerVison is showing github.com — Improve powershell startup time by daxian-dbw · Pull Request #8341 · PowerShell/PowerShell

Conversation

@daxian-dbw

@daxian-dbw Dongbo Wang (daxian-dbw) commented Nov 27, 2018 •
edited
Loading

Uh oh!

There was an error while loading. Please reload this page.

Copy link
Copy Markdown
Member

PR Summary

With this PR, the startup time of pwsh gets about 24.5% improvement on average comparing with the PS Core 6.1.0 official release. The following is an example measurement result by using BenchmarkDotNet v0.11.2 (the detailed information about this measurement result can be found at the end):

# Warm startup -- with module analysis cache pre-populated
pwsh.exe -noprofile -c echo 1

           Method |     Mean |    Error |    StdDev |
----------------- |---------:|---------:|----------:|
           Pwsh61 | 540.5 ms | 9.381 ms |  8.316 ms |
            WinPS | 332.9 ms | 6.497 ms | 10.675 ms |
 pwsh62_optimized | 408.3 ms | 8.936 ms |  9.176 ms |

Detailed Changes

  • Avoid SecuritySupport.IsProductBinary and unnecessary AMSI/suspicious code scan at startup time for a regular session
    • Update CompiledScriptBlockData.IsProductCode to avoid unnecessary calls to IsProductBinary, which attempts to retrieve catalog signature of the target file.
    • Update PerformSecurityChecks to skip AMSI and suspicious code scan for the .psd1 file that contains a safe HashtableAst only.
  • Use customized ReadOnlyBag instead of ImmutableHashSet so that we can avoid loading the System.Collections.Immutable.dll completely.
  • Replace SHA1 with CRC32 when generating module analysis cache file name
    • This remove the loading of System.Security.Cryptography.Algorithms.dll at startup
  • Move ConvertFrom-SddlString to C# to remove the Utility.psm1 file.
  • Crossgen Microsoft.ApplicationInsights.dll and enable tiered compilation
    • Even pwsh with crossgen assemblies spends a lot time in jitting at the startup, about 191.6ms comparing with 24.7ms for Windows PowerShell.
    • Jitting Microsoft.ApplicationInsights.dll took about 51.6ms.
    • By crossgen Microsoft.ApplicationInsights.dll and enable tiered compilation, the jitting time drops to about 98.9ms. Detailed information can be found at the end.

NOTE: Each commit is self-contained and the purpose of the commit is described by the commit message. So it would be easier to review per commit.

Compared with Windows PowerShell

The optimized pwsh is still about 75ms slower than Windows PowerShell. The main reason is jitting time difference, even though we crossgen all the assemblies in the table below except for pwsh.dll.

More work will be done to further bring down the jitting time at startup.

Reference Set Improvement

Impacting memory size loaded from disk (total): 5.9% less pages (606 / 10289 pages), 6% less memory (2.4 / 40.2 mb). The comparison of the image pages being loaded during startup before and after this PR is as follows:

TotalImagesAdded   : 0
TotalImagesRemoved : 15
TotalImagesChanged : 19
TotalPageChange    : -556


   type: Remove

type   image                                       pages
----   -----                                       -----
Remove AppxSip.dll                                 21
Remove coml2.dll                                   31
Remove iertutil.dll                                42
Remove mintdh.dll                                  22
Remove msisip.dll                                  7
Remove OpcServices.dll                             53
Remove pwrshsip.dll                                11
Remove System.Collections.Immutable.dll            74
Remove System.Security.Cryptography.Algorithms.dll 38
Remove System.Security.Permissions.dll             14
Remove System.Threading.AccessControl.dll          6
Remove tdh.dll                                     15
Remove urlmon.dll                                  66
Remove wshext.dll                                  12
Remove xmllite.dll                                 13

   type: Update

type   image                                             pages
----   -----                                             -----
Update clrjit.dll                                        -4
Update combase.dll                                       1
Update coreclr.dll                                       -10
Update crypt32.dll                                       -70
Update KernelBase.dll                                    -3
Update Microsoft.PowerShell.Commands.Utility.dll         4
Update msasn1.dll                                        -4
Update msvcrt.dll                                        -1
Update ntdll.dll                                         1
Update rpcrt4.dll                                        -2
Update sechost.dll                                       -5
Update SHCore.dll                                        -10
Update shell32.dll                                       -1
Update System.Private.CoreLib.dll                        -7
Update System.Runtime.Extensions.dll                     -1
Update System.Security.Cryptography.Primitives.dll       -3
Update System.Security.Cryptography.X509Certificates.dll -2
Update windows.storage.dll                               2
Update wintrust.dll                                      -16

Jitting Time Improvement

Windows PowerShell

Windows PowerShell Assembly Name JitTime msec Num Compilations IL Size Native Size Foreground msec Multicore JIT Background msec Tiered Compilation Background msec
TOTAL 24.7 83 1,506 16,149 24.7 0.0 0.0
Anonymously Hosted DynamicMethods Assembly 19.3 44 0 12,517 19.3 0.0 0.0
C:\WINDOWS\Microsoft.Net\assembly\GAC_MSIL...\System.Management.Automation.dll 4.3 38 1,181 2,782 4.3 0.0 0.0
C:\WINDOWS\Microsoft.Net\assembly\GAC_MSIL...\System.Core.dll 1.1 1 325 850 1.1 0.0 0.0

Before crossgen'ing Microsoft.ApplicationInsights.dll and applying tiered compilation

PWSH Assembly Name JitTime msec Num Compilations IL Size Native Size Foreground msec Multicore JIT Background msec Tiered Compilation Background msec
TOTAL 191.6 488 43,105 140,540 151.2 40.4 0.0
E:\PowerShell\bin\latest\Microsoft.ApplicationInsights.dll 51.6 147 9,866 30,735 51.6 0.0 0.0
E:\PowerShell\bin\latest\System.Management.Automation.dll 44.4 25 14,661 44,123 4.0 40.4 0.0
E:\PowerShell\bin\latest\System.Private.CoreLib.dll 36.0 143 11,947 20,691 36.0 0.0 0.0
E:\PowerShell\bin\latest\Microsoft.PowerShell.CoreCLR.Eventing.dll 22.1 80 0 23,342 22.1 0.0 0.0
E:\PowerShell\bin\latest\System.Collections.Concurrent.dll 17.6 34 4,018 12,261 17.6 0.0 0.0
E:\PowerShell\bin\latest\System.Collections.dll 9.3 34 1,317 3,542 9.3 0.0 0.0
E:\PowerShell\bin\latest\System.Linq.dll 7.6 17 1,085 4,911 7.6 0.0 0.0
Anonymously Hosted DynamicMethods Assembly 1.4 6 0 543 1.4 0.0 0.0
E:\PowerShell\bin\latest\Newtonsoft.Json.dll 0.8 1 196 357 0.8 0.0 0.0
E:\PowerShell\bin\latest\pwsh.dll 0.7 1 15 35 0.7 0.0 0.0

After crossgen Microsoft.ApplicationInsights.dll and applying tiered compilation

Updated PWSH Assembly Name JitTime msec Num Compilations IL Size Native Size Foreground msec Multicore JIT Background msec Tiered Compilation Background msec
TOTAL 98.9 422 34,500 144,231 78.3 20.5 0.0
E:\PowerShell\bin\base\System.Private.CoreLib.dll 26.7 181 12,442 36,649 26.7 0.0 0.0
E:\PowerShell\bin\base\System.Management.Automation.dll 22.7 25 14,661 51,754 2.4 20.3 0.0
E:\PowerShell\bin\base\Microsoft.PowerShell.CoreCLR.Eventing.dll 22.1 80 0 22,778 22.1 0.0 0.0
E:\PowerShell\bin\base\System.Collections.Concurrent.dll 9.9 53 4,429 19,337 9.6 0.3 0.0
E:\PowerShell\bin\base\System.Collections.dll 7.0 52 1,546 6,856 7.0 0.0 0.0
E:\PowerShell\bin\base\System.Linq.dll 5.3 23 1,211 5,770 5.3 0.0 0.0
Anonymously Hosted DynamicMethods Assembly 4.1 6 0 543 4.1 0.0 0.0
E:\PowerShell\bin\base\pwsh.dll 0.7 1 15 51 0.7 0.0 0.0
E:\PowerShell\bin\base\Newtonsoft.Json.dll 0.3 1 196 493 0.3 0.0 0.0

Startup Detailed Measurement Record

// * Detailed results *
PSStartupTime.Pwsh61: Core(Runtime=Core)
Runtime = .NET Core 2.1.6 (CoreCLR 4.6.27019.06, CoreFX 4.6.27019.05), 64bit RyuJIT; GC = Concurrent Workstation
Mean = 540.5245 ms, StdErr = 2.2226 ms (0.41%); N = 14, StdDev = 8.3163 ms
Min = 528.3226 ms, Q1 = 535.3209 ms, Median = 538.9606 ms, Q3 = 544.9347 ms, Max = 559.4117 ms
IQR = 9.6138 ms, LowerFence = 520.9002 ms, UpperFence = 559.3554 ms
ConfidenceInterval = [531.1432 ms; 549.9058 ms] (CI 99.9%), Margin = 9.3813 ms (1.74% of Mean)
Skewness = 0.66, Kurtosis = 2.66, MValue = 2
-------------------- Histogram --------------------
[525.303 ms ; 539.307 ms) | @@@@@@@
[539.307 ms ; 562.431 ms) | @@@@@@@
---------------------------------------------------

PSStartupTime.WinPS: Core(Runtime=Core)
Runtime = .NET Core 2.1.6 (CoreCLR 4.6.27019.06, CoreFX 4.6.27019.05), 64bit RyuJIT; GC = Concurrent Workstation
Mean = 332.9168 ms, StdErr = 1.8044 ms (0.54%); N = 35, StdDev = 10.6749 ms
Min = 316.7778 ms, Q1 = 323.8313 ms, Median = 330.4381 ms, Q3 = 340.1557 ms, Max = 356.9562 ms
IQR = 16.3244 ms, LowerFence = 299.3447 ms, UpperFence = 364.6423 ms
ConfidenceInterval = [326.4197 ms; 339.4139 ms] (CI 99.9%), Margin = 6.4971 ms (1.95% of Mean)
Skewness = 0.47, Kurtosis = 2.28, MValue = 2.2
-------------------- Histogram --------------------
[313.922 ms ; 324.935 ms) | @@@@@@@@@@
[324.935 ms ; 332.120 ms) | @@@@@@@@@
[332.120 ms ; 341.104 ms) | @@@@@@@@@
[341.104 ms ; 348.303 ms) | @@@
[348.303 ms ; 359.812 ms) | @@@@
---------------------------------------------------

PSStartupTime.pwsh62_optimized: Core(Runtime=Core)
Runtime = .NET Core 2.1.6 (CoreCLR 4.6.27019.06, CoreFX 4.6.27019.05), 64bit RyuJIT; GC = Concurrent Workstation
Mean = 408.2847 ms, StdErr = 2.2256 ms (0.55%); N = 17, StdDev = 9.1764 ms
Min = 387.1787 ms, Q1 = 403.7134 ms, Median = 409.1181 ms, Q3 = 414.1094 ms, Max = 428.8114 ms
IQR = 10.3960 ms, LowerFence = 388.1194 ms, UpperFence = 429.7034 ms
ConfidenceInterval = [399.3489 ms; 417.2204 ms] (CI 99.9%), Margin = 8.9358 ms (2.19% of Mean)
Skewness = -0.18, Kurtosis = 3.46, MValue = 2
-------------------- Histogram --------------------
[384.056 ms ; 395.103 ms) | @
[395.103 ms ; 403.504 ms) | @@@
[403.504 ms ; 418.618 ms) | @@@@@@@@@@@@
[418.618 ms ; 431.934 ms) | @
---------------------------------------------------

// * Summary *

BenchmarkDotNet=v0.11.2, OS=Windows 10.0.17763.134 (1809/October2018Update/Redstone5)
Intel Core i7-6700 CPU 3.40GHz (Skylake), 1 CPU, 8 logical and 4 physical cores
.NET Core SDK=2.1.500
  [Host] : .NET Core 2.1.6 (CoreCLR 4.6.27019.06, CoreFX 4.6.27019.05), 64bit RyuJIT
  Core   : .NET Core 2.1.6 (CoreCLR 4.6.27019.06, CoreFX 4.6.27019.05), 64bit RyuJIT

Job=Core  Runtime=Core

           Method |     Mean |    Error |    StdDev |
----------------- |---------:|---------:|----------:|
           Pwsh61 | 540.5 ms | 9.381 ms |  8.316 ms |
            WinPS | 332.9 ms | 6.497 ms | 10.675 ms |
 pwsh62_optimized | 408.3 ms | 8.936 ms |  9.176 ms |

// * Hints *
Outliers
  PSStartupTime.Pwsh61: Core           -> 1 outlier  was  removed
  PSStartupTime.pwsh62_optimized: Core -> 1 outlier  was  detected

// * Legends *
  Mean   : Arithmetic mean of all measurements
  Error  : Half of 99.9% confidence interval
  StdDev : Standard deviation of all measurements
  1 ms   : 1 Millisecond (0.001 sec)

// ***** BenchmarkRunner: End *****
Run time: 00:00:38 (38.84 sec), executed benchmarks: 3

PR Checklist

  • PR has a meaningful title
    • Use the present tense and imperative mood when describing your changes
  • Summarized changes
  • Change is not breaking
  • Make sure all .h, .cpp, .cs, .ps1 and .psm1 files have the correct copyright header
  • This PR is ready to merge and is not Work in Progress.
    • If the PR is work in progress, please add the prefix WIP: to the beginning of the title and remove the prefix when the PR is ready.
  • User-facing changes
    • Not Applicable
    • OR
    • User-facing Documentation needed
      • Issue filed - Issue link:
  • Testing - New and feature
    • Not Applicable or can only be tested interactively
    • OR
    • Make sure you've added a new test if existing tests do not effectively test the code changed
      • Add [feature] if the change is significant or affects feature tests

Sorry, something went wrong.

Uh oh!

There was an error while loading. Please reload this page.

rkeithhill, iSazonov, vexx32, SeeminglyScience, fonta, mklement0, kvprasoon, and RDIL reacted with thumbs up emoji rkeithhill, vexx32, SeeminglyScience, and stknohg reacted with hooray emoji rkeithhill, vexx32, SeeminglyScience, and bergmeister reacted with heart emoji
All reactions
  • 👍 8 reactions
  • 🎉 4 reactions
  • ❤️ 4 reactions
@daxian-dbw
Dongbo Wang (daxian-dbw) requested review from Paul Higinbotham (PaulHigin), Steve Lee (SteveL-MSFT), Travis Plunk (TravisEz13), Aditya Patwardhan (adityapatwardhan), Ilya (iSazonov) and Jason Shirk (lzybkr) November 27, 2018 04:56
@daxian-dbw
Dongbo Wang (daxian-dbw) requested review from Bruce Payette (BrucePay), James Truher (JamesWTruher) and Andrew (anmenaga) as code owners November 27, 2018 04:56
@iSazonov

Ilya (iSazonov) commented Nov 27, 2018

Copy link
Copy Markdown
Collaborator

More work will be done to further bring down the jitting time at startup.

Do you continue in the PR?

After crossgen Microsoft.ApplicationInsights.dll and applying tiered compilation

I don't see Microsoft.ApplicationInsights.dll in the table - no jitting?

I searched "Insights" in our code base and have questions:

  1. Do we really need types from the dll in CorePsTypeCatalog.cs? We could remove 239 lines.
  2. The dll is used for telemetry. Do we really need load the dll at startup? Seems we could delay the telemetry
  3. The telemetry is a static class. We have other static classes. I guess some static classes is initialized at startup (I guess they is initialized at first use time) - does this slow down startup? Make sense to analyze this and try to delay static classes initializations?

If ReadOnlyHashSet was rewrited I think we could look other classes used in PowerShell Core engine. Maybe it won't speed up the startup but increase performance.

Outliers
  PSStartupTime.Pwsh61: Core           -> 2 outliers were removed
  PSStartupTime.WinPS: Core            -> 4 outliers were removed
  PSStartupTime.pwsh62_optimized: Core -> 1 outlier  was  removed

having Outliers it is not good in the test - seems interference from other processes.

Intel Core i7-6700 CPU 3.40GHz (Skylake), 1 CPU, 8 logical and 4 physical cores

I think that an ordinary user computer is 2 physical cores and it would be correct to limit the test to two physical cores. (This may be related to tied compilation)

All reactions

Sorry, something went wrong.

Uh oh!

There was an error while loading. Please reload this page.

@iSazonov

Ilya (iSazonov) commented Nov 27, 2018

Copy link
Copy Markdown
Collaborator

I restarted CI-MacOs.

All reactions

Sorry, something went wrong.

Uh oh!

There was an error while loading. Please reload this page.

iSazonov
Ilya (iSazonov) reviewed Nov 27, 2018
View reviewed changes
Comment thread src/System.Management.Automation/engine/runtime/CompiledScriptBlock.cs Resolved

Uh oh!

There was an error while loading. Please reload this page.

Comment thread src/System.Management.Automation/engine/runtime/CompiledScriptBlock.cs Resolved

Uh oh!

There was an error while loading. Please reload this page.

Comment thread src/System.Management.Automation/engine/runtime/CompiledScriptBlock.cs Resolved

Uh oh!

There was an error while loading. Please reload this page.

Comment thread src/System.Management.Automation/engine/ExperimentalFeature/ExperimentalFeature.cs Resolved

Uh oh!

There was an error while loading. Please reload this page.

Comment thread src/System.Management.Automation/engine/Modules/AnalysisCache.cs Resolved

Uh oh!

There was an error while loading. Please reload this page.

Comment thread src/Modules/Unix/Microsoft.PowerShell.Utility/Microsoft.PowerShell.Utility.psd1 Resolved

Uh oh!

There was an error while loading. Please reload this page.

Comment thread test/powershell/Modules/Microsoft.PowerShell.Utility/ConvertFrom-SddlString.ps1 Resolved

Uh oh!

There was an error while loading. Please reload this page.

Comment thread src/System.Management.Automation/engine/InitialSessionState.cs Resolved

Uh oh!

There was an error while loading. Please reload this page.

Comment thread src/powershell-win-core/powershell-win-core.csproj Resolved

Uh oh!

There was an error while loading. Please reload this page.

Comment thread .gitignore Resolved

Uh oh!

There was an error while loading. Please reload this page.

lzybkr
Jason Shirk (lzybkr) reviewed Nov 27, 2018
View reviewed changes
Comment thread src/System.Management.Automation/engine/runtime/CompiledScriptBlock.cs Resolved

Uh oh!

There was an error while loading. Please reload this page.

lzybkr
Jason Shirk (lzybkr) reviewed Nov 27, 2018
View reviewed changes
Comment thread src/System.Management.Automation/engine/ExperimentalFeature/ExperimentalFeature.cs Resolved

Uh oh!

There was an error while loading. Please reload this page.

lzybkr
Jason Shirk (lzybkr) reviewed Nov 27, 2018
View reviewed changes
Comment thread src/System.Management.Automation/engine/ExperimentalFeature/ExperimentalFeature.cs Resolved

Uh oh!

There was an error while loading. Please reload this page.

lzybkr
Jason Shirk (lzybkr) reviewed Nov 27, 2018
View reviewed changes
Comment thread src/System.Management.Automation/engine/Modules/AnalysisCache.cs Resolved

Uh oh!

There was an error while loading. Please reload this page.

lzybkr
Jason Shirk (lzybkr) reviewed Nov 27, 2018
View reviewed changes
Comment thread src/Microsoft.PowerShell.Commands.Utility/commands/utility/Import-LocalizedData.cs Resolved

Uh oh!

There was an error while loading. Please reload this page.

TravisEz13
Travis Plunk (TravisEz13) reviewed Nov 27, 2018
View reviewed changes
Comment thread src/Microsoft.PowerShell.Commands.Utility/Microsoft.PowerShell.Commands.Utility.csproj Resolved

Uh oh!

There was an error while loading. Please reload this page.

@daxian-dbw

Dongbo Wang (daxian-dbw) commented Nov 27, 2018 •
edited
Loading

Uh oh!

There was an error while loading. Please reload this page.

Copy link
Copy Markdown
Member Author

Ilya (@iSazonov) Reply to your comment here:

More work will be done to further bring down the jitting time at startup.

Do you continue in the PR?

No, that will be in a new PR. The planned work are as follows:

  • Generate PDB for crossgen'ed assemblies that can be used by PerfView/WPA, so that I can do further stack analysis on CPU time.
  • Crossgen'ed assemblies still leave a high cost of jitting time comparing with ngen. It's probably by design as ngen is targeting a specific CPU while crossgen is targeting a general x64 architecture, but I need to contact .NET Core team to get better understanding and see if there are other options (profile-guided-opt?)
  • Ad-hoc code changes to avoid unnecessary work at startup time.

I don't see Microsoft.ApplicationInsights.dll in the table - no jitting?

After the change, no IL code needs to be jitted for this dll at startup time.

Do we really need types from the dll in CorePsTypeCatalog.cs? We could remove 239 lines.

Yes we do. Type conversion depends on the type catalog. Not all .NET Core assemblies shipped with PS Core are loaded at startup. Today, user can use a type even it's from an assembly that is not loaded yet, because powershell knows which assembly the type is from by looking in the type catalog. Without it, the user needs to know which assembly the type is in, and then load the assembly first before using the type. The type catalog is also used in tab completion, so that powershell can tab complete types that are not loaded yet.

The dll is used for telemetry. Do we really need load the dll at startup? Seems we could delay the telemetry

ApplicationInsight telemetry is done in console.dll at startup, as long as the user hasn't opted out.

The telemetry is a static class. We have other static classes. I guess some static classes is initialized at startup (I guess they is initialized at first use time) - does this slow down startup? Make sense to analyze this and try to delay static classes initializations?

The work that is done in this PR are based on the analysis of Reference Set and Jitting time. Some ad-hoc analysis on the static members might be useful, but I think our efforts should be guided by the measurement data, so our time can be spent on things that matters most.

If ReadOnlyHashSet was rewrited I think we could look other classes used in PowerShell Core engine. Maybe it won't speed up the startup but increase performance.

The reason to change ImmutableHashSet to ReadOnlyHashSet is because this only use of ImmutableHashSet causes System.Collections.Immutable.dll to be loaded at startup, which brings in 74 pages loaded from disk. This shows up as part of the reference set analysis. It might be useful to look at other classes, but again, I think our efforts should be guided by the measurement data.

having Outliers it is not good in the test - seems interference from other processes.

There is no interference from other pwsh processes when running the tests. BenchmarkDotNet starts each process many times, and sometimes there are outliers.

I think that an ordinary user computer is 2 physical cores and it would be correct to limit the test to two physical cores. (This may be related to tied compilation)

The baseline is the same, and here we care most about the percentage of improvement instead of the actual startup time. As for multi-core background jitting, with changes in this PR, only 20.5ms are spent in the multi-core background jitting, very small number comparatively, so I don't think it has noticeable effect on the improvement percentage.

All reactions

Sorry, something went wrong.

Uh oh!

There was an error while loading. Please reload this page.

@SteveL-MSFT

Steve Lee (SteveL-MSFT) commented Nov 27, 2018

Copy link
Copy Markdown
Member

The macOS failure appears to be a test code issue:

2018-11-27T12:24:13.7076000Z Description: Basic os_log tests on MacOS/
2018-11-27T12:24:13.7079830Z Name:        Verifies scriptblock logging
2018-11-27T12:24:13.7084250Z message:
2018-11-27T12:24:13.7088810Z did not recieve at least 18 records but 47 instead.
2018-11-27T12:24:13.7094210Z stack-trace:
2018-11-27T12:24:13.7097880Z at <ScriptBlock>, /Users/vsts/agent/2.142.1/work/1/s/test/tools/Modules/PSSysLog/PSSysLog.psm1: line 904
2018-11-27T12:24:13.7098430Z 904:             throw "did not recieve at least $MinimumCount records but $($log.Count) instead."

(note that receive is spelled wrong). According to the text, the test expects >= 18, but 47 is >= 18, so the validation must be wrong.

All reactions

Sorry, something went wrong.

Uh oh!

There was an error while loading. Please reload this page.

@daxian-dbw

Dongbo Wang (daxian-dbw) commented Nov 28, 2018

Copy link
Copy Markdown
Member Author

For the logging test that was failing in previous macOS CI, it's caused by removing Utility.psm1. The test script $testScriptPath has Write-Verbose in it, so when running & $powershell -NoProfile -SettingsFile $configFile -Command $testScriptPath, it triggers the auto-loading of Utility module. Before this PR, that results in 19 event logs. With this PR, two events that record the starting and completion of Utility.psm1 execution are gone, so the total number of event logs becomes 17. I have update the test code, also update PSSysLog.psm1 to correct the wrong message as Steve Lee (@SteveL-MSFT) pointed out above.

iSazonov reacted with thumbs up emoji
All reactions
  • 👍 1 reaction

Sorry, something went wrong.

Uh oh!

There was an error while loading. Please reload this page.

@iSazonov

Ilya (iSazonov) commented Nov 28, 2018

Copy link
Copy Markdown
Collaborator

Yes we do. Type conversion depends on the type catalog. Not all .NET Core assemblies shipped with PS Core are loaded at startup.

But the dll is loaded at startup. Only "Type conversion depends on the type catalog" prevents us from removing the dll from TypeCatalog?

ApplicationInsight telemetry is done in console.dll at startup, as long as the user hasn't opted out.

I understand. My request is - Does the telemetry delay startup or no? If yes we could postpone the telemetry call and loading the dll.

There is no interference from other pwsh processes when running the tests. BenchmarkDotNet starts each process many times, and sometimes there are outliers.

I think these outlies is important to investigate in the startup context. Outlier is unexpected delay. Why we see unexpected delay in the tests?
It is not for the PR but we shouldn't ignore this.

All reactions

Sorry, something went wrong.

Uh oh!

There was an error while loading. Please reload this page.

@daxian-dbw

Dongbo Wang (daxian-dbw) commented Nov 28, 2018 •
edited
Loading

Uh oh!

There was an error while loading. Please reload this page.

Copy link
Copy Markdown
Member Author

But the dll is loaded at startup. Only "Type conversion depends on the type catalog" prevents us from removing the dll from TypeCatalog?

Not sure what you mean by "But the dll is loaded at startup". Most of the assemblies included in the type catalog file are not loaded at startup.

Even for the dlls that are loaded at startup, type resolution would be much faster for a type from those dlls because we can avoid the effort to search types from all loaded assemblies to find the one.

I understand. My request is - Does the telemetry delay startup or no? If yes we could postpone the telemetry call and loading the dll.

The telemetry definitely play a role in the startup time, but I don't know how much after crossgen'ing the dll because I'm not able to analyze the stack info in PerfView/WPA with crossgen'ed assemblies yet.

I think these outlies is important to investigate in the startup context.

Every run of the test starts those processes many times for measurement, including the warm-up. Not every test has outliers in it. I think it's more related to the factors that is out of our control, such as the OS.

BTW, I replaced the detailed test record with a most recent run (after 2nd attempt to address comment commit). You can see that there is only 1 outlier and it's for measuring pwsh 6.1.

All reactions

Sorry, something went wrong.

Uh oh!

There was an error while loading. Please reload this page.

PaulHigin
Paul Higinbotham (PaulHigin) suggested changes Nov 28, 2018
View reviewed changes
Comment thread src/System.Management.Automation/engine/InitialSessionState.cs Resolved

Uh oh!

There was an error while loading. Please reload this page.

Comment thread src/System.Management.Automation/engine/runtime/CompiledScriptBlock.cs Resolved

Uh oh!

There was an error while loading. Please reload this page.

Comment thread src/System.Management.Automation/engine/runtime/CompiledScriptBlock.cs Resolved

Uh oh!

There was an error while loading. Please reload this page.

Comment thread src/System.Management.Automation/security/SecuritySupport.cs Resolved

Uh oh!

There was an error while loading. Please reload this page.

PaulHigin
Paul Higinbotham (PaulHigin) suggested changes Nov 28, 2018
View reviewed changes
Comment thread src/Microsoft.PowerShell.Commands.Utility/commands/utility/ConvertFrom-SddlString.cs Resolved

Uh oh!

There was an error while loading. Please reload this page.

PaulHigin
Paul Higinbotham (PaulHigin) suggested changes Nov 28, 2018
View reviewed changes
Comment thread src/System.Management.Automation/engine/hostifaces/LocalConnection.cs Resolved

Uh oh!

There was an error while loading. Please reload this page.

@daxian-dbw

Dongbo Wang (daxian-dbw) commented Nov 29, 2018 •
edited
Loading

Uh oh!

There was an error while loading. Please reload this page.

Copy link
Copy Markdown
Member Author

Jason Shirk (@lzybkr) Paul Higinbotham (@PaulHigin) Travis Plunk (@TravisEz13) Can you please look at the new changes to PerformSecurityChecks() in CompiledScriptBlock.cs ?

Major change is on how we decide to skip AMSI/malicious code scan. The previous way to check for skipping .psd1 files causes security vulnerabilities.

An attacker can put arbitrary content in a .psd1 file, and call [Parser]::ParseFile() to get an AST from the .psd1 file. Then the attacker can create a script block from the Ast by calling $myAst.GetScriptBlock(). That script block then will be considered from a .psd1 file and skip the code scan.

The skip-scan condition is changed to:

  • the script block should come from a .psd1 file
  • the script block is in fact a HashtableAst
  • the HashtableAst is safe, by calling IsSafeValueVisitor.IsAstSafe(hashtableAst, GetSafeValueVisitor.SafeValueContext.Default).

The API IsSafeValueVisitor.IsAstSafe has been used in GetSafeValueVisitor.GetSafeValue, which is used in module script analysis code, Import-PowerShellDataFile, and the public API Ast.SafeGetValue().

All reactions

Sorry, something went wrong.

Uh oh!

There was an error while loading. Please reload this page.

@iSazonov

Ilya (iSazonov) commented Nov 29, 2018 •
edited
Loading

Uh oh!

There was an error while loading. Please reload this page.

Copy link
Copy Markdown
Collaborator

We have many comments in the PR that is a problem for GitHub web interface. If security concerns have been fixed we could merge and continue with hash function in follow PR.

daxian-dbw reacted with thumbs up emoji
All reactions
  • 👍 1 reaction

Sorry, something went wrong.

Uh oh!

There was an error while loading. Please reload this page.

@iSazonov Ilya (iSazonov) added the CL-CodeCleanup Indicates that a PR should be marked as a Code Cleanup change in the Change Log label Nov 29, 2018
PaulHigin
Paul Higinbotham (PaulHigin) approved these changes Nov 29, 2018
View reviewed changes

@PaulHigin Paul Higinbotham (PaulHigin) left a comment

Copy link
Copy Markdown
Contributor

There was a problem hiding this comment.

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

LTGM. Just minor comments.

Sorry, something went wrong.

Uh oh!

There was an error while loading. Please reload this page.

All reactions
Comment thread src/System.Management.Automation/engine/runtime/CompiledScriptBlock.cs Resolved

Uh oh!

There was an error while loading. Please reload this page.

Comment thread src/System.Management.Automation/engine/runtime/CompiledScriptBlock.cs Resolved

Uh oh!

There was an error while loading. Please reload this page.

Dongbo Wang (daxian-dbw) added 10 commits November 30, 2018 11:20
@daxian-dbw
Use customized 'ReadOnlyHashSet' instead of 'ImmutableHashSet'
86c2157
@daxian-dbw
Replace SHA1 with CRC32 when generating module analysis cache file name
82baef0
@daxian-dbw
Move 'ConvertFrom-SddlString' to C# to avoid Utility.psm1 completely
518ab4f
@daxian-dbw
Update the packaging/signing metadata due to removal of utility.psm1
1770925
@daxian-dbw
Crossgen 'Microsoft.ApplicationInsights' and enable tiered compilation
bdd0acb
@daxian-dbw
[Feature] Update '.gitignore' to ignore .vscode folders from the sub …
9136282
…directories
@daxian-dbw
[Feature] fix macOS build + 1st attempt to address review comments
35abe34
@daxian-dbw
[Feature] 2nd attempt to address review comments
9f186af
Major change is about how we decide to skip AMSI/malicious code scan.

A script block may comes from a .psd1 file but still has arbitrary code in it.
An attacker can parse an .psd1 file to get an Ast and call Ast.GetScriptBlock()
to create a script block. That script block comes from a .psd1 file that may
contain arbitrary content.

The skip-scan condition is changed to:
- the script block should come from a .psd1 file
- the script block is essentially a HashtableAst
- the HashtableAst is safe.
@daxian-dbw
Update comments based on Paul's feedback
2a455d8
@daxian-dbw
[Feature] Address additional comments from Jason
51733c4
@daxian-dbw
Dongbo Wang (daxian-dbw) force-pushed the perf branch from 202535c to 51733c4 Compare November 30, 2018 19:31
@daxian-dbw

Dongbo Wang (daxian-dbw) commented Nov 30, 2018

Copy link
Copy Markdown
Member Author

Attempt to address comments + rebased to resolve the conflict in Microsoft.PowerShell.Commands.Utility.csproj.
Jason Shirk (@lzybkr) Can you please take another look? Thanks!

All reactions

Sorry, something went wrong.

Uh oh!

There was an error while loading. Please reload this page.

@daxian-dbw

Dongbo Wang (daxian-dbw) commented Nov 30, 2018 •
edited
Loading

Uh oh!

There was an error while loading. Please reload this page.

Copy link
Copy Markdown
Member Author

The failed test is most likely caused by #8346. It's a feature-level test, but the commits in that PR don't have the [feature] tag, so the feature tests didn't run for that PR CI.

Here is the failure:

2018-11-30T19:46:25.1215536Z     [-] ConvertFrom-Json deserializes an array of PSObjects (in multiple lines) as a single string. 32ms
2018-11-30T19:46:25.1604605Z       JsonSerializationException: Unexpected end when reading JSON. Path '', line 1, position 3.
2018-11-30T19:46:25.1617847Z       ArgumentException: Conversion from JSON failed with error: Unexpected end when reading JSON. Path '', line 1, position 3.
2018-11-30T19:46:25.1618346Z       at <ScriptBlock>, /home/vsts/work/1/s/test/powershell/Modules/Microsoft.PowerShell.Utility/Pester.Commands.Cmdlets.Json.Tests.ps1: line 1457
All reactions

Sorry, something went wrong.

Uh oh!

There was an error while loading. Please reload this page.

@daxian-dbw
Dongbo Wang (daxian-dbw) merged commit a11810b into PowerShell:master Dec 2, 2018
@daxian-dbw
Dongbo Wang (daxian-dbw) deleted the perf branch December 2, 2018 20:52
@iSazonov

Ilya (iSazonov) commented Dec 3, 2018

Copy link
Copy Markdown
Collaborator

Did we lose a bit of performance with latest commits?

All reactions

Sorry, something went wrong.

Uh oh!

There was an error while loading. Please reload this page.

@daxian-dbw

Dongbo Wang (daxian-dbw) commented Dec 3, 2018 •
edited
Loading

Uh oh!

There was an error while loading. Please reload this page.

Copy link
Copy Markdown
Member Author

Yeah, it looks so to me. The average startup time improvement compared with PS Core 6.1 drops to 24.5% in my tests with changes in the master branch. It's a 1.5% drop on average comparing with before my changing to IsSafeAst. I have updated the number and the example test record in the PR description.

It's the price for security, I guess :/ But I think we can possibly further improve it by having an internal overload of IsSafeAst. The current IsSafeAst always creates a new instance of IsSafeValueVisitor, but in this case here, we should reuse the same instance instead of creating a new object every time, which might add GC pressure given how frequently this method will be called. But doing this shouldn't help much on the startup time as we only call this method once during the startup pwsh -noprofile -c echo 1. I will pursue this lead in my follow-up PRs, which will be out soon.

PaulHigin reacted with thumbs up emoji
All reactions
  • 👍 1 reaction

Sorry, something went wrong.

Uh oh!

There was an error while loading. Please reload this page.

@TravisEz13 Travis Plunk (TravisEz13) mentioned this pull request Dec 4, 2018
Create module analysis cache in containers PowerShell/PowerShell-Docker#61
Closed
@iSazonov

Ilya (iSazonov) commented Dec 4, 2018

Copy link
Copy Markdown
Collaborator
  1. My comment above:

In fact, we come from one point - ScriptBlock.CreateDelayParsedScriptBlock("string", isProductCode: true).
I don't review in depth but I don't found the pattern "isProductCode: false". Perhaps we could implement separate code path.

  1. We have some frozen PRs from Staffan Gustafsson (@powercode) which can increase overall performance and speed up startup too.

  2. I will push a PR for using Unicode simple case folding that seed up too.

All reactions

Sorry, something went wrong.

Uh oh!

There was an error while loading. Please reload this page.

@daxian-dbw

Dongbo Wang (daxian-dbw) commented Dec 4, 2018

Copy link
Copy Markdown
Member Author

Can you elaborate a bit on the unicode simple case folding? I'm not sure what that is.

All reactions

Sorry, something went wrong.

Uh oh!

There was an error while loading. Please reload this page.

@vexx32

Rain Sallow (/u/ta11ow) (vexx32) commented Dec 4, 2018

Copy link
Copy Markdown
Collaborator

Dongbo Wang (@daxian-dbw) See here for the discussion on that: #8120

iSazonov and daxian-dbw reacted with thumbs up emoji
All reactions
  • 👍 2 reactions

Sorry, something went wrong.

Uh oh!

There was an error while loading. Please reload this page.

This was referenced Dec 30, 2018
PowerShell Core doesn't display text #8560
Closed
Rewrite ConvertFrom-SddlString in C# #3212
Closed
This was referenced Jan 21, 2020
Start-Job is now 6-10x slower, and does not preserve $env:PSModulePath #7402
Closed
pwsh is 2 times slower than powershell to load #6443
Closed
@daxian-dbw Dongbo Wang (daxian-dbw) mentioned this pull request Jul 6, 2020
Adding a $PROFILE file has significant impact on startup time #5345
Closed
@daxian-dbw Dongbo Wang (daxian-dbw) mentioned this pull request May 5, 2022
Certificate and execution policy strangeness #17267
Closed
5 tasks done
@daxian-dbw Dongbo Wang (daxian-dbw) mentioned this pull request Sep 26, 2022
Replace Newtonsoft.Json with System.Text.Json in PSConfiguration #14411
Closed
14 tasks
@agonzalezm

Alberto Gonzalez (agonzalezm) commented Dec 1, 2022

Copy link
Copy Markdown

I want to use Convertfrom-sddlstring in c# ? what is the equivalent method in c# and what library?

All reactions

Sorry, something went wrong.

Uh oh!

There was an error while loading. Please reload this page.

Thatgfsj (Thatgfsj) pushed a commit to Thatgfsj-contribs/PowerShell that referenced this pull request Aug 6, 2026
@daxian-dbw
Improve powershell startup time (PowerShell#8341)
b494c7a
Major changes are as follows:
- Avoid `SecuritySupport.IsProductBinary` and unnecessary AMSI/suspicious code scan at startup time
   - Update `CompiledScriptBlockData.IsProductCode` to avoid unnecessary calls to `IsProductBinary`, which attempts to retrieve catalog signature of the target file.
   - Update `PerformSecurityChecks` to skip AMSI and suspicious code scan for the `.psd1` file that contains a safe `HashtableAst` only.
- Use customized `ReadOnlyBag` instead of `ImmutableHashSet` so that we can avoid loading the `System.Collections.Immutable.dll` completely.
- Replace `SHA1` with `CRC32` when generating module analysis cache file name
   - This remove the loading of `System.Security.Cryptography.Algorithms.dll` at startup
- Move `ConvertFrom-SddlString` to C# to remove the `Utility.psm1` file.
- Crossgen `Microsoft.ApplicationInsights.dll` and enable tiered compilation
   - Even pwsh with crossgen assemblies spends a lot time in jitting at the startup, about `191.6ms` comparing with `24.7ms` for Windows PowerShell.
   - Jitting `Microsoft.ApplicationInsights.dll` takes about `51.6ms`.
   - By crossgen `Microsoft.ApplicationInsights.dll` and enable tiered compilation, the jitting time drops to about `98.9ms`.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Reviewers

@iSazonov Ilya (iSazonov) iSazonov left review comments
@TravisEz13 Travis Plunk (TravisEz13) TravisEz13 approved these changes
@SteveL-MSFT Steve Lee (SteveL-MSFT) Awaiting requested review from SteveL-MSFT
@adityapatwardhan Aditya Patwardhan (adityapatwardhan) Awaiting requested review from adityapatwardhan
@anmenaga Andrew (anmenaga) Awaiting requested review from anmenaga
@BrucePay Bruce Payette (BrucePay) Awaiting requested review from BrucePay
@JamesWTruher James Truher (JamesWTruher) Awaiting requested review from JamesWTruher
+2 more reviewers
@lzybkr Jason Shirk (lzybkr) lzybkr left review comments
@PaulHigin Paul Higinbotham (PaulHigin) PaulHigin approved these changes
Reviewers whose approvals may not affect merge requirements

Uh oh!

There was an error while loading. Please reload this page.

Assignees

@daxian-dbw Dongbo Wang (daxian-dbw)

Labels

CL-CodeCleanup Indicates that a PR should be marked as a Code Cleanup change in the Change Log

Projects

None yet

Milestone

No milestone

Development

Successfully merging this pull request may close these issues.

Uh oh!

There was an error while loading. Please reload this page.

8 participants

@daxian-dbw @iSazonov @SteveL-MSFT @vexx32 @agonzalezm @lzybkr @TravisEz13 @PaulHigin
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
You are visitor 01402503 — GeezerVison does not store the pages you look up.
Best viewed with Netscape Navigator 4.7 or Internet Explorer 6 at 800×600. No cookies required.