Wednesday, October 19, 2016

Powershell v3 Tab Completion Takes Forever sometimes Heres why Be warned Its long

Okay, lets say you have PowerShell v3 open and you are confused about some cmdlets name so you just start typing and figure you can tab complete to the rest.  For instance, instead of Send-MailMessage you start looking for the incorrect New-MailMessage by typing New-Mai [tab] where this means you hit the tab key.  A second goes by.  Two seconds.  Ten seconds.  Nothing happens.  Sometimes you do the same thing and it takes a split second to run.  For instance, New-Ob [tab] completes almost instantaneously.  So, what gives?

While doing some testing a few weeks ago I stumbled onto what happens beneath the hood.  When you type a cmdlet name and use tab completion PowerShell begins looking for matches in its list.  In a way, I think of it like AJAX drop down lists and text boxes on the web.  This is really evident when you type a command (in my example output) that does not resolve.  For instance, I use windbg.  I have this installed, but, not in a default location.  When I enter it I intentionally leave off the extension to give an exaggerated effect for both paths and extensions.  The key here is using the *command* wildcard in the Trace-Command -Name parameter.
Trace-Command -Name *command* -Expression { windbg } -PSHost
You can try it out on your machine to see what happens.  Hopefully, youre like me and didnt properly add windbg to your %PATH% variable. (Lazy mans grin.)  Later you can see the suffering youll face if you just run this.  But, before I torment you with the raw output, Ill summarize the high level details so you can see the patterns to get a little glimpse of the mechanics. Ill also include line references so you can follow along below:
  1. Line 1: The command itself.
  2. Line 2: The engine looks for a command: windbg.
  3. Line 3: It then looks up extensions for command testing in $env:PATHEXT.  We will see where these come into play later: .COM;.EXE;.BAT;.CMD;.VBS;.VBE;.JS;.JSE;.WSF;.WSH;.MSC;.CPL
  4. Line 4-11: Powershell looks up paths in the $env:path (or %path% to use old school) variable. Wrapping makes this look like more.
  5. Line 12-45: Whats interesting here is that you see the engine attempting to append built-in values (.ps1, psm1, .psd1) first to the command name (lines 12-17), then, when those fail, it attempts to parse the extensions from the PATHEXT collection (lines 18-45).  Note that it starts with %SystemRoot%system32WindowsPowerShellv1.0 ($PSHome).
  6. The same pattern matching search is repeated for several directories (the values stored in the $env:PATH variable) using the same, sequential order (built-in extensions then PATHEXT values):
    1. Line 12-45: C:Windowssystem32WindowsPowershellv1.0
    2. Line 46-78: C:Windowssystem32
    3. Line 79-111: C:Windows
    4. Line 112-145: C:WindowsSystem32Wbem
    5. Line 146-195: C:Program Files (x86)ATITechnologiesATI.ACECore-Static
    6. Line 196-245: C:Program Files (x86)Common FilesRoxio SharedDLLShared
    7. Line 246-279:  C:Program FilesSlikSvn in
    8. Line 280-313:  C:WindowsSystem32WindowsPowerShellv1.0
    9. Line 314-363:  C:Program Files (x86)Microsoft SQL Server100ToolsBinn
    10. Line 364-411:  C:Program FilesMicrosoft SQL Server100ToolsBinn
    11. Line 412-445:  C:Program FilesMicrosoft SQL Server100DTSBinn
    12. Line 446-493:  C:Program Files (x86)Microsoft SQL Server100ToolsBinnVSShellCommon7IDE
    13. Line 494-543:  C:Program Files (x86)Microsoft SQL Server100DTSBinn
    14. Line 544-593:  C:Program Files (x86)Microsoft Visual Studio 9.0Common7IDEPrivateAssemblies
  7. Lines 594-594: The host reports lookup failure, summarizing with this "All lookup paths exhausted, no more matches can be found"
  8. Lines 595-597: The host decided to prepend Get- to the command and rerun steps 3-5. 
  9. Lines 598-1211: A repeat of whats listed above with Get- put before windbg (for Get-windbg). Finally, it concedes for good and begins cleaning up and notification.
  10. Lines 1212-1237: The host attempts a few more things (module related) before failing and returning the common error message, "ERROR: windbg is not recognized as a cmdlet, function, operable program or script file."
Just for reference, heres my PSVersion info:
PS > $PSVersionTable
Name                           Value
----                           -----
WSManStackVersion              3.0
PSCompatibleVersions           {1.0, 2.0, 3.0}
SerializationVersion           1.1.0.1
BuildVersion                   6.2.8158.0
PSVersion                      3.0
CLRVersion                     4.0.30319.239
PSRemotingProtocolVersion      2.103

And, now, for some really, really, really long output (all 1237 lines of it).  I will just put it up for effect specifically to demonstrate whats going on at the engine while you sit there staring at the screen waiting for some sign of life:

0001: PS C:Usersowner> Trace-Command -Name *command* -Expression { windbg } -PSHost
0002: DEBUG: CommandDiscovery Information: 0 : Looking up command: windbg
0003: DEBUG: CommandDiscovery Information: 0 : PATHEXT: .COM;.EXE;.BAT;.CMD;.VBS;.VBE;.JS;.JSE;.WSF;.WSH;.MSC;.CPL
0004: DEBUG: CommandDiscovery Information: 0 : PATH:
0005: %SystemRoot%system32WindowsPowerShellv1.0;C:Windowssystem32;C:Windows;C:WindowsSystem32Wbem;C:Program Files
0006: (x86)ATI TechnologiesATI.ACECore-Static;C:Program Files (x86)Common FilesRoxio SharedDLLShared;C:Program
0007: FilesSlikSvn in;C:WindowsSystem32WindowsPowerShellv1.0;C:Program Files (x86)Microsoft SQL
0008: Server100ToolsBinn;C:Program FilesMicrosoft SQL Server100ToolsBinn;C:Program FilesMicrosoft SQL
0009: Server100DTSBinn;C:Program Files (x86)Microsoft SQL Server100ToolsBinnVSShellCommon7IDE;C:Program Files
0010: (x86)Microsoft SQL Server100DTSBinn;C:Program Files (x86)Microsoft Visual Studio
0011: 9.0Common7IDEPrivateAssemblies
0012: DEBUG: CommandDiscovery Information: 0 : Looking for windbg.ps1 in %SystemRoot%system32WindowsPowerShellv1.0
0013: DEBUG: CommandSearch Information: 0 :  WriteLine   Current directory results are invalid
0014: DEBUG: CommandDiscovery Information: 0 : Looking for windbg.psm1 in %SystemRoot%system32WindowsPowerShellv1.0
0015: DEBUG: CommandSearch Information: 0 :  WriteLine   Current directory results are invalid
0016: DEBUG: CommandDiscovery Information: 0 : Looking for windbg.psd1 in %SystemRoot%system32WindowsPowerShellv1.0
0017: DEBUG: CommandSearch Information: 0 :  WriteLine   Current directory results are invalid
0018: DEBUG: CommandDiscovery Information: 0 : Looking for windbg.COM in %SystemRoot%system32WindowsPowerShellv1.0
0019: DEBUG: CommandSearch Information: 0 :  WriteLine   Current directory results are invalid
0020: DEBUG: CommandDiscovery Information: 0 : Looking for windbg.EXE in %SystemRoot%system32WindowsPowerShellv1.0
0021: DEBUG: CommandSearch Information: 0 :  WriteLine   Current directory results are invalid
0022: DEBUG: CommandDiscovery Information: 0 : Looking for windbg.BAT in %SystemRoot%system32WindowsPowerShellv1.0
0023: DEBUG: CommandSearch Information: 0 :  WriteLine   Current directory results are invalid
0024: DEBUG: CommandDiscovery Information: 0 : Looking for windbg.CMD in %SystemRoot%system32WindowsPowerShellv1.0
0025: DEBUG: CommandSearch Information: 0 :  WriteLine   Current directory results are invalid
0026: DEBUG: CommandDiscovery Information: 0 : Looking for windbg.VBS in %SystemRoot%system32WindowsPowerShellv1.0
0027: DEBUG: CommandSearch Information: 0 :  WriteLine   Current directory results are invalid
0028: DEBUG: CommandDiscovery Information: 0 : Looking for windbg.VBE in %SystemRoot%system32WindowsPowerShellv1.0
0029: DEBUG: CommandSearch Information: 0 :  WriteLine   Current directory results are invalid
0030: DEBUG: CommandDiscovery Information: 0 : Looking for windbg.JS in %SystemRoot%system32WindowsPowerShellv1.0
0031: DEBUG: CommandSearch Information: 0 :  WriteLine   Current directory results are invalid
0032: DEBUG: CommandDiscovery Information: 0 : Looking for windbg.JSE in %SystemRoot%system32WindowsPowerShellv1.0
0033: DEBUG: CommandSearch Information: 0 :  WriteLine   Current directory results are invalid
0034: DEBUG: CommandDiscovery Information: 0 : Looking for windbg.WSF in %SystemRoot%system32WindowsPowerShellv1.0
0035: DEBUG: CommandSearch Information: 0 :  WriteLine   Current directory results are invalid
0036: DEBUG: CommandDiscovery Information: 0 : Looking for windbg.WSH in %SystemRoot%system32WindowsPowerShellv1.0
0037: DEBUG: CommandSearch Information: 0 :  WriteLine   Current directory results are invalid
0038: DEBUG: CommandDiscovery Information: 0 : Looking for windbg.MSC in %SystemRoot%system32WindowsPowerShellv1.0
0039: DEBUG: CommandSearch Information: 0 :  WriteLine   Current directory results are invalid
0040: DEBUG: CommandDiscovery Information: 0 : Looking for windbg.CPL in %SystemRoot%system32WindowsPowerShellv1.0
0041: DEBUG: CommandSearch Information: 0 :  WriteLine   Current directory results are invalid
0042: DEBUG: CommandDiscovery Information: 0 : Looking for windbg in %SystemRoot%system32WindowsPowerShellv1.0
0043: DEBUG: CommandSearch Information: 0 :  WriteLine   Current directory results are invalid
0044: DEBUG: CommandSearch Information: 0 :  WriteLine   Current patterns exhausted in current directory:
0045: %SystemRoot%system32WindowsPowerShellv1.0
0046: DEBUG: CommandDiscovery Information: 0 : Looking for windbg.ps1 in C:Windowssystem32
0047: DEBUG: CommandSearch Information: 0 :  WriteLine   Current directory results are invalid
0048: DEBUG: CommandDiscovery Information: 0 : Looking for windbg.psm1 in C:Windowssystem32
0049: DEBUG: CommandSearch Information: 0 :  WriteLine   Current directory results are invalid
0050: DEBUG: CommandDiscovery Information: 0 : Looking for windbg.psd1 in C:Windowssystem32
0051: DEBUG: CommandSearch Information: 0 :  WriteLine   Current directory results are invalid
0052: DEBUG: CommandDiscovery Information: 0 : Looking for windbg.COM in C:Windowssystem32
0053: DEBUG: CommandSearch Information: 0 :  WriteLine   Current directory results are invalid
0054: DEBUG: CommandDiscovery Information: 0 : Looking for windbg.EXE in C:Windowssystem32
0055: DEBUG: CommandSearch Information: 0 :  WriteLine   Current directory results are invalid
0056: DEBUG: CommandDiscovery Information: 0 : Looking for windbg.BAT in C:Windowssystem32
0057: DEBUG: CommandSearch Information: 0 :  WriteLine   Current directory results are invalid
0058: DEBUG: CommandDiscovery Information: 0 : Looking for windbg.CMD in C:Windowssystem32
0059: DEBUG: CommandSearch Information: 0 :  WriteLine   Current directory results are invalid
0060: DEBUG: CommandDiscovery Information: 0 : Looking for windbg.VBS in C:Windowssystem32
0061: DEBUG: CommandSearch Information: 0 :  WriteLine   Current directory results are invalid
0062: DEBUG: CommandDiscovery Information: 0 : Looking for windbg.VBE in C:Windowssystem32
0063: DEBUG: CommandSearch Information: 0 :  WriteLine   Current directory results are invalid
0064: DEBUG: CommandDiscovery Information: 0 : Looking for windbg.JS in C:Windowssystem32
0065: DEBUG: CommandSearch Information: 0 :  WriteLine   Current directory results are invalid
0066: DEBUG: CommandDiscovery Information: 0 : Looking for windbg.JSE in C:Windowssystem32
0067: DEBUG: CommandSearch Information: 0 :  WriteLine   Current directory results are invalid
0068: DEBUG: CommandDiscovery Information: 0 : Looking for windbg.WSF in C:Windowssystem32
0069: DEBUG: CommandSearch Information: 0 :  WriteLine   Current directory results are invalid
0070: DEBUG: CommandDiscovery Information: 0 : Looking for windbg.WSH in C:Windowssystem32
0071: DEBUG: CommandSearch Information: 0 :  WriteLine   Current directory results are invalid
0072: DEBUG: CommandDiscovery Information: 0 : Looking for windbg.MSC in C:Windowssystem32
0073: DEBUG: CommandSearch Information: 0 :  WriteLine   Current directory results are invalid
0074: DEBUG: CommandDiscovery Information: 0 : Looking for windbg.CPL in C:Windowssystem32
0075: DEBUG: CommandSearch Information: 0 :  WriteLine   Current directory results are invalid
0076: DEBUG: CommandDiscovery Information: 0 : Looking for windbg in C:Windowssystem32
0077: DEBUG: CommandSearch Information: 0 :  WriteLine   Current directory results are invalid
0078: DEBUG: CommandSearch Information: 0 :  WriteLine   Current patterns exhausted in current directory: C:Windowssystem32
0079: DEBUG: CommandDiscovery Information: 0 : Looking for windbg.ps1 in C:Windows
0080: DEBUG: CommandSearch Information: 0 :  WriteLine   Current directory results are invalid
0081: DEBUG: CommandDiscovery Information: 0 : Looking for windbg.psm1 in C:Windows
0082: DEBUG: CommandSearch Information: 0 :  WriteLine   Current directory results are invalid
0083: DEBUG: CommandDiscovery Information: 0 : Looking for windbg.psd1 in C:Windows
0084: DEBUG: CommandSearch Information: 0 :  WriteLine   Current directory results are invalid
0085: DEBUG: CommandDiscovery Information: 0 : Looking for windbg.COM in C:Windows
0086: DEBUG: CommandSearch Information: 0 :  WriteLine   Current directory results are invalid
0087: DEBUG: CommandDiscovery Information: 0 : Looking for windbg.EXE in C:Windows
0088: DEBUG: CommandSearch Information: 0 :  WriteLine   Current directory results are invalid
0089: DEBUG: CommandDiscovery Information: 0 : Looking for windbg.BAT in C:Windows
0090: DEBUG: CommandSearch Information: 0 :  WriteLine   Current directory results are invalid
0091: DEBUG: CommandDiscovery Information: 0 : Looking for windbg.CMD in C:Windows
0092: DEBUG: CommandSearch Information: 0 :  WriteLine   Current directory results are invalid
0093: DEBUG: CommandDiscovery Information: 0 : Looking for windbg.VBS in C:Windows
0094: DEBUG: CommandSearch Information: 0 :  WriteLine   Current directory results are invalid
0095: DEBUG: CommandDiscovery Information: 0 : Looking for windbg.VBE in C:Windows
0096: DEBUG: CommandSearch Information: 0 :  WriteLine   Current directory results are invalid
0097: DEBUG: CommandDiscovery Information: 0 : Looking for windbg.JS in C:Windows
0098: DEBUG: CommandSearch Information: 0 :  WriteLine   Current directory results are invalid
0099: DEBUG: CommandDiscovery Information: 0 : Looking for windbg.JSE in C:Windows
0100: DEBUG: CommandSearch Information: 0 :  WriteLine   Current directory results are invalid
0101: DEBUG: CommandDiscovery Information: 0 : Looking for windbg.WSF in C:Windows
0102: DEBUG: CommandSearch Information: 0 :  WriteLine   Current directory results are invalid
0103: DEBUG: CommandDiscovery Information: 0 : Looking for windbg.WSH in C:Windows
0104: DEBUG: CommandSearch Information: 0 :  WriteLine   Current directory results are invalid
0105: DEBUG: CommandDiscovery Information: 0 : Looking for windbg.MSC in C:Windows
0106: DEBUG: CommandSearch Information: 0 :  WriteLine   Current directory results are invalid
0107: DEBUG: CommandDiscovery Information: 0 : Looking for windbg.CPL in C:Windows
0108: DEBUG: CommandSearch Information: 0 :  WriteLine   Current directory results are invalid
0109: DEBUG: CommandDiscovery Information: 0 : Looking for windbg in C:Windows
0110: DEBUG: CommandSearch Information: 0 :  WriteLine   Current directory results are invalid
0111: DEBUG: CommandSearch Information: 0 :  WriteLine   Current patterns exhausted in current directory: C:Windows
0112: DEBUG: CommandDiscovery Information: 0 : Looking for windbg.ps1 in C:WindowsSystem32Wbem
0113: DEBUG: CommandSearch Information: 0 :  WriteLine   Current directory results are invalid
0114: DEBUG: CommandDiscovery Information: 0 : Looking for windbg.psm1 in C:WindowsSystem32Wbem
0115: DEBUG: CommandSearch Information: 0 :  WriteLine   Current directory results are invalid
0116: DEBUG: CommandDiscovery Information: 0 : Looking for windbg.psd1 in C:WindowsSystem32Wbem
0117: DEBUG: CommandSearch Information: 0 :  WriteLine   Current directory results are invalid
0118: DEBUG: CommandDiscovery Information: 0 : Looking for windbg.COM in C:WindowsSystem32Wbem
0119: DEBUG: CommandSearch Information: 0 :  WriteLine   Current directory results are invalid
0120: DEBUG: CommandDiscovery Information: 0 : Looking for windbg.EXE in C:WindowsSystem32Wbem
0121: DEBUG: CommandSearch Information: 0 :  WriteLine   Current directory results are invalid
0122: DEBUG: CommandDiscovery Information: 0 : Looking for windbg.BAT in C:WindowsSystem32Wbem
0123: DEBUG: CommandSearch Information: 0 :  WriteLine   Current directory results are invalid
0124: DEBUG: CommandDiscovery Information: 0 : Looking for windbg.CMD in C:WindowsSystem32Wbem
0125: DEBUG: CommandSearch Information: 0 :  WriteLine   Current directory results are invalid
0126: DEBUG: CommandDiscovery Information: 0 : Looking for windbg.VBS in C:WindowsSystem32Wbem
0127: DEBUG: CommandSearch Information: 0 :  WriteLine   Current directory results are invalid
0128: DEBUG: CommandDiscovery Information: 0 : Looking for windbg.VBE in C:WindowsSystem32Wbem
0129: DEBUG: CommandSearch Information: 0 :  WriteLine   Current directory results are invalid
0130: DEBUG: CommandDiscovery Information: 0 : Looking for windbg.JS in C:WindowsSystem32Wbem
0131: DEBUG: CommandSearch Information: 0 :  WriteLine   Current directory results are invalid
0132: DEBUG: CommandDiscovery Information: 0 : Looking for windbg.JSE in C:WindowsSystem32Wbem
0133: DEBUG: CommandSearch Information: 0 :  WriteLine   Current directory results are invalid
0134: DEBUG: CommandDiscovery Information: 0 : Looking for windbg.WSF in C:WindowsSystem32Wbem
0135: DEBUG: CommandSearch Information: 0 :  WriteLine   Current directory results are invalid
0136: DEBUG: CommandDiscovery Information: 0 : Looking for windbg.WSH in C:WindowsSystem32Wbem
0137: DEBUG: CommandSearch Information: 0 :  WriteLine   Current directory results are invalid
0138: DEBUG: CommandDiscovery Information: 0 : Looking for windbg.MSC in C:WindowsSystem32Wbem
0139: DEBUG: CommandSearch Information: 0 :  WriteLine   Current directory results are invalid
0140: DEBUG: CommandDiscovery Information: 0 : Looking for windbg.CPL in C:WindowsSystem32Wbem
0141: DEBUG: CommandSearch Information: 0 :  WriteLine   Current directory results are invalid
0142: DEBUG: CommandDiscovery Information: 0 : Looking for windbg in C:WindowsSystem32Wbem
0143: DEBUG: CommandSearch Information: 0 :  WriteLine   Current directory results are invalid
0144: DEBUG: CommandSearch Information: 0 :  WriteLine   Current patterns exhausted in current directory:
0145: C:WindowsSystem32Wbem
0146: DEBUG: CommandDiscovery Information: 0 : Looking for windbg.ps1 in C:Program Files (x86)ATI
0147: TechnologiesATI.ACECore-Static
0148: DEBUG: CommandSearch Information: 0 :  WriteLine   Current directory results are invalid
0149: DEBUG: CommandDiscovery Information: 0 : Looking for windbg.psm1 in C:Program Files (x86)ATI
0150: TechnologiesATI.ACECore-Static
0151: DEBUG: CommandSearch Information: 0 :  WriteLine   Current directory results are invalid
0152: DEBUG: CommandDiscovery Information: 0 : Looking for windbg.psd1 in C:Program Files (x86)ATI
0153: TechnologiesATI.ACECore-Static
0154: DEBUG: CommandSearch Information: 0 :  WriteLine   Current directory results are invalid
0155: DEBUG: CommandDiscovery Information: 0 : Looking for windbg.COM in C:Program Files (x86)ATI
0156: TechnologiesATI.ACECore-Static
0157: DEBUG: CommandSearch Information: 0 :  WriteLine   Current directory results are invalid
0158: DEBUG: CommandDiscovery Information: 0 : Looking for windbg.EXE in C:Program Files (x86)ATI
0159: TechnologiesATI.ACECore-Static
0160: DEBUG: CommandSearch Information: 0 :  WriteLine   Current directory results are invalid
0161: DEBUG: CommandDiscovery Information: 0 : Looking for windbg.BAT in C:Program Files (x86)ATI
0162: TechnologiesATI.ACECore-Static
0163: DEBUG: CommandSearch Information: 0 :  WriteLine   Current directory results are invalid
0164: DEBUG: CommandDiscovery Information: 0 : Looking for windbg.CMD in C:Program Files (x86)ATI
0165: TechnologiesATI.ACECore-Static
0166: DEBUG: CommandSearch Information: 0 :  WriteLine   Current directory results are invalid
0167: DEBUG: CommandDiscovery Information: 0 : Looking for windbg.VBS in C:Program Files (x86)ATI
0168: TechnologiesATI.ACECore-Static
0169: DEBUG: CommandSearch Information: 0 :  WriteLine   Current directory results are invalid
0170: DEBUG: CommandDiscovery Information: 0 : Looking for windbg.VBE in C:Program Files (x86)ATI
0171: TechnologiesATI.ACECore-Static
0172: DEBUG: CommandSearch Information: 0 :  WriteLine   Current directory results are invalid
0173: DEBUG: CommandDiscovery Information: 0 : Looking for windbg.JS in C:Program Files (x86)ATI
0174: TechnologiesATI.ACECore-Static
0175: DEBUG: CommandSearch Information: 0 :  WriteLine   Current directory results are invalid
0176: DEBUG: CommandDiscovery Information: 0 : Looking for windbg.JSE in C:Program Files (x86)ATI
0177: TechnologiesATI.ACECore-Static
0178: DEBUG: CommandSearch Information: 0 :  WriteLine   Current directory results are invalid
0179: DEBUG: CommandDiscovery Information: 0 : Looking for windbg.WSF in C:Program Files (x86)ATI
0180: TechnologiesATI.ACECore-Static
0181: DEBUG: CommandSearch Information: 0 :  WriteLine   Current directory results are invalid
0182: DEBUG: CommandDiscovery Information: 0 : Looking for windbg.WSH in C:Program Files (x86)ATI
0183: TechnologiesATI.ACECore-Static
0184: DEBUG: CommandSearch Information: 0 :  WriteLine   Current directory results are invalid
0185: DEBUG: Com

Related Post:

0 comments:

Post a Comment

 
Copyright 2009 Information Blog
Powered By Blogger