MSBuildStructuredLog icon indicating copy to clipboard operation
MSBuildStructuredLog copied to clipboard

Freeze while selecting item in the results tree

Open jairbubbles opened this issue 5 years ago • 31 comments

Randomly the UI freezes when selecting an item after doing a search.

When breaking in the code it seems to be stuck while measuring items in the VirtualizingStackPanel:

 	PresentationCore.dll!System.Windows.Media.Visual.GetDpi()	Inconnu
 	PresentationFramework.dll!System.Windows.FrameworkElement.MeasureCore(System.Windows.Size availableSize)	Inconnu
 	PresentationCore.dll!System.Windows.UIElement.Measure(System.Windows.Size availableSize)	Inconnu
 	PresentationFramework.dll!System.Windows.Controls.Grid.MeasureCell(int cell, bool forceInfinityV)	Inconnu
 	PresentationFramework.dll!System.Windows.Controls.Grid.MeasureCellsGroup(int cellsHead, System.Windows.Size referenceSize, bool ignoreDesiredSizeU, bool forceInfinityV, out bool hasDesiredSizeUChanged)	Inconnu
 	PresentationFramework.dll!System.Windows.Controls.Grid.MeasureOverride(System.Windows.Size constraint)	Inconnu
 	PresentationFramework.dll!System.Windows.FrameworkElement.MeasureCore(System.Windows.Size availableSize)	Inconnu
 	PresentationCore.dll!System.Windows.UIElement.Measure(System.Windows.Size availableSize)	Inconnu
 	PresentationFramework.dll!System.Windows.Controls.Control.MeasureOverride(System.Windows.Size constraint)	Inconnu
 	PresentationFramework.dll!System.Windows.FrameworkElement.MeasureCore(System.Windows.Size availableSize)	Inconnu
 	PresentationCore.dll!System.Windows.UIElement.Measure(System.Windows.Size availableSize)	Inconnu
 	PresentationFramework.dll!System.Windows.Controls.VirtualizingStackPanel.MeasureChild(ref System.Windows.Controls.Primitives.IItemContainerGenerator generator, ref System.Windows.Controls.Primitives.IContainItemStorage itemStorageProvider, ref System.Windows.Controls.Primitives.IContainItemStorage parentItemStorageProvider, ref object parentItem, ref bool hasUniformOrAverageContainerSizeBeenSet, ref double computedUniformOrAverageContainerSize, ref double computedUniformOrAverageContainerPixelSize, ref bool computedAreContainersUniformlySized, ref bool hasAnyContainerSpanChanged, ref System.Collections.IList items, ref object item, ref System.Collections.IList children, ref int childIndex, ref bool visualOrderChanged, ref bool isHorizontal, ref System.Windows.Size childConstraint, ref System.Windows.Rect viewport, ref System.Windows.Controls.VirtualizationCacheLength cacheSize, ref System.Windows.Controls.VirtualizationCacheLengthUnit cacheUnit, ref long scrollGeneration, ref bool foundFirstItemInViewport, ref double firstItemInViewportOffset, ref System.Windows.Size stackPixelSize, ref System.Windows.Size stackPixelSizeInViewport, ref System.Windows.Size stackPixelSizeInCacheBeforeViewport, ref System.Windows.Size stackPixelSizeInCacheAfterViewport, ref System.Windows.Size stackLogicalSize, ref System.Windows.Size stackLogicalSizeInViewport, ref System.Windows.Size stackLogicalSizeInCacheBeforeViewport, ref System.Windows.Size stackLogicalSizeInCacheAfterViewport, ref bool mustDisableVirtualization, bool isBeforeFirstItem, bool isAfterFirstItem, bool isAfterLastItem, bool skipActualMeasure, bool skipGeneration, ref bool hasBringIntoViewContainerBeenMeasured, ref bool hasVirtualizingChildren)	Inconnu
 	PresentationFramework.dll!System.Windows.Controls.VirtualizingStackPanel.MeasureOverrideImpl(System.Windows.Size constraint, ref double? lastPageSafeOffset, ref System.Collections.Generic.List<double> previouslyMeasuredOffsets, ref double? lastPagePixelSize, bool remeasure)	Inconnu
 	PresentationFramework.dll!System.Windows.Controls.VirtualizingStackPanel.MeasureOverride(System.Windows.Size constraint)	Inconnu
 	PresentationFramework.dll!System.Windows.FrameworkElement.MeasureCore(System.Windows.Size availableSize)	Inconnu

I have a fairly good repro:

  • open this binlog.
  • search for "ReferenceCopyLocalPaths"
    image
  • select the last item in the results tree image
  • hit the "Down Key" (it's the last item so it should have no effect)

NB: the text scaling is at 125%

jairbubbles avatar Oct 28 '20 14:10 jairbubbles

Looks like it's already logged https://github.com/KirillOsenkov/MSBuildStructuredLog/issues/21

jairbubbles avatar Oct 28 '20 14:10 jairbubbles

And I have a pretty recent (the latest?) .NET Framework version installed (528372).

jairbubbles avatar Oct 28 '20 14:10 jairbubbles

Yes, this is #21, the workaround is to uncheck this box: https://github.com/KirillOsenkov/MSBuildStructuredLog/issues/21#issuecomment-705112738

KirillOsenkov avatar Oct 28 '20 18:10 KirillOsenkov

BTW thanks for the repro steps, I tried to reproduce and couldn't on my machine. This is highly sensitive to screen DPI, window size, timing of input events, so really hard to find a reliable repro that works across machines. So the bug may still be there or it may be fixed.

KirillOsenkov avatar Oct 28 '20 18:10 KirillOsenkov

Hummm... I still do reproduce it even if I disable the tree virtualisation.
image

If I attach the debugger I still see the VirtualizingStackPanel in the stack trace:

>	PresentationCore.dll!System.Windows.UIElement.Arrange(System.Windows.Rect finalRect)	Inconnu
 	PresentationFramework.dll!System.Windows.Controls.Grid.ArrangeOverride(System.Windows.Size arrangeSize)	Inconnu
 	PresentationFramework.dll!System.Windows.FrameworkElement.ArrangeCore(System.Windows.Rect finalRect)	Inconnu
 	PresentationCore.dll!System.Windows.UIElement.Arrange(System.Windows.Rect finalRect)	Inconnu
 	PresentationFramework.dll!System.Windows.Controls.Control.ArrangeOverride(System.Windows.Size arrangeBounds)	Inconnu
 	PresentationFramework.dll!System.Windows.Controls.TreeViewItem.ArrangeOverride(System.Windows.Size arrangeSize)	Inconnu
 	PresentationFramework.dll!System.Windows.FrameworkElement.ArrangeCore(System.Windows.Rect finalRect)	Inconnu
 	PresentationCore.dll!System.Windows.UIElement.Arrange(System.Windows.Rect finalRect)	Inconnu
 	PresentationFramework.dll!System.Windows.Controls.VirtualizingStackPanel.ArrangeOtherItemsInExtendedViewport(bool isHorizontal, System.Windows.UIElement child, System.Windows.Size childDesiredSize, double arrangeLength, int index, ref System.Windows.Rect rcChild, ref System.Windows.Size previousChildSize, ref System.Windows.Point previousChildOffset, ref int previousChildItemIndex)	Inconnu
 	PresentationFramework.dll!System.Windows.Controls.VirtualizingStackPanel.ArrangeOverride(System.Windows.Size arrangeSize)	Inconnu

jairbubbles avatar Oct 28 '20 20:10 jairbubbles

I noticed a long delay yesterday while clicking around on search results. I think it occurred when I clicked an item which was one of many siblings in the tree. If I see it again I'll get a trace.

drewnoakes avatar Oct 28 '20 21:10 drewnoakes

yes, if you have a long list and not using virtualization, the long delay is expected and by design (just lots of layout work that needs to happen)

KirillOsenkov avatar Oct 28 '20 21:10 KirillOsenkov

@KirillOsenkov It is possible that the left tree control (filter) still have virtualization even if the checkbox is unticked and that's the one which is faulty in my case?

I'll look at the code source when I have free time

jairbubbles avatar Oct 29 '20 07:10 jairbubbles

Oh interesting, it might be possible indeed, need to check

KirillOsenkov avatar Oct 29 '20 07:10 KirillOsenkov

I can confirm that this is the other tree which is responsible for the freeze. If I disable the virtualization on "resultsList" by removing:

VirtualizingPanel.IsVirtualizing="True"
VirtualizingPanel.VirtualizationMode="Recycling"

I no longer have the issue.

jairbubbles avatar Oct 30 '20 18:10 jairbubbles

Although they're both hangs, this is not really the same as #21 - they have different root causes. To avoid polluting #21, I recommend moving the discussion back here.

The new hang is occurring with the latest .NET updates (that fixed the hangs in #21). Neither @KirillOsenkov nor I can repro it, but I think it's very sensitive to the exact height of the "resultsList" TreeView and the data it displays, and to the exact sequence of scrolling operations; we just haven't stumbled on the right combination. The .stf trace @jairbubbles attached to #21 should help, but I'm still tinkering. @anton-zaicev - can you attach an .stf trace for your case, to confirm that it's the same issue?

Note that this is really an issue in .NET/WPF; there's nothing wrong with Kirill's app. I've asked @KirillOsenkov to open an issue in the internal .NET database, which will justify spending time and effort to diagnose and fix the problem in a .NET servicing update.

SamBent avatar Nov 09 '20 18:11 SamBent

I've just made a change for the resultsList to respect the virtualization setting: https://github.com/KirillOsenkov/MSBuildStructuredLog/commit/4b307e49dcf171f054239db07f6c9dbb01b36fd0

At least as a workaround you can now turn off the virtualization checkbox on the startup screen to get unblocked: https://github.com/KirillOsenkov/MSBuildStructuredLog/issues/21#issuecomment-705112738

KirillOsenkov avatar Nov 09 '20 18:11 KirillOsenkov

@SamBent, here is my .stf trace: scrollTrace.zip

anton-zaicev avatar Nov 09 '20 18:11 anton-zaicev

@SamBent You might have missed it in the other thread but when compiling locally and run with .NET Core 3.1.9 I can't reproduce it. Maybe it doesn't contain the fix that created that new issue?

jairbubbles avatar Nov 09 '20 19:11 jairbubbles

The two STF traces both show hangs when using MouseWheelDown to scroll forward from a position that is very near, but not quite at, the end of the data. Which means they're probably hitting the same root-cause. But they're different in that one (from @jairbubbles) has "tidy" heights for the viewport and the ListViewItems - 936, 17.6, +2.4 for non-leaves - while the other (from @anton-zaicev) has "messy" heights - 546.857142857143, 17.1428571428571. It probably doesn't matter, but I'm curious if anyone can explain this?

My guess is that the "resultsList" TreeView has UseLayoutRounding=true, and that both users have high-DPI monitors (or enabled DPI scaling), one at 125% yielding an effective pixel size of 100/125 = 0.8, the other at 175% yielding an effective pixel size of 100/175 = .571428571428571. The trace doesn't record either UseLayoutRounding or effective pixel size so I can't confirm my guess. Can you?

SamBent avatar Nov 10 '20 23:11 SamBent

@SamBent, yes, I have 175% scale. MainWindow has UseLayoutRounding=true.

anton-zaicev avatar Nov 11 '20 17:11 anton-zaicev

@jairbubbles @anton-zaicev if you email me at my first name dot last name at microsoft, I'll e-mail you instructions on how to test the fix. @SamBent was able to reproduce and produced a fix that needs to be tested before they'll allow us to check it in.

KirillOsenkov avatar Nov 13 '20 04:11 KirillOsenkov

OK great news! I was able to reproduce the bug and validate the fix.

WPFHangReproFix

Here's the video:

  1. reproduced the hang with old binary
  2. did not reproduce with old binary, kinda hung but not reliably
  3. reproduced with old binary === installed the new binary ===
  4. did not reproduce with new binary
  5. did not reproduce with new binary === revert to old binary ===
  6. reproduced with old binary

Repro guidance:

  1. Windows Sandbox works great
  2. Set your host OS DPI to 125%
  3. In the Sandbox, install MSBuild Structured Log Viewer from https://msbuildlog.com
  4. Open freeze.binlog and search for ReferenceCopyLocalPaths
  5. Resize the viewer window such that the third scroll wheel scrolls almost to the end
  6. Try to repro by using scroll wheel only - repeat steps 5 and 6 until you can reliably reproduce
  7. Resize the Windows Sandbox window to exactly envelope the viewer window at that size
  8. Close and reopen the viewer and maximize, presumably it will fill the size and the repro will be easy
  9. Close the viewer, open C:\Windows\Microsoft.NET\assembly\GAC_MSIL\PresentationFramework\v4.0_4.0.0.0__31bf3856ad364e35 and replace PresentationFramework.dll with the one I sent
  10. Repeat steps 4-6 - hopefully the bug won't reproduce

KirillOsenkov avatar Nov 20 '20 03:11 KirillOsenkov

I had also validated the fix and can confirm that the bug is fixed. @SamBent, what is the planned date of release for this fix?

anton-zaicev avatar Nov 30 '20 16:11 anton-zaicev

The fix is in the pipeline of review/approval/packaging/testing for inclusion in a .NET servicing update. If no problems arise, it should appear early in 2021. I'll post back to this thread when that happens.

SamBent avatar Nov 30 '20 17:11 SamBent

@SamBent, are there any news about planned release date?

anton-zaicev avatar Feb 12 '21 10:02 anton-zaicev

Thanks for the reminder.

The fix was released in the .NET Update Preview on Jan 26, and in the .NET Update on Feb 9. The former is available for download, the latter is part of the monthly Windows Update payload. (The KB number depends on which OS version you're running.)

SamBent avatar Feb 12 '21 17:02 SamBent

I haven't seen any new reports of hangs for a couple of months now, so I'll consider this issue resolved. Thanks again everyone.

KirillOsenkov avatar Mar 26 '21 18:03 KirillOsenkov

I think we had found regress - same bug after recent update, can you re-check that? PresentationFramework.dll - version 4.8.4360.0

anton-zaicev avatar Jul 06 '21 11:07 anton-zaicev

Could you please upload PresentationFramework.dll here?

KirillOsenkov avatar Jul 06 '21 15:07 KirillOsenkov

Here it is. PresentationFramework.zip

anton-zaicev avatar Jul 06 '21 15:07 anton-zaicev

Hmm, I have the exact same version of the .dll, but I haven't noticed any hangs. I'll keep a close eye on it.

Any more details about the hang that you can share?

@anton-zaicev any chance that you could record another scrollTrace.stf like you did the last time? https://github.com/KirillOsenkov/MSBuildStructuredLog/issues/407#issuecomment-724201802

https://github.com/KirillOsenkov/MSBuildStructuredLog/issues/21#issuecomment-514701904

KirillOsenkov avatar Jul 06 '21 19:07 KirillOsenkov

Have you tried it with DPI value different from 100%? I'll be back with scroll trace soon.

anton-zaicev avatar Jul 06 '21 19:07 anton-zaicev

I usually run with 200% DPI, maybe I should try 125% again (last time we had a repro with 125%)

KirillOsenkov avatar Jul 06 '21 19:07 KirillOsenkov

It is not so easy to repro this time, but behaviour is all the same (DPI > 100%, same scroll actions), this time UseLayoutRounding property is involved. I end up with the same situation (scroll freezing) but only with the UseLayoutRounding="True" for virtualized container, with "False" value there is no any undesired behaviour and it is the temporary fix for now. I had collected scroll trace but not from the MSBuildStructuredLog app, there is same infinite scroll calculations loop as in the previous case. So, how I see, I should move to WPF repo and create issue there? ScrollTrace.zip

anton-zaicev avatar Jul 08 '21 19:07 anton-zaicev