Wednesday, May 30, 2012

MS CRM 2011: Strange error during sending of an email from plugin

I had scenario when my plugin based on some condition had to send an email. I developed plugin, deployed it to server and during the testing I have got quite strange error:

Message was generic and hasn’t explained what happened. I’ve downloaded log file which had following text:
Unhandled Exception: System.ServiceModel.FaultException`1[[Microsoft.Xrm.Sdk.OrganizationServiceFault, Microsoft.Xrm.Sdk, Version=5.0.0.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35]]: An unexpected error occurred.Detail: 
<OrganizationServiceFault xmlns:i="http://www.w3.org/2001/XMLSchema-instance" xmlns="http://schemas.microsoft.com/xrm/2011/Contracts">
  <ErrorCode>-2147220970</ErrorCode>
  <ErrorDetails xmlns:d2p1="http://schemas.datacontract.org/2004/07/System.Collections.Generic" />
  <Message>An unexpected error occurred.</Message>
  <Timestamp>2012-05-30T17:25:49.588336Z</Timestamp>
  <InnerFault i:nil="true" />
  <TraceText>
[EmailError.Plugins: Plugins.AccountHandler]
[d2056d47-7baa-e111-b22c-080027cd4540: EmailError]
Entered Plugins.AccountHandler.Execute(), Correlation Id: 8bd03a21-9b65-413d-b332-639042020fbd, Initiating User: 8ffe1b8c-0f9d-e111-8f09-080027cd4540
Plugins.AccountHandler is firing for Entity: account, Message: Create, Correlation Id: 8bd03a21-9b65-413d-b332-639042020fbd, Initiating User: 8ffe1b8c-0f9d-e111-8f09-080027cd4540
Exception: System.ServiceModel.FaultException`1[Microsoft.Xrm.Sdk.OrganizationServiceFault]: An unexpected error occurred. (Fault Detail is equal to Microsoft.Xrm.Sdk.OrganizationServiceFault)., Correlation Id: 8bd03a21-9b65-413d-b332-639042020fbd, Initiating User: 8ffe1b8c-0f9d-e111-8f09-080027cd4540
Exiting Plugins.AccountHandler.Execute(), Correlation Id: 8bd03a21-9b65-413d-b332-639042020fbd, Initiating User: 8ffe1b8c-0f9d-e111-8f09-080027cd4540
</TraceText>
</OrganizationServiceFault>


This log also didn’t explaine anything and I went to Trace:
>Crm Exception: Message: Assembly should be provided, ErrorCode: -2147204719
[2012-05-30 10:25:49.525] Process: w3wp |Organization:28cfb3ab-140d-4738-92e1-ade71b23a0f5 |Thread:   12 |Category: Platform.Sdk |User: ac3eb898-855e-497a-9b1c-766916989630 |Level: Error | VersionedPluginProxyStepBase.Execute
>Web Service Plug-in failed in SdkMessageProcessingStepId: {05CDBB1B-EA3E-DB11-86A7-000A3A5473E8}; EntityName: email; Stage: 30; MessageName: Send; AssemblyName: Microsoft.Crm.Extensibility.InternalOperationPlugin, Microsoft.Crm.ObjectModel, Version=5.0.0.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35; ClassName: Microsoft.Crm.Extensibility.InternalOperationPlugin; Exception: Unhandled Exception: System.Reflection.TargetInvocationException: Exception has been thrown by the target of an invocation.
   at System.RuntimeMethodHandle._InvokeMethodFast(IRuntimeMethodInfo method, Object target, Object[] arguments, SignatureStruct& sig, MethodAttributes methodAttributes, RuntimeType typeOwner)
   at System.Reflection.RuntimeMethodInfo.Invoke(Object obj, BindingFlags invokeAttr, Binder binder, Object[] parameters, CultureInfo culture, Boolean skipVisibilityChecks)
   at System.Reflection.RuntimeMethodInfo.Invoke(Object obj, BindingFlags invokeAttr, Binder binder, Object[] parameters, CultureInfo culture)
   at System.Web.Services.Protocols.LogicalMethodInfo.Invoke(Object target, Object[] values)
   at Microsoft.Crm.Extensibility.InternalOperationPlugin.Execute(IServiceProvider serviceProvider)
   at Microsoft.Crm.Extensibility.V5PluginProxyStep.ExecuteInternal(PipelineExecutionContext context)
   at Microsoft.Crm.Extensibility.VersionedPluginProxyStepBase.Execute(PipelineExecutionContext context)
Inner Exception: System.InvalidCastException: Specified cast is not valid.
   at Microsoft.Crm.ObjectModel.TrackingManager.GetNextTrackingToken(String subject, String& trackingToken)
   at Microsoft.Crm.ObjectModel.EmailService.Send(Guid emailId, Boolean issueSend, String trackingToken, ExecutionContext context)
>Crm Exception: Message: An unexpected error occurred., ErrorCode: -2147220970, InnerException: System.InvalidCastException: Specified cast is not valid.
   at Microsoft.Crm.ObjectModel.TrackingManager.GetNextTrackingToken(String subject, String& trackingToken)
   at Microsoft.Crm.ObjectModel.EmailService.Send(Guid emailId, Boolean issueSend, String trackingToken, ExecutionContext context)
[2012-05-30 10:25:49.588] Process: w3wp |Organization:28cfb3ab-140d-4738-92e1-ade71b23a0f5 |Thread:   12 |Category: Platform |User: ac3eb898-855e-497a-9b1c-766916989630 |Level: Error | MessageProcessor.Execute
>MessageProcessor fail to process message 'Send' for 'email'.
[2012-05-30 10:25:49.588] Process: w3wp |Organization:00000000-0000-0000-0000-000000000000 |Thread:   12 |Category: Platform |User: 00000000-0000-0000-0000-000000000000 |Level: Error | ExceptionConverter.ConvertMessageAndErrorCode
>System.InvalidCastException: Microsoft Dynamics CRM has experienced an error. Reference number for administrators or support: #F0329851: System.InvalidCastException: Specified cast is not valid.
>   at Microsoft.Crm.ObjectModel.TrackingManager.GetNextTrackingToken(String subject, String& trackingToken)
>   at Microsoft.Crm.ObjectModel.EmailService.Send(Guid emailId, Boolean issueSend, String trackingToken, ExecutionContext context)


I understood that this specific exception was generated not with my code but with CRM core operation – Sending of am email. I remain that about a year ago I faced and solved similar issue with tasks.

My habit is to instantiate IOrganizationService in plugins using system account:

IOrganizationServiceFactory factory = 
    (IOrganizationServiceFactory)serviceProvider.GetService(typeof(IOrganizationServiceFactory));
IOrganizationService service = factory.CreateOrganizationService(null);


I have changed instantiation of service to running user and everything worked without any issues:

IOrganizationServiceFactory factory = 
    (IOrganizationServiceFactory)serviceProvider.GetService(typeof(IOrganizationServiceFactory));
IOrganizationService service = factory.CreateOrganizationService(executioncontext.UserId);


I hope that this topic will help other developers to solve their issue faster then I solved it.