Skip to content

Commit

Permalink
feat: Use LoggerMessage to improve performance and reduce memory allo…
Browse files Browse the repository at this point in the history
…cations.
  • Loading branch information
jeanplevesque committed Dec 14, 2023
1 parent 24e3883 commit 8ef4a8e
Show file tree
Hide file tree
Showing 31 changed files with 227 additions and 50 deletions.
3 changes: 3 additions & 0 deletions BREAKING_CHANGES.md
Original file line number Diff line number Diff line change
@@ -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.

Expand Down
3 changes: 2 additions & 1 deletion src/DynamicMvvm.Abstractions/DynamicMvvm.Abstractions.csproj
Original file line number Diff line number Diff line change
Expand Up @@ -2,6 +2,7 @@

<PropertyGroup>
<TargetFrameworks>netstandard2.0</TargetFrameworks>
<LangVersion>10</LangVersion>
<RootNamespace>Chinook.DynamicMvvm</RootNamespace>
<Authors>nventive</Authors>
<Company>nventive</Company>
Expand Down Expand Up @@ -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>
Expand Down
13 changes: 13 additions & 0 deletions src/DynamicMvvm.Abstractions/LoggerMessages.Abstractions.cs
Original file line number Diff line number Diff line change
@@ -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);
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -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.
Expand Down
12 changes: 9 additions & 3 deletions src/DynamicMvvm.Benchmarks/Benchmark.cs
Original file line number Diff line number Diff line change
Expand Up @@ -30,6 +30,12 @@ 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),
Expand All @@ -40,7 +46,7 @@ public void CreateViewModel()
})]
public void SetupViewModel()
{
_viewModel1 = new ViewModel(_serviceProvider);
_viewModel1 = new ViewModel("ViewModel", _serviceProvider);
}

[IterationSetup(Targets = new[]
Expand All @@ -51,7 +57,7 @@ public void SetupViewModel()
})]
public void SetupViewModelWithListener()
{
_viewModel2 = new ViewModel(_serviceProvider);
_viewModel2 = new ViewModel("ViewModel", _serviceProvider);
_viewModel2.PropertyChanged += (s, e) => { };
}

Expand Down Expand Up @@ -101,5 +107,5 @@ public void SetProperty_Resolved_WithListener()
public void DisposeViewModel_WithListener()
{
_viewModel2!.Dispose();
}
}
}
18 changes: 18 additions & 0 deletions src/DynamicMvvm.Benchmarks/Program.cs
Original file line number Diff line number Diff line change
@@ -1,4 +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();
9 changes: 7 additions & 2 deletions src/DynamicMvvm.Benchmarks/ViewModel.cs
Original file line number Diff line number Diff line change
Expand Up @@ -9,12 +9,17 @@ namespace DynamicMvvm.Benchmarks;

public class ViewModel : ViewModelBase
{
public ViewModel(IServiceProvider serviceProvider)
: base(serviceProvider: serviceProvider)
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);
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -2,6 +2,7 @@

<PropertyGroup>
<TargetFrameworks>netstandard2.0</TargetFrameworks>
<LangVersion>10</LangVersion>
<RootNamespace>Chinook.DynamicMvvm</RootNamespace>
<Authors>nventive</Authors>
<Company>nventive</Company>
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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);
}
});
}
Expand Down
Original file line number Diff line number Diff line change
@@ -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);
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -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/>
Expand All @@ -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/>
Expand Down
3 changes: 1 addition & 2 deletions src/DynamicMvvm.Reactive/DynamicMvvm.Reactive.csproj
Original file line number Diff line number Diff line change
Expand Up @@ -2,6 +2,7 @@

<PropertyGroup>
<TargetFrameworks>netstandard2.0</TargetFrameworks>
<LangVersion>10</LangVersion>
<RootNamespace>Chinook.DynamicMvvm</RootNamespace>
<Authors>nventive</Authors>
<Company>nventive</Company>
Expand Down Expand Up @@ -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>
Expand Down
17 changes: 17 additions & 0 deletions src/DynamicMvvm.Reactive/LoggerMessages.Reactive.cs
Original file line number Diff line number Diff line change
@@ -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);

}
}
Original file line number Diff line number Diff line change
Expand Up @@ -56,13 +56,13 @@ public async Task ExecuteOnDispatcher(CancellationToken ct, Action action)
{
if (ct.IsCancellationRequested)
{
this.Log().LogDebug($"Cancelled 'ExecuteOnDispatcher' because of the cancellation token.");
this.Log().LogCancelledExecuteOnDispatcherBecauseOfCancellationToken();
return;
}

if (GetHasDispatcherAccess())
{
this.Log().LogDebug($"Executed action immediately because already on dispatcher.");
this.Log().LogExecutedActionImmediatelyBecauseAlreadyOnDispatcher();
action();
return;
}
Expand Down Expand Up @@ -94,20 +94,21 @@ await _dispatcherQueue.RunAsync(DispatcherQueuePriority.High, () =>
{
if (request.CT.IsCancellationRequested)
{
this.Log().LogDebug($"Cancelled 'ExecuteOnDispatcher' because of the cancellation token.");
this.Log().LogCancelledExecuteOnDispatcherBecauseOfCancellationToken();
continue;
}
request.Action();
}
catch (Exception e)
{
this.Log().LogError(e, "Failed 'ExecuteOnDispatcher'.");
this.Log().LogFailedExecuteOnDispatcher(e);
}
}
});

this.Log().LogDebug($"Batched {requests.Length} dispatcher requests.");
this.Log().LogBatchedDispatcherRequests(requests.Length);
}

private class Request
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -51,7 +51,7 @@ public async Task ExecuteOnDispatcher(CancellationToken ct, Action action)
{
if (ct.IsCancellationRequested)
{
this.Log().LogDebug($"Cancelled 'ExecuteOnDispatcher' because of the cancellation token.");
this.Log().LogCancelledExecuteOnDispatcherBecauseOfCancellationToken();
return;
}

Expand All @@ -61,15 +61,15 @@ public async Task ExecuteOnDispatcher(CancellationToken ct, Action action)
{
if (ct.IsCancellationRequested)
{
this.Log().LogDebug($"Cancelled 'ExecuteOnDispatcher' because of the cancellation token.");
this.Log().LogCancelledExecuteOnDispatcherBecauseOfCancellationToken();
return;
}
action();
}
catch (Exception e)
{
this.Log().LogError(e, "Failed 'ExecuteOnDispatcher'.");
this.Log().LogFailedExecuteOnDispatcher(e);
}
});
}
Expand Down
2 changes: 1 addition & 1 deletion src/DynamicMvvm.Uno.WinUI/DynamicMvvm.Uno.WinUI.csproj
Original file line number Diff line number Diff line change
@@ -1,6 +1,6 @@
<Project Sdk="MSBuild.Sdk.Extras/3.0.44">
<PropertyGroup>
<TargetFrameworks>net6.0-windows10.0.18362;netstandard2.0;net6.0-android;net6.0-ios;net6.0-macos;net6.0-maccatalyst;</TargetFrameworks>
<TargetFrameworks>net6.0-windows10.0.18362;netstandard2.0;net6.0-android;net6.0-ios;net6.0-maccatalyst;</TargetFrameworks>
<LangVersion>10.0</LangVersion>
<!-- Ensures the .xr.xml files are generated in a proper layout folder -->
<GenerateLibraryLayout>true</GenerateLibraryLayout>
Expand Down
24 changes: 24 additions & 0 deletions src/DynamicMvvm.Uno.WinUI/LoggerMessages.Uno.WinUI.cs
Original file line number Diff line number Diff line change
@@ -0,0 +1,24 @@
using System;
using System.Collections.Generic;
using System.Linq;
using System.Text;
using System.Threading.Tasks;
using Microsoft.Extensions.Logging;

namespace Chinook.DynamicMvvm
{
internal static partial class LoggerMessagesUnoWinUI
{
[LoggerMessage(401, LogLevel.Debug, "Cancelled 'ExecuteOnDispatcher' because of the cancellation token.")]
public static partial void LogCancelledExecuteOnDispatcherBecauseOfCancellationToken(this ILogger logger);

[LoggerMessage(402, LogLevel.Debug, "Executed action immediately because already on dispatcher.")]
public static partial void LogExecutedActionImmediatelyBecauseAlreadyOnDispatcher(this ILogger logger);

[LoggerMessage(403, LogLevel.Debug, "Batched {RequestCount} dispatcher requests.")]
public static partial void LogBatchedDispatcherRequests(this ILogger logger, int requestCount);

[LoggerMessage(404, LogLevel.Error, "Failed 'ExecuteOnDispatcher'.")]
public static partial void LogFailedExecuteOnDispatcher(this ILogger logger, Exception exception);
}
}
4 changes: 2 additions & 2 deletions src/DynamicMvvm/Command/DynamicCommand.cs
Original file line number Diff line number Diff line change
Expand Up @@ -75,7 +75,7 @@ public async Task Execute(object parameter)
if (_isDisposed)
{
// Note that we don't throw an ObjectDisposedException here because we're likely on a UI thread.
this.Log().LogError("Failed to execute command '{Name}' because it's disposed.", Name);
this.Log().LogCommandFailedBecauseDisposed(Name);
return;
}

Expand All @@ -99,7 +99,7 @@ public async Task Execute(object parameter)
{
// This will run on a UI thread, so we want to make sure
// this task doesn't throw otherwise it could lead to a crash.
this.Log().LogError(e, $"Command execution of '{Name}' failed. Consider using {nameof(ErrorHandlerCommandStrategy)}.");
this.Log().LogCommandFailedConsiderUsingErrorHandlerCommandStrategy(Name, e);
}
}

Expand Down
6 changes: 3 additions & 3 deletions src/DynamicMvvm/Command/Strategies/LoggerCommandStrategy.cs
Original file line number Diff line number Diff line change
Expand Up @@ -40,15 +40,15 @@ public override async Task Execute(CancellationToken ct, object parameter, IDyna
{
try
{
_logger.LogDebug($"Executing command '{command.Name}'.");
_logger.LogCommandExecuting(command.Name);

await base.Execute(ct, parameter, command);

_logger.LogInformation($"Executed command '{command.Name}'.");
_logger.LogCommandExecuted(command.Name);
}
catch (Exception e)
{
_logger.LogError(e, $"Failed to execute command '{command.Name}'.");
_logger.LogCommandFailed(command.Name, e);

throw;
}
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -72,7 +72,7 @@ public void Deactivate()

IsDeactivated = true;

typeof(IDeactivatable).Log().LogDebug($"Deactivated observable source of property '{Name}'.");
typeof(IDeactivatable).Log().LogDeactivatedObservableSource(Name);
}

/// <inheritdoc/>
Expand All @@ -87,7 +87,7 @@ public void Reactivate()

_subscription = _source.Subscribe(_propertyObserver);

typeof(IDeactivatable).Log().LogDebug($"Reactivated observable source of property '{Name}'.");
typeof(IDeactivatable).Log().LogReactivatedObservableSource(Name);
}
}
}
4 changes: 2 additions & 2 deletions src/DynamicMvvm/Deactivation/DeactivatableViewModelBase.cs
Original file line number Diff line number Diff line change
Expand Up @@ -84,7 +84,7 @@ public virtual void Deactivate()
child.Deactivate();
}

typeof(IDeactivatable).Log().LogDebug($"Deactivated ViewModel '{Name}'.");
typeof(IDeactivatable).Log().LogDeactivatedViewModel(Name);
}

/// <summary>
Expand Down Expand Up @@ -116,7 +116,7 @@ public virtual void Reactivate()
child.Reactivate();
}

typeof(IDeactivatable).Log().LogDebug($"Reactivated ViewModel '{Name}' and raised {toRaise.Length} property changes.");
typeof(IDeactivatable).Log().LogReactivatedViewModel(Name, toRaise.Length);
}
}
}
Loading

0 comments on commit 8ef4a8e

Please sign in to comment.