TailBlazer icon indicating copy to clipboard operation
TailBlazer copied to clipboard

Performance and Stability issues

Open jlanzarotta opened this issue 7 years ago • 19 comments

Hello,

I have been trying to use TailBlazer for a few months now and have noticed several significant performance and stability issues and I wanted to asked about them.

First, over time, TailBlazer used an excessive amount of memory. For example, I have been running it for about 3 hours today, and I have a 114 MB log file and TailBlazer is using 1.05 GB of memory... That sounds excessive to me. As I watch the usage in Visual Studio 2015, I see the memory usage steadily go up over time and never dropping.

The second issue I am seeing is that over time, TailBlazer become non responsive. As I mentioned, I have been running for about 3 hours and the application is no longer updating the screen even though it is using CPU and memory. The only want to fix the issue is to terminate the application.

Thoughts?

jlanzarotta avatar May 11 '17 16:05 jlanzarotta

That sounds totally wrong to me! Personally I have not seen such memory issues but I will profile it as something is obviously wrong.

In terms of unresponsiveness, I have seen TB fail to reconnect sometimes when a log file roles. I think it has something to do with exclusive locking when the logger creates a new file. Again I will take a look to see if I can work it out.

But perhaps the 2 issues are related.

RolandPheasant avatar May 11 '17 18:05 RolandPheasant

Thanks for the reply. I will continue to dig into it and report anything I find.

jlanzarotta avatar May 11 '17 18:05 jlanzarotta

For what it is worth, I am writing a LOT of records to the log file... I would say every few milliseconds...

jlanzarotta avatar May 11 '17 18:05 jlanzarotta

In the early days of dd I tested it against a market data logger which produced a 10Mb file every 1 minute then continually role and at the time there were no memory leaks. I have obviously introduced something since.

Out of interest, are the lines in the log files very long?

RolandPheasant avatar May 11 '17 18:05 RolandPheasant

Yes, some are fairly long upwards of 1049 characters.

jlanzarotta avatar May 11 '17 18:05 jlanzarotta

Maybe LOH fragmentation. Do you have a profiler to check?

RolandPheasant avatar May 11 '17 18:05 RolandPheasant

I am profiling right now... In the future lines have the potential to become longer as DEBUG or TRACE levels are enabled.

jlanzarotta avatar May 11 '17 18:05 jlanzarotta

I have not used the Visual Studio 2015 profiler before...

jlanzarotta avatar May 11 '17 18:05 jlanzarotta

Nor have I. Good luck with that one

RolandPheasant avatar May 11 '17 18:05 RolandPheasant

One other thing to note. I have three global search and highlight options set. One for DEBUG, one for WARN, and another one for INFO.

jlanzarotta avatar May 11 '17 19:05 jlanzarotta

By the way, I am testing with the latest 'master' code and seeing the same issue... I will keep digging.

jlanzarotta avatar May 12 '17 13:05 jlanzarotta

Okay, I have done a little more digging. I have no idea if these make sense... These were generated by using the .NET Memory Profiler...

Potential WPF binding memory leak

This snapshot has WPF bindings where the source types do not implement INotifyPropertyChanged and the targets of the bindings are reachable from the source instances. This may cause memory leaks. Investigate the type below for more information. TextBlock, ScrollViewer, ItemsControl, DragablzItemsControl, SearchProxyCollection, ListBoxItem, GeneralOptionBindings, ContentControl, Dragablz.DragablzItem, HeaderedView

This filter has 58 instances that are targets of WPF bindings where the source type does not implement INotifyPropertyChanged. The instances are reachable from the source instance, which may cause a memory leak. Implement INotifyPropertyChanged for the type, or make the binding a OneTime binding to avoid the memory leak. For more information investigate the instances below, and see Microsoft KB938416. #23,693, #738,999*, #739,249*, #739,562*, #739,687*, #739,949*, #740,109*, #740,672*, #740,844*, #741,437*, (...)

This filter has 4 instances that are sources of WPF bindings, but the type does not implement INotifyPropertyChanged. The target of the binding is reachable from the instances, which may cause a memory leak. Implement INotifyPropertyChanged for the type, or make the binding a OneTime binding to avoid the memory leak. For more information investigate the instances below, and see Microsoft KB938416. #24,536, #24,513, #1,663, #1,640

Direct EventHandler roots

6 types have instances that are directly rooted by an EventHandler. This can indicate that an EventHandler has not been properly removed. Investigate the types below for more information. Storyboard.ChangeListener, ResourceReferenceExpression.ResourceReferenceExpressionWeakContainer, VisualStateManager.GoToStateInternal().Closure_0, BootStrap.Main().Closure_0, WindowAssist.OnClosingDelegateSet().Closure_0, WindowFactory.Create().Closure_0

jlanzarotta avatar May 12 '17 18:05 jlanzarotta

Here is the complete overview...

Potential WPF binding memory leak

This snapshot has WPF bindings where the source types do not implement INotifyPropertyChanged and the targets of the bindings are reachable from the source instances. This may cause memory leaks. Investigate the type below for more information. TextBlock, ScrollViewer, ItemsControl, DragablzItemsControl, SearchProxyCollection, ContentControl, Dragablz.DragablzItem, HeaderedView, ListBoxItem, GeneralOptionBindings

Direct EventHandler roots

6 types have instances that are directly rooted by an EventHandler. This can indicate that an EventHandler has not been properly removed. Investigate the types below for more information. Storyboard.ChangeListener, ResourceReferenceExpression.ResourceReferenceExpressionWeakContainer, VisualStateManager.GoToStateInternal().Closure_0, BootStrap.Main().Closure_0, WindowAssist.OnClosingDelegateSet().Closure_0, WindowFactory.Create().Closure_0

Delegate roots via closure

3 types have instances that are rooted by a delegate via a closure. This can indicate that a delegate has not been properly removed. Investigate the types below for more information. LimitSizeTo<LineProxy>, GenericFamilyExpression, LineMatchProxy Direct delegate roots (Show details) (Ignore...) 150 types have instances that are directly rooted by a delegate. This can indicate that the delegate has not been properly removed. Investigate the types below for more information. MaxEx.Calculate().Closure_0<Line,int>, DynamicDataEx.LogErrors().Closure_0<IChangeSet<LineProxy,LineKey>>, DynamicDataEx.LogErrors().Closure_0, DynamicDataEx.LogErrors().Closure_0<FileInfo>, NotifyPropertyChangedEx.WhenAnyPropertyChanged().Closure_0<GeneralOptionsViewModel>, NotifyPropertyChangedEx.WhenValueChanged().Closure_0<GeneralOptionsViewModel,double>, NotifyPropertyChangedEx.WhenValueChanged().Closure_0<GeneralOptionsViewModel,int>, NotifyPropertyChangedEx.WhenValueChanged().Closure_0<IconSelector,IconDescription>, NotifyPropertyChangedEx.WhenValueChanged().Closure_0<SearchCollection,SearchViewModel>, NotifyPropertyChangedEx.WhenValueChanged().Closure_0<SearchHints,bool>, (...)

Pinned instances

117 types have instances that are pinned in memory. Investigate the types below for more information. __type_info_node, $ArrayType$$$BY09UCONTROL_TABLE@TtfDelta@Internal@MS@@, BASEAXIS_CONTROL$$BY0A@E, BASECOORDFORMAT2_CONTROL$$BY0A@E, BASEFEATMINMAXRECORD_CONTROL$$BY0A@E, BASEHEADER_CONTROL$$BY0A@E, BASELANGSYSRECORD_CONTROL$$BY0A@E, BASEMINMAX_CONTROL$$BY0A@E, BASESCRIPT_CONTROL$$BY0A@E, BASESCRIPTLIST_CONTROL$$BY0A@E, (...) Indirect EventHandler roots (Show details) (Ignore...) 6 types have instances that are indirectly rooted by an EventHandler. This can indicate that the EventHandler has not been properly removed. Investigate the types below for more information. <GCHandle>, ArrayList, EventHandlerList, System.Object[], System.Windows.Window, WindowCollection Indirect delegate roots (Show details) (Ignore...) 450 types have instances that are indirectly rooted by a delegate. This can indicate that the delegate has not been properly removed. Investigate the types below for more information. ObservableCollectionAdaptor<RecentFileProxy>, ObservableCollectionEx.ToObservableChangeSet().Closure_0<HeaderedView>, ObservableCollectionEx.ToObservableChangeSet().Closure_0<LineProxy>, SortedObservableCollectionAdaptor<SearchViewModel,string>, SortedObservableCollectionAdaptor<LineProxy,LineKey>, SortExpression, SortExpression[], SortExpression<Index>, SortExpression<Index>[], SortExpression<RecentFileProxy>, (...)

WPF bindings with source that does not implement INotifyPropertyChanged

This snapshot has WPF bindings where the source types do not implement INotifyPropertyChanged. This can delay the garbage collection of the involved instances and increase the risk of a memory leak.
Investigate the type below for more information. PackIcon, IconDescription, DragablzItemsControl, System.Windows.Size

Direct delegate roots to closure

3 closure types have instances that are directly rooted by a delegate. This can indicate that a delegate has not been properly removed. Investigate the types below for more information. LimitSizeTo<LineProxy>.Run().Closure_0, GenericFamilyExpression.alterAndContinue().Closure_0, LineMatchProxy..ctor().Closure_0

Duplicate instances

487 types have duplicate instances (7,956 sets, 7,141,520 duplicated bytes). Duplicate instances can cause unnecessary memory consumption. Investigate the types below for more information. System.String (3,112 sets, 1,662,900 duplicated bytes), UnmanagedMemoryStream (21 sets, 1,397,880 duplicated bytes), System.Byte[] (182 sets, 699,301 duplicated bytes), System.IO.MemoryStream (40 sets, 447,768 duplicated bytes), SourceValueInfo[] (185 sets, 301,470 duplicated bytes), System.Object (one set, 295,344 duplicated bytes), System.String[] (172 sets, 278,356 duplicated bytes), Baml2006SchemaContext.BamlProperty (460 sets, 266,714 duplicated bytes), Baml2006SchemaContext.BamlAssembly (9 sets, 249,934 duplicated bytes), Dictionary<string,string>.Entry[] (48 sets, 239,072 duplicated bytes), (...)

Instances queued for finalization (pending finalizer)

5 types have instances that are queued for finalization. Investigate the types below for more information. GCNotificationToken, GCNotificationToken, ConditionalWeakTable<object,object>, Gen2GcCallback, GCNotificationToken

####Empty weak reference The WeakReference type has instances that are no longer alive. Investigate the WeakReference type for more information. System.WeakReference, WeakReference, WeakReference<BindingGroup>, WeakReference<ImmComposition>

Interned string

There are strings that have been interned. Interning a string may avoid duplication, but will prevent the string from ever being garbage collected. Investigate the String type for more information. System.String

Large instances

2 types have instances that are located in the large object heap. Investigate the types below for more information. System.Int64[], System.Object[]

Possible duplicate instances

1,211 types with possibly duplicate instances have been found. Duplicate instances can cause unnecessary memory consumption. Investigate the types below for more information. <GCHandle>, AnonymousDisposable, SerialDisposable, VerticalOrganiser, VerticalPositionMonitor, MaxEx.Calculate().Closure_0<Line,int>, DynamicDataEx.LogErrors().Closure_0<IChangeSet<LineProxy,LineKey>>, ObservableCollectionEx.ToObservableChangeSet().Closure_0<LineProxy>, ObservableCollectionEx.ToObservableChangeSet().Closure_2<LineProxy>, ObservableCollectionExtended, (...)

Held duplicate instances

46 types have 547 sets of duplicate instances that are held by other duplicate instances. Investigate the types below for more information. System.String (166 sets, 1,254 instances), System.IDisposable[] (3 sets, 724 instances), ConditionalWeakTable<object,object>.Entry[] (194 sets, 518 instances), System.Int16[] (20 sets, 323 instances), System.Double (8 sets, 141 instances), System.Int32[] (26 sets, 128 instances), CustomAttributeData[] (one set, 124 instances), System.Char[] (44 sets, 102 instances), System.Byte[] (27 sets, 98 instances), TextHidden (one set, 86 instances), (...)

jlanzarotta avatar May 12 '17 18:05 jlanzarotta

So far, I have had no lunch tracking down what is causing the above issues...

jlanzarotta avatar May 15 '17 20:05 jlanzarotta

Thanks for investigating in such detail. I will take a good look at the results tomorrow

RolandPheasant avatar May 15 '17 21:05 RolandPheasant

You are welcome. I really like TailBlazer; however, with the volume of lines being written to our log files, TailBlazer is really struggling. If there is anything else I can help you out with, I will try. I have worked with C# for many years, just not with WPF...

I did switch over to an evaluation copy of the .NET memory profiler (https://memprofiler.com); however, my evaluation period is about to expire.

jlanzarotta avatar May 16 '17 12:05 jlanzarotta

Not sure if this was resolved. I recently started using Tailblazer, its nice! But having left it running last night, this morning the process is using between 800mb & 1.2gb (peaks & toughs frequently from looking at task manager), possible leak some where? Its hard to know whats going on as its UI is just a black screen, so guessing something has foobarred. I have a memory dump file if it helps.

robsonj avatar Jul 27 '17 12:07 robsonj

Alas this is not solved. I have been meaning for a very long time to get back into TB but have been consumed with dynamic data for almost all of the last year.

I will definitely get back on the case in the near future and the first thing I will tackle is the memory issues

RolandPheasant avatar Jul 27 '17 12:07 RolandPheasant

No problem Roland. Just wanted to add the observation point. I like whats there in tailblazer so far!

robsonj avatar Jul 27 '17 12:07 robsonj