ReportCall scenario is always skipped

[z3d0]

Hi all,

I've created a custom CRM template and it works smoothly testing it with the provided tool in the "parameter values" section.
Using it in a live environment and enabling verbose logging, I noticed that the contact request is processed but the call journaling request is always skipped.

Scenario 1: contact is found in CRM and is already in 3CX address book:

2022/01/10 16:02:43.712|4908|0008|Info|CRM ProcessActiveConnections(). Attached entries to connection: 258
2022/01/10 16:02:43.712|4908|0008|Verb|CRM: LocalMatches=258. Number=XXX, connection=7, state=Dialing
2022/01/10 16:02:43.712|4908|0008|Info|CRM: Synchronize(...) called
2022/01/10 16:02:43.712|4908|0054|Info|CRM: maxConcurrency=2
2022/01/10 16:02:43.712|4908|0054|Info|CRM: making request to CRM. Number=XXX
2022/01/10 16:02:43.712|4908|0054|Trac|Obtaining scenario entity order for entity ''
2022/01/10 16:02:43.712|4908|0054|Trac|Ordering configuration not found, using scenario entity order 0 for entity ''
2022/01/10 16:02:43.712|4908|0054|Verb|Processing scenario 'Default'.
2022/01/10 16:02:43.713|4908|0054|Verb|Creating new HttpClient with no authentication
2022/01/10 16:02:43.713|4908|0054|Verb|Performing GET request 'URL'.
2022/01/10 16:02:43.794|4908|0051|Verb|The response is: '{json data}'
2022/01/10 16:02:43.794|4908|0051|Verb|Unknown path element: xxx. Null value is returned.
2022/01/10 16:02:43.794|4908|0051|Verb|Filtered variables for matching:
2022/01/10 16:02:43.794|4908|0051|Verb|   'FirstName' = 'xxx'
2022/01/10 16:02:43.794|4908|0051|Verb|   'Email' = 'xxx'
2022/01/10 16:02:43.794|4908|0051|Verb|   'PhoneMobile' = 'xxx'
2022/01/10 16:02:43.794|4908|0051|Verb|   'PhoneBusiness' = ''
2022/01/10 16:02:43.794|4908|0051|Verb|   'CompanyName' = ''
2022/01/10 16:02:43.795|4908|0051|Verb|   'ContactID' = '15'
2022/01/10 16:02:43.796|4908|0051|Info|CRM: No changes detected for contact Wphonebook.258: Wtenant.1: default - xxx
2022/01/10 16:02:43.796|4908|0051|Verb|Removed from processing. Number=xxx
2022/01/10 16:02:43.796|4908|0051|Info|CRM: processing of xxx has been finished

[...]

2022/01/10 16:02:52.330|4908|0043|Info|CRM: about to report 1 calls at maxConcurrency 1
2022/01/10 16:02:52.330|4908|0043|Verb|Processing scenario 'ReportCall'.
2022/01/10 16:02:52.330|4908|0043|Verb|Creating new HttpClient with no authentication
2022/01/10 16:02:52.331|4908|0043|Verb|Skipping request...
2022/01/10 16:02:52.331|4908|0043|Verb|Continue with empty matching.
2022/01/10 16:02:52.331|4908|0043|Verb|Processing scenario 'ReportCallMissed'.
2022/01/10 16:02:52.331|4908|0043|Verb|Creating new HttpClient with no authentication
2022/01/10 16:02:52.331|4908|0043|Verb|Skipping request...
2022/01/10 16:02:52.331|4908|0043|Verb|Continue with empty matching.
2022/01/10 16:02:52.331|4908|0043|Verb|Processing scenario 'ReportCallOutbound'.
2022/01/10 16:02:52.331|4908|0043|Verb|Creating new HttpClient with no authentication
2022/01/10 16:02:52.331|4908|0043|Verb|Skipping request...
2022/01/10 16:02:52.331|4908|0043|Verb|Continue with empty matching.
2022/01/10 16:02:52.331|4908|0043|Verb|Processing scenario 'ReportCallNotanswered'.
2022/01/10 16:02:52.331|4908|0043|Verb|Creating new HttpClient with no authentication
2022/01/10 16:02:52.331|4908|0043|Verb|Skipping request...
2022/01/10 16:02:52.331|4908|0043|Verb|No matchings found.

Scenario 2: contact is found in CRM and is not in 3cx address book

2022/01/10 15:52:55.292|4908|0008|Info|CRM ProcessActiveConnections(). Attached entries to connection: 104
2022/01/10 15:52:55.292|4908|0008|Verb|CRM: LocalMatches=104. Number=xxx, connection=6, state=Ringing
2022/01/10 15:52:55.292|4908|0008|Info|CRM: Synchronize(...) called
2022/01/10 15:52:55.292|4908|0038|Info|CRM: maxConcurrency=2
2022/01/10 15:52:55.293|4908|0038|Info|CRM: making request to CRM. Number=xxx
2022/01/10 15:52:55.293|4908|0038|Trac|Obtaining scenario entity order for entity ''
2022/01/10 15:52:55.293|4908|0038|Trac|Ordering configuration not found, using scenario entity order 0 for entity ''
2022/01/10 15:52:55.293|4908|0038|Verb|Processing scenario 'Default'.
2022/01/10 15:52:55.293|4908|0038|Verb|Creating new HttpClient with no authentication
2022/01/10 15:52:55.294|4908|0038|Verb|Performing GET request 'URL'.
2022/01/10 15:52:55.396|4908|0050|Verb|The response is: 'json data'
2022/01/10 15:52:55.411|4908|0050|Verb|Unknown path element: xxx. Null value is returned.
2022/01/10 15:52:55.412|4908|0050|Verb|Filtered variables for matching:
2022/01/10 15:52:55.412|4908|0050|Verb|   'FirstName' = 'xxx'
2022/01/10 15:52:55.412|4908|0050|Verb|   'Email' = 'xxx'
2022/01/10 15:52:55.412|4908|0050|Verb|   'PhoneMobile' = 'xxx'
2022/01/10 15:52:55.412|4908|0050|Verb|   'PhoneBusiness' = ''
2022/01/10 15:52:55.412|4908|0050|Verb|   'CompanyName' = 'xxx'
2022/01/10 15:52:55.412|4908|0050|Verb|   'ContactID' = '16'
2022/01/10 15:52:55.425|4908|0008|Trac|###TRANSACTION.11 started
2022/01/10 15:52:55.425|4908|0008|Verb|Enqueue Inserted.TRANSACTION.11
2022/01/10 15:52:55.425|4908|0012|Verb|Dequeue Inserted.TRANSACTION.11
2022/01/10 15:52:55.426|4908|0008|Trac|+++TRANSACTION.11 updated - elapsed 0,9094
2022/01/10 15:52:55.426|4908|0008|Verb|Enqueue Updated.TRANSACTION.11
2022/01/10 15:52:55.427|4908|0050|Info|CRM: New contact created from CRM: Wphonebook.260: Wtenant.1: default - xxx
2022/01/10 15:52:55.428|4908|0050|Info|CRM: New lookup data '104,260' will be attached to all connections related to number xxx
2022/01/10 15:52:55.428|4908|0012|Verb|Dequeue Updated.TRANSACTION.11
2022/01/10 15:52:55.428|4908|0008|Verb|Enqueue Updated.PHONEBOOK.260
2022/01/10 15:52:55.428|4908|0008|Trac|Finalizing TRANSACTION.11
2022/01/10 15:52:55.428|4908|0008|Verb|Enqueue Deleted.TRANSACTION.11
2022/01/10 15:52:55.428|4908|0008|Trac|---TRANSACTION.11 finished 3,3363ms
    data:0,9064ms
    Events:2,2333ms
    externals:0,1966ms
2022/01/10 15:52:55.428|4908|0012|Verb|Dequeue Updated.PHONEBOOK.260
2022/01/10 15:52:55.429|4908|0012|Verb|Dequeue Deleted.TRANSACTION.11
2022/01/10 15:52:55.431|4908|0050|Verb|Removed from processing. Number=xxx
2022/01/10 15:52:55.431|4908|0050|Info|CRM: processing of xxx has been finished

[...]

2022/01/10 15:56:58.838|4908|0054|Info|CRM: about to report 1 calls at maxConcurrency 1
2022/01/10 15:56:58.840|4908|0054|Verb|Processing scenario 'ReportCall'.
2022/01/10 15:56:58.840|4908|0054|Verb|Creating new HttpClient with no authentication
2022/01/10 15:56:58.846|4908|0054|Verb|Skipping request...
2022/01/10 15:56:58.846|4908|0054|Verb|Continue with empty matching.
2022/01/10 15:56:58.846|4908|0054|Verb|Processing scenario 'ReportCallMissed'.
2022/01/10 15:56:58.846|4908|0054|Verb|Creating new HttpClient with no authentication
2022/01/10 15:56:58.846|4908|0054|Verb|Skipping request...
2022/01/10 15:56:58.846|4908|0054|Verb|Continue with empty matching.
2022/01/10 15:56:58.846|4908|0054|Verb|Processing scenario 'ReportCallOutbound'.
2022/01/10 15:56:58.846|4908|0054|Verb|Creating new HttpClient with no authentication
2022/01/10 15:56:58.846|4908|0054|Verb|Skipping request...
2022/01/10 15:56:58.846|4908|0054|Verb|Continue with empty matching.
2022/01/10 15:56:58.846|4908|0054|Verb|Processing scenario 'ReportCallNotanswered'.
2022/01/10 15:56:58.846|4908|0054|Verb|Creating new HttpClient with no authentication
2022/01/10 15:56:58.846|4908|0054|Verb|Skipping request...
2022/01/10 15:56:58.846|4908|0054|Verb|No matchings found.

Scenario 3: contact is not found in CRM

2022/01/10 15:21:39.872|4908|0030|Info|CRM: about to report 1 calls at maxConcurrency 1
2022/01/10 15:21:39.872|4908|0030|Trac|Obtaining scenario entity order for entity ''
2022/01/10 15:21:39.872|4908|0030|Trac|Ordering configuration not found, using scenario entity order 0 for entity ''
2022/01/10 15:21:39.872|4908|0030|Verb|Processing scenario 'Default'.
2022/01/10 15:21:39.872|4908|0030|Verb|Creating new HttpClient with no authentication
2022/01/10 15:21:39.872|4908|0030|Verb|Performing GET request 'URL'.
2022/01/10 15:21:39.919|4908|0035|Erro|Exception during number processing: System.Exception: Server returned a non successful status code - HTTPStatusCode=NotFound - Reason=Not Found - Content={"error":"Client not found"}
   at CrmIntegration.ScenarioProcessorBase.ProcessRequest(ScenarioRequest request, IValueManager customManager, HttpClient client, CancellationToken token)
   at CrmIntegration.ScenarioProcessorBase.ProcessScenario(ProtocolScenario scenario, IValueManager customManager, CancellationToken token)
   at CrmIntegration.ScenarioProcessorBase.Execute(ProtocolScenario scenario, CancellationToken token)
   at CrmIntegration.CrmProcessor.GetContactInfoFromCrm(String contactNumber, Boolean isInboundCall, String destinationEmail, Boolean createIfNotFound, CancellationToken token)
2022/01/10 15:21:39.919|4908|0035|Info|Call not reported because contact could not be found for number: xxx

In scenario 1 and 2 I'm expecting the ReportCall request not to be skipped. Am I missing something?

Thanks in advance!

 

[Evolute IT]

Can you upload your XML template? Something is definitely wrong somewhere in it.

 

[z3d0]

Here it is
Thanks!

 

[Evolute IT]

I guess all the (MYURL) are placeholders that you actually replace? Can you show me a sample JSON returned from your API?

DM me if you prefer to keep this private.