Powershell: Write-Progress not rendered when it called too fast

[ili101]

Steps to reproduce

foreach ($item in 1..3) {
    Write-Progress -Activity "I: $item" -Status 'Start'
    Write-Progress -Activity "I: $item" -Status 'Work'
    Start-Sleep 3
    Write-Progress -Activity "I: $item" -Status 'End'
}

Expected behavior

On PS 5.1 it works as expected:

I: 1
    Work
I: 2
    Work
I: 3
    Work

Actual behavior

On PS 6-7 it shows

I: 1
    Start
I: 1
    End
I: 2
    End

So if you have a few Write-Progress without Sleep or something that takes a long time between them only the first one is displayed

I see there is an optimization mentioned here https://github.com/PowerShell/PowerShell/issues/5370#issuecomment-342803915
It listed in https://github.com/PowerShell/PowerShell/issues/3366 as point "4." but I don't think it's only a Write-Progress -Completed problem, it's a problem on any Write-Progress

Maybe a good solution instead of not updating after Write-Progress for 200ms is to wait 200ms after Write-Progress then write to screen the last Write-Progress in this 200ms. this way you will have a 200ms delay but in return you will get the correct/more relevant Write-Progress shown and not display an irrelevant Write-Progress for potentially minutes/hours?

[iSazonov]

Main purpose of the cmdlet is to inform users about a progress in long time process. Current implementation allows to cover most of real scenarios. Even in the above example, you can place important information instead of "End" string. (I believe that it is possible to write a script that will do this the same way in both versions.)
Current optimization is really skipping all updates for 200 ms. It is simple and gives great performance. You ask to track last update. This will complicate the code and consume more resources. Given other issues with this cmdlet, this is not worth the effort.

[vexx32]

Hmm. It shouldn't be _too_ much more complicated to just cache the last update somewhere & overwrite that reference when a new record is received, I wouldn't think?

Sounds like a fairly straightforward improvement to me.

[iSazonov]

Improving what? Do you know a real scenario that requires this?

[ili101]

Improving what? Do you know a real scenario that requires this?

In the example I posted lest say the the loop takes an hour to complete. you see in the progress bar something like "I: 1" "step xxx" manning you are somewhere on loop 1 but in reality loop 1 finished half an hour ago and you are actually on loop 2 for the last half hour .
The progress bar in this scenario is more confusing then helpful.

putting information in the "End" string as you say will not help as this stage is not relevant any more.

Hope it's clear.

[iSazonov]

@ili101 In "Expected behavior" you say that you expect "Work". This also says that you agree ignore "Start" and "End". In the case you can remove these two Write-Progress and get expected behavior.

[ili101]

@ili101 In "Expected behavior" you say that you expect "Work". This also says that you agree ignore "Start" and "End". In the case you can remove these two Write-Progress and get expected behavior.

Now you may say do something like this:

foreach ($item in 1..3) {
    Write-Progress -Activity "Working on: $item"
    Start-Sleep 3
}

That will work but not always because lest say 1 takes an hour (shows correctly as "Working on: 1"), then step 2 take no time (lest say something not exists so noting to do for 2), then step 3 take an hour like 1.
for the entire hour of step 3 you will see in the progress bar "Working on: 2" and not 3.

[iSazonov]

@ili101 If you know that one cycle can take 1 hour and next 0 sec you can add short delay in 200 ms.

[vexx32]

Yeah, but that's the kind of implementation detail that should just be handled nicely by the cmdlet / underlying system already.

Users shouldn't have to know the fine details of exactly how progress buffers records to make it work.

[iSazonov]

It is an implementation detail for developers, not for end users.
Also you ask to address "Work" but next request would be to address "Start" and/or "End". This can not be resolved automatically in common - in any case developers will have to do a workaround while the optimization exits but we can not remove it.

[vexx32]

Can you describe the issues you're foreseeing in more detail? I'm not sure I understand why that would be any different to its current behaviour, nor why the suggested improvement will make a non-negligible impact there.

[iSazonov]

@vexx32 A root of the issue is that we _skip_ some progress records for performance. This means that there will _always_ be a situation that will require a workaround. Today we have a compromise. In fact, the situation is even worse because there may be several runspaces which affect each other.

[vexx32]

Sure, but it stands to reason that the most recently-submitted progress record should be the one used to redraw after a rest period.

The current implementation assumes that there will always be a constant stream of progress records, so when no more progress records are received, any sent since the last update are completely ignored. Instead we can flip this around so that the more recent record is always displayed.

There are a multitude of other issues we could bring up -- I enumerated _many_ of them in my issue #7983 from 2018. At the very least, until someone is willing to redesign the whole system we can allow smaller QOL fixes for the current system to be a little more usable.

[iSazonov]

Sure, but it stands to reason that the most recently-submitted progress record should be the one used to redraw after a rest period.

That is how it works. I assumed that we ignore records at all, but in fact we put them in a cache and delay only for show to the screen.
To address the request we would to have to make the show code async and put the show code in another thread. This was rejected in time the performance optimization was added because of complicity.
So it is by-design since a simple workaround with delay exists and until this area will be redesigned and reimplemented.

[SeeminglyScience]

I think the most common thing I see Write-Progress used for is "copying files with a progress bar". While generally not super advisable, it's the first experience a lot of folks are going to have with the cmdlet. For this use case, it's pretty much exclusively going to show the wrong thing:

for ($i = 0; $true; $i++) {
    Write-Progress "Processing $i"
    Write-Host "Actually processing $i"

    # Simulate the occasional large file
    if ($i % 5 -eq 0) {
        Start-Sleep 5
    }
}

Most folks aren't going to research the work around, they're just going to assume the cmdlet is broken and never touch it again.

Would it be possible to simply put the show code in the TimerCallback (enclosed in a try/finally that starts and stops the timer)?

[iSazonov]

Would it be possible to simply put the show code in the TimerCallback (enclosed in a try/finally that starts and stops the timer)?

This was my first impulse, but after discussion, we chose an easier way. Why? This is a fundamental property of this progress bar function that developers have to adopt to every specific scenario.
An operation can take 1ms or/and 1 hour. In first case we should skip updates because users cannot see such frequent updates. In second case users will see one message long time - it is not good experience. Windows file copy API can register and call a callback so that if we copy 1 Tb file we can see that a progress bar is updated. But .Net API does not utilize the API. (I did not found such API in Linux too.). In the third case, short and long operations may alternate. This again requires a special approach.
Even if we move the show code to the timer callback, we will not solve most scenarios. Therefore, the conclusion was that the simplest thing that users can do is add a delay as needed.
Taking into account that MSFT team does not do a review for most contributions, at present I do not think that any changes in this code will be approved.

[SeeminglyScience]

This was my first impulse, but after discussion, we chose an easier way. Why? This is a fundamental property of this progress bar function that developers have to adopt to every specific scenario.

Can you elaborate a bit? I'm having a hard time following how this is a fundamental property.

An operation can take 1ms or/and 1 hour. In first case we should skip updates because users cannot see such frequent updates.

My proposal will still skip the same amount of updates, it'll just ensure that the most relevant one is rendered instead of waiting until the next WriteProgress call.

In second case users will see one message long time - it is not good experience.

What about 5 seconds like my example? If most operations take 50ms but some take 2 seconds the progress message will still be consistently wrong.

Windows file copy API can register and call a callback so that if we copy 1 Tb file we can see that a progress bar is updated. But .Net API does not utilize the API. (I did not found such API in Linux too.). In the third case, short and long operations may alternate. This again requires a special approach.

Yeah like I said, not generally advisable. Still though, it's going to be what a lot of newbies try first, and if it just straight up shows the wrong thing a lot will just never touch the command again.

Even if we move the show code to the timer callback, we will not solve most scenarios.

Gotcha. Out of curiosity could you elaborate on the scenarios that will miss?

Therefore, the conclusion was that the simplest thing that users can do is add a delay as needed.

Is that really better than just ditching progress entirely though? The only time you don't have to add the delay is if you don't care if the message shows the wrong step. Or if you know for sure that there are no machines where one step will take under 200ms, and another will take a couple seconds. I guess what I'm getting at is, was performance really fixed if the only way to use it reliably is to add a delay?

[iSazonov]

@SeeminglyScience You intend to plunge me into a redesign of this feature. :-) But I do not see any chance that this will be realized in near months... :-(
Although ... I think I know a better way - to add more flexibility to this feature.
But it bothers me more that this feature creates strong pressure on garbage.
I hope to resolve this after the project comes to life.

[SeeminglyScience]

You intend to plunge me into a redesign of this feature. :-)

Maaaybee... 😀

Let me just spell out real quick what I'm suggesting though. Feel free to disregard if you have a better plan 🙂

1. Put a lock around https://github.com/PowerShell/PowerShell/blob/7500513911763d5cd9ad08ded6ce0a7f3b336617/src/Microsoft.PowerShell.ConsoleHost/host/msh/ConsoleHostUserInterfaceProgress.cs#L72

2. Change https://github.com/PowerShell/PowerShell/blob/7500513911763d5cd9ad08ded6ce0a7f3b336617/src/Microsoft.PowerShell.ConsoleHost/host/msh/ConsoleHostUserInterfaceProgress.cs#L93-L98 to be:

   Interlocked.Exchange(ref someNewFlagIndicatingUpdateNeeded, 1)
   

3. Change https://github.com/PowerShell/PowerShell/blob/7500513911763d5cd9ad08ded6ce0a7f3b336617/src/Microsoft.PowerShell.ConsoleHost/host/msh/ConsoleHostUserInterfaceProgress.cs#L107-L110 to be:

   ProgressPaneUpdateTimerElapsed(object sender)
   {
       if (Interlocked.CompareExchange(ref someNewFlagIndicatingUpdateNeeded, 0, 0) == 0)
       {
           return;
       }
   
       var timer = (Timer)sender;
       timer.Stop();
       try
       {
           lock (_sameLockAsUpdate)
           {
               _progPane.Show(_pendingProgress);
               Interlocked.Exchange(ref someNewFlagIndicatingUpdateNeeded, 0);
           }
       }
       finally
       {
           timer.Start();
       }
   }
   

Needs tweaking but hopefully gives the full idea.