Synchronization between 3CX and Bitrix 24 CRM - sometimes works or not

Status
Not open for further replies.

mdtmed

Customer
Joined
Jul 5, 2015
Messages
18
Reaction score
0
I have issue with this, because I dont want how to check why sometimes the synchronization works and sometimes dont during the call outbound or inbound also . Is there any min. time between the process ?
where can I check this ?
if something is blocking then it shouldn't work at all...
 
In order to troubleshoot this, please enable verbose logs from the 3CX Console > Dashboard > Activity Log > Settings. Then make a test call, and when you detect the issue check the 3cxSystemService.log. There you will see all the interactions between 3CX and Bitrix, so any issue will be visible there.
 
thanks for this and now take a look:
this is the log from the call, when synchrofailed...


|Verb|Add to processing. Number=516129006, connection=8268, state=Ringing
2020/02/27 13:57:04.805|10440|0014|Info|CRM ProcessActiveConnections(). Attached entries to connection: 3648
2020/02/27 13:57:04.805|10440|0014|Verb|CRM: LocalMatches=3648. Number=516129006, connection=8268, state=Ringing
2020/02/27 13:57:04.805|10440|0014|Info|CRM: Synchronize(...) called
2020/02/27 13:57:04.806|10440|0095|Info|CRM: maxConcurrency=16
2020/02/27 13:57:04.807|10440|0095|Info|CRM: making request to CRM. Number=516129006
2020/02/27 13:57:04.807|10440|0095|Info|CRM: No changes detected for contact Wphonebook.3648: Wtenant.1: default - - TEST SYNCHRO
2020/02/27 13:57:04.807|10440|0095|Verb|Removed from processing. Number=516129006
2020/02/27 13:57:04.807|10440|0095|Info|CRM: processing of 516129006 has been finished

what CRM exactly check ?
because in CRM the first name and the second name was different since last call...
( TEST SYNCHRO - I changed for TEST 2 SYNCHRO 2 )
 
and now next successful attemped

2020/02/27 14:13:12.222|10440|0014|Verb|Add to processing. Number=516129006, connection=8272, state=Ringing
2020/02/27 14:13:12.222|10440|0014|Info|CRM ProcessActiveConnections(). Attached entries to connection: 3648
2020/02/27 14:13:12.222|10440|0014|Verb|CRM: LocalMatches=3648. Number=516129006, connection=8272, state=Ringing
2020/02/27 14:13:12.222|10440|0014|Info|CRM: Synchronize(...) called
2020/02/27 14:13:12.223|10440|0004|Verb|Dequeue Inserted.CONNECTION.8272
2020/02/27 14:13:12.223|10440|0065|Info|CRM: maxConcurrency=16
2020/02/27 14:13:12.223|10440|0065|Info|CRM: making request to CRM. Number=516129006
2020/02/27 14:13:12.224|10440|0065|Trac|Obtaining scenario entity order for entity 'Companies'
2020/02/27 14:13:12.224|10440|0065|Trac|Obtained scenario entity order '2' for entity 'Companies'
2020/02/27 14:13:12.224|10440|0065|Trac|Obtaining scenario entity order for entity 'Leads'
2020/02/27 14:13:12.224|10440|0065|Trac|Obtained scenario entity order '0' for entity 'Leads'
2020/02/27 14:13:12.224|10440|0065|Trac|Obtaining scenario entity order for entity 'Contacts'
2020/02/27 14:13:12.224|10440|0065|Trac|Obtained scenario entity order '1' for entity 'Contacts'
2020/02/27 14:13:12.224|10440|0065|Verb|Processing scenario 'Default'.
2020/02/27 14:13:12.224|10440|0065|Verb|Creating new HttpClient with no authentication
2020/02/27 14:13:12.225|10440|0065|Verb|Performing GET request 'https://xxx.bitrix24.eu/rest/4/xxxi12r/crm.lead.list.json?filter[PHONE]=516129006&select[]=*&select[]=PHONE&select[]=EMAIL'.
2020/02/27 14:13:12.402|10440|0024|Verb|The response is: '{"result":[],"total":0,"time":{"start":1582809193.224673,"finish":1582809193.254504,"duration":0.0298309326171875,"processing":0.0081508159637451172,"date_start":"2020-02-27T16:13:13+03:00","date_finish":"2020-02-27T16:13:13+03:00"}}'
2020/02/27 14:13:12.402|10440|0024|Verb|No matchings found.
2020/02/27 14:13:12.402|10440|0024|Verb|Processing scenario 'Default'.
2020/02/27 14:13:12.402|10440|0024|Verb|Creating new HttpClient with no authentication
2020/02/27 14:13:12.402|10440|0024|Verb|Performing GET request 'https://xxx.bitrix24.eu/rest/4xxx/c...9006&select[]=*&select[]=PHONE&select[]=EMAIL'.
2020/02/27 14:13:12.488|10440|0024|Verb|The response is: '{"result":[{"ID":"22622","POST":null,"COMMENTS":null,"HONORIFIC":null,"NAME":"TEST 2","SECOND_NAME":null,"LAST_NAME":"SYNCHRO 2","PHOTO":null,"LEAD_ID":null,"TYPE_ID":null,"SOURCE_ID":null,"SOURCE_DESCRIPTION":null,"COMPANY_ID":null,"BIRTHDATE":"","EXPORT":"N","HAS_PHONE":"Y","HAS_EMAIL":"N","HAS_IMOL":"N","DATE_CREATE":"2020-02-24T17:01:27+03:00","DATE_MODIFY":"2020-02-27T15:56:31+03:00","ASSIGNED_BY_ID":"4","CREATED_BY_ID":"4","MODIFY_BY_ID":"4","OPENED":"N","ORIGINATOR_ID":null,"ORIGIN_ID":null,"ORIGIN_VERSION":null,"FACE_ID":null,"ADDRESS":null,"ADDRESS_2":null,"ADDRESS_CITY":null,"ADDRESS_POSTAL_CODE":null,"ADDRESS_REGION":null,"ADDRESS_PROVINCE":null,"ADDRESS_COUNTRY":null,"ADDRESS_COUNTRY_CODE":null,"UTM_SOURCE":null,"UTM_MEDIUM":null,"UTM_CAMPAIGN":null,"UTM_CONTENT":null,"UTM_TERM":null,"PHONE":[{"ID":"29908","VALUE_TYPE":"WORK","VALUE":"516129006","TYPE_ID":"PHONE"}]}],"total":1,"time":{"start":1582809193.310473,"finish":1582809193.341012,"duration":0.030539035797119141,"processing":0.0083930492401123047,"date_start":"2020-02-27T16:13:13+03:00","date_finish":"2020-02-27T16:13:13+03:00"}}'
2020/02/27 14:13:12.489|10440|0024|Verb|Filtered variables for matching:
2020/02/27 14:13:12.489|10440|0024|Verb| 'PhoneMobile2' = ''
2020/02/27 14:13:12.489|10440|0024|Verb| 'FaxBusiness' = ''
2020/02/27 14:13:12.489|10440|0024|Verb| 'PhoneBusiness' = '516129006'
2020/02/27 14:13:12.489|10440|0024|Verb| 'PhoneMobile' = ''
2020/02/27 14:13:12.489|10440|0024|Verb| 'PhoneHome2' = ''
2020/02/27 14:13:12.489|10440|0024|Verb| 'Pager' = ''
2020/02/27 14:13:12.489|10440|0024|Verb| 'PhoneBusiness2' = '516129006'
2020/02/27 14:13:12.489|10440|0024|Verb| 'ContactId' = '22622'
2020/02/27 14:13:12.489|10440|0024|Verb| 'FaxHome' = ''
2020/02/27 14:13:12.489|10440|0024|Verb| 'LastName' = 'SYNCHRO 2'
2020/02/27 14:13:12.489|10440|0024|Verb| 'FirstName' = 'TEST 2'
2020/02/27 14:13:12.490|10440|0024|Verb| 'PhoneOther' = ''
2020/02/27 14:13:12.490|10440|0024|Verb| 'PhoneHome' = ''
2020/02/27 14:13:12.490|10440|0024|Verb| 'Email' = ''
2020/02/27 14:13:12.490|10440|0024|Verb|Processing scenario 'Default'.
2020/02/27 14:13:12.490|10440|0024|Verb|Creating new HttpClient with no authentication
2020/02/27 14:13:12.490|10440|0024|Verb|Skipping request...
2020/02/27 14:13:12.490|10440|0024|Verb|No matchings found.
2020/02/27 14:13:12.497|10440|0014|Verb|Enqueue Updated.PHONEBOOK.3648
2020/02/27 14:13:12.497|10440|0004|Verb|Dequeue Updated.PHONEBOOK.3648
2020/02/27 14:13:12.498|10440|0024|Info|CRM: Contact Wphonebook.3648: Wtenant.1: default - - TEST 2 SYNCHRO 2 was updated from CRM
2020/02/27 14:13:12.498|10440|0024|Info|CRM: New lookup data '3648,3648' will be attached to all connections related to number 516129006
2020/02/27 14:13:12.499|10440|0024|Verb|Removed from processing. Number=516129006
2020/02/27 14:13:12.499|10440|0024|Info|CRM: processing of 516129006 has been finished


as you can see now TEST 2 SYNCHRO 2 - is found and worked...

where is the difference about this 2 calls ... only time...
 
The CRM engine has a 10 minutes cache. If you call 2 times in less than 10 minutes, the second time the information is returned from cache. This can't be disabled.
 
Status
Not open for further replies.

Forum statistics

Threads
112,325
Messages
591,898
Members
165,479
Latest member
Senergia