JanDeDobbeleer / oh-my-posh

The most customisable and low-latency cross platform/shell prompt renderer
https://ohmyposh.dev
MIT License
16.79k stars 2.35k forks source link

Extreme slowness in Powershell Core Win10 Pro 19042.685 #315

Closed ormico closed 3 years ago

ormico commented 3 years ago

Prerequisites

Description

I loved oh-my-posh but slowness in GitRepos had me turn it off last year (v2). Its a new year so I decided to try v3 but it is extremely slow even with almost everything turned off. Its so slow that I think something must be wrong or setup wrong.

It takes 6231 ms for profile to load and takes 3 - 5 seconds to render a new line if I just press [ENTER].

What could be causing this and is there any way to debug?

Environment

Steps to Reproduce

  1. upgrade to omp v3
  2. install CaskaydiaCove NF font in Windows Terminal
  3. add omp v3 to pwsh profile
  4. open a terminal window

Expected behavior: [What you expected to happen] prompts render and normal speed

Actual behavior: [What actually happened] prompts render very slowly 3 to 5 seconds and profile takes over 6000 ms to load.

my schema omp json file

{
  "$schema": "https://raw.githubusercontent.com/JanDeDobbeleer/oh-my-posh3/main/themes/schema.json",
  "blocks": [
    {
      "type": "prompt",
      "alignment": "left",
      "segments": [
        {
          "type": "path",
          "style": "powerline",
          "powerline_symbol": "\uE0B0",
          "foreground": "#ffffff",
          "background": "#61AFEF",
          "properties": {
            "prefix": " \uE5FF ",
            "style": "folder"
          }
        },
        {
          "type": "time",
          "style": "plain",
          "foreground": "#007ACC",
          "properties": {
            "time_format": "15:04:05"
          }
        }
      ]
    }
  ],
  "final_space": true
}

this is my profile script: C:\Users\ME\OneDrive - LBA Ware\Documents\PowerShell\Microsoft.PowerShell_profile.ps1

Invoke-Expression (oh-my-posh --init --shell pwsh --config ~/.poshthemes/jandedobbeleer-zack.omp.json);

function Get-PublicIp4 {
    Write-Host (invoke-webrequest "https://api.ipify.org?format=json").Content;
}

function Get-PublicIp6 {
    Write-Host (invoke-webrequest "https://api6.ipify.org?format=json").Content;
}

function ll {
    Get-ChildItem -Force $args;
}

#Clear-Host;

screenshot. this is me loading new shell and just pressing enter a few times while waiting for profile to load. you can see how long it takes to render each line after profile loads.

image

JanDeDobbeleer commented 3 years ago

@ormico you can use oh-my-posh --debug --shell pwsh --config ~/.poshthemes/jandedobbeleer-zack.omp.json to see which segment is causing trouble. Be aware we're having a big performance issue at #305 as well.

ormico commented 3 years ago

I ran this, but I have to say the module list it shows data for does not seem to match what is in my config file. I did move the config file as part of debugging to the path you see in this screenshot but it doesn't seem to matter if I use old or new path.

In the screenshot it seems to still be running git segment and a bunch of others I removed. I tried adding the kubectl one and can see in in the prompt but it doesn't show up when I run debug.

(as a side note, are command line args supposed to be - or --. it seems to be different in different places)

image

ormico commented 3 years ago

~./ wasn't working for --config. if I try an absolute path it gives a correct debug list.

image

ormico commented 3 years ago

changed profile to use Invoke-Expression (oh-my-posh --init --shell pwsh --config C:\Users\zack.moore\.zack.omp.json); but still slow. Just to test.

JanDeDobbeleer commented 3 years ago

The git segment worries me, but we're fixing that this week hopefully. I'd say something else is messing with the timings here. Can you try by just adding the prompt function from the init script to your profile, rather than invoking it? There might be something in there that's taking a lot of time.

ormico commented 3 years ago

lets see if I did this correctly. I made my profile look just like the code at the link you referenced and it executed instantly. Prompt now looks like PS>

ormico commented 3 years ago

executing this takes a while PS>Invoke-Expression (@(&"C:\bin\oh-my-posh.exe" --print-init --shell pwsh --config C:\Users\zack.moore\.zack.omp.json) -join "n")`

ormico commented 3 years ago

this executes quickly and prints the same powershell oh-my-posh --print-init --shell pwsh --config C:\Users\zack.moore\.zack.omp.json

ormico commented 3 years ago

I tried breaking the steps down but couldn't find a smoking gun. Apologies for the log dump but maybe you will see something I should try

PS>$x = oh-my-posh --init --shell pwsh --config C:\Users\zack.moore\.zack.omp.json;
PS>$x
Invoke-Expression (@(&"C:\bin\oh-my-posh.exe" --print-init --shell pwsh --config C:\Users\zack.moore\.zack.omp.json) -join "`n")
PS>$y = oh-my-posh --print-init --shell pwsh --config C:\Users\zack.moore\.zack.omp.json
PS>$y
$global:PoshSettings = New-Object -TypeName PSObject -Property @{
    Theme = "";
}

if (Test-Path "C:\Users\zack.moore\.zack.omp.json") {
    $global:PoshSettings.Theme = Resolve-Path -Path "C:\Users\zack.moore\.zack.omp.json"
}
function Set-PoshContext {}

function Set-GitStatus {
    if (Get-Command -Name "Get-GitStatus" -ErrorAction SilentlyContinue) {
        [Diagnostics.CodeAnalysis.SuppressMessageAttribute('PSProvideCommentHelp', '', Justification='Variable used later(not in this scope)')]
        $Global:GitStatus = Get-GitStatus
    }
}

[ScriptBlock]$Prompt = {
    #store if the last command was successfull
    $lastCommandSuccess = $?
    #store the last exit code for restore
    $realLASTEXITCODE = $global:LASTEXITCODE
    $errorCode = 0
    Set-PoshContext
    if ($lastCommandSuccess -eq $false) {
        #native app exit code
        if ($realLASTEXITCODE -is [int] -and $realLASTEXITCODE -gt 0) {
            $errorCode = $realLASTEXITCODE
        }
        else {
            $errorCode = 1
        }
    }

    $executionTime = -1
    $history = Get-History -ErrorAction Ignore -Count 1
    if ($null -ne $history -and $null -ne $history.EndExecutionTime -and $null -ne $history.StartExecutionTime) {
        $executionTime = ($history.EndExecutionTime - $history.StartExecutionTime).TotalMilliseconds
    }

    $startInfo = New-Object System.Diagnostics.ProcessStartInfo
    $startInfo.FileName = "C:/bin/oh-my-posh.exe"
    $config = $global:PoshSettings.Theme
    $cleanPWD = $PWD.ProviderPath.TrimEnd("\")
    $startInfo.Arguments = "--config=""$config"" --error=$errorCode --pwd=""$cleanPWD"" --execution-time=$executionTime"
    $startInfo.Environment["TERM"] = "xterm-256color"
    $startInfo.CreateNoWindow = $true
    $startInfo.StandardOutputEncoding = [System.Text.Encoding]::UTF8
    $startInfo.RedirectStandardOutput = $true
    $startInfo.UseShellExecute = $false
    if ($PWD.Provider.Name -eq 'FileSystem') {
        $startInfo.WorkingDirectory = $PWD.ProviderPath
    }
    $process = New-Object System.Diagnostics.Process
    $process.StartInfo = $startInfo
    $process.Start() | Out-Null
    $standardOut = $process.StandardOutput.ReadToEnd()
    $process.WaitForExit()
    $standardOut
    Set-GitStatus
    $global:LASTEXITCODE = $realLASTEXITCODE
    #remove temp variables
    Remove-Variable realLASTEXITCODE -Confirm:$false
    Remove-Variable lastCommandSuccess -Confirm:$false
}
Set-Item -Path Function:prompt -Value $Prompt -Force
PS>Invoke-Expression (@(&"C:\bin\oh-my-posh.exe" --print-init --shell pwsh --config C:\Users\zack.moore\.zack.omp.json) -join "`n")
  ~█ 14:15:07  ❯  $z = @(($y) -join "`n")
  ~█ 14:18:02  ❯  $z
$global:PoshSettings = New-Object -TypeName PSObject -Property @{
    Theme = "";
}

if (Test-Path "C:\Users\zack.moore\.zack.omp.json") {
    $global:PoshSettings.Theme = Resolve-Path -Path "C:\Users\zack.moore\.zack.omp.json"
}
function Set-PoshContext {}

function Set-GitStatus {
    if (Get-Command -Name "Get-GitStatus" -ErrorAction SilentlyContinue) {
        [Diagnostics.CodeAnalysis.SuppressMessageAttribute('PSProvideCommentHelp', '', Justification='Variable used later(not in this scope)')]
        $Global:GitStatus = Get-GitStatus
    }
}

[ScriptBlock]$Prompt = {
    #store if the last command was successfull
    $lastCommandSuccess = $?
    #store the last exit code for restore
    $realLASTEXITCODE = $global:LASTEXITCODE
    $errorCode = 0
    Set-PoshContext
    if ($lastCommandSuccess -eq $false) {
        #native app exit code
        if ($realLASTEXITCODE -is [int] -and $realLASTEXITCODE -gt 0) {
            $errorCode = $realLASTEXITCODE
        }
        else {
            $errorCode = 1
        }
    }

    $executionTime = -1
    $history = Get-History -ErrorAction Ignore -Count 1
    if ($null -ne $history -and $null -ne $history.EndExecutionTime -and $null -ne $history.StartExecutionTime) {
        $executionTime = ($history.EndExecutionTime - $history.StartExecutionTime).TotalMilliseconds
    }

    $startInfo = New-Object System.Diagnostics.ProcessStartInfo
    $startInfo.FileName = "C:/bin/oh-my-posh.exe"
    $config = $global:PoshSettings.Theme
    $cleanPWD = $PWD.ProviderPath.TrimEnd("\")
    $startInfo.Arguments = "--config=""$config"" --error=$errorCode --pwd=""$cleanPWD"" --execution-time=$executionTime"
    $startInfo.Environment["TERM"] = "xterm-256color"
    $startInfo.CreateNoWindow = $true
    $startInfo.StandardOutputEncoding = [System.Text.Encoding]::UTF8
    $startInfo.RedirectStandardOutput = $true
    $startInfo.UseShellExecute = $false
    if ($PWD.Provider.Name -eq 'FileSystem') {
        $startInfo.WorkingDirectory = $PWD.ProviderPath
    }
    $process = New-Object System.Diagnostics.Process
    $process.StartInfo = $startInfo
    $process.Start() | Out-Null
    $standardOut = $process.StandardOutput.ReadToEnd()
    $process.WaitForExit()
    $standardOut
    Set-GitStatus
    $global:LASTEXITCODE = $realLASTEXITCODE
    #remove temp variables
    Remove-Variable realLASTEXITCODE -Confirm:$false
    Remove-Variable lastCommandSuccess -Confirm:$false
}
Set-Item -Path Function:prompt -Value $Prompt -Force
  ~█ 14:18:08  ❯  Invoke-Expression $z
Invoke-Expression: Cannot convert 'System.Object[]' to the type 'System.String' required by parameter 'Command'. Specified method is not supported.
  ~█ 14:18:28  ❯  Invoke-Expression ($z)
Invoke-Expression: Cannot convert 'System.Object[]' to the type 'System.String' required by parameter 'Command'. Specified method is not supported.
  ~█ 14:18:58  ❯  Invoke-Expression $z.ToString()
System.Object[]: The term 'System.Object[]' is not recognized as a name of a cmdlet, function, script file, or executable program.
Check the spelling of the name, or if a path was included, verify that the path is correct and try again.
  ~█ 14:19:11  ❯  $z
$global:PoshSettings = New-Object -TypeName PSObject -Property @{
    Theme = "";
}

if (Test-Path "C:\Users\zack.moore\.zack.omp.json") {
    $global:PoshSettings.Theme = Resolve-Path -Path "C:\Users\zack.moore\.zack.omp.json"
}
function Set-PoshContext {}

function Set-GitStatus {
    if (Get-Command -Name "Get-GitStatus" -ErrorAction SilentlyContinue) {
        [Diagnostics.CodeAnalysis.SuppressMessageAttribute('PSProvideCommentHelp', '', Justification='Variable used later(not in this scope)')]
        $Global:GitStatus = Get-GitStatus
    }
}

[ScriptBlock]$Prompt = {
    #store if the last command was successfull
    $lastCommandSuccess = $?
    #store the last exit code for restore
    $realLASTEXITCODE = $global:LASTEXITCODE
    $errorCode = 0
    Set-PoshContext
    if ($lastCommandSuccess -eq $false) {
        #native app exit code
        if ($realLASTEXITCODE -is [int] -and $realLASTEXITCODE -gt 0) {
            $errorCode = $realLASTEXITCODE
        }
        else {
            $errorCode = 1
        }
    }

    $executionTime = -1
    $history = Get-History -ErrorAction Ignore -Count 1
    if ($null -ne $history -and $null -ne $history.EndExecutionTime -and $null -ne $history.StartExecutionTime) {
        $executionTime = ($history.EndExecutionTime - $history.StartExecutionTime).TotalMilliseconds
    }

    $startInfo = New-Object System.Diagnostics.ProcessStartInfo
    $startInfo.FileName = "C:/bin/oh-my-posh.exe"
    $config = $global:PoshSettings.Theme
    $cleanPWD = $PWD.ProviderPath.TrimEnd("\")
    $startInfo.Arguments = "--config=""$config"" --error=$errorCode --pwd=""$cleanPWD"" --execution-time=$executionTime"
    $startInfo.Environment["TERM"] = "xterm-256color"
    $startInfo.CreateNoWindow = $true
    $startInfo.StandardOutputEncoding = [System.Text.Encoding]::UTF8
    $startInfo.RedirectStandardOutput = $true
    $startInfo.UseShellExecute = $false
    if ($PWD.Provider.Name -eq 'FileSystem') {
        $startInfo.WorkingDirectory = $PWD.ProviderPath
    }
    $process = New-Object System.Diagnostics.Process
    $process.StartInfo = $startInfo
    $process.Start() | Out-Null
    $standardOut = $process.StandardOutput.ReadToEnd()
    $process.WaitForExit()
    $standardOut
    Set-GitStatus
    $global:LASTEXITCODE = $realLASTEXITCODE
    #remove temp variables
    Remove-Variable realLASTEXITCODE -Confirm:$false
    Remove-Variable lastCommandSuccess -Confirm:$false
}
Set-Item -Path Function:prompt -Value $Prompt -Force
  ~█ 14:19:30  ❯  get-type $z
get-type: The term 'get-type' is not recognized as a name of a cmdlet, function, script file, or executable program.
Check the spelling of the name, or if a path was included, verify that the path is correct and try again.
  ~█ 14:19:42  ❯  ls $z
Get-ChildItem: Cannot find drive. A drive with the name '$global' does not exist.
  ~█ 14:19:49  ❯  Invoke-Expression "$z"
  ~█ 14:20:23  ❯
JanDeDobbeleer commented 3 years ago

I'll give you a sample you can use in the morning. Just to make sure I don't mess things up.

JanDeDobbeleer commented 3 years ago

@ormico I can't find a root cause as I can't reproduce it on my end. However, the git segment did a timeout there for about 6 seconds which could be the origin of the issue. Can you check if the latest version still has this issue? We did quite te rework already to get the timings on Windows under control. As an alternative means of troubleshooting, you could also use the module rather than the manual route and see if that resolves things.

stale[bot] commented 3 years ago

This issue has been automatically marked as stale because it has not had recent activity. It will be closed in 7 days if no further activity occurs. Thank you for your contributions.

ormico commented 3 years ago

I'll check this again today

Get Outlook for iOShttps://aka.ms/o0ukef


From: stale[bot] notifications@github.com Sent: Saturday, January 16, 2021 3:46:46 PM To: JanDeDobbeleer/oh-my-posh3 oh-my-posh3@noreply.github.com Cc: Zack Moore zack@zackmoore.xyz; Mention mention@noreply.github.com Subject: Re: [JanDeDobbeleer/oh-my-posh3] Extreme slowness in Powershell Core Win10 Pro 19042.685 (#315)

This issue has been automatically marked as stale because it has not had recent activity. It will be closed in 7 days if no further activity occurs. Thank you for your contributions.

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHubhttps://github.com/JanDeDobbeleer/oh-my-posh3/issues/315#issuecomment-761643421, or unsubscribehttps://github.com/notifications/unsubscribe-auth/AANGWJG546SXH64C37673DLS2H3LNANCNFSM4VTI3XXA.

JanDeDobbeleer commented 3 years ago

@ormico any update on your end?

stale[bot] commented 3 years ago

This issue has been automatically marked as stale because it has not had recent activity. It will be closed in 7 days if no further activity occurs. Thank you for your contributions.

silverqx commented 3 years ago

I have upgraded to version 3 and have exactly the same problem with the git segment, one of my repository takes around 3 seconds on empty command, only enter pressed, another repository is fine ( but not as fast as the v2 ), I have to downgrade. Just for the record, all other changes in the v3 version are great, I love it.

ormico commented 3 years ago

i haven't had a chance to get back to this. its been really busy. I have a little time this weekend. I'll try upgrading and testing again.

JanDeDobbeleer commented 3 years ago

@silverqx unfortunately, that's more related to git than oh-my-posh. There is some offset between running directly in the shell vs running it from go, but not seconds. We could omit status as that one's taking up the time, but then again, you don't want that everywhere. If someone can point me to an OSS git repo that has this issue, I'll gladly see if we can speed things up a bit, but we already did a lot of work in that regard. Also, on Windows everything is noticeably slower compared to mac and linux. Not necessarily related to go either (we went fully crazy trying to validate the root cause end of last year).

silverqx commented 3 years ago

thank you for the clarification, I'm going to try to clone the problematic repo, ...

Ok I have tried clone my repo and I can not reproduce the problem on a freshly cloned repo 🤔, so I compressed it and attached it here: dotfiles.zip

I absolutely don't know what can cause this issue, I also tried to call git gc it didn't help. @JanDeDobbeleer

JanDeDobbeleer commented 3 years ago

@silverqx chances are my latest release resolves this. We now no longer update the index which could've been the issue due to it being locked. That also explains why it happens for some people but not all.

silverqx commented 3 years ago

Thx, I see you have added --no-optional-locks parameter, but it didn't help, I tried 3.106.4 version now, still above 2 seconds, you can add timers to the source code and catch up function which consumes the most time, this way you can track it nicely.

It has nothing to do with the size of the repository, because I have some huge repositories like qBittorrent, libtorrent or some internal repos which has huge amount of commits and I have tried all of them now, and I can not reproduce this problem on the other huge repos.

That repo dotfiles which I sent you yesterday is small, as regards the number of commits, maybe the size of the files matter, because this dotfiles repo contains some files which have 1-5MB, but I'm just guessing.

Can you reproduce 2-3 seconds problem on an enter keypress on the repository which I sent you? @JanDeDobbeleer

silverqx commented 3 years ago

I'm sure that 3.106.4 is loaded, I checked it by Get-Command -CommandType Function -Module oh-my-posh command, which also displays version numbers, just for the record. 🙂

silverqx commented 3 years ago

This is my git version git version 2.30.1.windows.1 and I'm attaching .gitconfig, maybe you will see something there, nothing special though, I substituted sensitive info.

gitconfig.txt

JanDeDobbeleer commented 3 years ago

@silverqx I can't reproduce your repo being slow on my machine:

Your config also doesn't show something that rings a bell either.

image
silverqx commented 3 years ago

It looks like this at my side: Screenshot 2021-03-07 163739

If you send me a modified exe with timers code added, I can execute it on my side, otherwise I don't know how to help. @JanDeDobbeleer

silverqx commented 3 years ago

Simple debug timers that outputs ms to the console in functions which can cause this, if you will have some time let me know, I can help with this.

JanDeDobbeleer commented 3 years ago

@silverqx There's something noticeably different about your prompt vs mine. According to what I see, you have a repo without commits (notice the bottle).

What's the output when you run git --no-optional-locks -c core.quotepath=false -c color.status=false status -unormal --short --branch

JanDeDobbeleer commented 3 years ago

@silverqx I found the issue. You have a git.cmd file inside the bin folder. That one's interpreted as an executable which is why the output doesn't work anymore. When running git directly it works, but from go we're stuck at that would-be executable. You can validate this by renaming that file.

silverqx commented 3 years ago

fhdjkslkasdfh wtf 😈😁😂, what is doing this peace of xyz here 😎, git.cmd omg, I can't find out how did you discover this 😲

Screenshot 2021-03-07 172120

Now it looks amazing 115ms, I'm happy going to use oh-my-posh v3, thank you for your time ⌚🙏 @JanDeDobbeleer

JanDeDobbeleer commented 3 years ago

@silverqx actually I think you helped identify an issue more users are experiencing (we were also never able to reproduce this). If you happen to have a git.cmd in your PATH that takes precedence over git.exe, you're in for a ride.

ormico commented 3 years ago

I have 2 computers that I'm running oh-my-posh on. one is a work computer and one is personal but they are pretty similar.

on my personal computer, the latest oh-my-posh runs really fast and is nice.

on my work computer, the latest version is still really slow. To just press enter and get a new line takes a/b 3 seconds. Not in a git folder either. Just any random folder on my hard drive. removing Set-PoshPrompt from my Microsoft.PowerShell_profile.ps1 and opening a new terminal tab brings the terminal speed back to normal. I have the theme set to powerlevel10k_classic atm.

Typing oh-my-posh at the prompt does not run anything but I did change to the folder where the module binaries were stored to run the -debug command.

image

JanDeDobbeleer commented 3 years ago

@ormico are you sure there's not something like Microsoft Defender actively trying to mess with executables being ran it doesn't trust?

To exclude that use case, you can add a rule to Defender to leave executables from the powershell module folder alone for example.

ormico commented 3 years ago

the work machine has a different AV solution and we tried looking into that and experimenting with settings. it doesn't appear that is the cause but its always possible.

JanDeDobbeleer commented 3 years ago

@ormico if the screenshot from above is oh-my-posh running on that machine, the machine itself is slowing down the execution.

adam-grant-hendry commented 2 years ago

Is there a way to turn off ConsoleTitle?

image

JanDeDobbeleer commented 2 years ago

@adam-grant-hendry yes, you can edit the config. Removing those settings will also no longer run that logic. It's a bit strange as to why that takes so much time though.

adam-grant-hendry commented 2 years ago

@JanDeDobbeleer I commented out the 1 line in your "jandedobbeleer.omp.json" with a console argument

// "console_title_template": "{{ .Shell }} in {{ .Folder }}"

and it still runs slow with the console title as the culprit:

image

adam-grant-hendry commented 2 years ago

Also, if that's the only console line, why is ConsoleTitle still showing up as true...?

JanDeDobbeleer commented 2 years ago

@adam-grant-hendry could it be you're editing the wrong file? Either way, I'll check tomorrow. Debug actually doesn't seem to care about the template being there or not, I'll for sure already fix that. For my information, can you copy-paste the entire debug output? A screenshot is tricky to work with and I'm really curious is what's below the timing.

adam-grant-hendry commented 2 years ago

could it be you're editing the wrong file?

My $PROFILE is

oh-my-posh --init --shell pwsh --config $env:POSH_THEMES_PATH/jandedobbeleer.omp.json | Invoke-Expression

and the POSH_THEMES_PATH environment variable is

C:\Program Files (x86)\oh-my-posh\themes

So the file I edited is

C:\Program Files (x86)\oh-my-posh\themes\jandedobbeleer.omp.json

which I'm assuming is correct.

For my information, can you copy-paste the entire debug output?

Yes, please see the attached:

debug.txt

adam-grant-hendry commented 2 years ago

Note that the above slowness is occurring both in git folders and non-git folders.

JanDeDobbeleer commented 2 years ago

@adam-grant-hendry allow me to add some more meaningful logging as the 700 is surely not related to the console title.

github-actions[bot] commented 7 months ago

This issue has been automatically locked since there has not been any recent activity (i.e. last half year) after it was closed. It helps our maintainers focus on the active issues. If you have found a problem that seems similar, please open a discussion first, complete the body with all the details necessary to reproduce, and mention this issue as reference.