Dynamics CRM Plugin Development: Create TracingServiceExtensions for Logging Time Information

Have you got an error request time out in the plugin? If the plugin only contains simple business logic, It will not be hard to catch the problem. But what if you got lots of business logic that updating more than one entity? Today we will create simple extension functions that you can implement to analyze and take action on it. We will use ITracingService object to put the logger because it’s already sufficient for us to use this logger. You can learn how to enable the trace log in this blog post.

System Setting> Customization > Enable logging to plug-in trace log set to All

The objective of the extension is to make the implementation easier without violating the DRY (Don’t Repeat Yourself) principle. Here is the sample if we want to do it manually which required lots of effort to implement:

var start = DateTime.Now;
// Run Business Logic 1
var end = DateTime.Now;
traceService.Trace($"Information: Business Logic 1. Begin: {start}. End: {end}. Total Seconds: {(end - start).TotalSeconds}.");

start = DateTime.Now;
// Run Business Logic 2
end = DateTime.Now;
traceService.Trace($"Information: Business Logic 2. Begin: {start}. End: {end}. Total Seconds: {(end - start).TotalSeconds}.");

For example, here is the void code (an Action) that we will log later on:

Entity followup = new Entity("task")
{
 ["subject"] = "Send e-mail to the new customer.",
 ["description"] =
 "Follow up with the customer. Check if there are any new issues that need resolution.",
 ["scheduledstart"] = DateTime.Now.AddDays(7),
 ["scheduledend"] = DateTime.Now.AddDays(7),
 ["category"] = localPluginContext.PluginExecutionContext.PrimaryEntityName
};

// Refer to the account in the task activity.
if (localPluginContext.PluginExecutionContext.OutputParameters.Contains("id"))
{
 Guid regardingobjectid = new Guid(localPluginContext.PluginExecutionContext.OutputParameters["id"].ToString());
 string regardingobjectidType = "account";

 followup["regardingobjectid"] =
	 new EntityReference(regardingobjectidType, regardingobjectid);
}

// Create the task in Microsoft Dynamics CRM.
localPluginContext.Trace("FollowupPlugin: Creating the task activity.");
localPluginContext.CurrentUserService.Create(followup);

Here is the function that returns a value (Funct<T>) that we will log later on:

private Entity[] GetContacts(IOrganizationService service)
{
	var query = new QueryExpression()
	{
		Distinct = false,
		EntityName = "contact",
		ColumnSet = new ColumnSet("fullname", "address1_telephone1"),
		LinkEntities =
		{
			new LinkEntity
			{
				JoinOperator = JoinOperator.LeftOuter,
				LinkFromAttributeName = "parentcustomerid",
				LinkFromEntityName = "contact",
				LinkToAttributeName = "accountid",
				LinkToEntityName = "account",
				LinkCriteria =
				{
					Conditions =
					{
						new ConditionExpression("name", ConditionOperator.Equal, "Litware, Inc.")
					}
				}
			}
		},
		Criteria =
		{
			Filters =
			{
				new FilterExpression
				{
					FilterOperator = LogicalOperator.And,
					Conditions =
					{
						new ConditionExpression("address1_stateorprovince", ConditionOperator.Equal, "WA"),
						new ConditionExpression("address1_city", ConditionOperator.In, "Redmond", "Bellevue", "Kirkland", "Seattle"),
						new ConditionExpression("createdon", ConditionOperator.LastXDays, 30),
						new ConditionExpression("emailaddress1", ConditionOperator.NotNull)
					},
				},
				new FilterExpression
				{
					FilterOperator = LogicalOperator.Or,
					Conditions =
					{
						new ConditionExpression("address1_telephone1", ConditionOperator.Like, "(206)%"),
						new ConditionExpression("address1_telephone1", ConditionOperator.Like, "(425)%")
					}
				}
			}
		}
	};

	return service.RetrieveMultiple(query).Entities.ToArray();
}

We can create a simple function to create these loggers:

public static class TracingServiceExtensions
{
	public static T LogTime<T>(this ITracingService traceService, string information, Func<T> func)
	{
		T result;

		var start = DateTime.Now;
		try
		{
			result = func.Invoke();
		}
		catch (Exception ex)
		{
			traceService.Trace("Error: " + ex);
			throw;
		}
		finally
		{
			var end = DateTime.Now;

			traceService.Trace($"Information: {information}. Begin: {start}. End: {end}. Total Seconds: {(end - start).TotalSeconds}.");
		}

		return result;
	}

	public static void LogTime(this ITracingService traceService, string information, Action action)
	{
		traceService.LogTime(information, () =>
		{
			action.Invoke();
			return 1;
		});
	}
}

From the above code, you can see that the last parameter of each function is Action/Func<T>. The idea of the function is we will start counting the time – invoke the function – record the closing time – and then put it in the logger. With these extensions, we don’t need to change how the structure of the code heavily.

Here is the implementation of the code after we put the logger:

var result = localPluginContext.TracingService.LogTime("Demo extensions - function",
	() => GetContacts(localPluginContext.CurrentUserService));

localPluginContext.Trace("Receive Contacts: " + result.Length);

localPluginContext.TracingService.LogTime("Demo extensions - void - " + result, () =>
 {
	 Entity followup = new Entity("task")
	 {
		 ["subject"] = "Send e-mail to the new customer.",
		 ["description"] =
		 "Follow up with the customer. Check if there are any new issues that need resolution.",
		 ["scheduledstart"] = DateTime.Now.AddDays(7),
		 ["scheduledend"] = DateTime.Now.AddDays(7),
		 ["category"] = localPluginContext.PluginExecutionContext.PrimaryEntityName
	 };

	 // Refer to the account in the task activity.
	 if (localPluginContext.PluginExecutionContext.OutputParameters.Contains("id"))
	 {
		 Guid regardingobjectid = new Guid(localPluginContext.PluginExecutionContext.OutputParameters["id"].ToString());
		 string regardingobjectidType = "account";

		 followup["regardingobjectid"] =
			 new EntityReference(regardingobjectidType, regardingobjectid);
	 }

	 // Create the task in Microsoft Dynamics CRM.
	 localPluginContext.Trace("FollowupPlugin: Creating the task activity.");
	 localPluginContext.CurrentUserService.Create(followup);
 });

We just need to wrap the existing code to our extension and viola, we got the information of how long the code inside the function run. Below is the sample of the result in the logger:

The logging result

Summary

  • For the code above, I use the structure (of the plugin) from the Power Apps CLI generator. The implementation of LocalPluginContext that they provided will give you a good idea of how to make your plugin structure better and easier to build customization on top of it.
  • The logger extensions in the above code are very easy and clean to implement in your code
  • I suggest you create the extensions class by yourself, you will get addicted because it will improve your code readability + cleanliness!

One thought on “Dynamics CRM Plugin Development: Create TracingServiceExtensions for Logging Time Information

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out /  Change )

Twitter picture

You are commenting using your Twitter account. Log Out /  Change )

Facebook photo

You are commenting using your Facebook account. Log Out /  Change )

Connecting to %s

This site uses Akismet to reduce spam. Learn how your comment data is processed.