diff --git a/Perspex.Base/Perspex.Base.csproj b/Perspex.Base/Perspex.Base.csproj index d23f3650cb..6a492bf582 100644 --- a/Perspex.Base/Perspex.Base.csproj +++ b/Perspex.Base/Perspex.Base.csproj @@ -65,6 +65,10 @@ + + ..\packages\Serilog.1.5.5\lib\portable-net45+win+wpa81+wp80+MonoAndroid10+MonoTouch10\Serilog.dll + True + ..\packages\Splat.1.6.2\lib\Portable-net45+win+wpa81+wp80\Splat.dll True diff --git a/Perspex.Base/PerspexObject.cs b/Perspex.Base/PerspexObject.cs index f749c320b3..5fb57a7bac 100644 --- a/Perspex.Base/PerspexObject.cs +++ b/Perspex.Base/PerspexObject.cs @@ -7,7 +7,8 @@ namespace Perspex { using Perspex.Reactive; - using Splat; + using Serilog; + using Serilog.Core.Enrichers; using System; using System.Collections.Generic; using System.ComponentModel; @@ -64,7 +65,7 @@ namespace Perspex /// /// This class is analogous to DependencyObject in WPF. /// - public class PerspexObject : INotifyPropertyChanged, IEnableLogger + public class PerspexObject : INotifyPropertyChanged { /// /// The registered properties by type. @@ -88,11 +89,23 @@ namespace Perspex /// private PropertyChangedEventHandler inpcChanged; + /// + /// A serilog logger for logging property events. + /// + private ILogger propertyLog; + /// /// Initializes a new instance of the class. /// public PerspexObject() { + this.propertyLog = Log.ForContext(new[] + { + new PropertyEnricher("Area", "Property"), + new PropertyEnricher("SourceContext", this.GetType()), + new PropertyEnricher("Id", this.GetHashCode()), + }); + foreach (var property in this.GetRegisteredProperties()) { var e = new PerspexPropertyChangedEventArgs( @@ -515,14 +528,12 @@ namespace Perspex v = this.CreatePriorityValue(property); this.values.Add(property, v); } - - this.Log().Debug( - "Set local value of {0}.{1} (#{2:x8}) to {3}", - this.GetType().Name, - property.Name, - this.GetHashCode(), - value); + this.propertyLog.Verbose( + "Set {Property} to {$Value} with priority {Priority}", + property, + value, + priority); v.SetDirectValue(value, (int)priority); } @@ -569,12 +580,11 @@ namespace Perspex this.values.Add(property, v); } - this.Log().Debug( - "Bound value of {0}.{1} (#{2:x8}) to {3}", - this.GetType().Name, - property.Name, - this.GetHashCode(), - description != null ? description.Description : "[Anonymous]"); + this.propertyLog.Verbose( + "Bound {Property} to {Binding} with priority {Priority}", + property, + source, + priority); return v.Add(source, (int)priority); } @@ -699,13 +709,12 @@ namespace Perspex { this.RaisePropertyChanged(property, oldValue, newValue, (BindingPriority)result.ValuePriority); - this.Log().Debug( - "Value of {0}.{1} (#{2:x8}) changed from {3} to {4}", - this.GetType().Name, - property.Name, - this.GetHashCode(), + this.propertyLog.Verbose( + "{Property} changed from {$Old} to {$Value} with priority {Priority}", + property, oldValue, - newValue); + newValue, + (BindingPriority)result.ValuePriority); } }); diff --git a/Perspex.Base/packages.config b/Perspex.Base/packages.config index aa2dbd982f..8c57210e70 100644 --- a/Perspex.Base/packages.config +++ b/Perspex.Base/packages.config @@ -5,5 +5,6 @@ + \ No newline at end of file diff --git a/Perspex.Controls/Perspex.Controls.csproj b/Perspex.Controls/Perspex.Controls.csproj index 5c5279b854..8cdcd7de17 100644 --- a/Perspex.Controls/Perspex.Controls.csproj +++ b/Perspex.Controls/Perspex.Controls.csproj @@ -127,6 +127,10 @@ + + ..\packages\Serilog.1.5.5\lib\portable-net45+win+wpa81+wp80+MonoAndroid10+MonoTouch10\Serilog.dll + True + ..\packages\Splat.1.6.2\lib\Portable-net45+win+wpa81+wp80\Splat.dll True diff --git a/Perspex.Controls/Primitives/TemplatedControl.cs b/Perspex.Controls/Primitives/TemplatedControl.cs index 21049fa9a5..0cf46790c9 100644 --- a/Perspex.Controls/Primitives/TemplatedControl.cs +++ b/Perspex.Controls/Primitives/TemplatedControl.cs @@ -13,7 +13,8 @@ namespace Perspex.Controls.Primitives using Perspex.Media; using Perspex.Styling; using Perspex.VisualTree; - using Splat; + using Serilog; + using Serilog.Core.Enrichers; public class TemplatedControl : Control, ITemplatedControl { @@ -46,6 +47,8 @@ namespace Perspex.Controls.Primitives private bool templateApplied; + private ILogger templateLog; + static TemplatedControl() { TemplateProperty.Changed.Subscribe(e => @@ -56,6 +59,16 @@ namespace Perspex.Controls.Primitives }); } + public TemplatedControl() + { + this.templateLog = Log.ForContext(new[] + { + new PropertyEnricher("Area", "Template"), + new PropertyEnricher("SourceContext", this.GetType()), + new PropertyEnricher("Id", this.GetHashCode()), + }); + } + public Brush Background { get { return this.GetValue(BackgroundProperty); } @@ -122,10 +135,7 @@ namespace Perspex.Controls.Primitives if (this.Template != null) { - this.Log().Debug( - "Creating template for {0} (#{1:x8})", - this.GetType().Name, - this.GetHashCode()); + this.templateLog.Verbose("Creating control template"); var child = this.Template.Build(this); this.SetTemplatedParent(child); diff --git a/Perspex.Controls/packages.config b/Perspex.Controls/packages.config index aa2dbd982f..8c57210e70 100644 --- a/Perspex.Controls/packages.config +++ b/Perspex.Controls/packages.config @@ -5,5 +5,6 @@ + \ No newline at end of file diff --git a/Perspex.Layout/LayoutManager.cs b/Perspex.Layout/LayoutManager.cs index 2a5975da35..19a2146df8 100644 --- a/Perspex.Layout/LayoutManager.cs +++ b/Perspex.Layout/LayoutManager.cs @@ -11,6 +11,9 @@ namespace Perspex.Layout using System.Reactive.Subjects; using NGenerics.DataStructures.General; using Perspex.VisualTree; + using Serilog; + using Serilog.Core.Enrichers; + using System.Reactive.Disposables; /// /// Manages measuring and arranging of controls. @@ -53,11 +56,28 @@ namespace Perspex.Layout /// private Heap toArrange = new Heap(HeapType.Minimum); + /// + /// Prevents re-entrancy. + /// + private bool running; + + /// + /// The logger to use. + /// + private ILogger log; + /// /// Initializes a new instance of the class. /// public LayoutManager() { + this.log = Log.ForContext(new[] + { + new PropertyEnricher("Area", "Layout"), + new PropertyEnricher("SourceContext", this.GetType()), + new PropertyEnricher("Id", this.GetHashCode()), + }); + this.layoutNeeded = new Subject(); this.layoutCompleted = new Subject(); } @@ -102,25 +122,45 @@ namespace Perspex.Layout /// public void ExecuteLayoutPass() { - this.LayoutQueued = false; + if (this.running) + { + return; + } - for (int i = 0; i < MaxTries; ++i) + using (Disposable.Create(() => this.running = false)) { - if (this.measureNeeded) - { - this.ExecuteMeasure(); - this.measureNeeded = false; - } + this.running = true; + this.LayoutQueued = false; - this.ExecuteArrange(); + this.log.Information( + "Started layout pass. To measure: {Measure} To arrange: {Arrange}", + this.toMeasure.Count, + this.toArrange.Count); - if (this.toMeasure.Count == 0) + var stopwatch = new System.Diagnostics.Stopwatch(); + stopwatch.Start(); + + for (int i = 0; i < MaxTries; ++i) { - break; + if (this.measureNeeded) + { + this.ExecuteMeasure(); + this.measureNeeded = false; + } + + this.ExecuteArrange(); + + if (this.toMeasure.Count == 0) + { + break; + } } - } - this.layoutCompleted.OnNext(Unit.Default); + stopwatch.Stop(); + this.log.Information("Layout pass finised in {Time}", stopwatch.Elapsed); + + this.layoutCompleted.OnNext(Unit.Default); + } } /// diff --git a/Perspex.Layout/Layoutable.cs b/Perspex.Layout/Layoutable.cs index b5a46c1ffd..d4e700984f 100644 --- a/Perspex.Layout/Layoutable.cs +++ b/Perspex.Layout/Layoutable.cs @@ -9,7 +9,8 @@ namespace Perspex.Layout using System; using System.Linq; using Perspex.VisualTree; - using Splat; + using Serilog; + using Serilog.Core.Enrichers; public enum HorizontalAlignment { @@ -27,7 +28,7 @@ namespace Perspex.Layout Bottom, } - public class Layoutable : Visual, ILayoutable, IEnableLogger + public class Layoutable : Visual, ILayoutable { public static readonly PerspexProperty WidthProperty = PerspexProperty.Register("Width", double.NaN); @@ -63,6 +64,8 @@ namespace Perspex.Layout private Rect? previousArrange; + private ILogger layoutLog; + static Layoutable() { Layoutable.AffectsMeasure(Visual.IsVisibleProperty); @@ -77,6 +80,16 @@ namespace Perspex.Layout Layoutable.AffectsMeasure(Layoutable.VerticalAlignmentProperty); } + public Layoutable() + { + this.layoutLog = Log.ForContext(new[] + { + new PropertyEnricher("Area", "Layout"), + new PropertyEnricher("SourceContext", this.GetType()), + new PropertyEnricher("Id", this.GetHashCode()), + }); + } + public double Width { get { return this.GetValue(WidthProperty); } @@ -192,11 +205,7 @@ namespace Perspex.Layout this.DesiredSize = desiredSize; this.previousMeasure = availableSize; - this.Log().Debug( - "Measure of {0} (#{1:x8}) requested {2} ", - this.GetType().Name, - this.GetHashCode(), - this.DesiredSize); + this.layoutLog.Verbose("Measure requested {DesiredSize}", this.DesiredSize); } } @@ -218,11 +227,7 @@ namespace Perspex.Layout if (force || !this.IsArrangeValid || this.previousArrange != rect) { - this.Log().Debug( - "Arrange of {0} (#{1:x8}) gave {2} ", - this.GetType().Name, - this.GetHashCode(), - rect); + this.layoutLog.Verbose("Arrange to {Rect} ", rect); this.IsArrangeValid = true; this.ArrangeCore(rect); @@ -236,10 +241,7 @@ namespace Perspex.Layout if (this.IsMeasureValid) { - this.Log().Debug( - "Invalidated measure of {0} (#{1:x8})", - this.GetType().Name, - this.GetHashCode()); + this.layoutLog.Verbose("Invalidated measure"); } this.IsMeasureValid = false; @@ -268,10 +270,7 @@ namespace Perspex.Layout if (this.IsArrangeValid) { - this.Log().Debug( - "Invalidated arrange of {0} (#{1:x8})", - this.GetType().Name, - this.GetHashCode()); + this.layoutLog.Verbose("Arrange measure"); } this.IsArrangeValid = false; diff --git a/Perspex.Layout/Perspex.Layout.csproj b/Perspex.Layout/Perspex.Layout.csproj index 0ccf003e22..bbd334bef4 100644 --- a/Perspex.Layout/Perspex.Layout.csproj +++ b/Perspex.Layout/Perspex.Layout.csproj @@ -64,6 +64,10 @@ + + ..\packages\Serilog.1.5.5\lib\portable-net45+win+wpa81+wp80+MonoAndroid10+MonoTouch10\Serilog.dll + True + ..\packages\Splat.1.6.2\lib\Portable-net45+win+wpa81+wp80\Splat.dll True diff --git a/Perspex.Layout/packages.config b/Perspex.Layout/packages.config index aa2dbd982f..8c57210e70 100644 --- a/Perspex.Layout/packages.config +++ b/Perspex.Layout/packages.config @@ -5,5 +5,6 @@ + \ No newline at end of file diff --git a/Perspex.SceneGraph/Perspex.SceneGraph.csproj b/Perspex.SceneGraph/Perspex.SceneGraph.csproj index 0b93a1bb16..ced7573ee8 100644 --- a/Perspex.SceneGraph/Perspex.SceneGraph.csproj +++ b/Perspex.SceneGraph/Perspex.SceneGraph.csproj @@ -107,6 +107,10 @@ + + ..\packages\Serilog.1.5.5\lib\portable-net45+win+wpa81+wp80+MonoAndroid10+MonoTouch10\Serilog.dll + True + ..\packages\Splat.1.6.2\lib\Portable-net45+win+wpa81+wp80\Splat.dll True diff --git a/Perspex.SceneGraph/Visual.cs b/Perspex.SceneGraph/Visual.cs index c70b1b5d73..5b3a1e2e6a 100644 --- a/Perspex.SceneGraph/Visual.cs +++ b/Perspex.SceneGraph/Visual.cs @@ -17,7 +17,8 @@ namespace Perspex using Perspex.Platform; using Perspex.Rendering; using Perspex.VisualTree; - using Splat; + using Serilog; + using Serilog.Core.Enrichers; public class Visual : Animatable, IVisual { @@ -46,6 +47,8 @@ namespace Perspex private Visual visualParent; + private ILogger visualLogger; + static Visual() { AffectsRender(IsVisibleProperty); @@ -55,6 +58,13 @@ namespace Perspex public Visual() { + this.visualLogger = Log.ForContext(new[] + { + new PropertyEnricher("Area", "Visual"), + new PropertyEnricher("SourceContext", this.GetType()), + new PropertyEnricher("Id", this.GetHashCode()), + }); + this.visualChildren = new PerspexList(); this.visualChildren.CollectionChanged += this.VisualChildrenChanged; } @@ -307,10 +317,7 @@ namespace Perspex private void NotifyAttachedToVisualTree(IRenderRoot root) { - this.Log().Debug( - "Attached {0} (#{1:x8}) to visual tree", - this.GetType().Name, - this.GetHashCode()); + this.visualLogger.Verbose("Attached to visual tree"); this.OnAttachedToVisualTree(root); @@ -325,10 +332,7 @@ namespace Perspex private void NotifyDetachedFromVisualTree(IRenderRoot oldRoot) { - this.Log().Debug( - "Detached {0} (#{1:x8}) from visual tree", - this.GetType().Name, - this.GetHashCode()); + this.visualLogger.Verbose("Detached from visual tree"); this.OnDetachedFromVisualTree(oldRoot); diff --git a/Perspex.SceneGraph/packages.config b/Perspex.SceneGraph/packages.config index aa2dbd982f..8c57210e70 100644 --- a/Perspex.SceneGraph/packages.config +++ b/Perspex.SceneGraph/packages.config @@ -5,5 +5,6 @@ + \ No newline at end of file diff --git a/TestApplication/Program.cs b/TestApplication/Program.cs index f20334c20f..7047bd9a33 100644 --- a/TestApplication/Program.cs +++ b/TestApplication/Program.cs @@ -17,24 +17,12 @@ using Perspex.Gtk; #endif using ReactiveUI; using Splat; +using Serilog; +using Serilog.Filters; +using Serilog.Events; namespace TestApplication { - class TestLogger : ILogger - { - public LogLevel Level - { - get; - set; - } - - public void Write(string message, LogLevel logLevel) - { - if ((int)logLevel < (int)Level) return; - System.Diagnostics.Debug.WriteLine(message); - } - } - class Item { public string Name { get; set; } @@ -106,9 +94,11 @@ namespace TestApplication static void Main(string[] args) { - //LogManager.Enable(new TestLogger()); - //LogManager.Instance.LogLayoutMessages = true; - //LogManager.Instance.LogPropertyMessages = true; + Log.Logger = new LoggerConfiguration() + .Filter.ByIncludingOnly(Matching.WithProperty("Area", "Layout")) + .MinimumLevel.Verbose() + .WriteTo.Trace(outputTemplate: "[{Id:X8}] [{SourceContext}] {Message}") + .CreateLogger(); // The version of ReactiveUI currently included is for WPF and so expects a WPF // dispatcher. This makes sure it's initialized. diff --git a/TestApplication/TestApplication.csproj b/TestApplication/TestApplication.csproj index bebd32e1a2..7e368a9270 100644 --- a/TestApplication/TestApplication.csproj +++ b/TestApplication/TestApplication.csproj @@ -38,6 +38,14 @@ False ..\packages\reactiveui-core.6.4.0.1\lib\Net45\ReactiveUI.dll + + ..\packages\Serilog.1.5.5\lib\net45\Serilog.dll + True + + + ..\packages\Serilog.1.5.5\lib\net45\Serilog.FullNetFx.dll + True + ..\packages\Splat.1.6.2\lib\Net45\Splat.dll True diff --git a/TestApplication/packages.config b/TestApplication/packages.config index 8337079d29..76d0fcf6ec 100644 --- a/TestApplication/packages.config +++ b/TestApplication/packages.config @@ -8,6 +8,7 @@ +