Custom Code Tracing & Exception Logging in Dynamics 365 v.9

As a Solution Architect I often review Microsoft Dynamics 365 custom server and client side code.
One of the most common rejects regards tracing and exception handling mechanisms, or their absence. Some code constructs may have empty Try/Catch blocks or none at all, other catch exceptions and just re-throw. As for tracing, code often contains debugging ‘aids’ such as alerts and debugger statements or no tracing notifications at all.

Why is this a reject?

  • Unhandled raw exceptions float to UI, confusing and frustrating users while exposing internal implementation details to potential attackers
  • System Administrator is unaware of custom code exceptions unless users decide to report an error message or a bug
  • Tracing mechanism help diagnose faults and sometimes allow resolving without debugging or recompiling code

Microsoft Dynamics 365 contains a Plug-in Trace repository which contains trace and exception entries originating from Plug-in and Custom Workflow Activity components.
While this is a good built in solution, it has some drawbacks:

  • It does not support common types of custom code such as client side JavaScript and external components consuming Microsoft Dynamics API directly
  • There is no straight forward method to filter Plug-in Trace notification to search for specific text in trace/exception messages
  • No option to trigger a notification to system administrator once an exception is logged
  • No option to accurately correlate a user reported error message to a specific exception entry

In this post I would like to suggest an updated implementation of a more wholesome infrastructure for tracing and exceptions logging. Using this  infrastructure, any developer can easily log trace entries and exceptions from any custom code interacting with Microsoft Dynamics 365 application, while admins can easily monitor the application health in that aspect.

WIIFM

Why using this infrastructure?

  • Easily log trace entries and exceptions from any client and server side custom code interacting with Microsoft Dynamics 365 application in a unified manner
  • You can add processes triggered by exception Log record creation to alert system administrator regarding a fault as it occurs
  • Easily search and filter specific exceptions/trace records according to unique Reference Token provided by users/clients using Quick/Advanced Find

In the following How To Use section you can download a un/managed solution and follow setup and usage instructions.  You can view the GitHub project here.

How to use

  1. Download and import solution

    You can download a managed solution here.
    If you want to make any changes to this solution, download the un-managed version. In that case, open the solution, navigate to the Log entity and check ‘Settings’ to display the entity in the settings area. Finally, publish the solution.

    open the solution, navigate to the Log entity and check ‘Settings’ to display the entity in the settings area

  2. Using in an entity form JavaScript code

    Add the dyn_utils.js Web Resource to the target entity form libraries collection.
    Call the LogTrace and LogException functions in your custom code.

    Add the dyn_utils.js Web Resource to the target entity form Libraries collection

        //perform some business logic including tracing and exception handling 
        ns.DoSomeBusinessLogic = function () {
            //define verbose trace entry
            var traceEntry = {
                //title
                "title": "loggingSample.DoSomeBusinessLogic",
                //description
                "description": "Start execution",
                //related business record id 
                "relatedBusinessRecordId": "2514FC63-9E58-4D1E-8226-69256D0197E3",
                //related business record URL
                "relatedBusinessRecordURL": "https://xxx.crm.dynamics.com/main.aspx?etc=8&extraqs=&histKey=520872127&id=%7b2514FC63-9E58-4D1E-8226-69256D0197E3%7d&newWindow=true&pagetype=entityrecord#923042",
                //set current user id as related user id 
                "relatedUserId": getContext().userSettings.userId
            };
    
            //trace function execution start asynchronously
            Utils.LogTrace(traceEntry, true, SuccessHandler, FailureHandler);
    
            try {
                //some business logic including some exception 
                NonExistingFunctionCall();
            }
            catch (err) {
                //define verbose exception entry
                var exceptionEntry = {
                    //title
                    "title": "loggingSample.DoSomeBusinessLogic",
                    //description
                    "description": Constants.MSG_GENERAL_FAILURE,
                    //related business record id 
                    "errorMessage": err.message,
                    //related business record URL
                    "stackTrace": err.stack
                };
    
                //log exception and return reference token
                var referenceToken = Utils.LogException(exceptionEntry, false);
    
                //notify user with a reference token to report back to admin
                alert(Constants.MSG_GENERAL_FAILURE + referenceToken);
            }
            finally {
                //define thin trace entry 
                var traceEntry = {
                    //title
                    "title": "loggingSample.DoSomeBusinessLogic",
                    //description
                    "description": "Start execution",
                };
    
                //trace function exectuion end asynchronously
                Utils.LogTrace(traceEntry, true, SuccessHandler, FailureHandler);    
            }
        }
    
  3. Using in Web Resource JavaScript code

    You can view the code in action by launching the dyn_loggingSample.htm Web Resource (replace organization base address)
    https://YOUR_ORG_NAME.crm.dynamics.com//WebResources/dyn_loggingSample.htm

    You can view the code in action by launching the dyn_loggingSample.htm Web

    Make sure you include the dyn_utils.js as a referenced resource:

    
    
        
        Logging Sample
        
        
        
        
    
    

    The sample code in the dyn_loggingSample.js demonstrates tracing and exception handling, same as in the code sample above.

  4. Using in Plug-in/Custom Workflow Activity/external SDK client

    The following code sample represents usage in Plug-in and is similar to CWA and external SDK client usage:

        public class LogTraceAndException : IPlugin
        {
            public void Execute(IServiceProvider serviceProvider)
            {
                // Obtain the execution context from the service provider
                IPluginExecutionContext context = (IPluginExecutionContext)serviceProvider.GetService(typeof(IPluginExecutionContext));
                // Get a reference to the organization service
                IOrganizationServiceFactory factory = (IOrganizationServiceFactory)serviceProvider.GetService(typeof(IOrganizationServiceFactory));
                IOrganizationService organizationService = factory.CreateOrganizationService(context.UserId);
    
                //define a trace entry, all attributes are optional except title 
                Log traceEntry1 = new Log
                {
                    title = "ServerSideLogging: Execute",
                    description = "Execution end",
                    //replace user id with an valid one
                    relatedUser = new EntityReference("systemuser", 
                        Guid.Parse("37ACCC73-0FCE-474B-A206-19C08163438B")),
                    relatedBusinessRecordURL = "https://YOURORGNAME.crm.dynamics.com/main.aspx?etc=1&extraqs=&histKey=87055256&id=%7b381FA757-60D7-E811-A97E-000D3AB20035%7d",
                };
    
                //log trace entry, get reference token back 
                string refToken1 = GenericLogging.Log(traceEntry1, 
                    GenericLogging.LogType.Trace, organizationService);
    
                try
                {
                    //some exception raising code.
                    //If transaction is rolled back, Log entries will persist
                    throw new Exception("An error occurred, please notify the System Administrator");
                }
                catch (Exception ex)
                {
                    //define an exception entry 
                    Log excptionEntry = new Log
                    {
                        title = "ServerSideLogging: Execute",
                        errorMessage = ex.Message,
                        stackTrace = ex.StackTrace
                    };
    
                    //log exception entry, get reference token back
                    string refToken2 = GenericLogging.Log(excptionEntry,
                        GenericLogging.LogType.Exception,
                        organizationService);
    
                    throw new InvalidPluginExecutionException(
                        string.Format("An error occurred, please notify the System Administrator. Reference token: {0}", 
                        refToken2));
                }
            }
        }
    

    A resulting exception raised from the Plug-in code includes the reference token. Once reported to an Admin, he can easily find the relevant Log entry using Quick Find

    A resulting exception includes the reference token

    Once reported to an Admin, he can easily find the relevant Log entry using Quick Find

    View Log details

Implementation Notes

I have written about the subject in the past and the described approach has not changed much. The implementation has been updated to leverage version 9 features (currently available on for Online implementations)

What has changed since last version:

  • Using Action definition to activate, deactivate and control logging level
  • Using built-in auto-numbering attribute to generate reference token, so a designated CWA component is no longer required
  • Optional usage of client side asynchronous logging operation to keep UX uninterrupted

In order to support logging from transactional components (such as Plugin registered to pre/post operation stages), the Log method in GenericLogging.cs file is using the ExecuteMultipleRequest class to execute the dyn_Log request.
As the ExecuteMultipleRequest instance is external to the Plugin transaction, it manages to create a Log record without the Plugin transaction rolling it back.
Using the Execute method directly with the dyn_LogRequest request instead, would have executed the Log Action, but the created Exception record would have been deleted by the Plugin transaction rollback, leaving no trace.

Custom Trace & Exception Logging diagram

 

Advertisement

Get (Online) Ready

If your Microsoft Dynamics CRM organization is deployed on-premise and Online is not even a remote option, stop reading now, this post not for you. Or is it?

Most of my clients are enterprise level organizations with Microsoft Dynamics CRM deployed on-premise. But even in these organizations, Online is no longer a theoretic concept. Sooner or later, Online is coming…oh wait. it’s here.

Following are some tips which implemented today may render your migration to Online a bit easier in the future, but will probably make your life easier even while on-premise.

1. Keep it supported
There is an infinite number of unsupported customization methods and even more available for an on-premise deployment: direct database access, using database triggers, editing ASPX and CSS files, adding HTTP modules…the list goes on.
If you currently implement any of the methods mentioned above, start planning to replace it with a supported customization method, since these are not viable in Online deployment.

2. Get Sandboxed
Although on-premise you can register Plug-in and Custom Workflow Activities DLLs in full trust, I suggest registering these components to Sandbox mode.
In Online deployment, Plug-in and Custom Workflow Activities DLLs can only execute in sandbox, but even on-premise you can benefit from the sandbox isolation in security and performance aspects.
If you have code that exceeds sandbox limitations (file system/database access etc.), consider moving it to a different component such as an external Web Service.

3. Solution contained
Whenever possible, prefer a solution aware component rather than an external component. HTML (JavaScript, Images etc.) Web Resource over an external ASPX page, Action over a WCF/ASMX service. This will simplify your deployment process considerably even when moving a version between your on-premise test and production environments

4. Go Client
Whenever possible, prefer client side business logic over server side. Implementing business logic using JavaScript rather than Plug-in/Synchronous Workflow will yield better UX and reduce maintenance efforts in any deployment type:

  • There is a plethora of free utility JS libraries that can simplify and expedite your business logic implementation
  • JavaScript code does not require re-compilation
  • Debugging JavaScript code does not require in external tool (the browser developer tools will suffice)

Note that in Online deployment you can’t debug Plug-in/CWA components with the Attach To Process technique as server processes are not exposed.

5. Use modern APIs
Upgrade existing code to use the latest Microsoft Dynamics CRM APIs and end points. These APIs will last longer along with your business logic code and probably have performance and maintenance benefits.
When Online, old APIs and end points have higher probability to be decommissioned whether you like it or not.

6. Exposable Integration points
Integrating Microsoft Dynamics CRM with external on-premise applications is common in enterprise level applications.
Assuming some of these external applications will remain on-premise, make sure the integration points can be exposed directly or indirectly to Microsoft Dynamics CRM Online and vice versa in a secured and simple manner. Integrating an external application via a Web Service is preferred over consuming database stored procedures.

Plug-in Configuration Manager Utility

Plug-in components often require external configuration settings. Maybe the Plug-in code consumes a web service which end point alternates between test and production environments or maybe you use the Plug-in configuration to turn logging on and off. Basically, any code setting which depend upon external resources is worth exporting to external configuration as it may prevent code re-compilation, additional testing etc.

There are some common approaches to implement configuration settings for Plug-in components:

  1. Configuration file: each Plug-in instance consumes a configuration file
  2. Configuration record: each Plug-in instance executes a query to retrieve a designated Microsoft Dynamics CRM configuration record
  3. Step configuration: each Plug-in instance constructor receives configuration settings from the Step secure/unsecure configuration

Performance wise, option 3 is preferred as the Step’s secure/unsecure configuration is cached alongside the Plug-in step and no additional operation is required to retrieve it. Changing the Step’s secure/unsecure configuration will automatically un-cache and reload relevant Plug-in with updated configuration. If you are not familiar with this option implementation, read this.
Options 1 and 2 require an expensive IO operation or query as each Plug-in instance explicitly consumes additional resources to retrieve configuration settings. When one of these approaches are applied in large scale (or with poor server resources), it will take a considerable toll on server performance and sometimes, the UX.

While option 3 yields better performance, it is not maintenance friendly. In enterprise scale applications, you may have to go through hundreds of Plug-in steps to update secure/unsecure configuration settings. Now think about doing this while deploying a version to the Production environment a 3 AM.

In this post, I offer a utility which allows you to enjoy Step configuration performance benefit along with simple maintenance for configuration bound Plug-in components.

WIIFM?

An unmanaged solution can be downloaded here. Use this tool as is or change the code to better suit you needs.
Although this tool was designed and built for Microsoft Dynamics CRM 2016 (Online/On-premise), the approach behind it can be implemented with previous versions, probably down to 2011.

As displayed below, the Plug-in Configuration Utility allows you select a registered Plug-in assembly, view related Steps and finally view each Step configuration details.
Clicking the ‘Update Configuration’ while a single or multiple Steps are selected will updated the respective configuration settings.

By default, Custom Work Flow Activities and System owned Plug-in assemblies are hidden, but can be revealed by unchecking the matching checkbox. You can view some interesting configuration settings under the Microsoft.Crm.ObjectModel assembly Steps, which are hidden when using the Plugin Registration Tool.
Although possible, do not change any configuration settings for these Steps.

Plugin Configuration Manager Demo

Bits & Bytes

The entities used behind the scenes here are

  1. pluginAssembly – representing registered Plug-in DLL file
  2. pluginType – representing IPlugin event handler class contained in the Plug-in DLL file
  3. sdkMessageProcessingStep – representing Step details binding the plugintype event handler to specific entity and message. Contains the unsecure configuration string
  4. sdkMessageProcessingStepSecureConfig – representing a secure configuration record related to the sdkmessageprocessingstep. Contains the secure configuration string

Plugin Configruation Entity Model

Although the Plug-in Registration Tool displays the secure configuration string as part of the Step settings (represented by the sdkMessageProcessingStep entity), this attribute actually resides in the related sdkMessageProcessingStepSecureConfig entity. Moving the secure configuration string to a different entity allows setting different privileges, as the secure configuration string may contain sensitive data like password.

This also means the in order to programmatically set new secure configuration string for a Step, it is required to create and relate a new sdkMessageProcessingStepSecureConfig  record.

Plugin Step Secure Configruation Privileges