Currently, we have option to store data in Application Insight instead of using Plugin Trace Logs. The most crucial benefit of using this way for me is to get performance information and extract that information using Kusto Query Language. Still, we need to have an excellent strategy to get the max of it with minimum effort. For those who don’t know how to enable the setting for your Dataverse Environment and set up the Azure Application Insight, you can go to this blog post which is still relevant 😎.
I see in many projects, we are still relying on the sample structure project like below:
namespace DemoPlugin
{
public class Plugin1Demo : PluginBase
{
public Plugin1Demo() : base(nameof(Plugin1Demo))
{
}
protected override void ExecuteCdsPlugin(ILocalPluginContext localPluginContext)
{
Logic1(localPluginContext);
Logic2(localPluginContext);
// Maybe you write the implementation in here?
var target = localPluginContext.PluginExecutionContext.InputParameters["Target"];
// do operation in here 🙂
}
// Sample structure plugin project
public void Logic1(ILocalPluginContext localPluginContext)
{
}
// Sample structure plugin project
public void Logic2(ILocalPluginContext localPluginContext)
{
}
}
}
If your structure plugin is like the above and when you want to implement the telemetry performance, you will end up like this:
using System;
namespace DemoPlugin
{
public class Plugin1Demo : PluginBase
{
public Plugin1Demo() : base(nameof(Plugin1Demo))
{
}
protected override void ExecuteCdsPlugin(ILocalPluginContext localPluginContext)
{
Logic1(localPluginContext);
Logic2(localPluginContext);
// Maybe you write the implementation in here?
var start = DateTime.UtcNow;
var target = localPluginContext.PluginExecutionContext.InputParameters["Target"];
// do operation in here 🙂
var end = DateTime.UtcNow;
localPluginContext.TelemetryLogger.LogInformation($"Logic1.Execute(). Start: {start}. End: {end}. " +
$"Total seconds: {(end - start).TotalSeconds}.");
}
// Sample structure plugin project
public void Logic1(ILocalPluginContext localPluginContext)
{
var start = DateTime.UtcNow;
// Business logic run here
var end = DateTime.UtcNow;
localPluginContext.TelemetryLogger.LogInformation($"Logic1.Execute(). Start: {start}. End: {end}. " +
$"Total seconds: {(end-start).TotalSeconds}.");
}
// Sample structure plugin project
public void Logic2(ILocalPluginContext localPluginContext)
{
var start = DateTime.UtcNow;
// Business logic run here
var end = DateTime.UtcNow;
localPluginContext.TelemetryLogger.LogInformation($"Logic1.Execute(). Start: {start}. End: {end}. " +
$"Total seconds: {(end - start).TotalSeconds}.");
}
}
}
As you can see, in the end, we need to add those codes in each of the methods which is okay if you are willing to do that. But let me suggest another way to do it:
Below is the sample code to implement this (PluginBase, LocalPluginContext and several classes are generated from the command “pac plugin init“):
using Microsoft.Xrm.Sdk;
using Microsoft.Xrm.Sdk.PluginTelemetry;
using System;
using System.ServiceModel;
namespace DemoPlugin
{
public abstract class BusinessBase
{
public ILocalPluginContext LocalPluginContext { get; }
protected BusinessBase(ILocalPluginContext localPluginContext)
{
LocalPluginContext = localPluginContext;
}
public void Execute()
{
var start = DateTime.UtcNow;
try
{
HandleExecute();
}
finally
{
var end = DateTime.UtcNow;
LocalPluginContext.TelemetryLogger.LogInformation($"Exiting {this.GetType().Name}.Execute(). Start {start}. End {end}. " +
$"Total Seconds: {(end - start).TotalSeconds}.");
}
}
public abstract void HandleExecute();
}
public abstract class PluginBase : IPlugin
{
protected string PluginClassName { get; }
internal PluginBase(string pluginClassName)
{
PluginClassName = pluginClassName;
}
[System.Diagnostics.CodeAnalysis.SuppressMessage("Microsoft.Globalization", "CA1303:Do not pass literals as localized parameters", Justification = "Execute")]
public void Execute(IServiceProvider serviceProvider)
{
if (serviceProvider == null)
{
throw new InvalidPluginExecutionException("serviceProvider");
}
var localPluginContext = new LocalPluginContext(serviceProvider);
localPluginContext.Trace($"Entered {PluginClassName}.Execute() " +
$"Correlation Id: {localPluginContext.PluginExecutionContext.CorrelationId}, " +
$"Initiating User: {localPluginContext.PluginExecutionContext.InitiatingUserId}");
using (localPluginContext.TelemetryLogger.BeginScope(PluginClassName))
{
var start = DateTime.UtcNow;
try
{
ExecuteCdsPlugin(localPluginContext);
return;
}
catch (FaultException<OrganizationServiceFault> orgServiceFault)
{
localPluginContext.Trace($"Exception: {orgServiceFault.ToString()}");
throw new InvalidPluginExecutionException($"OrganizationServiceFault: {orgServiceFault.Message}", orgServiceFault);
}
finally
{
localPluginContext.Trace($"Exiting {PluginClassName}.Execute()");
}
}
}
protected virtual void ExecuteCdsPlugin(ILocalPluginContext localPluginContext)
{
// Do nothing.
}
}
public interface ILocalPluginContext
{
IOrganizationService CurrentUserService { get; }
IOrganizationService SystemUserService { get; }
IPluginExecutionContext PluginExecutionContext { get; }
IServiceEndpointNotificationService NotificationService { get; }
ITracingService TracingService { get; }
ILogger TelemetryLogger { get; }
void Trace(string message);
}
public class LocalPluginContext : ILocalPluginContext
{
internal IServiceProvider ServiceProvider { get; }
public IOrganizationService CurrentUserService { get; }
public IOrganizationService SystemUserService { get; }
public IPluginExecutionContext PluginExecutionContext { get; }
public IServiceEndpointNotificationService NotificationService { get; }
public ITracingService TracingService { get; }
public ILogger TelemetryLogger { get; }
public LocalPluginContext(IServiceProvider serviceProvider)
{
if (serviceProvider == null)
{
throw new InvalidPluginExecutionException("serviceProvider");
}
PluginExecutionContext = (IPluginExecutionContext)serviceProvider.GetService(typeof(IPluginExecutionContext));
TracingService = new LocalTracingService(serviceProvider);
NotificationService = (IServiceEndpointNotificationService)serviceProvider.GetService(typeof(IServiceEndpointNotificationService));
IOrganizationServiceFactory factory = (IOrganizationServiceFactory)serviceProvider.GetService(typeof(IOrganizationServiceFactory));
TelemetryLogger = (ILogger)serviceProvider.GetService(typeof(ILogger));
CurrentUserService = factory.CreateOrganizationService(PluginExecutionContext.UserId);
SystemUserService = factory.CreateOrganizationService(null);
}
public void Trace(string message)
{
if (string.IsNullOrWhiteSpace(message) || TracingService == null)
{
return;
}
if (PluginExecutionContext == null)
{
TracingService.Trace(message);
}
else
{
TracingService.Trace(
"{0}, Correlation Id: {1}, Initiating User: {2}",
message,
PluginExecutionContext.CorrelationId,
PluginExecutionContext.InitiatingUserId);
}
}
}
public class LocalTracingService : ITracingService
{
private readonly ITracingService _tracingService;
private DateTime _previousTraceTime;
public LocalTracingService(IServiceProvider serviceProvider)
{
DateTime utcNow = DateTime.UtcNow;
var context = (IExecutionContext)serviceProvider.GetService(typeof(IExecutionContext));
DateTime initialTimestamp = context.OperationCreatedOn;
if (initialTimestamp > utcNow)
{
initialTimestamp = utcNow;
}
_tracingService = (ITracingService)serviceProvider.GetService(typeof(ITracingService));
_previousTraceTime = initialTimestamp;
}
public void Trace(string message, params object[] args)
{
var utcNow = DateTime.UtcNow;
// The duration since the last trace.
var deltaMilliseconds = utcNow.Subtract(_previousTraceTime).TotalMilliseconds;
_tracingService.Trace($"[+{deltaMilliseconds:N0}ms)] - {message}");
_previousTraceTime = utcNow;
}
}
}
In the code above, you can see that BusinessBase is the key to all of this. We only need to implement telemetry codes in this class (on method Execute) and all the classes inherited from this class will automatically have the same behavior!
Below is the implementation when we create the plugin + business classes:
using System;
using System.Threading;
namespace DemoPlugin
{
public class BusinessLogic1 : BusinessBase
{
public BusinessLogic1(ILocalPluginContext localPluginContext) : base(localPluginContext)
{
}
public override void HandleExecute()
{
// Heavy operation
Thread.Sleep(TimeSpan.FromSeconds(10));
}
}
public class BusinessLogic2 : BusinessBase
{
public BusinessLogic2(ILocalPluginContext localPluginContext) : base(localPluginContext)
{
}
public override void HandleExecute()
{
// Another operation
Thread.Sleep(TimeSpan.FromSeconds(5));
}
}
public class BusinessLogic3 : BusinessBase
{
public BusinessLogic3(ILocalPluginContext localPluginContext) : base(localPluginContext)
{
}
public override void HandleExecute()
{
// Light operation
Thread.Sleep(TimeSpan.FromSeconds(3));
}
}
public class Plugin1Demo : PluginBase
{
public Plugin1Demo() : base(nameof(Plugin1Demo))
{
}
protected override void ExecuteCdsPlugin(ILocalPluginContext localPluginContext)
{
// Make the generated trace can be find in 1 single operationId
using (localPluginContext.TelemetryLogger.BeginScope(nameof(Plugin1Demo)))
{
new BusinessLogic1(localPluginContext).Execute();
new BusinessLogic2(localPluginContext).Execute();
new BusinessLogic3(localPluginContext).Execute();
}
}
}
}
In the above code, you can see that the generated LocalPluginContext already has property for ILogger (TelemetryLogger) which will be used to save our telemetry data to the Application Insight. The TelemetryLogger.BeginScope method will help us to associate all the log in the reach will be in the same operation id.
Below is the result from the Application Insight > Logs:
Happy CRM-ing!
Temmy Wahyu Raharjo 
One thought on “Dataverse: Simple advice on how to design your plug-in”