-
Notifications
You must be signed in to change notification settings - Fork 7.4k
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
Improve a progress pane performance (one thread) #2822
Conversation
{ | ||
HandleIncomingProgressRecord(sourceId, record); | ||
} | ||
// lock (_instanceLock) is moved into HandleIncomingProgressRecord |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
This comment should be removed.
It's good for the code-review purposes (i.e. in the commit message) but not in the actual code.
if (_progPane != null) | ||
{ | ||
Dbg.Assert(_pendingProgress != null, "How can you have a progress pane and no backing data structure?"); | ||
|
||
// lock (_instanceLock) is not needed here because lock is done at global level |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
same: do we need this comment?
I'd rather see an aggregated comment somewhere that explains threading strategy at one place.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
There are two entry points:
HandleIncomingProgressRecord
- here there arelock (_instanceLock)
ResetProgress
- here there is nolock (_instanceLock)
. This looks like a bug. I wanted to add the lock, but then discovered that there is a global lock in calling functions.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I like this comment. Could you please elaborate a bit more about the "global level" lock? For example, pointing out where this global level lock is enforced.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I lost the lock for the three months 😄
There is three points to call ResetProgress
:
ui.ResetProgress(); _parent.ui.ResetProgress(); _parent.ui.ResetProgress();
All without a lock. It seems we need add lock (_instanceLock)
in ResetProgress.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
This method is usually called after a pipeline finishes running, maybe that makes it rarely have a race condition. But the race condition is still possible to happen, for example when 2 runspace share the same host. I think we should have the _instanceLock
to protect the operations in this method.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I added the lock.
We need to point out another problem: the finished pipeline will remove the progress bar still unfinished pipeline from another runspace. The problem is only if the second runspace doesn't update its progress bar long. It seems we can ignore this.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Yes, that's a potential problem that has always been there. Luckily we rarely see it happen.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
#Closed
|
||
_progPane = new ProgressPane(this); | ||
|
||
if (_progPaneUpdateTimer == null && _progPane != null) |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
&& _progPage != null
is redundent.
_progPane = new ProgressPane(this)
Just one line above
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
new ProgressPane(this)
cannot return null?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
A constructor should never return null, though it might throw exception.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
However, _progPane
could be null when execution reaches here, because another thread might be calling ResetProgress
on the same ConsoleHostUserInterface
instance (e.g. another runspace is created using the same host).
This is a race condition caused by moving the lock within this method.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
The lock change was reverted. #Closed
1. All updates left in one thread. (The use of multiple threads was the main problem previous PR PowerShell#2640) 2. The timer is only used to set up a update flag. (According to my tests calling Datetime.Now() and verifing the time delta creates a much larger delay) 3. The timer interval is 200 ms. I test intervals from 50 ms to 2000 ms. I don't see any differences on the screen with 100 ms and 200 ms. So I chose the more cost-effective option. What do you think about this? 4. Removed unnecessary locking. `WriteProgress` is executed as quickly as possible, as a result the entire script executes significantly faster
0dc3e40
to
1136635
Compare
@vors Do you have any additional comments or requests for this PR? |
@daxian-dbw did a lot of the previous PR. Maybe he will help here too. |
|
||
_progPane = new ProgressPane(this); | ||
|
||
if (_progPaneUpdateTimer == null && _progPane != null) |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
However, _progPane
could be null when execution reaches here, because another thread might be calling ResetProgress
on the same ConsoleHostUserInterface
instance (e.g. another runspace is created using the same host).
This is a race condition caused by moving the lock within this method.
// Update the progress pane only when the timer set up the flag | ||
// as a result, we do not block WriteProgress and whole script | ||
// and eliminate unnecessary console locks and updates | ||
lock (_instanceLock) |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Moving the lock here could cause race conditions. The operations on _pendingProgress
, _progPane
and _progPaneUpdateTimer
outside the lock may interleave with a call to ResetProgress
on another thread -- another runspace created with the same PSHost
instance. That would cause unpredictable states to those members.
Is moving this lock really contribute a lot to the performance improvements? It looks to me that lock is to protect the PSHost
object from being operated on by 2 pipeline threads at the same time, so it shouldn't add any blocking in most cases that Write-Progress is invoked -- creating multiple runspaces with the same PSHost
object is rare.
Given that, I think we should leave the lock where it was.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I agree. Reverted.
lock (_instanceLock) | ||
{ | ||
_pendingProgress?.Update(sourceId, record); | ||
_progPane?.Show(_pendingProgress); |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
You obviously noticed that _pendingProgress
and _progPane
could be null when reaching here 😄
The way you are doing does prevent NullReference
and ObjectDisposed
exceptions, but it also make it harder to understand the code. Same as above, I suggest move the lock back to where it was.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Fixed.
{ | ||
_pendingProgress?.Update(sourceId, record); | ||
_progPane?.Show(_pendingProgress); | ||
progPaneUpdateFlag = false; |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
How about activating the timer when progPaneUpdateFlag
is set to false? So the timer doesn't need to fire when progPaneUpdateFlag
is still true.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
My thoughts were that if we do UpdateTimerThreshold
large enough the showing can become uneven.
Your offer will be only if machine is too slow. I suppose in this case the PR optimization is generally meaningless.
progPaneUpdateFlag = true; | ||
} | ||
|
||
_progPaneUpdateTimer?.Change(UpdateTimerThreshold, Timeout.Infinite); |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Maybe make the timer fire only if an actual Show
is done, instead always fire at certain interval.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
The same: the showing can become uneven.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
#Close
@@ -166,6 +217,10 @@ class ConsoleHostUserInterface : System.Management.Automation.Host.PSHostUserInt | |||
|
|||
private ProgressPane _progPane = null; | |||
private PendingProgress _pendingProgress = null; | |||
// The timer set up 'progPaneUpdateFlag' every 'UpdateTimerThreshold' milliseconds to update 'ProgressPane' | |||
private Timer _progPaneUpdateTimer; |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
An issue with showing progress bar on the same thread with a timer is that it's possible there is still activity records not shown and progPaneUpdateFlag
is true, but there is no more Write-Progress
calls. In such case, some progress records will never be shown. Is there a way to guarantee all pending progress records to be shown before Reset
is called? Or maybe do another Show
in Reset
when _pendingProgress
is not empty?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I added check ProgressRecordType.Completed
.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I think _pendingProgress.Update
with a completed
record will just clear up all structures for the corresponding progress activity. It won't really solve the potential freeze
problem, but it's good to have.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Fixed. ( _pendingProgress.Update )
fb24a52
to
0a494c1
Compare
appveyor is in waiting very long - I am trying restart. |
@daxian-dbw Could you please continue the review? |
@iSazonov Sorry for the delay. I'm currently busy on something, will get back to this ASAP. |
if (_progPane != null) | ||
{ | ||
Dbg.Assert(_pendingProgress != null, "How can you have a progress pane and no backing data structure?"); | ||
|
||
// lock (_instanceLock) is not needed here because lock is done at global level |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I like this comment. Could you please elaborate a bit more about the "global level" lock? For example, pointing out where this global level lock is enforced.
|
||
_progPane = new ProgressPane(this); | ||
|
||
if (_progPaneUpdateTimer == null && _progPane != null) |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
The lock change was reverted. #Closed
@@ -60,19 +70,56 @@ class ConsoleHostUserInterface : System.Management.Automation.Host.PSHostUserInt | |||
_pendingProgress = new PendingProgress(); | |||
} | |||
|
|||
_pendingProgress.Update(sourceId, record); |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I think we should always update _pendingProgress
, instead of only updating it when we are about to call show
.
My reasons:
the progress record
could be associated with a parent progress activity, but progPaneUpdateFlag
was not true when that record
comes. The next time HandleIncomingProgressRecord
gets called, the record
might be associated with a child progress activity and we are going to call show
because progPaneUpdateFlag
becomes true. In this case, we want to show both the child progress activity record
and the parent progress record
that came before.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I am trying to avoid this strongly because otherwise we will lose half of optimization effects. 😕
May we still be able to avoid this?
- If there is update the percentage, we can safely ignore this loss.
- If header is updated as in web cmdlets, then we can safely ignore this loss.
- If there is an update to a parent progress activity and next a change to a child progress activity, then we have a problem as you pointed out. And I don't see how we can solve it in this place.
---Update---
Strangely when I tested it first, it ate at up to 40%
The current test showed around 5%. Perhaps we have become faster for some other reason.
So I totally agree with your proposal.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
#Closed
|
||
_progPane = new ProgressPane(this); | ||
|
||
if (_progPaneUpdateTimer == null && _progPane != null) | ||
{ |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
In line 82:
if (_progPaneUpdateTimer == null && _progPane != null)
the && _progPane != null
is still reduntant.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Removed.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
#Closed
|
||
// Invoke the timer only once to exclude overlaps | ||
// The timer will be restarted in 'ProgressPaneUpdateTimerElapsed' | ||
_progPaneUpdateTimer = new Timer( new TimerCallback(ProgressPaneUpdateTimerElapsed), null, UpdateTimerThreshold, Timeout.Infinite); |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Why not let the timer to fire repeatedly itself? Like:
new Timer(new TimerCallback(ProgressPaneUpdateTimerElapsed), null, UpdateTimerThreshold, UpdateTimerThreshold);
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I suppose this is not important for fast computers (update slot relatively small compared with the slot of the timer), but on slower computers the situation is reversed and we'd better restart the timer after updating and thus avoid overlap:
100ms - timer slot
50ms - update slot
- Manual restart: 100+50=150ms update cycle - 33% for update - it is better for slow computers.
- Auto restart: 100 ms update cycle - 50% for update.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
But the current implementation is the same as having the timer fire repeatedly itself.
ProgressPaneUpdateTimerElapsed(object sender)
{
Interlocked.CompareExchange(ref progPaneUpdateFlag, 1, 0);
_progPaneUpdateTimer?.Change(UpdateTimerThreshold, Timeout.Infinite);
}
when the timer is fired, the call back check/set the flag and trigger the next fire in 200ms. It doesn't wait until the show
to complete to trigger the next fire.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
After the third repetition I realized 😄
(That's left in my mind from previous PR)
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
#Closed
progPaneUpdateFlag = true; | ||
} | ||
|
||
_progPaneUpdateTimer?.Change(UpdateTimerThreshold, Timeout.Infinite); |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
#Close
void | ||
ProgressPaneUpdateTimerElapsed(object sender) | ||
{ | ||
if (_progPane != null) |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
If we make the timer repeatedly fire by itself, then we can avoid the call to timer.Change
. And it actually doesn't matter whether _progPane
is null or not because the worst that can happen is that the timer set the flag to 1 and we call show
one more time.
Given that, I think this method can be simplified to this:
private
void
ProgressPaneUpdateTimerElapsed(object sender)
{
Interlocked.CompareExchange(ref progPaneUpdateFlag, 1, 0);
}
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
The same.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
The current implementation is the same as letting the timer fire repeatedly. Please see my comment above.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Fixed.
// The timer set up 'progPaneUpdateFlag' every 'UpdateTimerThreshold' milliseconds to update 'ProgressPane' | ||
private Timer _progPaneUpdateTimer; | ||
private const int UpdateTimerThreshold = 200; | ||
private bool progPaneUpdateFlag; |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
progPaneUpdateFlag
needs to be changed to an int
field if we want to use InterLock.CompareAndExchange
.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Fixed.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
#Closed
@@ -166,6 +217,10 @@ class ConsoleHostUserInterface : System.Management.Automation.Host.PSHostUserInt | |||
|
|||
private ProgressPane _progPane = null; | |||
private PendingProgress _pendingProgress = null; | |||
// The timer set up 'progPaneUpdateFlag' every 'UpdateTimerThreshold' milliseconds to update 'ProgressPane' | |||
private Timer _progPaneUpdateTimer; |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I think _pendingProgress.Update
with a completed
record will just clear up all structures for the corresponding progress activity. It won't really solve the potential freeze
problem, but it's good to have.
_progPaneUpdateTimer.Dispose(); | ||
_progPaneUpdateTimer = null; | ||
} | ||
progPaneUpdateFlag = false; |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Quoted from MSDN:
Callbacks can occur after the Dispose() method overload has been called, because the timer queues callbacks for execution by thread pool threads.
That means line 38 here doesn't guarantee the flag is set to false, because the timer call back may still run and set it to true. I think we don't need the line 38, because
- the flag is purely for optimization, calling
Show
one time more sometimes won't affect the correctness, and thus it doesn't have to be really accurate. - when we create a new timer for the next
Write-Progress
call, we will set the flag to true anyway.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Good catch! Replaced on comment.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
#Closed
Thanks for pointing out these 2 remaining pieces. I will not focus on the potential Freeze issue in this PR. As long as we have an issue tracking it, we can postpone the fix until we know more about how bad it will freeze the progress pane after this fix. |
I didn't saw difference between 100 ms and 200 ms on my computer in previous PR so I leave 200 ms. In previous PR @lzybkr made the change from 200 ms to 100 ms. If we take into account the slow and heavily loaded computers, the better 200 ms. When 500 ms notable artifacts appears. |
I changed to 100ms because my test (I forget what it was exactly) didn't feel very smooth despite there being steady progress. |
} | ||
// We don't reset 'progPaneUpdateFlag = false' here | ||
// because `HandleIncomingProgressRecord` will be init 'progPaneUpdateFlag' in any way. | ||
// (Also the timer callback can still set it to 'true' accidentally) |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
This comment is not clear enough. How about
// We don't set 'progPaneUpdateFlag = 0' here, because:
// 1. According to MSDN, the timer callback can occur after the Dispose() method has been called. So we cannot guarantee the flag is truly set to 0.
// 2. When creating a new timer in 'HandleIncomingProgressRecord', we will set the flag to 1 anyway
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
👍 Fixed.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
#Closed
// The timer set up 'progPaneUpdateFlag' every 'UpdateTimerThreshold' milliseconds to update 'ProgressPane' | ||
private Timer _progPaneUpdateTimer; | ||
private const int UpdateTimerThreshold = 200; | ||
private int progPaneUpdateFlag; |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I know the default values for _progPaneUpdateTimer
and progPaneUpdateFlag
will be null and 0, but I recommend to explicitly initialize the fields with a default value. It's also for keeping consistency as the rest fields of the class.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Fixed.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
#Closed.
{ | ||
Interlocked.CompareExchange(ref progPaneUpdateFlag, 1, 0); | ||
|
||
_progPaneUpdateTimer?.Change(UpdateTimerThreshold, Timeout.Infinite); |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I added my comments above. This implementation is the same as letting the timer fire repeatedly.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Fixed.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
#Closed.
@iSazonov Thank you for pushing it through!
Do you mind opening a new issue tracking these 2 potential problems? It's possible that they will rarely be noticed and will become a wont-fix issue, but it's still better to keep them somewhere. |
I believe we should still include:
I shall create new tracking Issue. |
@daxian-dbw Thanks for great comments and help!!! 🥇 |
@daxian-dbw Please comment: Recently cmdlets (web cmdlets) can potentially create hundreds of thousands of |
@iSazonov - thanks for noticing. Feel free to open an issue any time you notice significant memory allocation - the fixes are often simple, and the improvements are often measurable. |
A question - does the interrupt write all progress records since the last rendered one, or just the last one issued during the interval? I know that there is no hard requirement that sequential percentage-based progress records are going to increment but if we're doing the former, I might question the value of this. It seems only important to not miss out the "Complete" marker record, but others might be safely skipped. Thoughts? I haven't seen this discussed in any other threads. UPDATE: Oh, never mind -- I'm having a slow day today as I try to get back into work that involves thinking again. Of course you're not doing this. |
We do not collect ProgressRecords, each next entry updates previous in "cache", then on timer expire we render the "cache" and write to a console. |
…he Host has this feature built-in. PowerShell/PowerShell#2822
Close #2138
(Reference #2800)
All updates left in one thread. (The use of multiple threads was the main problem previous PR Improve a progress pane performance #2640)
The timer is only used to set up a update flag. (According to my tests calling Datetime.Now() and verifing the time delta creates a much larger delay)
The timer interval is set to 200 ms. I test intervals from 50 ms to 2000 ms. I don't see any differences on the screen with 100 ms and 200 ms. So I chose the more cost-effective option. @lzybkr What do you think about this?
Removed unnecessary locks and updates.
WriteProgress
is executed as quickly as possible, as a result the entire script executes significantly faster.Performance tests:
After:
Before:
6.1
Hung
orFreeze
of a progress pane. If Write-Progress is not called very frequently user sees that the pane freeze.6.2 If Write-Progress frequently updates a progress pane and the script make output to console the user sees that the display flickers. The following script illustrates this: