[NoBrainer] PowerShell and Broken TabCompletion

The other day I was working in a PowerShell session when I suddenly realised that Powershell’s TabCompletion feature was no longer working. That was strange, as it certainly normally and definitely worked before. And of course, I did not change anything – so I thought.

After a quick look at lmgtfy did not show any obvious and working solutions for my problem, I came to the conclusion that this must have been something specific to my machine or environment. So I tried to recap what (I) could have been altered or updated. Some more troubleshooting then quickly revealed a specific module that actually caused the error, but that had not been changed in a while.

Shortly before I wanted to enable the fusion log to track any loader exceptions I had a look at the ErrorRecord array, where I discovered the following exception that was caused every time I tried to use tab completion:

>> PS > $error[0]
>> Exception calling “CompleteInput” with “3” argument(s): “Unable to load one or more of the requested types. Retrieve the LoaderExceptions property for more information.”
>> At line:38 char:16
>> + … return [System.Management.Automation.CommandCompletion]::Complet …
>> + ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
>> + CategoryInfo : NotSpecified: (:) [], MethodInvocationException
>> + FullyQualifiedErrorId : ReflectionTypeLoadException

So in fact there was a LoaderException, it was just not visible on StdError. From there it was easy to get the assembly that was causing the error:

>> PS > $error[0].Exception.InnerException.LoaderExceptions | fl * -force
>> Message : Could not load file or assembly ‘Newtonsoft.Json, Version=4.5.0.0, Culture=neutral, PublicKeyToken=30ad4fe6b2a6aeed’ or one of its dependencies. The system cannot find the
>> file specified.
>> FileName : Newtonsoft.Json, Version=4.5.0.0, Culture=neutral, PublicKeyToken=30ad4fe6b2a6aeed
>> FusionLog : WRN: Assembly binding logging is turned OFF.
>> To enable assembly bind failure logging, set the registry value [HKLM\Software\Microsoft\Fusion!EnableLog] (DWORD) to 1.
>> Note: There is some performance penalty associated with assembly bind failure logging.
>> To turn this feature off, remove the registry value [HKLM\Software\Microsoft\Fusion!EnableLog].

But when I checked all the modules I could find none that was referencing the one that was causing the LoaderException (‘Newtonsoft.Json 4.5.0.0’). After I did not come to a good solution I resorted to a rather drastic approach. I intercepted the loader and registered a ResolveEventHandler. From there I could easily check the assembly and return the correct version of it.

The code below I placed into my $profile and from there on I could use tab completion again. Problem ‘solved’ …

$assemblyPathFileName = "C:\Program Files\WindowsPowerShell\Modules\biz.dfch.PS.Appclusive.Client\3.0.0.20160715\Newtonsoft.Json.dll"
$assemlyTypes = Add-Type -Path $assemblyPathFileName;
$assembly = [System.AppDomain]::CurrentDomain.GetAssemblies() |? Location -eq $assemblyPathFileName

$assemblyResolveEventHandler = [System.ResolveEventHandler] {
PARAM
(
  $sender
  , 
  $resolveEventArgs
)

  if("Newtonsoft.Json, Version=4.5.0.0, Culture=neutral, PublicKeyToken=30ad4fe6b2a6aeed" -ieq $resolveEventArgs.Name) 
  { 
    return $assembly;
  }

  foreach($assembly in [System.AppDomain]::CurrentDomain.GetAssemblies())
  {
    if ($assembly.FullName -ieq $resolveEventArgs.Name)
    {
      return $assembly;
    }
  }

  return;
}

[System.AppDomain]::CurrentDomain.add_AssemblyResolve($assemblyResolveEventHandler);

The actual cause for this error was the System.Net.Http.Formatting.dll assembly which tried to load Netwonsoft.Json 4.5.0.0. This was easily revealed with the FUSLOGVW:

Fusion Log Viewer

Fusion Log Viewer

=== Pre-bind state information ===
LOG: DisplayName = Newtonsoft.Json, Version=4.5.0.0, Culture=neutral, PublicKeyToken=30ad4fe6b2a6aeed
 (Fully-specified)
LOG: Appbase = file:///C:/WINDOWS/system32/WindowsPowerShell/v1.0/
LOG: Initial PrivatePath = NULL
LOG: Dynamic Base = NULL
LOG: Cache Base = NULL
LOG: AppName = powershell.exe
Calling assembly : System.Net.Http.Formatting, Version=4.0.0.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35.
===
LOG: This bind starts in default load context.
LOG: No application configuration file found.
LOG: Using host configuration file: 
LOG: Using machine configuration file from C:\Windows\Microsoft.NET\Framework64\v4.0.30319\config\machine.config.
LOG: Post-policy reference: Newtonsoft.Json, Version=4.5.0.0, Culture=neutral, PublicKeyToken=30ad4fe6b2a6aeed
LOG: GAC Lookup was unsuccessful.
LOG: Attempting download of new URL file:///C:/WINDOWS/system32/WindowsPowerShell/v1.0/Newtonsoft.Json.DLL.
LOG: Attempting download of new URL file:///C:/WINDOWS/system32/WindowsPowerShell/v1.0/Newtonsoft.Json/Newtonsoft.Json.DLL.
LOG: Attempting download of new URL file:///C:/WINDOWS/system32/WindowsPowerShell/v1.0/Newtonsoft.Json.EXE.
LOG: Attempting download of new URL file:///C:/WINDOWS/system32/WindowsPowerShell/v1.0/Newtonsoft.Json/Newtonsoft.Json.EXE.
LOG: All probing URLs attempted and failed.

Update

If you do not want in-code replacements you can still update your machine.config with this redirect. I would normally not do this, however in this case I would accept such a change, as the Newtonsoft.Json library seems to be quite often the source of such problems. And with that change we get rid of it once for all.

<configuration>
    <runtime>
    <assemblyBinding xmlns="urn:schemas-microsoft-com:asm.v1">
      <dependentAssembly>
        <assemblyIdentity name="Newtonsoft.Json" publicKeyToken="30ad4fe6b2a6aeed" culture="neutral"/>
        <bindingRedirect oldVersion="0.0.0.0-6.0.0.0" newVersion="6.0.0.0"/>
      </dependentAssembly>
    </assemblyBinding>
  </runtime>
</configuration>

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s

%d bloggers like this: