So one of my customers ran into this issue while opening an Opportunity. As you can see, a custom plugin was throwing an exception because it could not find a Account with a specified ID.
That part is 100% correct. The Account with that ID indeed does not exist in the database.
The problem is, this plugin should never have been fired. As I mentioned, this was happening on a Retrieve operation and there are no plugins registered against the Retrieve Message.
So I waited until tonight so I could turn on Tracing (on-premise, of course), and this is what I found:
[2014-10-16 20:12:57.600] Process: w3wp |Organization:d98bbf24-8eed-4cb4-a379-6aa848499cb0 |
Thread: 25 |Category: Exception |User: fb9a439c-b578-4a4b-83e0-39ea0059ad2a |
Level: Error |ReqId: eb0bc9e4-e6e6-4552-b322-1c2fa0bdbc10 |
CrmException..ctor ilOffset = 0x7
at CrmException..ctor(String message, Exception innerException, Int32 errorCode,
Boolean isFlowControlException) ilOffset = 0x7
at CrmException..ctor(String message, Exception innerException, Int32 errorCode) ilOffset = 0x5
at RuntimeMethodHandle.InvokeMethod(Object target, Object[] arguments, Signature sig,
Boolean constructor) ilOffset = 0xFFFFFFFF
at RuntimeConstructorInfo.Invoke(BindingFlags invokeAttr, Binder binder,
Object[] parameters, CultureInfo culture) ilOffset = 0xF7
at RuntimeType.CreateInstanceImpl(BindingFlags bindingAttr, Binder binder, Object[] args,
CultureInfo culture, Object[] activationAttributes, StackCrawlMark& stackMark) ilOffset = 0x1E8
at Activator.CreateInstance(Type type, BindingFlags bindingAttr, Binder binder, Object[] args,
CultureInfo culture, Object[] activationAttributes) ilOffset = 0xBB
at Activator.CreateInstance(Type type, Object[] args) ilOffset = 0xA
at VersionedPluginProxyStepBase.WrapExceptionToThrow(CrmException exception) ilOffset = 0xD3
at VersionedPluginProxyStepBase.Execute(PipelineExecutionContext context) ilOffset = 0x65
at Pipeline.Execute(PipelineExecutionContext context) ilOffset = 0x65
at MessageProcessor.Execute(PipelineExecutionContext context) ilOffset = 0x1C5
at InternalMessageDispatcher.Execute(PipelineExecutionContext context) ilOffset = 0xE4
at ExternalMessageDispatcher.ExecuteInternal(IInProcessOrganizationServiceFactory serviceFactory,
IPlatformMessageDispatcherFactory dispatcherFactory, String messageName, String requestName,
Int32 primaryObjectTypeCode, Int32 secondaryObjectTypeCode, ParameterCollection fields,
CorrelationToken correlationToken, CallerOriginToken originToken, UserAuth userAuth, Guid callerId,
Guid transactionContextId, Int32 invocationSource, Nullable`1 requestId, Version endpointVersion) ilOffset = 0x156
at OrganizationSdkServiceInternal.ExecuteRequest(OrganizationRequest request, CorrelationToken correlationToken,
CallerOriginToken callerOriginToken, WebServiceType serviceType, UserAuth userAuth, Guid targetUserId,
Boolean traceRequest, OrganizationContext context, Boolean returnResponse) ilOffset = 0x145
at OrganizationSdkServiceInternal.ExecuteRequest(OrganizationRequest request, CorrelationToken correlationToken,
CallerOriginToken callerOriginToken, WebServiceType serviceType) ilOffset = 0x3D
at OrganizationSdkServiceInternal.Retrieve(String entityName, Guid id, ColumnSet columnSet,
CorrelationToken correlationToken, CallerOriginToken callerOriginToken, WebServiceType serviceType) ilOffset = 0x66
at InprocessServiceProxy.RetrieveCore(String entityName, Guid id, ColumnSet columnSet) ilOffset = 0x28
at OrganizationServiceProxy.Retrieve(String entityName, Guid id, ColumnSet columnSet) ilOffset = 0x4
at Utility.UpdateAccountKeyword(IOrganizationService service, Guid accountId) ilOffset = 0xE8
C:\Plugins\SupportingClasses\Utility.cs(205)
at InvoiceCancelOpportunityCloseKeywords.Execute(IServiceProvider serviceProvider) ilOffset = 0x164
C:\Plugins\InvoiceCancelOpportunityCloseKeywords.cs(70)
at V5PluginProxyStep.ExecuteInternal(PipelineExecutionContext context) ilOffset = 0xD0
at VersionedPluginProxyStepBase.Execute(PipelineExecutionContext context) ilOffset = 0x65
at Pipeline.Execute(PipelineExecutionContext context) ilOffset = 0x65
at MessageProcessor.Execute(PipelineExecutionContext context) ilOffset = 0x1FB
at InternalMessageDispatcher.Execute(PipelineExecutionContext context) ilOffset = 0xE4
at ExtensiblePlatformMessageDispatcher.Execute(PipelineExecutionContext pluginContext) ilOffset = 0x0
at ExtensiblePlatformMessageDispatcher.UpdateWithInvocationSource(BusinessEntity entity, FilterExpression filter,
Int32 invocationSource, ExecutionContext context) ilOffset = 0xCE
at ExtensiblePlatformMessageDispatcher.Update(BusinessEntity entity, FilterExpression filter, ExecutionContext context)
ilOffset = 0x5
at BusinessProcessObject.UpdateWithPipelineAndExtensions(IBusinessEntity entity, ExecutionContext context) ilOffset = 0x78
at QOIPriceService.UpdateEntity(BusinessEntity newQoi, BusinessEntity oldQoi, ExecutionContext context) ilOffset = 0x87
at PriceService.CalculatePrice(BusinessEntity entity, Guid lineItemId, Boolean skipQOIDetailPricing,
Boolean overridePricePerUnitLock, Boolean overrideDiscountLock, ExecutionContext context) ilOffset = 0x6E1
at OpportunityPriceService.CalculatePrice(BusinessEntity entity, Guid lineItemId, Boolean skipQOIDetailPricing,
Boolean overridePricePerUnitLock, Boolean overrideDiscountLock, ExecutionContext context) ilOffset = 0x70
at QOIPriceService.CalculatePrice(Guid qoiId, Guid lineItemId, Boolean skipLineItemPricing, Boolean overridePricePerUnitLock,
Boolean overrideDiscountLock, Boolean isModifiedBySystem, ExecutionContext context) ilOffset = 0x2E
at OpportunityService.CalculatePrice(Guid opportunityId, Guid opportunityProductId, Boolean skipOpportunityProductPricing,
Boolean overridePricePerUnitLock, Boolean overrideDiscountLock, Boolean isModifiedBySystem, ExecutionContext context)
ilOffset = 0x12
at QOIService.Retrieve(BusinessEntityMoniker moniker, EntityExpression entityExpression, ExecutionContext context,
Boolean isModifiedBySystem, Boolean calculatePrice, Int32 state) ilOffset = 0x2D
at OpportunityService.Retrieve(BusinessEntityMoniker moniker, EntityExpression entityExpression,
ExecutionContext context) ilOffset = 0x14
at RuntimeMethodHandle.InvokeMethod(Object target, Object[] arguments, Signature sig,
Boolean constructor) ilOffset = 0xFFFFFFFF
at RuntimeMethodInfo.UnsafeInvokeInternal(Object obj, Object[] parameters, Object[] arguments)
ilOffset = 0x25
at RuntimeMethodInfo.Invoke(Object obj, BindingFlags invokeAttr, Binder binder,
Object[] parameters, CultureInfo culture) ilOffset = 0x89
at LogicalMethodInfo.Invoke(Object target, Object[] values) ilOffset = 0x4F
at InternalOperationPlugin.Execute(IServiceProvider serviceProvider) ilOffset = 0x57
at V5PluginProxyStep.ExecuteInternal(PipelineExecutionContext context) ilOffset = 0x58
at VersionedPluginProxyStepBase.Execute(PipelineExecutionContext context) ilOffset = 0x65
at Pipeline.Execute(PipelineExecutionContext context) ilOffset = 0x65
at MessageProcessor.Execute(PipelineExecutionContext context) ilOffset = 0x1C5
at InternalMessageDispatcher.Execute(PipelineExecutionContext context) ilOffset = 0xE4
at ExternalMessageDispatcher.ExecuteInternal(IInProcessOrganizationServiceFactory serviceFactory,
IPlatformMessageDispatcherFactory dispatcherFactory, String messageName, String requestName,
Int32 primaryObjectTypeCode, Int32 secondaryObjectTypeCode, ParameterCollection fields,
CorrelationToken correlationToken, CallerOriginToken originToken, UserAuth userAuth, Guid callerId,
Guid transactionContextId, Int32 invocationSource, Nullable`1 requestId, Version endpointVersion) ilOffset = 0x156
at OrganizationSdkServiceInternal.ExecuteRequest(OrganizationRequest request, CorrelationToken correlationToken,
CallerOriginToken callerOriginToken, WebServiceType serviceType, UserAuth userAuth, Guid targetUserId,
Boolean traceRequest, OrganizationContext context, Boolean returnResponse) ilOffset = 0x145
at OrganizationSdkServiceInternal.ExecuteRequest(OrganizationRequest request, CorrelationToken correlationToken,
CallerOriginToken callerOriginToken, WebServiceType serviceType) ilOffset = 0x3D
at OrganizationSdkServiceInternal.Execute(OrganizationRequest request, CorrelationToken correlationToken,
CallerOriginToken callerOriginToken, WebServiceType serviceType) ilOffset = 0x24
at InprocessServiceProxy.ExecuteCore(OrganizationRequest request) ilOffset = 0x34
at PlatformCommand.XrmExecuteInternal() ilOffset = 0xF6
at RetrieveCommand.Execute() ilOffset = 0x2
at EntityProxy.Retrieve(String[] columns, Guid auditingTransactionId, Boolean addRequiredColumns) ilOffset = 0x69
at EntityProxy.Retrieve(String[] columns, Guid auditingTransactionId) ilOffset = 0x4
at EntityProxy.Retrieve(String columnSet, Guid auditingTransactionId) ilOffset = 0xB
at EntityProxy.Retrieve(String columnSet) ilOffset = 0x7
at AppForm.FormLoadEvent() ilOffset = 0x11
at AppForm.RaiseDataEvent(FormEventId eventId) ilOffset = 0xC7
at EndUserForm.Initialize(Entity entity) ilOffset = 0x1F
at CustomizableForm.Execute(Entity entity, FormDescriptor fd) ilOffset = 0x62
at RecordPageHandler.ConfigureFormWrapper() ilOffset = 0xC
at GenericEventProcessor.RaiseEvent(String eventName) ilOffset = 0x2D
at PageManager.OnPreRender(EventArgs e) ilOffset = 0x47
at Control.PreRenderRecursiveInternal() ilOffset = 0x54
at Page.ProcessRequestMain(Boolean includeStagesBeforeAsyncPoint, Boolean includeStagesAfterAsyncPoint) ilOffset = 0x6D3
at Page.ProcessRequest(Boolean includeStagesBeforeAsyncPoint, Boolean includeStagesAfterAsyncPoint) ilOffset = 0x3C
at Page.ProcessRequest() ilOffset = 0x14
at Page.ProcessRequest(HttpContext context) ilOffset = 0x33
at CallHandlerExecutionStep.System.Web.HttpApplication.IExecutionStep.Execute() ilOffset = 0x18D
at HttpApplication.ExecuteStep(IExecutionStep step, Boolean& completedSynchronously) ilOffset = 0x15
at ApplicationStepManager.ResumeSteps(Exception error) ilOffset = 0x10A
at HttpApplication.System.Web.IHttpAsyncHandler.BeginProcessRequest(HttpContext context, AsyncCallback cb, Object extraData) ilOffset = 0x5C
at HttpRuntime.ProcessRequestInternal(HttpWorkerRequest wr) ilOffset = 0x16A
at ISAPIRuntime.ProcessRequest(IntPtr ecb, Int32 iWRType) ilOffset = 0x4B
That is 75 calls, if you didn’t feel like counting, and in the middle of all of that was the failing call to my plugin.
The nearest thing I can figure is that this Opportunity is set to be System Calculated and when it was opened, a update to the revenue numbers. This ended up firing my plugin which failed because data that was passed to it turned out to be invalid.
I temporarily disabled the plugin and was able to save the Opportunity and correct the invalid data issue.
I could not have done this troubleshooting without the following tools:
If you do not have these tools in your toolbox, you need to fix that today.
