Vscode-powershell: Format document hangs indefinitely

[mattmcnabb]

Right clicking on a script and selecting format document sometimes stalls out and all you get is the text "Formatting current document..." in the status bar.

System Details

• Operating system name and version:
• VS Code version: 1.13.0
• PowerShell extension version: 1.3.1
• Output from $PSVersionTable:
  Name Value
  ---- -----
  PSVersion 5.1.15063.296
  PSEdition Desktop
  PSCompatibleVersions {1.0, 2.0, 3.0, 4.0...}
  BuildVersion 10.0.15063.296
  CLRVersion 4.0.30319.42000
  WSManStackVersion 3.0
  PSRemotingProtocolVersion 2.3
  SerializationVersion 1.1.0.1

Issue Description

I am experiencing a problem with...

Attached Logs

[0:2:50] Language server starting...
powershell.exe started --
pid: 7396
exe: C:\WINDOWS\Sysnative\WindowsPowerShell\v1.0\powershell.exe
args: C:\Users\matt.vscode\extensions\ms-vscode.powershell-1.3.1\scripts\Start-EditorServices.ps1 -EditorServicesVersion '1.3.1' -HostName 'Visual Studio Code Host' -HostProfileId 'Microsoft.VSCode' -HostVersion '1.3.1' -BundledModulesPath 'C:\Users\matt.vscode\extensions\ms-vscode.powershell-1.3.1\modules' -EnableConsoleRepl -LogLevel 'Normal' -LogPath 'C:\Users\matt.vscode\extensions\ms-vscode.powershell-1.3.1\logs1497067370-99efb25e-e506-4ad6-9e6d-0a28c6750e141497064145804\EditorServices.log' -SessionDetailsPath 'C:\Users\matt.vscode\extensions\ms-vscode.powershell-1.3.1\sessions\PSES-VSCode-16500-919759' -FeatureFlags @()

[0:2:58] Language server started.
{"debugServicePort":23032,"status":"started","channel":"tcp","languageServicePort":26349}
Connecting to language service on port 26349...

Language service connected.

[daviwil]

@kapilmb wanna take a look at this one?

[MattAllison]

Same problem. Error portion of logs below.

Working in PowerShell - seems to work fine for simple scenarios. Breaks most commonly when there are a lot of block comments.

6/10/2017 8:56:00 AM [ERROR] - Method "DispatchMessage" at line 147 of C:\projects\powershelleditorservices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageDispatcher.cs

MessageDispatcher: No handler registered for Event type 'initialized'

6/10/2017 8:56:00 AM [ERROR] - Method "DispatchMessage" at line 147 of C:\projects\powershelleditorservices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageDispatcher.cs

MessageDispatcher: No handler registered for Event type '$/setTraceNotification'

6/10/2017 8:56:11 AM [ERROR] - Method "OnListenTaskCompleted" at line 391 of C:\projects\powershelleditorservices\src\PowerShellEditorServices.Protocol\MessageProtocol\ProtocolEndpoint.cs

ProtocolEndpoint message loop terminated due to unhandled exception:

System.AggregateException: One or more errors occurred. ---> System.NullReferenceException: Object reference not set to an instance of an object.
   at Microsoft.PowerShell.EditorServices.CodeLenses.ReferencesCodeLensProvider.<ResolveCodeLensAsync>d__4.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Microsoft.PowerShell.EditorServices.CodeLenses.CodeLensFeature.<HandleCodeLensResolveRequest>d__9.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Microsoft.PowerShell.EditorServices.Protocol.MessageProtocol.MessageDispatcher.<DispatchMessage>d__7.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Microsoft.PowerShell.EditorServices.Protocol.MessageProtocol.ProtocolEndpoint.<ListenForMessages>d__36.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Microsoft.PowerShell.EditorServices.Utility.AsyncContext.Start(Func`1 asyncMainFunc, ILogger logger)
   at System.Threading.Tasks.Task.Execute()
   --- End of inner exception stack trace ---
---> (Inner Exception #0) System.NullReferenceException: Object reference not set to an instance of an object.
   at Microsoft.PowerShell.EditorServices.CodeLenses.ReferencesCodeLensProvider.<ResolveCodeLensAsync>d__4.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Microsoft.PowerShell.EditorServices.CodeLenses.CodeLensFeature.<HandleCodeLensResolveRequest>d__9.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Microsoft.PowerShell.EditorServices.Protocol.MessageProtocol.MessageDispatcher.<DispatchMessage>d__7.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Microsoft.PowerShell.EditorServices.Protocol.MessageProtocol.ProtocolEndpoint.<ListenForMessages>d__36.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Microsoft.PowerShell.EditorServices.Utility.AsyncContext.Start(Func`1 asyncMainFunc, ILogger logger)
   at System.Threading.Tasks.Task.Execute()<---

[daviwil]

Hmmm, maybe both of you are seeing a manifestation of #857. This causes the language server to hang once it happens. I think I just fixed it, might ship an update today or tomorrow!

[MattAllison]

Was thinking it just may not like people named Matt.

[daviwil]

That's the fix, I took out this line:

    throw new InvalidMattException();

[muzzar78]

I'm seeing the editor service crash too when I open up a number of our pester test files (see attached log). I have seen the format document hang indefinitely on our bigger dsc files.

EditorServices .txt

[kapilmb]

@daviwil I will revisit this after #857 is resolved. There is nothing related to formatting that we checked in the last couple of releases so I doubt this is a formatting issue, but you never know!

[daviwil]

@muzzar78 Thanks for the logs Adam, I now see another issue. I'll ship a fix tomorrow.

[daviwil]

@mattmcnabb can you reproduce the issue and grab Editor Services logs so I can see the specific error you get?

https://github.com/PowerShell/vscode-powershell#reporting-problems

[mattmcnabb]

@daviwil sent via email

[daviwil]

Relevant snippet from Matt's logs, looks to be the same as @muzzar78's.

    ProtocolEndpoint message loop terminated due to unhandled exception:

    System.AggregateException: One or more errors occurred. ---> System.NullReferenceException: Object reference not set to an instance of an object.
       at Microsoft.PowerShell.EditorServices.Symbols.PesterSymbolReference.GetCommandType(String commandName)
       at Microsoft.PowerShell.EditorServices.Symbols.PesterDocumentSymbolProvider.<>c.<Microsoft.PowerShell.EditorServices.Symbols.IDocumentSymbolProvider.ProvideDocumentSymbols>b__0_0(Ast ast)
       at System.Management.Automation.Language.AstSearcher.Check(Ast ast)
       at System.Management.Automation.Language.CommandAst.InternalVisit(AstVisitor visitor)
       at System.Management.Automation.Language.PipelineAst.InternalVisit(AstVisitor visitor)
       at System.Management.Automation.Language.AssignmentStatementAst.InternalVisit(AstVisitor visitor)
       at System.Management.Automation.Language.StatementBlockAst.InternalVisit(AstVisitor visitor, ReadOnlyCollection`1 traps, ReadOnlyCollection`1 statements, AstVisitAction action)
       at System.Management.Automation.Language.NamedBlockAst.InternalVisit(AstVisitor visitor)
       at System.Management.Automation.Language.ScriptBlockAst.InternalVisit(AstVisitor visitor)
       at System.Management.Automation.Language.ScriptBlockExpressionAst.InternalVisit(AstVisitor visitor)
       at System.Management.Automation.Language.CommandAst.InternalVisit(AstVisitor visitor)
       at System.Management.Automation.Language.PipelineAst.InternalVisit(AstVisitor visitor)
       at System.Management.Automation.Language.StatementBlockAst.InternalVisit(AstVisitor visitor, ReadOnlyCollection`1 traps, ReadOnlyCollection`1 statements, AstVisitAction action)
       at System.Management.Automation.Language.NamedBlockAst.InternalVisit(AstVisitor visitor)
       at System.Management.Automation.Language.ScriptBlockAst.InternalVisit(AstVisitor visitor)
       at System.Management.Automation.Language.Ast.FindAll(Func`2 predicate, Boolean searchNestedScriptBlocks)
       at 

[muzzar78]

Thanks @daviwil . Our module is available on github if you want to reproduce the issue https://github.com/nubustech/NubusTech.CredentialStore. Any time I select a pester script from the tests folder the problem occurs.