Exceptions

From Resco's Wiki
Jump to navigation Jump to search
Resco Academy
Resco Academy has a course on a similar subject:
Resco Support


This article is designed for technical support providers responsible for helping users of Resco mobile apps who are in charge of analyzing log files and who want to understand better some of the exceptions included in the logs.

What is an exception?

An exception is a programming construct usually describing an error. Unlike simple errors which are represented by a string, exceptions bear more information:

  • The exception name often gives semantic information about the kind of problem encountered. E.g., WebException refers to a problem in web communication.
  • The message is the string describing the problem.
  • The StackTrace (also known as the call stack) is the information for the programmer showing a sequence of calls that lead to the problem.
  • InnerException (if any) refers to a chained (wrapped) exception.

Here are some of the common exceptions you may encounter:

  • Exception - general exception, no additional information available
  • SqliteException refers to a database problem (SQLite is the database engine used by Resco mobile apps)
  • MobileCrm.Data.Google.UnauthorizedException refers to an authorization problem, probably related to some Google service
  • WebException and WebRequestException refer to a web communication problem.
  • HttpException refers to an HTTP communication problem (Resco mobile apps use the HTTP protocol to communicate with various servers)
  • Java.IO.IOException: Low-level Android exception related to input/output operation. Usually wrapped into a more general exception.
  • SyncDownloadException reports sync downloader problem.

Some exceptions clearly indicate a programming bug, for example:

  • NullReferenceException - using a null pointer without proper check
  • InvalidOperationException - some operation was attempted without checking the context, argument, etc.
  • ArgumentOutOfRangeException - some parameter was submitted without checking the allowed range

There are many more exceptions thrown either by the operating system (actually .Net) or by Resco Mobile CRM itself. There is no point in learning them. All you need to realize is that the name may give you some hint.

Two important exceptions

These two Resco Mobile CRM exceptions deserve more attention: RescoSoapException and UserAbortException.

RescoSoapException

Resco uses this exception to denote server error response in a format understood by Resco mobile apps. (Actually, an HTTP error 500 containing SOAP error response, that's why the exception name.)

What is specific about this exception is that it contains selected details from the server error response.

These details are listed under <soap> tag, for example

<soap>"error" : "invalid_grant", "error_description" : "Token has been expired or revoked."</soap>

You should read them as

error = invalid_grant
error_description = "Token has been expired or revoked."

UserAbortException

UserAbortException is used by the sync module to denote abort events. Abort can be initiated either by the user or by the operating system (when terminating Resco Mobile CRM because the user switched to another app).

The latter case will generate also crash log entry such as

Application 11.2.3.0 ERROR 2018-11-03 09:31:44.061+01:00
System.Exception: OnAbortBackgroundTask

Exception chaining

Let's have a look at this exception log:

Exception: Can't connect --->
Net.WebRequestException: Unable to resolve host "besin.crm5.dynamics.com": No address associated with hostname | Duration: 4ms ---> 
Java.IO.IOException: Unable to resolve host "besin.crm5.dynamics.com": No address associated with hostname ---> 
Java.Lang.RuntimeException: android_getaddrinfo failed: EAI_NODATA (No address associated with hostname)

As far as the error itself is concerned, it must be a very basic connection problem, such as a missing or misconfigured internet connection.

However, this excerpt was selected for another reason - to illustrate the chaining of exceptions. In this case, it makes sense to read the chain from bottom to top.

  • On the lowest level, the operating system generated a RuntimeException with a rather technical message.
  • The middle OS layer intercepted this exception, wrapped it into IOException(RuntimeException) with a better message.
  • Resco communication module intercepted this exception and wrapped it into WebRequestException(IOException(RuntimeException)).
  • Finally, the top layer of the app (maybe SyncEngine) intercepted WebRequestException and produced the log together with the details coming from wrapped exceptions.

Error codes

Server error responses often contain error codes, such as:

Detail.OrganizationServiceFault.ErrorCode=-2147187962.

It would often help when we could translate them into a meaningful statement.

  • In the case of Dynamics CRM we could use e.g. this reference.
  • Search for Salesforce error codes at developer.salesforce.com
  • Resco Cloud error codes are listed here.

Then we could replace the above error code with this sentence:

"Not enough privilege to access the Microsoft Dynamics 365 object or perform the requested operation."

What else can be done?

Exception logs tend to be cluttered with tons of unneeded information. Resco Mobile CRM tries to simplify the exception description before writing it to the log file, yet the result may still remain unclear.

What you should do first is try to extract a piece of information that tells something relevant. Yes, it requires experience, knowledge, and intuition. But you should try it anyway.

In the next sections, we show examples of real-life exceptions together with tips on how to read them. If there is any universal advice we could give you it is this one: Simplify the exception log by stripping off unneeded details.

And do not forget - a lot of keywords used in the logs are explained somewhere on the web. So launch your favorite browser and search for that information.

Examples with detailed analysis

These first two examples demonstrate the techniques that can be used to analyze complex exception logs.

Library used incorrectly

Say we have this exception log (taken from the sync log):

<Exception>08:55:13.216: SqliteException: Library used incorrectly
library routine called out of sequence
Failed cmd: DELETE FROM AttachmentQueue WHERE ID=?
  at SQLite3.Prepare (SqliteConnection cnn, String strSql, UInt32 timeoutMS, String& strRemain) <0x101b069b0 + 0x001dc> in <badc6885562c498f940d11e69afe7419#9b6c8013b1e83bbd2d6574e7d4e39f6b>:0 
  at Resco.Data.SQLite.SQLiteDatabase.ExecuteSingleNonQuery (String query, Collections.Generic.IEnumerable`1[T] parameters) <0x101b035c0 + 0x0009b> in <badc6885562c498f940d11e69afe7419#9b6c8013b1e83bbd2d6574e7d4e39f6b>:0 
  at Resco.Data.SQLite.SQLiteDatabase.ExecuteSingleNonQuery (String query, Object[] parameters) <0x101b03940 + 0x0002f> in <badc6885562c498f940d11e69afe7419#9b6c8013b1e83bbd2d6574e7d4e39f6b>:0 
  at AttachmentManager.MarkAttachmentDownloaded (SyncEngine SE, Resco.Data.db, Attachment a) <0x100ecb470 + 0x0016f> in <751aa8fdcaf64e108abd379aac6ebdb6#9b6c8013b1e83bbd2d6574e7d4e39f6b>:0 
  at AttachmentManager+<>c__DisplayClass18_0.<SyncAttachments>b__1 (Attachment a) <0x100ecbe30 + 0x00027> in <751aa8fdcaf64e108abd379aac6ebdb6#9b6c8013b1e83bbd2d6574e7d4e39f6b>:0 
  at MultiAttachmentDownloader.Execute (Boolean asyncDownload, AttachmentDownloader downloader, Collections.Generic.List`1[T] attachments, Action`1[T] MarkDownloaded, Action CheckAbort) <0x100ecc1f0 + 0x004d3> in <751aa8fdcaf64e108abd379aac6ebdb6#9b6c8013b1e83bbd2d6574e7d4e39f6b>:0 
  at AttachmentManager.SyncAttachments (ICrmService service, SyncEngine SE, Resco.Data.db) <0x100ecacd0 + 0x0053b> in <751aa8fdcaf64e108abd379aac6ebdb6#9b6c8013b1e83bbd2d6574e7d4e39f6b>:0 
  at AttachmentManager.DownloadQueueSync (ICrmService service, SyncEngine SE, Resco.Data.db, MobileCrm.config, Int32 n_skipped, Action`1[T] Log) <0x100ec8640 + 0x00077> in <751aa8fdcaf64e108abd379aac6ebdb6#9b6c8013b1e83bbd2d6574e7d4e39f6b>:0 
  at SyncEngine.DoExecute (Resco.Data.db) <0x100e8f650 + 0x02157> in <751aa8fdcaf64e108abd379aac6ebdb6#9b6c8013b1e83bbd2d6574e7d4e39f6b>:0 
  at SyncEngine.Execute (Resco.Data.db, Boolean isHighEndDevice, SyncResult& result) <0x100e92ef0 + 0x01c07> in <751aa8fdcaf64e108abd379aac6ebdb6#9b6c8013b1e83bbd2d6574e7d4e39f6b>:0 
  at SyncEngine.Execute (Resco.Data.db, MobileCrm.config, SyncResult& result, Func`3[T1,T2,TResult] progress, SyncConflict conflictCallback, Boolean isHighEndDevice, Boolean isRequestedByUser, Boolean isRestartSync, SyncBook syncBook) <0x100e95cf0 + 0x0021f> in <751aa8fdcaf64e108abd379aac6ebdb6#9b6c8013b1e83bbd2d6574e7d4e39f6b>:0
</Exception>

The above log can be simplified to this (we removed a lot of clumsy details, which not even programmers need):

<Exception>08:55:13.216: SqliteException: Library used incorrectly
library routine called out of sequence
Failed cmd: DELETE FROM AttachmentQueue WHERE ID=?
  at SQLite3.Prepare ()
  at Resco.Data.SQLite.SQLiteDatabase.ExecuteSingleNonQuery ()
  at AttachmentManager.MarkAttachmentDownloaded ()
  at MultiAttachmentDownloader.Execute ()
  at AttachmentManager.SyncAttachments ()
  at SyncEngine.Execute ()
</Exception>

As the next step, we can try to extract some meaning, e.g.:

  • This is some kind of database problem (SQLite is the database engine used by Resco mobile apps) described as "Library used incorrectly" or "library routine called out of sequence".
  • The problem arose for this SQL command: "DELETE FROM AttachmentQueue WHERE ID=?"
  • This happened during synchronization, specifically during attachment download.

In this case, we could not explain the problem, but at least we were able to describe it.

Insufficient privileges

Here is another example (taken from the online log):

OnlineError 2020-09-14T23:37:36.6485490+05:30
Called from: DynamicEntityForm`1.SaveAsyncCompleted(MobileCrm.Controllers.Common.AccountForm)
Net.RescoSoapException: Server Error: {"CallerPrincipal":{"PrincipalId":"4f0d247e-019c-e811-a96c-000d3aa30ac8", "Type":8, "IsUserPrincipal":true}, "OwnerPrincipal":{"PrincipalId":"00000000-0000-0000-0000-000000000000", "Type":8, "IsUserPrincipal":true}, "ObjectId":"fdf21d78-019c-e811-a96c-000d3aa30ac8", "ObjectTypeCode":8, "EntityName":"systemuser", "ObjectBusinessUnitId":"64160e70-ca11-ea11-a811-000d3a085b2b", "RightsToCheck":"AppendToAccess", "RoleAccessRights":"None", "PoaAccessRights":"None", "HsmAccessRights":"None", "GrantedAccessRights":"None", "Messages":["PrincipalHasOwnerPrincipalWithAtLeastBasicPrivilegeDepth = False", "EntityUserGroupRights = None", "MinimumPrivilegeDepthRequired = Global", "SecLib::AccessCheckEx2 failed. Owner Data: User principal 00000000-0000-0000-0000-000000000000 is not loaded in UserDataCache yet; Principal Data: roleCount=2, privilegeCount=821, accessMode=0"], "EntityOwnershipTypeMask":4, "CallerInfo":{"IsSystemUser":false, "IsSupportUser":false, "IsAdministrator":false, "IsCustomizer":false, "IsDisabled":false, "IsIntegrationUser":false, "Teams":null, "Roles":null}, "ReadOnlyState":"UserAndOrgFullAccess", "IsHsmEnabled":false, "HsmInfo":null}
<soap>Code.Value=s:Sender| Detail.OrganizationServiceFault.ActivityId=605735e2-db46-4b69-89fa-fb1184e8fce2| Detail.OrganizationServiceFault.ErrorCode=-2147187962| Detail.OrganizationServiceFault.HelpLink=http://go.microsoft.com/fwlink/?LinkID=398563&error=Microsoft.Crm.CrmException%3a80048306&client=platform| Detail.OrganizationServiceFault.Timestamp=2020-09-14T18:07:36.4953731Z| Detail.OrganizationServiceFault.ExceptionRetriable=false</soap>
  at WebServiceBase.ThrowSoapException (Net.HttpException ex) [0x00043] in <50637abbe03e41ca9d84f19a186fc0d1>:0 
  at WebServiceBase+XmlResponse..ctor (Object context, Boolean soap, WebServiceBase webService, Xml.XmlReaderSettings xmlSettings, Boolean processMultipartResponses) [0x00068] in <50637abbe03e41ca9d84f19a186fc0d1>:0 
  at WebServiceBase.InternalEndInvoke (Object request, Func`2[T,TResult] readResponse) [0x00007] in <50637abbe03e41ca9d84f19a186fc0d1>:0 
  at WebServiceBase.Invoke (String action, Object args, Action`2[T1,T2] writeRequest, Action`1[T] writeHeader, Func`2[T,TResult] readResponse) [0x0000c] in <50637abbe03e41ca9d84f19a186fc0d1>:0 
  at WebServiceBase.Invoke (String action, Object args, Action`2[T1,T2] writeRequest, Func`2[T,TResult] readResponse) [0x0000a] in <50637abbe03e41ca9d84f19a186fc0d1>:0 
  at Crm2011.CrmService2011.InternalExecuteRequest (Crm2011.InternalRequest request) [0x0002d] in <50637abbe03e41ca9d84f19a186fc0d1>:0 
  at Crm2011.CrmService2011.ExecuteRequest (Object request) [0x00007] in <50637abbe03e41ca9d84f19a186fc0d1>:0 
  at MobileCrm.Data.Online.SaveRequest.SendEntityInternal (ICrmService service, MobileCrm.Data.DynamicEntity record) [0x0000c] in <50637abbe03e41ca9d84f19a186fc0d1>:0 
  at MobileCrm.Data.Online.SaveRequest.SendEntity (ICrmService service, MobileCrm.Data.DynamicEntity entity, Boolean recursive) [0x00045] in <50637abbe03e41ca9d84f19a186fc0d1>:0 
  at MobileCrm.Data.Online.SaveRequest.Execute (ICrmService service) [0x00013] in <50637abbe03e41ca9d84f19a186fc0d1>:0 
  at MobileCrm.Data.Online.OnlineRepository.RequestThread () [0x000eb] in <50637abbe03e41ca9d84f19a186fc0d1>:0

After the simplification:

OnlineError 2020-09-14T23:37:36.6485490+05:30
Called from: DynamicEntityForm.SaveAsyncCompleted(AccountForm)
RescoSoapException: Server Error: {"CallerPrincipal":{"PrincipalId":"4f0d247e-019c-e811-a96c-000d3aa30ac8", "Type":8, "IsUserPrincipal":true}, "OwnerPrincipal":{"PrincipalId":"00000000-0000-0000-0000-000000000000", "Type":8, "IsUserPrincipal":true}, "ObjectId":"fdf21d78-019c-e811-a96c-000d3aa30ac8", "ObjectTypeCode":8, "EntityName":"systemuser", "ObjectBusinessUnitId":"64160e70-ca11-ea11-a811-000d3a085b2b", "RightsToCheck":"AppendToAccess", "RoleAccessRights":"None", "PoaAccessRights":"None", "HsmAccessRights":"None", "GrantedAccessRights":"None", "Messages":["PrincipalHasOwnerPrincipalWithAtLeastBasicPrivilegeDepth = False", "EntityUserGroupRights = None", "MinimumPrivilegeDepthRequired = Global", "SecLib::AccessCheckEx2 failed. Owner Data: User principal 00000000-0000-0000-0000-000000000000 is not loaded in UserDataCache yet; Principal Data: roleCount=2, privilegeCount=821, accessMode=0"], "EntityOwnershipTypeMask":4, "CallerInfo":{"IsSystemUser":false, "IsSupportUser":false, "IsAdministrator":false, "IsCustomizer":false, "IsDisabled":false, "IsIntegrationUser":false, "Teams":null, "Roles":null}, "ReadOnlyState":"UserAndOrgFullAccess", "IsHsmEnabled":false, "HsmInfo":null}
<soap>Code.Value=s:Sender| Detail.OrganizationServiceFault.ActivityId=605735e2-db46-4b69-89fa-fb1184e8fce2| Detail.OrganizationServiceFault.ErrorCode=-2147187962| Detail.OrganizationServiceFault.HelpLink=http://go.microsoft.com/fwlink/?LinkID=398563&error=Microsoft.Crm.CrmException%3a80048306&client=platform| Detail.OrganizationServiceFault.Timestamp=2020-09-14T18:07:36.4953731Z| Detail.OrganizationServiceFault.ExceptionRetriable=false</soap>
  at WebServiceBase+XmlResponse..ctor ()
  at WebServiceBase.Invoke ()
  at Crm2011.CrmService2011.ExecuteRequest ()
  at MobileCrm.Data.Online.SaveRequest.SendEntity ()
  at MobileCrm.Data.Online.SaveRequest.Execute ()
  at MobileCrm.Data.Online.OnlineRepository.RequestThread ()

The first conclusion is that the problem happened when saving (because of "SaveRequest") an account (because of "AccountForm") to the (Dynamics) server. We also see that server responded with some error message. Let's try to extract some useful info out of it.

The main error message is here:

{"CallerPrincipal":{"PrincipalId":"4f0d247e-019c-e811-a96c-000d3aa30ac8", "Type":8, "IsUserPrincipal":true}, "OwnerPrincipal":{"PrincipalId":"00000000-0000-0000-0000-000000000000", "Type":8, "IsUserPrincipal":true}, "ObjectId":"fdf21d78-019c-e811-a96c-000d3aa30ac8", "ObjectTypeCode":8, "EntityName":"systemuser", "ObjectBusinessUnitId":"64160e70-ca11-ea11-a811-000d3a085b2b", "RightsToCheck":"AppendToAccess", "RoleAccessRights":"None", "PoaAccessRights":"None", "HsmAccessRights":"None", "GrantedAccessRights":"None", "Messages":["PrincipalHasOwnerPrincipalWithAtLeastBasicPrivilegeDepth = False", "EntityUserGroupRights = None", "MinimumPrivilegeDepthRequired = Global", "SecLib::AccessCheckEx2 failed. Owner Data: User principal 00000000-0000-0000-0000-000000000000 is not loaded in UserDataCache yet; Principal Data: roleCount=2, privilegeCount=821, accessMode=0"], "EntityOwnershipTypeMask":4, "CallerInfo":{"IsSystemUser":false, "IsSupportUser":false, "IsAdministrator":false, "IsCustomizer":false, "IsDisabled":false, "IsIntegrationUser":false, "Teams":null, "Roles":null}, "ReadOnlyState":"UserAndOrgFullAccess", "IsHsmEnabled":false, "HsmInfo":null}

Note that the message uses JSON formatting, which uses to be explained as a property bag. It means a set of properties with their values; values can be strings, numbers, or more complex objects:

  • Array (enclosed in [])
  • Another property bag (enclosed in {})

Let's format our error to make it more readable:

CallerPrincipal : {PrincipalId:"4f0d247e-019c-e811-a96c-000d3aa30ac8", Type:8, IsUserPrincipal:true},
OwnerPrincipal : {PrincipalId:"00000000-0000-0000-0000-000000000000", Type:8, IsUserPrincipal:true},
ObjectId : "fdf21d78-019c-e811-a96c-000d3aa30ac8",
ObjectTypeCode : 8,
EntityName : systemuser,
ObjectBusinessUnitId : "64160e70-ca11-ea11-a811-000d3a085b2b",
RightsToCheck : AppendToAccess,
RoleAccessRights : None,
PoaAccessRights : None,
HsmAccessRights : None,
GrantedAccessRights : None,
Messages:[
  PrincipalHasOwnerPrincipalWithAtLeastBasicPrivilegeDepth = False,
  EntityUserGroupRights = None,
  MinimumPrivilegeDepthRequired = Global,
  SecLib::AccessCheckEx2 failed. Owner Data: User principal 00000000-0000-0000-0000-000000000000 is not loaded in UserDataCache yet; Principal Data: roleCount=2, privilegeCount=821, accessMode=0
],
EntityOwnershipTypeMask : 4,
CallerInfo : {IsSystemUser:false, IsSupportUser:false, IsAdministrator:false, IsCustomizer:false, IsDisabled:false, IsIntegrationUser:false, Teams:null, Roles:null},
ReadOnlyState : UserAndOrgFullAccess,
IsHsmEnabled : false,
HsmInfo : null

The above text should be interpreted by a Dynamics expert, but we can draw some conclusions, too.

  • The term principal refers to users or teams, i.e. to subjects that can be assigned security roles (and thus access permissions).
  • The concerned entity is systemuser (8 is its typecode). We see also the ID of systemuser record, but we can't use this information right now.
  • As next we see several statements related to access rights. Here is some background info: Role refers to user access rights, POA refers to sharing, HSM probably to hierarchical security, etc. AppendToAccess refers to the access right defined as "The right to append another record to the specified object." In all cases we see "None" which seems to indicate insufficient privileges.

Additional details of the server response are listed between the tags <soap>...</soap>. Most of them seem to be useless, but we could at least try to decipher ErrorCode=-2147187962.

I used Google and out of many results selected this advice: "Can you check what permissions you have for the AppendTo privilege for your custom entity. Also, check that the systemuser entity has append and appendto privileges for the role that you are testing with."

Conclusion: Looks like our mobile user has insufficient privileges to execute the attempted operation. Ask the server admin for help.

Examples with connection error

OAuth mode required

Application 12.0.3.0 ERROR 2019-05-23 18:44:11.623+02:00
Mem:9277152
Disk space Free/Total [MB] : 197393 / 244080
free/used/total [MB]: 75 / 1933 / 2823 
System.Exception: Can't connect ---> System.Net.RescoSoapException: Server Login Failed: AADSTS50076: Due to a configuration change made by your administrator, or because you moved to a new location, you must use multi-factor authentication to access ''.
  at MobileCrm.Data.WebService.WebServiceBase+XmlResponse..ctor ()
  at MobileCrm.Data.WebService.WebServiceBase.InternalEndInvoke (System.Object request, System.Func`2[T,TResult] readResponse)
  at MobileCrm.Data.WebService.WebServiceBase.Invoke ()
  at MobileCrm.Data.WebService.Crm2011.LiveIdService.IssueSecurityToken ()
  at MobileCrm.Data.WebService.Crm2011.CrmService2011+ConnectionCache.GetSecurityToken ()
  at MobileCrm.Data.WebService.WebServiceBase.Invoke (string action, System.Object args, System.Action`2[T1,T2] writeRequest, System.Func`2[T,TResult] readResponse)
  at MobileCrm.Data.WebService.Crm2011.CrmService2011.ExecuteWhoAmI ()
  at MobileCrm.Data.WebService.Crm2011.CrmService2011.Connect (MobileCrm.LoginInfo settings, MobileCrm.SimpleLoginInfo login, System.Action`2[T1,T2] Log)
  at MobileCrm.Data.WebService.CrmServiceFactory.Connect (MobileCrm.LoginInfo settings, MobileCrm.SimpleLoginInfo login, System.Action`2[T1,T2] Log)
<soap>Code.Value=S:Sender| Code.Subcode.Value=wst:FailedAuthentication| Reason.Text=Authentication Failure| Detail.error.value=0x800434D4</soap>

Context: Unknown. We only see a server connection attempt. There is no information about who initiated this action.

Error analysis: Connection attempt failed. The main messages are:

  • FailedAuthentication
  • "you must use multi-factor authentication".

We see a typical configuration error. (OAuth mode required.)

HTTP Error unauthorized (401)

<Exception>18:07:22.457: Exception: Impossibile connettersi --->
Net.HttpException: HTTP Error unauthorized (401)
  at CrmServiceFactory.Connect (MobileCrm.LoginInfo settings, Action`2[T1,T2] Log)
  at SyncEngine.CreateServiceForSync (MobileCrm.LoginInfo settings)
  at SyncEngine.Execute (Resco.Data.db, Boolean isHighEndDevice, Synchronization.SyncResult& result) <0x101989490 + 0x001c3>
  at SyncEngine.Execute (Resco.Data.db, MobileCrm.config, Synchronization.SyncResult& result, Func`3[T1,T2,TResult] progress, Synchronization.SyncConflict conflictCallback, Boolean isHighEndDevice, Boolean isRequestedByUser, Boolean isRestartSync)
</Exception>

Context: Synchronization start, connection attempt.

Error analysis: The mobile user lacks valid authentication credentials. Check the user info you entered into the login dialog or ask the system admin for help.

Name resolution failure

OnlineError 2019-12-16T10:55:19.9444776+01:00
Called from: <>c__DisplayClass6.<SaveInstance>b__5(MobileCrm.Data.DynamicRepository+<>c__DisplayClass6)
Exception: Can't connect ---> 
WebException: NameResolutionFailure: The remote name could not be resolved: 'build.rescocrm.com'
   at Net.HttpWebRequestSync.GetResponse()
   at WebServiceBase.GetServerResponse(HttpWebRequestSync request)
   at WebServiceBase.XmlResponse..ctor()
   at WebServiceBase.Invoke(String action, Object args, Action`2 writeRequest, Func`2 readResponse)
   at Xrm.XrmService.ExecuteWhoAmI()
   at Xrm.XrmService.Connect(LoginInfo settings, SimpleLoginInfo login, Action`2 Log, WhoAmI& whoAmI)
   at CrmServiceFactory.Connect(LoginInfo settings, Action`2 Log)
   at MobileCrm.Data.Online.OnlineRepository.GetService()
   at MobileCrm.Data.Online.OnlineRepository.OnlineRequestThread()

Context: Online mode, saving some record to the server. ("SaveInstance" reveals that.)

Error analysis:

  • The actual save action did not even start as it was preceded by a connection attempt, which failed.
  • Connection failed because of "NameResolutionFailure: The remote name could not be resolved".
  • This typically points to an Internet connectivity issue. (But also a DNS error is possible.)

Can't connect: Authorization failure

<EXCEPTION>09:36:30.699: Exception: Can't connect ---> 
AggregateException: ExtAuth failed. (iservices.resco.net,,iservices.rescocrm.com) (Server Error: Internal Server Error) (Server Error: Internal Server Error) ---> 
Net.RescoSoapException: Server Error: Internal Server Error
<soap>Code.Value=Sender</soap>
at WebServiceBase.ThrowSoapException(Net.HttpException ex)
at WebServiceBase.XmlResponse..ctor(Object context, Boolean soap, Data.WebService.WebServiceBase webService, Xml.XmlReaderSettings xmlSettings, Boolean processMultipartResponses)
at WebServiceBase.InternalEndInvoke(Object request, Func<Xml.XmlReader,Object> readResponse)
at WebServiceBase.Invoke(String action, Object args, Action<Xml.XmlWriter,Object> writeRequest, Action<Xml.XmlWriter> writeHeader, Func<Xml.XmlReader,Object> readResponse)
at MobileCrm.Data.Customization.MobileLicenseBase.AuthenticateEx(LoginInfo settings, SimpleLoginInfo userLogin, ExternalAuthType authType, Action<String,String> log)
--- End of inner exception stack trace --- --->

Context: External sync.

Error analysis: There are several things that could be wrong here:

  • Wrong external user name/password
  • Wrong CRM User user name/password in the external project properties
  • CRM User does not have permission to see the external user records
  • Wrong type of password (Hash in project properties, while password is saved as text in CRM)

HTTP Error forbidden (403)

Date:2020-07-24 10:00:29+04:00
Org: 00000000-0000-0000-0000-000000000000
User:DEMO

XRMConnectFailed: HttpException: HTTP Error forbidden (403)

Crm2011ConnectFailed: InvalidOperationException: Cannot determine CRM deployment for url:https://customer.crm.dymanics.com/XRMServices/2011/Organization.svc?wsdl=wsdl0| HttpException: HTTP Error forbidden (403)

CRM4: Disco connection failed to :'https://customer.crm.dymanics.com/MSCRMServices/2007/AD/CrmDiscoveryService.asmx'
Crm4ConnectFailed: HttpException: HTTP Error forbidden (403)

<EXCEPTION>10:00:29.482: Exception: Can't connect --->
Net.HttpException: HTTP Error forbidden (403)
***** Access Forbidden *****

Context: Connection issue.

Error analysis: This may seem like a permission issue, but it is a typo in the URL. The user entered "dymanics".

Other examples

  • SQLite error: the app has some problem interacting with its database saved on the device

Internal error

Log file: syncLog.txt
<History>
Date:2020-07-22 10:06:39
User:DEMO
<Summary>
<Settings App='13.1.1.0' Server='?' Threads='0' MaxExecMultiple='0' Foreground='true' Launch='Auto'/> <Results Sent='0' Recv='0' Result='ConnectFailed'/> <Times Total='6390ms'/>
<Exception>10:06:39.540: Exception: No se puede conectar ---&gt;
Net.RescoSoapException: Error del servidor: The server was unable to process the request due to an internal error.  For more information about the error, either turn on IncludeExceptionDetailInFaults (either from ServiceBehaviorAttribute or from the &lt;serviceDebug&gt; configuration behavior) on the server in order to send the exception information back to the client, or turn on tracing as per the Microsoft .NET Framework SDK documentation and inspect the server trace logs.
</Exception>

Need to check with the CRM admin what is the cause on the server; or try again later.

Argument type error

RescoSoapException: Server Error: An exception System.FormatException was thrown while trying to convert input value 'a%' to attribute 'crmp_rebateprogramsignup.crmp_year'. 
Expected type of attribute value: System.Int32. Exception raised: Input string was not in a correct format.
at WebServiceBase.XmlResponse..ctor()
at MobileCrm.Data.WebService.Crm2011.CrmService2011.<ExecuteFetch>d__60.MoveNext()
at MobileCrm.Data.Online.LoadRequest.Execute(Data.WebService.ICrmService service)
at MobileCrm.Data.Online.OnlineRepository.RequestThread()
<soap>
  Code.Value=s:Sender|
  Detail.OrganizationServiceFault.ActivityId=7dbb0cf0-83aa-4acb-b195-200570a1e2a0|
  Detail.OrganizationServiceFault.ErrorCode=-2147220989|
  Detail.OrganizationServiceFault.Timestamp=2019-01-28T16:27:59.0379735Z|
  Detail.OrganizationServiceFault.ExceptionRetriable=false|
  Detail.OrganizationServiceFault.InnerFault.InnerFault.ErrorCode=-2147220970|
  Detail.OrganizationServiceFault.InnerFault.InnerFault.Message=System.FormatException: Input string was not in a correct format.
    at System.Number.StringToNumber(String str, NumberStyles options, NumberBuffer& number, NumberFormatInfo info, Boolean parseDecimal)
    at System.Number.ParseInt32(String s, NumberStyles style, NumberFormatInfo info)
    at Microsoft.Crm.Platform.ConvertHelper.FromXmlString(AttributeMetadata attributeMetadata, String xmlString): 
    Microsoft Dynamics CRM has experienced an error. Reference number for administrators or support: #6968E566
</soap>

Error analysis:

  • LoadRequest indicates reading records.
  • Stack trace starts with OnlineRepository.RequestThread(), which acts as a queue for fetches.
  • Older versions of Resco mobile apps used OnlineRepository also for reading from the database, hence we still don't know whether we communicate with the server.
  • The proof is here: "CrmService2011" (reminds Dynamics CRM 2011) or "WebServiceBase". So we have an online mode fetch.
  • According to the error message the fetch concerned crmp_rebateprogramsignup entity. The problem: The client supplied string value "a%" to the attribute crmp_year.

<soap> details supply a few interesting details:

  • ErrorCode=-2147220970 means "Invalid argument".
  • Other keys such FormatException, StringToNumber, or ParseInt32 clearly indicate that the server expects an integer value, but receives something else (a string in this case).

Probable error: This is an argument type error.

  • If you think about the fetch anatomy, attribute values are supplied only in conditions.
  • However, we have a rather special value - "a%" - which pretty much reminds a wildcard (which are mostly used in the view search bar).
  • A feasible explanation would be an incorrect search for some view. However, this is just speculation. In any case, we should double-check view definitions for the crmp_rebateprogramsignup entity.

Unauthorized access

OnlineError 2020-06-22T15:01:14.7899261+02:00
Called from: DynamicRepository.AsyncLoadInstanceByIdCompleted()
Net.RescoSoapException: Server-Fehler: Attempted to perform an unauthorized operation. User is missing privilege for entity on organization.
<soap>
  Code=500| 
  ErrorCode=-2147220873| 
  Reason=UnauthorizedAccessException| 
  Detail=Attempted to perform an unauthorized operation. User 'xyz@abcde-2020.demo' is missing 'Read' privilege for 'resco_mobileaudit' entity on organization 'salesforcedemo00d2x000000trqzuag'.| 
  SupportId=3525615d-1d01-4ee5-be8b-995c2a45e25c
</soap>
at WebServiceBase.XmlResponse..ctor()
at Xrm.XrmService.BeginInvoke(String action, Object context, Action<Xml.XmlWriter,Object> writeXml, Xml.XmlReader& reader)
at Xrm.XrmService.<ExecuteFetch>d__30.MoveNext()
at Salesforce.SalesforceService.<ExecuteFetch>d__65.MoveNext()
at MobileCrm.Data.Online.LoadRequest.Execute(Data.WebService.ICrmService service)
at MobileCrm.Data.Online.OnlineRepository.OnlineRequestThread()

Context: Online mode, loading a specific record from the server. (LoadInstanceById refers to loading a single record with the specified ID.)

Error analysis: Mobile user (xyz@abcde-2020.demo) is not allowed to read resco_mobileaudit records.

Google account access denied

MobileCrm.Data.Google.UnauthorizedException: Google account access denied. ---> 
HttpException: The remote server returned an error: (400) Bad Request.
<soap>{
  "error" : "invalid_grant", 
  "error_description" : "Token has been expired or revoked."
}</soap>
  at HttpWebRequestSync.GetResponse()
  at MobileCrm.Data.Google.GoogleServiceBase.RefreshAccessToken()
  at MobileCrm.Data.Google.GmailService.CreateRequest(String url)
  at MobileCrm.Data.Google.GmailService.<Fetch>d__15.MoveNext()
  at MobileCrm.Data.Google.GoogleEmailService.<DownloadIds>d__2.MoveNext()
  at MobileCrm.Data.Google.GoogleEmailService.DownloadEmails(SyncContext context)
  at MobileCrm.Data.Integration.EmailService.SyncInternal(SyncContext context)
  at MobileCrm.Data.Google.GoogleEmailService.Sync(GoogleSyncContext context)
  at MobileCrm.Data.Google.Google.Sync(IDatabase db, Func`3 progressCallback)
  at MobileCrm.Data.Integration.Synchronization.Execute(IDatabase db, Func`3 progressCallback)

Context: Gmail sync, connection attempt

Error analysis: Authentication (OAuth2) problem. If you synced with Gmail successfully in the past, then you might need to refresh the security token. (Try to connect to Gmail from the Setup form.)

HTTP Error service unavailable (503)

<Exception>17:36:16.807: Exception: Fatal Upload Error ---> 
Net.HttpException: HTTP Error service unavailable (503)
***** Bad Gateway *****

The service is temporarily unavailable. Please check again later.

Your request ID was: XuiSFZVftstslmUUETQ3GAAAAUs

(o)  go back[javascript:history.back()]    

16/Jun/2020, 11:36:16 MEST

  at WebServiceBase+XmlResponse..ctor ()
  at WebServiceBase.Invoke (String action, Object args, Action`2[T1,T2] writeRequest, Func`2[T,TResult] readResponse)
  at Crm2011.CrmService2011.ExecuteMultiple (Collections.Generic.List`1[T] requests)
  at SyncEngine+EntityUploader.ExecuteSync (Collections.Generic.List`1[T] requests, SyncEngine+SyncUploader syncUploader, TableSyncAnchor anchor, Resco.Data.db, Action progressCallback)
  at SyncEngine+SyncUploader.UploadSync_DoExecute (Resco.Data.db)
  at SyncEngine.Execute (Resco.Data.db, Boolean isHighEndDevice, SyncResult& result)
</Exception>

Context: Synchronization. The connection was successful. A bit later the sync uploader fails with this error.

Error analysis:

  • Error 503 typically indicates that the server is temporarily unable to handle the request, perhaps due to being overloaded or down for maintenance.
  • Note the strange exception message - this is because it is primarily meant to be displayed in a web browser.
  • In any case, this should be a temporary problem; the next sync should succeed.
  • If you have access to the server, check if it's running and reachable.

Fetch timed out

Application 12.1.4.0 ERROR 2019-09-13 09:23:50.882+02:00
Mem:6870088
Disk space Free/Total [MB] : 190163 / 244080
free/used/total [MB]: 78 / 1805 / 2823 
Net.WebRequestException: The request timed out. (-1001) | NetInfo: [Reachable] | Duration: 1417908ms
  at Net.HttpConnection.GetResponse (Net.HttpWebRequestSync request)
  at Net.HttpWebRequestSync.GetResponse ()
  at WebServiceBase.GetWebResponse (Object request)
  at WebServiceBase+XmlResponse..ctor ()
  at Crm2011.CrmService2011+<ExecuteFetch>d__60.MoveNext ()
  at MobileCrm.Data.Online.LoadRequest.Execute (ICrmService service)
  at MobileCrm.Data.Online.OnlineRepository.RequestThread ()

Context: Online mode, executing a fetch from the server.

Error analysis: All we can say is that the fetch timed out. 1417 seconds is rather suspicious because Resco sets the timeout to 3 minutes, but the log does not give any clue.

KeyNotFoundException

App 12.0.3.0 5/24/2019:
8:51 AM: System.Reflection.TargetInvocationException: Arg_TargetInvocationException ---> 
System.Collections.Generic.KeyNotFoundException: Arg_KeyNotFound
  at System.Collections.Generic.Dictionary<System.String,System.Collections.Generic.List<System.Int32>>.get_Item(String key)
  at MobileCrm.Json.InvokeMethod(Object obj, String methodPath, String paramsJson, Func<System.String,System.Object> getExtObject)
  at MobileCrm.UI.Controllers.WebController.InvokeMethod(String data, Object& result)
  at MobileCrm.UI.Controllers.WebController.OnInvokeMethod(String data, Action<System.String> success, Action<System.String> failure)
  at Resco.UI.WindowsRT.JSBridge.ProcessCommand(String cmd)

Context: The excerpt is from JSBridge.log and we really see the call stack starting at JSBridge.ProcessCommand(). Hence, it must be the processing of a command from the custom JavaScript code.

Error analysis:

  • The key is KeyNotFoundException. (Wrapped in TargetInvocationException, but this is just a formal layer - kind of a postman - which just delivers wrapped exception.)
  • This error is used with Dictionaries, which in turn are used to represent JavaScript objects (e.g., entity records).
  • Looks like an invalid attribute name was used, however in the absence of additional information we cannot exclude other explanations.
  • In any case, the error comes from custom JavaScript code.

FileNotFoundException

8:51 AM: System.Reflection.TargetInvocationException: Arg_TargetInvocationException ---> 
System.IO.FileNotFoundException: IO_FileNotFound_FileName, C:\Users\xyz\AppData\Local\Packages\Resco.MobileCRM_nf1vnwdtkksgr\LocalState\MobileCRM\fe44b293-9fbf-4d9f-a4be-f8f3fcad12b9\MobileCrm\Controllers\systemuser.list.generated.bin
  at System.IO.IsolatedStorageFileStream.Open(String path, IO.FileMode uCreateDisposition, IO.FileAccess uAccess, IO.FileShare uShare)
  at System.IO.IsolatedStorageFileStream..ctor(String path, IO.FileMode uCreateDisposition, IO.FileAccess uAccess, IO.FileShare uShare, Storage.IStorageFolder folder)
  at System.IO.StreamReaderEx.Create(String path, Storage.IStorageFolder folder)
  at MobileCrm.Configuration.OpenStorageReader(String fileName)
  at MobileCrm.Configuration.OpenUIConfig(String configName)
  at MobileCrm.Json.InvokeMethod(Object obj, String methodPath, String paramsJson, Func<System.String,System.Object> getExtObject)
  at MobileCrm.Json.InvokeStaticMethod(String assembly, String typeName, String methodName, String paramsJson, Func<System.String,System.Object> getExtObject)
  at MobileCrm.UI.Controllers.WebController.InvokeMethod(String data, Object& result)
  at MobileCrm.UI.Controllers.WebController.OnExposeMethodResult(String data, Action<System.String> success, Action<System.String> failure)
  at Resco.UI.WindowsRT.JSBridge.ProcessCommand(String cmd)

Context: The excerpt is from JSBridge.log and we really see the call stack starting at JSBridge.ProcessCommand(). Hence, it must be the processing of a command from the custom JavaScript code.

Error analysis:

  • We see that the problem is (FileNotFoundException) missing file systemuser.list.generated.bin.
  • This is the config file describing a list of users (systemuser entity), which should be delivered as part of the customization.
  • The action is initiated from custom JavaScript code and it looks like it tried to execute some action on the user list without ensuring that this list is included in the current customization.