Never ending "Formatting Powershell document ..."

artisticcheese commented 7 years ago

System Details

Operating system name and version:
VS Code version: 1.13.0
PowerShell extension version: 1.3.2

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

Copy / paste the below commands into the PowerShell Integrated Terminal, and paste the output here

code -v $pseditor.EditorServicesVersion code --list-extensions --show-versions $PSVersionTable

PS C:\gd\Documents\s\docker\tools\vstsagent> code -v
1.13.0
376c52b955428d205459bea6619fc161fc8faacf
PS C:\gd\Documents\s\docker\tools\vstsagent> $pseditor.EditorServicesVersion

Major  Minor  Build  Revision
-----  -----  -----  --------
1      3      2      0

PS C:\gd\Documents\s\docker\tools\vstsagent> code --list-extensions --show-versions
DotJoshJohnson.xml@1.8.0
mkloubert.vs-deploy@9.25.0
ms-vscode.csharp@1.10.0
ms-vscode.PowerShell@1.3.2
PeterJausovec.vscode-docker@0.0.16

Issue Description

Seeing never ending formatting powershell document

1497305178-957d91d3-58fd-4e96-a470-66c2668669871497305175368.zip Sometimes even 2 of them

daviwil commented 7 years ago

Is this when formatting the same script as in your other issue? I don't see any errors in the latest log directory.

artisticcheese commented 7 years ago

it's in general when working with DSC, might be related to Intellisense in other thread here.

daviwil commented 7 years ago

Do you mind closing down VS Code, deleting the contents of the log folder (all of those Guid-named folders) and then trying to reproduce the issue again? I need to make sure I'm looking at the right logs before I start making assumptions.

artisticcheese commented 7 years ago

Here is updated logs as well as sample DSC file which shows this behavior 1497305879-097b666e-05ba-4b5e-9d6a-e30e6200279e1497305876434.zip

daviwil commented 7 years ago

Thanks! That's helpful. I think something in the TypeScript code must be getting tripped up by this script because I never see the request(s) get sent to perform the formatting operation.

@kapilmb do you mind looking into why the extension code would get stuck on formatting this script? Seems like it never even makes the script region request.

kapilmb commented 7 years ago

This issue is the result of a combination of slow parsing of the file and the formatting implementation. The presence of Import-DscResourc keyword slows down the parser a lot, especially if the module is not present on the system. We cannot really do much about the parser but will have the formatting fix soon.

wsmelton commented 7 years ago

This was not using any DSC scripting. Was opening and closing about 90 files in a module to change a parameter type...starting committing the changes and noticed this...

dan-escott commented 7 years ago

This issue is the result of a combination of slow parsing of the file and the formatting implementation. The presence of Import-DscResourc keyword slows down the parser a lot, especially if the module is not present on the system. We cannot really do much about the parser...

Where would be the appropriate place to raise an issue regarding the parser?

kapilmb commented 7 years ago

I think the PowerShell repository should be the right place for a parser related issues.

zachChilders commented 6 years ago

Is there any update on this? We're working on a very DSC intensive project and VSCode has become almost unusably slow in the last month or so. vscode-Powershell Version 1.5.1 VSCode Version 1.18.1

chriskuech commented 6 years ago

This issue is causing many significant problems, as we've grown to rely significantly on correct linting for PSScriptAnalyzer issue resolution and this issue can deceptively create false errors. @dandiddy cited 8-second lag; however, my team has seen significantly higher lag and I believe that the linter has actually timed out.

Is there any update on this issue?

rkeithhill commented 6 years ago

If I run PSSA directly on the file that was posted in the zip file by @artisticcheese, I get one error about a missing module and PSSA takes 14 secs to complete:

10:6ms> Invoke-ScriptAnalyzer .\swarm_manager.ps1
Invoke-ScriptAnalyzer : Parse error in file C:\Users\Keith\Downloads\SlowDscFormatting\swarm_manager.ps1:  Could not
find the module 'xPSDesiredStateConfiguration' at line 39 column 5.
At line:1 char:1
+ Invoke-ScriptAnalyzer .\swarm_manager.ps1
+ ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
    + CategoryInfo          : ParserError: (ModuleNotFoundDuringParse:String) [Invoke-ScriptAnalyzer], ParseException
    + FullyQualifiedErrorId : Parse error in file C:\Users\Keith\Downloads\SlowDscFormatting\swarm_manager.ps1:  Could
    not find the module 'xPSDesiredStateConfiguration' at line 39 column 5.,Microsoft.Windows.PowerShell.ScriptAnalyz
  er.Commands.InvokeScriptAnalyzerCommand

RuleName                            Severity     ScriptName Line  Message
--------                            --------     ---------- ----  -------
PSUseDeclaredVarsMoreThanAssignment Warning      swarm_mana 76    The variable 'dockerConfig' is assigned but never
s                                                ger.ps1          used.
PSPossibleIncorrectComparisonWithNu Warning      swarm_mana 9     $null should be on the left side of equality
ll                                               ger.ps1          comparisons.
PSUseBOMForUnicodeEncodedFile       Warning      swarm_mana       Missing BOM encoding for non-ASCII encoded file
                                                 ger.ps1          'swarm_manager.ps1'

If I install that module, subsequent invocations of PSSA still take ~5 seconds.

It is unfortunate that a missing module adds so much delay to the Invoke-ScriptAnalyzer command - ~9 seconds.

@zachChilders / @chriskuech - it would help if you guys could zip up and post the log files from a session where you've experienced this issue. And if you can add the script that was being edited, that would help even more. Execute the PowerShell: Show PowerShell Extension Logs command and you should see the log folder path for the session in the output window:

12/9/2017 4:18:50 PM [NORMAL] - args: C:\Users\Keith.vscode\extensions\ms-vscode.powershell-1.5.1\scripts\Start-EditorServices.ps1 -EditorServicesVersion '1.5.1' -HostName 'Visual Studio Code Host' -HostProfileId 'Microsoft.VSCode' -HostVersion '1.5.1' -AdditionalModules @('PowerShellEditorServices.VSCode') -BundledModulesPath 'C:\Users\Keith.vscode\extensions\ms-vscode.powershell-1.5.1\modules' -EnableConsoleRepl -WaitForDebugger -LogLevel 'Verbose' -LogPath 'C:\Users\Keith.vscode\extensions\ms-vscode.powershell-1.5.1\logs\1512861530-0e890765-657b-4637-9102-f6b66445a98b1512861085183\EditorServices.log' -SessionDetailsPath 'C:\Users\Keith.vscode\extensions\ms-vscode.powershell-1.5.1\sessions\PSES-VSCode-7056-639776' -FeatureFlags @()

zachChilders commented 6 years ago

Here are the requested logs, along with the file I saw the behavior in. In this particular instance, intellisense flagged me on "xWebSite" before I completed writing out my DSC Resource. The error stayed around for several minutes, until I purposely introduced a typo which seems to force it to run. This is the standard practice that @chriskuech and I have adopted with this particular bug/issue.

vscodeLogs.zip

rkeithhill commented 6 years ago

@zachChilders There are a ton of /cancelRequest messages in that log. Currently we don't handle that message. IIRC we are on an older version of the language protocol and need to update to the latest version. I don't think that is the major problem here but might be a part of it.

chriskuech commented 6 years ago

Anecdotally, I've seen VS Code update linting for every character I've typed, but with a long delay. The fact that these changes are queued leads me to believe that the Task/Promise generated for IntelliSense is not being canceled before the next one is generated.

dan-escott commented 6 years ago

I still encounter this when DSC files are in the workspace. Running procmon, I see that powershell.exe is repeatedly scanning the disk for modules every time a file that contains a function is opened or changed. This is multiple scans for one change, so my guess is once per DSC file to gather intellisense. It pretty much makes intellisense unusable for me in our repo. I’d love a way to exclude these files from intellisense scanning if the powershell parser can’t be fixed. Actually generating MOFs from the DSC files is way faster than generating intellisense.

Let me know if this doesn’t make sense - I can include more details when not typing on a phone :)

chriskuech commented 6 years ago

I'm actually having this issue on non-DSC projects as well, though (anecdotally) not as bad. I'm seeing the same cancelRequest messages @rkeithhill mentioned from the other logs.

Could it be possible that not canceling old linting threads is DOSing the editor service, resulting in the queued/sequentially applied linting results (instead of only analyzing/applying the latest) and linting timeouts we've observed?

EditorServices.log

masaeedu commented 6 years ago

Hi @artisticcheese. Why was this closed?

artisticcheese commented 6 years ago

I'm not seeing this issue anymore and in addition it has been open for close to a year now so I thought both things warrants archival.

TeamIST commented 6 years ago

I am new to VSCode but I am experiencing this issue on Server 2016 32 and 63bit.

TylerLeonhardt commented 6 years ago

Hey all, just seeing this - apologies for the delay. @chriskuech you raise a good point (I've been thinking about this recently). We need to better manage when we format/invoke PSScriptAnalyzer. This includes canceling requests that are taking to long and some retry logic.

RobCannon commented 6 years ago

Can this be re-opened? It is occurring in the latest VS Code release, 1.26.0. It blocks something where the editor and terminal panes are non-responsive.

rjmholt commented 6 years ago

I'll reopen this issue since it sounds like it's not actually resolved. Problems like this are currently a bit tricky to diagnose in the EditorServices codebase, but we're working incrementally toward improving that

RobCannon commented 6 years ago

I can definitely recreate the issue of the never ending 'Formatting PowerShell document'. I think editor services is not working at that point because Intellisense and syntax checking stops working. But I can't recreate the non-responsive issue with the terminal and editor panes.

iamshital commented 6 years ago

I have this issue in every VSCODE version I had. Current reproducible in August update.

cheshrkat commented 5 years ago

Getting this problem in VS Code 1.30.2 on Win10.

Talcon2 commented 5 years ago

I also have this issue, Im always having to use the ISE because of it

masaeedu commented 5 years ago

Hi @SydneyhSmith. I don't think this is a performance issue. It's not that formatting takes too long; it's that it simply never finishes, which is a bug.

Deathnerd commented 5 years ago

Still having this issue on VSCode 1.36.1 on Win10. Anybody figured it out yet?

TylerLeonhardt commented 5 years ago

@rjmholt has been doing a ton of work on PSScriptAnalyzer’s formatter performance. Naturally, the vscode extension takes advantage of that perf bump. It’s coming soon! Thanks for your patience.

Altern1ty commented 4 years ago

We have this issue as well were it will endlessly try to format a document while taking up a good chunk of CPU, mostly with DSC resources same as mentioned above. Weirdly enough occasionally after trying it a few times and restarting vscode it will be able to format a file very quickly. Running latest vscode and extension version.

rjmholt commented 4 years ago

Running latest vscode and extension version

@Altern1ty would you be able to try the powershell-preview extension. We've been doing some work around this area recently, so this might improve things.