Benchmarks and LoggerMessage optimizations

BREAKING_CHANGES.md

@@ -1,5 +1,8 @@
 # Breaking Changes
 
+## 1.3.0
+- The NuGet reference to `Microsoft.Extensions.Logging.Abstractions` now requires version 6.0.0 and up.
+
 ## 0.11.0
 - `DecoratorCommandStrategy` not longer exists. Use `DelegatingCommandStrategy` instead.
 

DynamicMvvm.sln

@@ -21,6 +21,8 @@ Project("{9A19103F-16F7-4668-BE54-9A1E7A4F7556}") = "DynamicMvvm.Uno.WinUI", "sr
 EndProject
 Project("{D954291E-2A0B-460D-934E-DC6B0785DB48}") = "DynamicMvvm.Shared", "src\DynamicMvvm.Shared\DynamicMvvm.Shared.shproj", "{8BCF881B-035B-4572-A0B5-27C379DEBEE8}"
 EndProject
+Project("{FAE04EC0-301F-11D3-BF4B-00C04F79EFBC}") = "DynamicMvvm.Benchmarks", "src\DynamicMvvm.Benchmarks\DynamicMvvm.Benchmarks.csproj", "{8494F013-2C55-4B51-98E1-6006807C2D4C}"
+EndProject
 Global
 	GlobalSection(SolutionConfigurationPlatforms) = preSolution
 		Debug|Android = Debug|Android
@@ -289,6 +291,38 @@ Global
 		{1E13272A-4270-4F68-88B7-A54375866640}.Release|x64.Build.0 = Release|x64
 		{1E13272A-4270-4F68-88B7-A54375866640}.Release|x86.ActiveCfg = Release|x86
 		{1E13272A-4270-4F68-88B7-A54375866640}.Release|x86.Build.0 = Release|x86
+		{8494F013-2C55-4B51-98E1-6006807C2D4C}.Debug|Android.ActiveCfg = Debug|Any CPU
+		{8494F013-2C55-4B51-98E1-6006807C2D4C}.Debug|Android.Build.0 = Debug|Any CPU
+		{8494F013-2C55-4B51-98E1-6006807C2D4C}.Debug|Any CPU.ActiveCfg = Debug|Any CPU
+		{8494F013-2C55-4B51-98E1-6006807C2D4C}.Debug|Any CPU.Build.0 = Debug|Any CPU
+		{8494F013-2C55-4B51-98E1-6006807C2D4C}.Debug|iOS.ActiveCfg = Debug|Any CPU
+		{8494F013-2C55-4B51-98E1-6006807C2D4C}.Debug|iOS.Build.0 = Debug|Any CPU
+		{8494F013-2C55-4B51-98E1-6006807C2D4C}.Debug|NuGet.ActiveCfg = Debug|Any CPU
+		{8494F013-2C55-4B51-98E1-6006807C2D4C}.Debug|NuGet.Build.0 = Debug|Any CPU
+		{8494F013-2C55-4B51-98E1-6006807C2D4C}.Debug|Simulator.ActiveCfg = Debug|Any CPU
+		{8494F013-2C55-4B51-98E1-6006807C2D4C}.Debug|Simulator.Build.0 = Debug|Any CPU
+		{8494F013-2C55-4B51-98E1-6006807C2D4C}.Debug|UAP.ActiveCfg = Debug|Any CPU
+		{8494F013-2C55-4B51-98E1-6006807C2D4C}.Debug|UAP.Build.0 = Debug|Any CPU
+		{8494F013-2C55-4B51-98E1-6006807C2D4C}.Debug|x64.ActiveCfg = Debug|Any CPU
+		{8494F013-2C55-4B51-98E1-6006807C2D4C}.Debug|x64.Build.0 = Debug|Any CPU
+		{8494F013-2C55-4B51-98E1-6006807C2D4C}.Debug|x86.ActiveCfg = Debug|Any CPU
+		{8494F013-2C55-4B51-98E1-6006807C2D4C}.Debug|x86.Build.0 = Debug|Any CPU
+		{8494F013-2C55-4B51-98E1-6006807C2D4C}.Release|Android.ActiveCfg = Release|Any CPU
+		{8494F013-2C55-4B51-98E1-6006807C2D4C}.Release|Android.Build.0 = Release|Any CPU
+		{8494F013-2C55-4B51-98E1-6006807C2D4C}.Release|Any CPU.ActiveCfg = Release|Any CPU
+		{8494F013-2C55-4B51-98E1-6006807C2D4C}.Release|Any CPU.Build.0 = Release|Any CPU
+		{8494F013-2C55-4B51-98E1-6006807C2D4C}.Release|iOS.ActiveCfg = Release|Any CPU
+		{8494F013-2C55-4B51-98E1-6006807C2D4C}.Release|iOS.Build.0 = Release|Any CPU
+		{8494F013-2C55-4B51-98E1-6006807C2D4C}.Release|NuGet.ActiveCfg = Release|Any CPU
+		{8494F013-2C55-4B51-98E1-6006807C2D4C}.Release|NuGet.Build.0 = Release|Any CPU
+		{8494F013-2C55-4B51-98E1-6006807C2D4C}.Release|Simulator.ActiveCfg = Release|Any CPU
+		{8494F013-2C55-4B51-98E1-6006807C2D4C}.Release|Simulator.Build.0 = Release|Any CPU
+		{8494F013-2C55-4B51-98E1-6006807C2D4C}.Release|UAP.ActiveCfg = Release|Any CPU
+		{8494F013-2C55-4B51-98E1-6006807C2D4C}.Release|UAP.Build.0 = Release|Any CPU
+		{8494F013-2C55-4B51-98E1-6006807C2D4C}.Release|x64.ActiveCfg = Release|Any CPU
+		{8494F013-2C55-4B51-98E1-6006807C2D4C}.Release|x64.Build.0 = Release|Any CPU
+		{8494F013-2C55-4B51-98E1-6006807C2D4C}.Release|x86.ActiveCfg = Release|Any CPU
+		{8494F013-2C55-4B51-98E1-6006807C2D4C}.Release|x86.Build.0 = Release|Any CPU
 	EndGlobalSection
 	GlobalSection(SolutionProperties) = preSolution
 		HideSolutionNode = FALSE

src/DynamicMvvm.Abstractions/DynamicMvvm.Abstractions.csproj

@@ -2,6 +2,7 @@
 
 	<PropertyGroup>
 		<TargetFrameworks>netstandard2.0</TargetFrameworks>
+		<LangVersion>10</LangVersion>
 		<RootNamespace>Chinook.DynamicMvvm</RootNamespace>
 		<Authors>nventive</Authors>
 		<Company>nventive</Company>
@@ -30,7 +31,7 @@
 
 	<ItemGroup>
 		<PackageReference Include="Microsoft.Extensions.DependencyInjection.Abstractions" Version="3.1.0" />
-		<PackageReference Include="Microsoft.Extensions.Logging.Abstractions" Version="3.1.0" />
+		<PackageReference Include="Microsoft.Extensions.Logging.Abstractions" Version="6.0.0" />
 	</ItemGroup>
 
 	<ItemGroup>

src/DynamicMvvm.Abstractions/LoggerMessages.Abstractions.cs

@@ -0,0 +1,13 @@
+using System;
+using System.Collections.Generic;
+using System.Text;
+using Microsoft.Extensions.Logging;
+
+namespace Chinook.DynamicMvvm
+{
+	internal static partial class LoggerMessagesAbstractions
+	{
+		[LoggerMessage(101, LogLevel.Warning, "Resolving property '{ViewModelTypeName}.{PropertyName}' using reflection on '{ViewModelName}'.")]
+		public static partial void LogViewModelResolvingPropertyUsingReflection(this ILogger logger, string viewModelTypeName, string propertyName, string viewModelName);
+	}
+}

src/DynamicMvvm.Abstractions/ViewModel/IViewModel.Extensions.Properties.cs

@@ -248,7 +248,7 @@ public static IDynamicProperty GetOrResolveProperty(this IViewModel viewModel, s
 
 			if (!viewModel.TryGetDisposable<IDynamicProperty>(name, out var property))
 			{
-				typeof(IViewModel).Log().LogWarning($"Resolving property '{viewModel.GetType().Name}.{name}' using reflection on '{viewModel.Name}'.");
+				typeof(IViewModel).Log().LogViewModelResolvingPropertyUsingReflection(viewModel.GetType().Name, name, viewModel.Name);
 
 				// This is a rare case where the property was resolved before being created.
 				// We simply resolve it manually on the type.

src/DynamicMvvm.Benchmarks/Benchmark.cs

@@ -0,0 +1,111 @@
+using System;
+using System.Collections.Generic;
+using System.Linq;
+using System.Text;
+using System.Threading.Tasks;
+using BenchmarkDotNet.Attributes;
+using Chinook.DynamicMvvm;
+using Microsoft.Extensions.DependencyInjection;
+using Microsoft.Extensions.Hosting;
+
+namespace DynamicMvvm.Benchmarks;
+
+[MemoryDiagnoser]
+public class Benchmark
+{
+	private readonly IServiceProvider _serviceProvider = new HostBuilder()
+		.ConfigureServices(serviceCollection => serviceCollection
+			.AddSingleton<IDynamicCommandBuilderFactory, DynamicCommandBuilderFactory>()
+			.AddSingleton<IDynamicPropertyFactory, DynamicPropertyFactory>()
+		)
+		.Build()
+		.Services;
+
+	private ViewModel? _viewModel1;
+	private ViewModel? _viewModel2;
+
+	[Benchmark]
+	public void CreateViewModel()
+	{
+		var vm = new ViewModel(_serviceProvider);
+	}
+
+	[Benchmark]
+	public void CreateViewModel_WithExplicitName()
+	{
+		var vm = new ViewModel("ViewModel", _serviceProvider);
+	}
+
+	[IterationSetup(Targets = new[]
+	{
+		nameof(ReadProperty_Unresolved),
+		nameof(ReadProperty_Resolved),
+		nameof(SetProperty_Unresolved),
+		nameof(SetProperty_Resolved),
+		nameof(DisposeViewModel),
+	})]
+	public void SetupViewModel()
+	{
+		_viewModel1 = new ViewModel("ViewModel", _serviceProvider);
+	}
+
+	[IterationSetup(Targets = new[]
+	{
+		nameof(SetProperty_Unresolved_WithListener),
+		nameof(SetProperty_Resolved_WithListener),
+		nameof(DisposeViewModel_WithListener),
+	})]
+	public void SetupViewModelWithListener()
+	{
+		_viewModel2 = new ViewModel("ViewModel", _serviceProvider);
+		_viewModel2.PropertyChanged += (s, e) => { };
+	}
+
+	[Benchmark]
+	public void ReadProperty_Unresolved()
+	{
+		var value = _viewModel1!.Number;
+	}
+
+	[Benchmark]
+	public void ReadProperty_Resolved()
+	{
+		var value = _viewModel1!.NumberResolved;
+	}
+
+	[Benchmark]
+	public void SetProperty_Unresolved()
+	{
+		_viewModel1!.Number = 1;
+	}
+
+	[Benchmark]
+	public void SetProperty_Resolved()
+	{
+		_viewModel1!.NumberResolved = 1;
+	}
+
+	[Benchmark]
+	public void DisposeViewModel()
+	{
+		_viewModel1!.Dispose();
+	}
+
+	[Benchmark]
+	public void SetProperty_Unresolved_WithListener()
+	{
+		_viewModel2!.Number = 1;
+	}
+
+	[Benchmark]
+	public void SetProperty_Resolved_WithListener()
+	{
+		_viewModel2!.NumberResolved = 1;
+	}
+
+	[Benchmark]
+	public void DisposeViewModel_WithListener()
+	{
+		_viewModel2!.Dispose();
+	}
+}

src/DynamicMvvm.Benchmarks/DynamicMvvm.Benchmarks.csproj

@@ -0,0 +1,23 @@
+<Project Sdk="Microsoft.NET.Sdk">
+
+  <PropertyGroup>
+    <OutputType>Exe</OutputType>
+    <TargetFramework>net6.0</TargetFramework>
+    <ImplicitUsings>enable</ImplicitUsings>
+    <Nullable>enable</Nullable>
+		<IsPackable>false</IsPackable>
+  </PropertyGroup>
+
+  <ItemGroup>
+    <PackageReference Include="BenchmarkDotNet" Version="0.13.11" />
+    <PackageReference Include="Microsoft.Extensions.Hosting" Version="6.0.0" />
+  </ItemGroup>
+
+  <ItemGroup>
+    <ProjectReference Include="..\DynamicMvvm.CollectionTracking\DynamicMvvm.CollectionTracking.csproj" />
+    <ProjectReference Include="..\DynamicMvvm.FluentValidation\DynamicMvvm.FluentValidation.csproj" />
+    <ProjectReference Include="..\DynamicMvvm.Reactive\DynamicMvvm.Reactive.csproj" />
+    <ProjectReference Include="..\DynamicMvvm\DynamicMvvm.csproj" />
+  </ItemGroup>
+
+</Project>

src/DynamicMvvm.Benchmarks/Program.cs

@@ -0,0 +1,22 @@
+using BenchmarkDotNet.Running;
+using DynamicMvvm.Benchmarks;
+using Chinook.DynamicMvvm;
+using Microsoft.Extensions.DependencyInjection;
+using Microsoft.Extensions.Hosting;
+
+BenchmarkRunner.Run<Benchmark>();
+
+// The following section is to profile manually using Visual Studio's debugger.
+
+//var serviceProvider = new HostBuilder()
+//	.ConfigureServices(serviceCollection => serviceCollection
+//		.AddSingleton<IDynamicCommandBuilderFactory, DynamicCommandBuilderFactory>()
+//		.AddSingleton<IDynamicPropertyFactory, DynamicPropertyFactory>()
+//	)
+//	.Build()
+//	.Services;
+
+//var vm1 = new ViewModel("ViewModel", serviceProvider);
+//var vm2 = new ViewModel("ViewModel", serviceProvider);
+
+//Console.Read();

src/DynamicMvvm.Benchmarks/ViewModel.cs

@@ -0,0 +1,34 @@
+using System;
+using System.Collections.Generic;
+using System.Linq;
+using System.Text;
+using System.Threading.Tasks;
+using Chinook.DynamicMvvm;
+
+namespace DynamicMvvm.Benchmarks;
+
+public class ViewModel : ViewModelBase
+{
+	public ViewModel(string? name, IServiceProvider serviceProvider)
+		: base(name, serviceProvider)
+	{
+		var value = NumberResolved;
+	}
+
+	public ViewModel(IServiceProvider serviceProvider)
+		: this(name: default, serviceProvider: serviceProvider)
+	{
+	}
+
+	public int Number
+	{
+		get => this.Get(initialValue: 42);
+		set => this.Set(value);
+	}
+
+	public int NumberResolved
+	{
+		get => this.Get(initialValue: 42);
+		set => this.Set(value);
+	}
+}

src/DynamicMvvm.FluentValidation/DynamicMvvm.FluentValidation.csproj

@@ -2,6 +2,7 @@
 
 	<PropertyGroup>
 		<TargetFrameworks>netstandard2.0</TargetFrameworks>
+		<LangVersion>10</LangVersion>
 		<RootNamespace>Chinook.DynamicMvvm</RootNamespace>
 		<Authors>nventive</Authors>
 		<Company>nventive</Company>

src/DynamicMvvm.FluentValidation/IViewModel.Extensions.Validation.cs

@@ -168,7 +168,7 @@ private void OnValueChanged(IDynamicProperty property)
 					}
 					catch (Exception e)
 					{
-						this.Log().LogError(e, $"Validation failed for property '{property.Name}'.");
+						this.Log().LogValidationFailed(property.Name, e);
 					}
 				});
 			}

src/DynamicMvvm.FluentValidation/LoggerMessages.FluentValidation.cs

@@ -0,0 +1,13 @@
+using System;
+using System.Collections.Generic;
+using System.Text;
+using Microsoft.Extensions.Logging;
+
+namespace Chinook.DynamicMvvm
+{
+	internal static partial class LoggerMessages
+	{
+		[LoggerMessage(201, LogLevel.Error, "Validation failed for property '{PropertyName}'.")]
+		public static partial void LogValidationFailed(this ILogger logger, string propertyName, Exception exception);
+	}
+}

src/DynamicMvvm.Reactive/Deactivation/DeactivatableObservable.cs

@@ -61,7 +61,7 @@ public void Deactivate()
 
 			IsDeactivated = true;
 
-			typeof(IDeactivatable).Log().LogDebug($"Deactivated observable of type '{typeof(T).Name}'.");
+			typeof(IDeactivatable).Log().LogDeactivatedObservable(typeof(T).Name);
 		}
 
 		/// <inheritdoc/>
@@ -79,7 +79,7 @@ public void Reactivate()
 				_subscription = _source.Subscribe(_observer);
 			}
 
-			typeof(IDeactivatable).Log().LogDebug($"Reactivated observable of type '{typeof(T).Name}'.");
+			typeof(IDeactivatable).Log().LogReactivatedObservable(typeof(T).Name);
 		}
 
 		/// <inheritdoc/>

src/DynamicMvvm.Reactive/DynamicMvvm.Reactive.csproj

@@ -2,6 +2,7 @@
 
 	<PropertyGroup>
 		<TargetFrameworks>netstandard2.0</TargetFrameworks>
+		<LangVersion>10</LangVersion>
 		<RootNamespace>Chinook.DynamicMvvm</RootNamespace>
 		<Authors>nventive</Authors>
 		<Company>nventive</Company>
@@ -29,8 +30,6 @@
 	</ItemGroup>
 
 	<ItemGroup>
-		<PackageReference Include="Microsoft.Extensions.DependencyInjection.Abstractions" Version="3.1.0" />
-		<PackageReference Include="Microsoft.Extensions.Logging.Abstractions" Version="3.1.0" />
 		<PackageReference Include="System.Diagnostics.DiagnosticSource" Version="4.7.0" />
 		<PackageReference Include="System.Reactive" Version="4.4.1" />
 	</ItemGroup>

src/DynamicMvvm.Reactive/LoggerMessages.Reactive.cs

@@ -0,0 +1,17 @@
+using System;
+using System.Collections.Generic;
+using System.Text;
+using Microsoft.Extensions.Logging;
+
+namespace Chinook.DynamicMvvm
+{
+	internal static partial class LoggerMessagesReactive
+	{
+		[LoggerMessage(301, LogLevel.Debug, "Deactivated observable of type '{TypeName}'.")]
+		public static partial void LogDeactivatedObservable(this ILogger logger, string typeName);
+
+		[LoggerMessage(302, LogLevel.Debug, "Reactivated observable of type '{TypeName}'.")]
+		public static partial void LogReactivatedObservable(this ILogger logger, string typeName);
+
+	}
+}