SPAsteriskConnector-1.4.2 и LookUpVariablesNames

Free Russian CRM based on Vtiger CRM project.

Brought to you by: istruchkov, lexerus

#145 SPAsteriskConnector-1.4.2 и LookUpVariablesNames

Milestone: 7.0.1-201707

Status: open

Owner: nobody

Labels: None

Updated: 2018-07-26

Created: 2018-07-26

Creator: Pavel Kopchyk

Private: No

Здравствуйте!
В продолжение темы на форуме (https://community.salesplatform.ru/groups/vtiger-integration/forum/topic/%D0%BE%D1%82%D1%81%D0%BB%D0%B5%D0%B6%D0%B8%D0%B2%D0%B0%D0%BD%D0%B8%D0%B5-%D0%B2%D0%BD%D0%B5%D1%88%D0%BD%D0%B5%D0%B3%D0%BE-%D0%B7%D0%B2%D0%BE%D0%BD%D0%BA%D0%B0-%D1%81-salesplatform-vtiger-asterisk-conn/)

SPAsteriskConnector-1.4.2
Asterisk 11.25.3
Переменные в конфиге:

LookUpVariablesNames=pstncallerid,corpcallerid,connline,totalvar

После старта/рестарта коннектора в базе добавились столбцы:

sqlite> SELECT * FROM spvtiger_calls_info;
uid|srcuid|destuid|event|direction|channel|from_number|to_number|starttime|endtime|totalduration|bridged|callcause|recordingpath|recordingurl|pstncallerid|corpcallerid|connline|totalvar
990000000||||||||||||||||||
990000001|test_ippbx-1532440387|test_ippbx-1532440391|HangupEvent||IAX2/1111-296|1111|ZZXXXXXXXXX|2018-07-24 15:53:11|2018-07-24 15:53:19|8|Unlink|Normal Clearing||||||
990000002|test_ippbx-1532440715|test_ippbx-1532440720|HangupEvent||IAX2/1111-2627|1111|ZZXXXXXXXXX|2018-07-24 15:58:40|2018-07-24 15:58:49|9|Unlink|Normal Clearing||||||
990000003|test_ippbx-1532522401|test_ippbx-1532522403|CdrEvent||Local/2222@default-00000001;1|2222|ZZXXXXXXXXX|2018-07-25 14:40:03|2018-07-25 14:40:06|3|Unlink|Normal Clearing||||||
990000004|test_ippbx-1532522447|test_ippbx-1532522449|CdrEvent||Local/2222@default-00000002;1|2222|ZZXXXXXXXXX|2018-07-25 14:40:49|2018-07-25 14:40:53|4|Unlink|Normal Clearing||||||
990000005|test_ippbx-1532522665|test_ippbx-1532522667|CdrEvent||Local/2222@default-00000003;1|2222|ZZXXXXXXXXX|2018-07-25 14:44:28|2018-07-25 14:44:32|4|Unlink|Normal Clearing||||||
990000006|test_ippbx-1532523043|test_ippbx-1532523046|HangupEvent||Local/2222@default-00000004;1|2222|ZZXXXXXXXXX|2018-07-25 14:50:46|2018-07-25 14:51:04|18|Unlink|Normal Clearing||||||
990000007|test_ippbx-1532590542|test_ippbx-1532590545|CdrEvent||IAX2/1111-8422|1111|ZZXXXXXXXXX|2018-07-26 09:35:45|2018-07-26 09:35:56|11||User busy|||ZZXXXXXXXXX|||
990000008|test_ippbx-1532591088|test_ippbx-1532591099|HangupEvent||IAX2/1111-2233|1111|ZZXXXXXXXXX|2018-07-26 09:44:59|2018-07-26 09:45:13|14|Unlink|Normal Clearing|||ZZXXXXXXXXX|||
990000009|test_ippbx-1532591175|test_ippbx-1532591179|CdrEvent||IAX2/1111-9025|1111|ZZXXXXXXXXX|2018-07-26 09:46:19|2018-07-26 09:46:21|2||Normal Clearing|||ZZXXXXXXXXX|||
990000010|test_ippbx-1532591435|test_ippbx-1532591439|HangupEvent||IAX2/1111-3008|1111|ZZXXXXXXXXX|2018-07-26 09:50:39|2018-07-26 09:50:51|12|Unlink|Normal Clearing|||ZZXXXXXXXXX|||
990000011|test_ippbx-1532591737|test_ippbx-1532591740|HangupEvent||IAX2/1111-4258|1111|ZZXXXXXXXXX|2018-07-26 09:55:40|2018-07-26 09:55:52|12|Unlink|Normal Clearing|||ZZXXXXXXXXX|||
990000012|test_ippbx-1532591790|test_ippbx-1532591793|HangupEvent||IAX2/1111-4821|1111|ZZXXXXXXXXX|2018-07-26 09:56:33|2018-07-26 09:56:46|13|Unlink|Normal Clearing|||ZZXXXXXXXXX|||
990000013|test_ippbx-1532591845|test_ippbx-1532591849|HangupEvent||IAX2/1111-4281|1111|ZZXXXXXXXXX|2018-07-26 09:57:29|2018-07-26 09:57:41|12|Unlink|Normal Clearing|||ZZXXXXXXXXX|||
990000014|test_ippbx-1532591963|test_ippbx-1532591967|HangupEvent||IAX2/1111-4562|1111|ZZXXXXXXXXX|2018-07-26 09:59:27|2018-07-26 09:59:34|7|Unlink|Normal Clearing|||ZZXXXXXXXXX|||
990000015|test_ippbx-1532592130|test_ippbx-1532592134|HangupEvent||IAX2/1111-10023|1111|ZZXXXXXXXXX|2018-07-26 10:02:14|2018-07-26 10:02:21|7|Unlink|Normal Clearing|||ZZXXXXXXXXX|||
990000016|test_ippbx-1532593270|test_ippbx-1532593280|HangupEvent||IAX2/1111-13890|1111|ZZXXXXXXXXX|2018-07-26 10:21:20|2018-07-26 10:21:26|6|Unlink|Normal Clearing|||ZZXXXXXXXXX|||

В консоли Asterisk при исходящем (click2call) звонке:

[Jul 26 10:21:20]     -- Executing [ZZXXXXXXXXX@from_crm:1] NoOp("IAX2/1111-13890", " from_crm: Outgoing call from "" <1111> to ZZXXXXXXXXX ") in new stack
[Jul 26 10:21:20]     -- Executing [ZZXXXXXXXXX@from_crm:2] Set("IAX2/1111-13890", "CONNECTEDLINE(name,i)=ZZXXXXXXXXX") in new stack
[Jul 26 10:21:20]     -- Executing [ZZXXXXXXXXX@from_crm:3] Set("IAX2/1111-13890", "CONNECTEDLINE(name-pres,i)=allowed") in new stack
[Jul 26 10:21:20]     -- Executing [ZZXXXXXXXXX@from_crm:4] NoOp("IAX2/1111-13890", " ZZXXXXXXXXX ") in new stack
[Jul 26 10:21:20]     -- Executing [ZZXXXXXXXXX@from_crm:5] Set("IAX2/1111-13890", "pstncallerid=ZZXXXXXXXXX") in new stack
[Jul 26 10:21:20]     -- Executing [ZZXXXXXXXXX@from_crm:6] Set("IAX2/1111-13890", "corpcallerid=1111") in new stack
[Jul 26 10:21:20]     -- Executing [ZZXXXXXXXXX@from_crm:7] Set("IAX2/1111-13890", "connline=1111") in new stack
[Jul 26 10:21:20]     -- Executing [ZZXXXXXXXXX@from_crm:8] NoOp("IAX2/1111-13890", " ZZXXXXXXXXX and 1111 and 1111 ") in new stack
[Jul 26 10:21:20]     -- Executing [ZZXXXXXXXXX@from_crm:9] Set("IAX2/1111-13890", "totalvar=ZZXXXXXXXXX,1111") in new stack
[Jul 26 10:21:20]     -- Executing [ZZXXXXXXXXX@from_crm:10] NoOp("IAX2/1111-13890", " from_crm: Outgoing call from 1111 to ZZXXXXXXXXX ") in new stack
[Jul 26 10:21:20]     -- Goto (from_crm,ZZXXXXXXXXX,43)
[Jul 26 10:21:20]     -- Executing [ZZXXXXXXXXX@from_crm:43] Dial("IAX2/1111-13890", "IAX2/mypeer/ZZXXXXXXXXX,,CI") in new stack
[Jul 26 10:21:20]     -- Called IAX2/mypeer/ZZXXXXXXXXX
[Jul 26 10:21:21]     -- IAX2/mypeer-19706 answered IAX2/1111-13890
[Jul 26 10:21:26]     -- Hungup 'IAX2/mypeer-19706'
[Jul 26 10:21:26]   == Spawn extension (from_crm, ZZXXXXXXXXX, 43) exited non-zero on 'IAX2/1111-13890'
[Jul 26 10:21:26]     -- Hungup 'IAX2/1111-13890'

Что получает/читает коннектор, переменные (value='' и variable=''):

2018-07-26 10:21:20,356 ... org.asteriskjava.manager.event.VarSetEvent[dateReceived='Thu Jul 26 10:21:20 CEST 2018', ... value='ZZXXXXXXXXX', ... ,variable='pstncallerid',accountcode=null,systemHashcode=932635906]

2018-07-26 10:21:20,370 ... org.asteriskjava.manager.event.VarSetEvent[dateReceived='Thu Jul 26 10:21:20 CEST 2018', ... value='1111', ... ,variable='corpcallerid',accountcode=null,systemHashcode=701282742]

2018-07-26 10:21:20,376 ... org.asteriskjava.manager.event.VarSetEvent[dateReceived='Thu Jul 26 10:21:20 CEST 2018', ... value='1111', ... ,variable='connline',accountcode=null,systemHashcode=700508763]

2018-07-26 10:21:20,380 ... org.asteriskjava.manager.event.VarSetEvent[dateReceived='Thu Jul 26 10:21:20 CEST2018', ... value='ZZXXXXXXXXX,1111', ... ,variable='totalvar',accountcode=null,systemHashcode=1173539316]

connectedLineName=ZZXXXXXXXXX - тоже по идее приходит правильно к конектору (?):

2018-07-26 10:21:20,400 command.helpers.CommandsExecutor INFO [Asterisk-Java ManagerConnection-0-Reader-0] - DialEvent [subEvent=Begin, ... connectedLineNum=1111, connectedLineName=ZZXXXXXXXXX]

Судя по тому что инфо. в логах есть и переменным присвоены значения то все должно быть Ок, но к сожалению в CRM эти данные не передаются:

...
2018-07-26 10:21:20,745 org.apache.http.impl.conn.DefaultClientConnection DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Sending request: POST /modules/PBXManager/callbacks/PBXManager.php HTTP/1.1
2018-07-26 10:21:20,745 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  >> "POST /modules/PBXManager/callbacks/PBXManager.php HTTP/1.1[\r][\n]"
...
2018-07-26 10:21:20,747 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  >> "vtigersignature=TEST20&pstncallerid=ZZXXXXXXXXX&corpcallerid&connline&totalvar&event=DialEvent&callerIdNumber=1111&dialString=mypeer%2FZZXXXXXXXXX&connectedLineName&StartTime=2018-07-26+10%3A21%3A20&callUUID=990000016&callstatus=DialBegin"
...

Тоесть из всех - pstncallerid,corpcallerid,connline,totalvar переменных правильно передается только pstncallerid (первая переменная которая приходит через VarSetEvent).

Методом перебора, удалось установить что коннектор передает и записывает в базу только первую переменную которая приходит через VarSetEvent:
если в диалплане указать

[from_crm]
exten => _X.,1,Noop( from_crm: Outgoing call from ${CALLERID(all)} to ${EXTEN} )
 same => n,Set(MyVAR1=TEST1)
 same => n,Set(MyVAR2=TEST2)
 same => n,Set(MyVAR3=TEST3)
 same => n,Set(MyVAR4=TEST4)

то POST будет таким:

"vtigersignature=TEST20&MyVAR1=TEST1&MyVAR2&MyVAR3&MyVAR4&event ..."

делаем перестановку

[from_crm]
exten => _X.,1,Noop( from_crm: Outgoing call from ${CALLERID(all)} to ${EXTEN} )
 same => n,Set(MyVAR3=TEST3)
same => n,Set(MyVAR1=TEST1)
 same => n,Set(MyVAR2=TEST2)
 same => n,Set(MyVAR4=TEST4)

POST будет таким:

"vtigersignature=TEST20&MyVAR1&MyVAR2&MyVAR3=TEST3&MyVAR4&event ..."

Весь лог коннектора при выполнени звонка:

[qtp88558700-16] INFO org.asteriskjava.manager.internal.ManagerConnectionImpl - Connecting to 127.0.0.1:5038
[Asterisk-Java ManagerConnection-1-Reader-0] INFO org.asteriskjava.manager.internal.ManagerConnectionImpl - Connected via Asterisk Call Manager/1.3
[qtp88558700-16] INFO org.asteriskjava.manager.internal.ManagerConnectionImpl - Successfully logged in
[qtp88558700-16] INFO org.asteriskjava.manager.internal.ManagerConnectionImpl - Determined Asterisk version: Asterisk 11
2018-07-26 10:21:10,865 command.helpers.CommandsExecutor INFO [Asterisk-Java ManagerConnection-0-Reader-0] - org.asteriskjava.manager.event.NewChannelEvent[dateReceived='Thu Jul 26 10:21:10 CEST 2018',privilege='call,all',linkedid=null,server=null,calleridname='',channel='IAX2/1111-13890',language=null,exten='s',calleridnum='',context='',state='Down',callerid='',connectedlinenum=null,uniqueid='test_ippbx-1532593270.18',timestamp=null,channelstatedesc='Down',systemname=null,connectedlinename=null,priority=null,sequencenumber=null,channelstate='0',accountcode='',systemHashcode=1435149760]
2018-07-26 10:21:10,866 command.helpers.CommandsExecutor INFO [Asterisk-Java ManagerConnection-0-Reader-0] - org.asteriskjava.manager.event.ChannelUpdateEvent[dateReceived='Thu Jul 26 10:21:10 CEST 2018',privilege='system,all',peername=null,server=null,calleridname=null,channel='',sipfullcontact=null,gtalksid=null,exten=null,calleridnum=null,channeltype='IAX2',context=null,connectedlinenum=null,uniqueid=null,sipcallid=null,iax2callnolocal='13890',timestamp=null,channelstatedesc=null,iax2peer='',systemname=null,connectedlinename=null,priority=null,sequencenumber=null,iax2callnoremote='0',channelstate=null,systemHashcode=530444254]
2018-07-26 10:21:10,866 command.helpers.CommandsExecutor INFO [Asterisk-Java ManagerConnection-0-Reader-0] - org.asteriskjava.manager.event.NewAccountCodeEvent[dateReceived='Thu Jul 26 10:21:10 CEST 2018',privilege='call,all',linkedid=null,server=null,calleridname=null,channel='IAX2/1111-13890',language=null,exten=null,calleridnum=null,context=null,connectedlinenum=null,uniqueid='test_ippbx-1532593270.18',timestamp=null,channelstatedesc=null,systemname=null,connectedlinename=null,priority=null,sequencenumber=null,channelstate=null,oldaccountcode='',accountcode='',systemHashcode=1091905091]
2018-07-26 10:21:10,867 command.helpers.CommandsExecutor INFO [Asterisk-Java ManagerConnection-0-Reader-0] - org.asteriskjava.manager.event.NewCallerIdEvent[dateReceived='Thu Jul 26 10:21:10 CEST 2018',privilege='call,all',linkedid=null,server=null,calleridname='',cidcallingprestxt='Presentation Allowed, Not Screened',channel='IAX2/1111-13890',language=null,exten=null,calleridnum='1111',context=null,callerid='1111',connectedlinenum=null,uniqueid='test_ippbx-1532593270.18',timestamp=null,channelstatedesc=null,systemname=null,connectedlinename=null,priority=null,sequencenumber=null,channelstate=null,cidcallingpres='0',accountcode=null,systemHashcode=1729554233]
2018-07-26 10:21:10,868 command.helpers.CommandsExecutor INFO [Asterisk-Java ManagerConnection-0-Reader-0] - org.asteriskjava.manager.event.NewStateEvent[dateReceived='Thu Jul 26 10:21:10 CEST 2018',privilege='call,all',linkedid=null,server=null,calleridname='',channel='IAX2/1111-13890',language=null,exten=null,calleridnum='1111',context=null,state='Ringing',callerid='1111',connectedlinenum='1111',uniqueid='test_ippbx-1532593270.18',timestamp=null,channelstatedesc='Ringing',systemname=null,connectedlinename='',priority=null,sequencenumber=null,channelstate='5',accountcode=null,systemHashcode=1205371387]
2018-07-26 10:21:20,338 command.helpers.CommandsExecutor INFO [Asterisk-Java ManagerConnection-0-Reader-0] - org.asteriskjava.manager.event.NewStateEvent[dateReceived='Thu Jul 26 10:21:20 CEST 2018',privilege='call,all',linkedid=null,server=null,calleridname='',channel='IAX2/1111-13890',language=null,exten=null,calleridnum='1111',context=null,state='Up',callerid='1111',connectedlinenum='1111',uniqueid='test_ippbx-1532593270.18',timestamp=null,channelstatedesc='Up',systemname=null,connectedlinename='',priority=null,sequencenumber=null,channelstate='6',accountcode=null,systemHashcode=2024447313]
2018-07-26 10:21:20,339 command.helpers.CommandsExecutor INFO [Asterisk-Java ManagerConnection-0-Reader-0] - org.asteriskjava.manager.event.NewExtenEvent[dateReceived='Thu Jul 26 10:21:20 CEST 2018',privilege='dialplan,all',linkedid=null,server=null,extension='ZZXXXXXXXXX',calleridname=null,channel='IAX2/1111-13890',language=null,exten=null,calleridnum=null,context='from_crm',connectedlinenum=null,uniqueid='test_ippbx-1532593270.18',timestamp=null,channelstatedesc=null,systemname=null,connectedlinename=null,priority='1',sequencenumber=null,channelstate=null,application='NoOp',accountcode=null,appdata='from_crm: Outgoing call from "" <1111> to ZZXXXXXXXXX',systemHashcode=993678993]
2018-07-26 10:21:20,340 command.helpers.CommandsExecutor INFO [Asterisk-Java ManagerConnection-0-Reader-0] - org.asteriskjava.manager.event.NewExtenEvent[dateReceived='Thu Jul 26 10:21:20 CEST 2018',privilege='dialplan,all',linkedid=null,server=null,extension='ZZXXXXXXXXX',calleridname=null,channel='IAX2/1111-13890',language=null,exten=null,calleridnum=null,context='from_crm',connectedlinenum=null,uniqueid='test_ippbx-1532593270.18',timestamp=null,channelstatedesc=null,systemname=null,connectedlinename=null,priority='2',sequencenumber=null,channelstate=null,application='Set',accountcode=null,appdata='CONNECTEDLINE(name,i)=ZZXXXXXXXXX',systemHashcode=946786132]
2018-07-26 10:21:20,340 command.helpers.CommandsExecutor INFO [Asterisk-Java ManagerConnection-0-Reader-0] - org.asteriskjava.manager.event.NewExtenEvent[dateReceived='Thu Jul 26 10:21:20 CEST 2018',privilege='dialplan,all',linkedid=null,server=null,extension='ZZXXXXXXXXX',calleridname=null,channel='IAX2/1111-13890',language=null,exten=null,calleridnum=null,context='from_crm',connectedlinenum=null,uniqueid='test_ippbx-1532593270.18',timestamp=null,channelstatedesc=null,systemname=null,connectedlinename=null,priority='3',sequencenumber=null,channelstate=null,application='Set',accountcode=null,appdata='CONNECTEDLINE(name-pres,i)=allowed',systemHashcode=335715613]
2018-07-26 10:21:20,340 command.helpers.CommandsExecutor INFO [Asterisk-Java ManagerConnection-0-Reader-0] - org.asteriskjava.manager.event.NewExtenEvent[dateReceived='Thu Jul 26 10:21:20 CEST 2018',privilege='dialplan,all',linkedid=null,server=null,extension='ZZXXXXXXXXX',calleridname=null,channel='IAX2/1111-13890',language=null,exten=null,calleridnum=null,context='from_crm',connectedlinenum=null,uniqueid='test_ippbx-1532593270.18',timestamp=null,channelstatedesc=null,systemname=null,connectedlinename=null,priority='4',sequencenumber=null,channelstate=null,application='NoOp',accountcode=null,appdata='ZZXXXXXXXXX',systemHashcode=281107149]
2018-07-26 10:21:20,355 command.helpers.CommandsExecutor INFO [Asterisk-Java ManagerConnection-0-Reader-0] - org.asteriskjava.manager.event.NewExtenEvent[dateReceived='Thu Jul 26 10:21:20 CEST 2018',privilege='dialplan,all',linkedid=null,server=null,extension='ZZXXXXXXXXX',calleridname=null,channel='IAX2/1111-13890',language=null,exten=null,calleridnum=null,context='from_crm',connectedlinenum=null,uniqueid='test_ippbx-1532593270.18',timestamp=null,channelstatedesc=null,systemname=null,connectedlinename=null,priority='5',sequencenumber=null,channelstate=null,application='Set',accountcode=null,appdata='pstncallerid=ZZXXXXXXXXX',systemHashcode=930905221]
2018-07-26 10:21:20,356 command.helpers.CommandsExecutor INFO [Asterisk-Java ManagerConnection-0-Reader-0] - org.asteriskjava.manager.event.VarSetEvent[dateReceived='Thu Jul 26 10:21:20 CEST 2018',privilege='dialplan,all',linkedid=null,server=null,calleridname=null,channel='IAX2/1111-13890',language=null,exten=null,calleridnum=null,context=null,value='ZZXXXXXXXXX',connectedlinenum=null,uniqueid='test_ippbx-1532593270.18',timestamp=null,channelstatedesc=null,systemname=null,connectedlinename=null,priority=null,sequencenumber=null,channelstate=null,variable='pstncallerid',accountcode=null,systemHashcode=932635906]
[qtp88558700-16] INFO org.asteriskjava.manager.internal.ManagerConnectionImpl - Closing socket.
2018-07-26 10:21:20,370 command.helpers.CommandsExecutor INFO [Asterisk-Java ManagerConnection-0-Reader-0] - org.asteriskjava.manager.event.NewExtenEvent[dateReceived='Thu Jul 26 10:21:20 CEST 2018',privilege='dialplan,all',linkedid=null,server=null,extension='ZZXXXXXXXXX',calleridname=null,channel='IAX2/1111-13890',language=null,exten=null,calleridnum=null,context='from_crm',connectedlinenum=null,uniqueid='test_ippbx-1532593270.18',timestamp=null,channelstatedesc=null,systemname=null,connectedlinename=null,priority='6',sequencenumber=null,channelstate=null,application='Set',accountcode=null,appdata='corpcallerid=1111',systemHashcode=765183503]
2018-07-26 10:21:20,370 command.helpers.CommandsExecutor INFO [Asterisk-Java ManagerConnection-0-Reader-0] - org.asteriskjava.manager.event.VarSetEvent[dateReceived='Thu Jul 26 10:21:20 CEST 2018',privilege='dialplan,all',linkedid=null,server=null,calleridname=null,channel='IAX2/1111-13890',language=null,exten=null,calleridnum=null,context=null,value='1111',connectedlinenum=null,uniqueid='test_ippbx-1532593270.18',timestamp=null,channelstatedesc=null,systemname=null,connectedlinename=null,priority=null,sequencenumber=null,channelstate=null,variable='corpcallerid',accountcode=null,systemHashcode=701282742]
[Asterisk-Java ManagerConnection-1-Reader-0] INFO org.asteriskjava.manager.internal.ManagerReaderImpl - Terminating reader thread: No more lines available: null
2018-07-26 10:21:20,375 command.helpers.CommandsExecutor INFO [Asterisk-Java ManagerConnection-0-Reader-0] - org.asteriskjava.manager.event.NewExtenEvent[dateReceived='Thu Jul 26 10:21:20 CEST 2018',privilege='dialplan,all',linkedid=null,server=null,extension='ZZXXXXXXXXX',calleridname=null,channel='IAX2/1111-13890',language=null,exten=null,calleridnum=null,context='from_crm',connectedlinenum=null,uniqueid='test_ippbx-1532593270.18',timestamp=null,channelstatedesc=null,systemname=null,connectedlinename=null,priority='7',sequencenumber=null,channelstate=null,application='Set',accountcode=null,appdata='connline=1111',systemHashcode=272869845]
2018-07-26 10:21:20,376 command.helpers.CommandsExecutor INFO [Asterisk-Java ManagerConnection-0-Reader-0] - org.asteriskjava.manager.event.VarSetEvent[dateReceived='Thu Jul 26 10:21:20 CEST 2018',privilege='dialplan,all',linkedid=null,server=null,calleridname=null,channel='IAX2/1111-13890',language=null,exten=null,calleridnum=null,context=null,value='1111',connectedlinenum=null,uniqueid='test_ippbx-1532593270.18',timestamp=null,channelstatedesc=null,systemname=null,connectedlinename=null,priority=null,sequencenumber=null,channelstate=null,variable='connline',accountcode=null,systemHashcode=700508763]
2018-07-26 10:21:20,377 command.helpers.CommandsExecutor INFO [Asterisk-Java ManagerConnection-0-Reader-0] - org.asteriskjava.manager.event.NewExtenEvent[dateReceived='Thu Jul 26 10:21:20 CEST 2018',privilege='dialplan,all',linkedid=null,server=null,extension='ZZXXXXXXXXX',calleridname=null,channel='IAX2/1111-13890',language=null,exten=null,calleridnum=null,context='from_crm',connectedlinenum=null,uniqueid='test_ippbx-1532593270.18',timestamp=null,channelstatedesc=null,systemname=null,connectedlinename=null,priority='8',sequencenumber=null,channelstate=null,application='NoOp',accountcode=null,appdata='ZZXXXXXXXXX and 1111 and 1111',systemHashcode=1834309790]
2018-07-26 10:21:20,377 command.helpers.CommandsExecutor INFO [Asterisk-Java ManagerConnection-0-Reader-0] - org.asteriskjava.manager.event.NewExtenEvent[dateReceived='Thu Jul 26 10:21:20 CEST 2018',privilege='dialplan,all',linkedid=null,server=null,extension='ZZXXXXXXXXX',calleridname=null,channel='IAX2/1111-13890',language=null,exten=null,calleridnum=null,context='from_crm',connectedlinenum=null,uniqueid='test_ippbx-1532593270.18',timestamp=null,channelstatedesc=null,systemname=null,connectedlinename=null,priority='9',sequencenumber=null,channelstate=null,application='Set',accountcode=null,appdata='totalvar=ZZXXXXXXXXX,1111',systemHashcode=35975302]
2018-07-26 10:21:20,380 command.helpers.CommandsExecutor INFO [Asterisk-Java ManagerConnection-0-Reader-0] - org.asteriskjava.manager.event.VarSetEvent[dateReceived='Thu Jul 26 10:21:20 CEST 2018',privilege='dialplan,all',linkedid=null,server=null,calleridname=null,channel='IAX2/1111-13890',language=null,exten=null,calleridnum=null,context=null,value='ZZXXXXXXXXX,1111',connectedlinenum=null,uniqueid='test_ippbx-1532593270.18',timestamp=null,channelstatedesc=null,systemname=null,connectedlinename=null,priority=null,sequencenumber=null,channelstate=null,variable='totalvar',accountcode=null,systemHashcode=1173539316]
2018-07-26 10:21:20,381 command.helpers.CommandsExecutor INFO [Asterisk-Java ManagerConnection-0-Reader-0] - org.asteriskjava.manager.event.NewExtenEvent[dateReceived='Thu Jul 26 10:21:20 CEST 2018',privilege='dialplan,all',linkedid=null,server=null,extension='ZZXXXXXXXXX',calleridname=null,channel='IAX2/1111-13890',language=null,exten=null,calleridnum=null,context='from_crm',connectedlinenum=null,uniqueid='test_ippbx-1532593270.18',timestamp=null,channelstatedesc=null,systemname=null,connectedlinename=null,priority='10',sequencenumber=null,channelstate=null,application='NoOp',accountcode=null,appdata='from_crm: Outgoing call from 1111 to ZZXXXXXXXXX',systemHashcode=652550356]
2018-07-26 10:21:20,392 command.helpers.CommandsExecutor INFO [Asterisk-Java ManagerConnection-0-Reader-0] - org.asteriskjava.manager.event.NewExtenEvent[dateReceived='Thu Jul 26 10:21:20 CEST 2018',privilege='dialplan,all',linkedid=null,server=null,extension='ZZXXXXXXXXX',calleridname=null,channel='IAX2/1111-13890',language=null,exten=null,calleridnum=null,context='from_crm',connectedlinenum=null,uniqueid='test_ippbx-1532593270.18',timestamp=null,channelstatedesc=null,systemname=null,connectedlinename=null,priority='43',sequencenumber=null,channelstate=null,application='Dial',accountcode=null,appdata='IAX2/mypeer/ZZXXXXXXXXX,,CI',systemHashcode=220545420]
2018-07-26 10:21:20,392 command.helpers.CommandsExecutor INFO [Asterisk-Java ManagerConnection-0-Reader-0] - org.asteriskjava.manager.event.VarSetEvent[dateReceived='Thu Jul 26 10:21:20 CEST 2018',privilege='dialplan,all',linkedid=null,server=null,calleridname=null,channel='IAX2/1111-13890',language=null,exten=null,calleridnum=null,context=null,value='',connectedlinenum=null,uniqueid='test_ippbx-1532593270.18',timestamp=null,channelstatedesc=null,systemname=null,connectedlinename=null,priority=null,sequencenumber=null,channelstate=null,variable='DIALSTATUS',accountcode=null,systemHashcode=2594581]
2018-07-26 10:21:20,394 command.helpers.CommandsExecutor INFO [Asterisk-Java ManagerConnection-0-Reader-0] - org.asteriskjava.manager.event.VarSetEvent[dateReceived='Thu Jul 26 10:21:20 CEST 2018',privilege='dialplan,all',linkedid=null,server=null,calleridname=null,channel='IAX2/1111-13890',language=null,exten=null,calleridnum=null,context=null,value='',connectedlinenum=null,uniqueid='test_ippbx-1532593270.18',timestamp=null,channelstatedesc=null,systemname=null,connectedlinename=null,priority=null,sequencenumber=null,channelstate=null,variable='DIALEDPEERNUMBER',accountcode=null,systemHashcode=2094957203]
2018-07-26 10:21:20,396 command.helpers.CommandsExecutor INFO [Asterisk-Java ManagerConnection-0-Reader-0] - org.asteriskjava.manager.event.VarSetEvent[dateReceived='Thu Jul 26 10:21:20 CEST 2018',privilege='dialplan,all',linkedid=null,server=null,calleridname=null,channel='IAX2/1111-13890',language=null,exten=null,calleridnum=null,context=null,value='',connectedlinenum=null,uniqueid='test_ippbx-1532593270.18',timestamp=null,channelstatedesc=null,systemname=null,connectedlinename=null,priority=null,sequencenumber=null,channelstate=null,variable='DIALEDPEERNAME',accountcode=null,systemHashcode=1151257166]
2018-07-26 10:21:20,396 command.helpers.CommandsExecutor INFO [Asterisk-Java ManagerConnection-0-Reader-0] - org.asteriskjava.manager.event.VarSetEvent[dateReceived='Thu Jul 26 10:21:20 CEST 2018',privilege='dialplan,all',linkedid=null,server=null,calleridname=null,channel='IAX2/1111-13890',language=null,exten=null,calleridnum=null,context=null,value='',connectedlinenum=null,uniqueid='test_ippbx-1532593270.18',timestamp=null,channelstatedesc=null,systemname=null,connectedlinename=null,priority=null,sequencenumber=null,channelstate=null,variable='ANSWEREDTIME',accountcode=null,systemHashcode=1574572137]
2018-07-26 10:21:20,396 command.helpers.CommandsExecutor INFO [Asterisk-Java ManagerConnection-0-Reader-0] - org.asteriskjava.manager.event.VarSetEvent[dateReceived='Thu Jul 26 10:21:20 CEST 2018',privilege='dialplan,all',linkedid=null,server=null,calleridname=null,channel='IAX2/1111-13890',language=null,exten=null,calleridnum=null,context=null,value='',connectedlinenum=null,uniqueid='test_ippbx-1532593270.18',timestamp=null,channelstatedesc=null,systemname=null,connectedlinename=null,priority=null,sequencenumber=null,channelstate=null,variable='DIALEDTIME',accountcode=null,systemHashcode=1526363171]
2018-07-26 10:21:20,397 command.helpers.CommandsExecutor INFO [Asterisk-Java ManagerConnection-0-Reader-0] - org.asteriskjava.manager.event.NewChannelEvent[dateReceived='Thu Jul 26 10:21:20 CEST 2018',privilege='call,all',linkedid=null,server=null,calleridname='',channel='IAX2/mypeer-19706',language=null,exten='s',calleridnum='',context='',state='Down',callerid='',connectedlinenum=null,uniqueid='test_ippbx-1532593280.19',timestamp=null,channelstatedesc='Down',systemname=null,connectedlinename=null,priority=null,sequencenumber=null,channelstate='0',accountcode='',systemHashcode=1379446773]
2018-07-26 10:21:20,397 command.helpers.CommandsExecutor INFO [Asterisk-Java ManagerConnection-0-Reader-0] - org.asteriskjava.manager.event.ChannelUpdateEvent[dateReceived='Thu Jul 26 10:21:20 CEST 2018',privilege='system,all',peername=null,server=null,calleridname=null,channel='',sipfullcontact=null,gtalksid=null,exten=null,calleridnum=null,channeltype='IAX2',context=null,connectedlinenum=null,uniqueid=null,sipcallid=null,iax2callnolocal='19706',timestamp=null,channelstatedesc=null,iax2peer='',systemname=null,connectedlinename=null,priority=null,sequencenumber=null,iax2callnoremote='0',channelstate=null,systemHashcode=1615254342]
2018-07-26 10:21:20,398 command.helpers.CommandsExecutor INFO [Asterisk-Java ManagerConnection-0-Reader-0] - org.asteriskjava.manager.event.VarSetEvent[dateReceived='Thu Jul 26 10:21:20 CEST 2018',privilege='dialplan,all',linkedid=null,server=null,calleridname=null,channel='IAX2/mypeer-19706',language=null,exten=null,calleridnum=null,context=null,value='mypeer/ZZXXXXXXXXX',connectedlinenum=null,uniqueid='test_ippbx-1532593280.19',timestamp=null,channelstatedesc=null,systemname=null,connectedlinename=null,priority=null,sequencenumber=null,channelstate=null,variable='DIALEDPEERNUMBER',accountcode=null,systemHashcode=1838337663]
2018-07-26 10:21:20,398 command.helpers.CommandsExecutor INFO [Asterisk-Java ManagerConnection-0-Reader-0] - org.asteriskjava.manager.event.NewCallerIdEvent[dateReceived='Thu Jul 26 10:21:20 CEST 2018',privilege='call,all',linkedid=null,server=null,calleridname='ZZXXXXXXXXX',cidcallingprestxt='Presentation Allowed, Not Screened',channel='IAX2/mypeer-19706',language=null,exten=null,calleridnum='ZZXXXXXXXXX',context=null,callerid='ZZXXXXXXXXX',connectedlinenum=null,uniqueid='test_ippbx-1532593280.19',timestamp=null,channelstatedesc=null,systemname=null,connectedlinename=null,priority=null,sequencenumber=null,channelstate=null,cidcallingpres='0',accountcode=null,systemHashcode=1681978498]
2018-07-26 10:21:20,399 command.helpers.CommandsExecutor INFO [Asterisk-Java ManagerConnection-0-Reader-0] - org.asteriskjava.manager.event.NewStateEvent[dateReceived='Thu Jul 26 10:21:20 CEST 2018',privilege='call,all',linkedid=null,server=null,calleridname='ZZXXXXXXXXX',channel='IAX2/mypeer-19706',language=null,exten=null,calleridnum='ZZXXXXXXXXX',context=null,state='Ringing',callerid='ZZXXXXXXXXX',connectedlinenum='1111',uniqueid='test_ippbx-1532593280.19',timestamp=null,channelstatedesc='Ringing',systemname=null,connectedlinename='',priority=null,sequencenumber=null,channelstate='5',accountcode=null,systemHashcode=1938860280]
2018-07-26 10:21:20,400 command.helpers.CommandsExecutor INFO [Asterisk-Java ManagerConnection-0-Reader-0] - DialEvent [subEvent=Begin, channel=IAX2/1111-13890, destination=IAX2/mypeer-19706, callerIdNum=1111, callerIdName=null, uniqueId=test_ippbx-1532593270.18, destUniqueId=test_ippbx-1532593280.19, dialString=mypeer/ZZXXXXXXXXX, dialStatus=null, connectedLineNum=1111, connectedLineName=ZZXXXXXXXXX]
2018-07-26 10:21:20,712 org.apache.http.impl.conn.tsccm.ThreadSafeClientConnManager DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Get connection: {}->http://test-vtiger-sp.local, timeout = 0
2018-07-26 10:21:20,713 org.apache.http.impl.conn.tsccm.ConnPoolByRoute DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - [{}->http://test-vtiger-sp.local] total kept alive: 0, total issued: 0, total allocated: 0 out of 20
2018-07-26 10:21:20,713 org.apache.http.impl.conn.tsccm.ConnPoolByRoute DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - No free connections [{}->http://test-vtiger-sp.local][null]
2018-07-26 10:21:20,713 org.apache.http.impl.conn.tsccm.ConnPoolByRoute DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Available capacity: 2 out of 2 [{}->http://test-vtiger-sp.local][null]
2018-07-26 10:21:20,713 org.apache.http.impl.conn.tsccm.ConnPoolByRoute DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Creating new connection [{}->http://test-vtiger-sp.local]
2018-07-26 10:21:20,721 org.apache.http.impl.conn.DefaultClientConnectionOperator DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Connecting to test-vtiger-sp.local:80
2018-07-26 10:21:20,735 org.apache.http.client.protocol.RequestAddCookies DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - CookieSpec selected: best-match
2018-07-26 10:21:20,742 org.apache.http.client.protocol.RequestAuthCache DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Auth cache not set in the context
2018-07-26 10:21:20,742 org.apache.http.client.protocol.RequestTargetAuthentication DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Target auth state: UNCHALLENGED
2018-07-26 10:21:20,745 org.apache.http.client.protocol.RequestProxyAuthentication DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Proxy auth state: UNCHALLENGED
2018-07-26 10:21:20,745 org.apache.http.impl.client.DefaultHttpClient DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Attempt 1 to execute request
2018-07-26 10:21:20,745 org.apache.http.impl.conn.DefaultClientConnection DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Sending request: POST /modules/PBXManager/callbacks/PBXManager.php HTTP/1.1
2018-07-26 10:21:20,745 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  >> "POST /modules/PBXManager/callbacks/PBXManager.php HTTP/1.1[\r][\n]"
2018-07-26 10:21:20,746 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  >> "Content-Length: 246[\r][\n]"
2018-07-26 10:21:20,746 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  >> "Content-Type: application/x-www-form-urlencoded; charset=UTF-8[\r][\n]"
2018-07-26 10:21:20,746 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  >> "Host: test-vtiger-sp.local[\r][\n]"
2018-07-26 10:21:20,746 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  >> "Connection: Keep-Alive[\r][\n]"
2018-07-26 10:21:20,746 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  >> "[\r][\n]"
2018-07-26 10:21:20,746 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - >> POST /modules/PBXManager/callbacks/PBXManager.php HTTP/1.1
2018-07-26 10:21:20,746 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - >> Content-Length: 246
2018-07-26 10:21:20,747 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - >> Content-Type: application/x-www-form-urlencoded; charset=UTF-8
2018-07-26 10:21:20,747 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - >> Host: test-vtiger-sp.local
2018-07-26 10:21:20,747 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - >> Connection: Keep-Alive
2018-07-26 10:21:20,747 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  >> "vtigersignature=TEST20&pstncallerid=ZZXXXXXXXXX&corpcallerid&connline&totalvar&event=DialEvent&callerIdNumber=1111&dialString=mypeer%2FZZXXXXXXXXX&connectedLineName&StartTime=2018-07-26+10%3A21%3A20&callUUID=990000016&callstatus=DialBegin"
2018-07-26 10:21:21,006 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  << "HTTP/1.1 200 OK[\r][\n]"
2018-07-26 10:21:21,008 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  << "Date: Thu, 26 Jul 2018 08:21:20 GMT[\r][\n]"
2018-07-26 10:21:21,008 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  << "Server: Apache/2.4.6 () PHP/5.6.31[\r][\n]"
2018-07-26 10:21:21,008 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  << "X-Powered-By: PHP/5.6.31[\r][\n]"
2018-07-26 10:21:21,008 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  << "Content-Length: 0[\r][\n]"
2018-07-26 10:21:21,008 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  << "Keep-Alive: timeout=5, max=100[\r][\n]"
2018-07-26 10:21:21,008 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  << "Connection: Keep-Alive[\r][\n]"
2018-07-26 10:21:21,008 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  << "Content-Type: text/html; charset=UTF-8[\r][\n]"
2018-07-26 10:21:21,008 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  << "[\r][\n]"
2018-07-26 10:21:21,009 org.apache.http.impl.conn.DefaultClientConnection DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Receiving response: HTTP/1.1 200 OK
2018-07-26 10:21:21,009 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - << HTTP/1.1 200 OK
2018-07-26 10:21:21,009 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - << Date: Thu, 26 Jul 2018 08:21:20 GMT
2018-07-26 10:21:21,009 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - << Server: Apache/2.4.6 () PHP/5.6.31
2018-07-26 10:21:21,009 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - << X-Powered-By: PHP/5.6.31
2018-07-26 10:21:21,009 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - << Content-Length: 0
2018-07-26 10:21:21,009 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - << Keep-Alive: timeout=5, max=100
2018-07-26 10:21:21,009 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - << Connection: Keep-Alive
2018-07-26 10:21:21,009 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - << Content-Type: text/html; charset=UTF-8
2018-07-26 10:21:21,014 org.apache.http.impl.client.DefaultHttpClient DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Connection can be kept alive for 5000 MILLISECONDS
2018-07-26 10:21:21,503 command.helpers.CommandsExecutor INFO [Asterisk-Java ManagerConnection-0-Reader-0] - org.asteriskjava.manager.event.NewStateEvent[dateReceived='Thu Jul 26 10:21:21 CEST 2018',privilege='call,all',linkedid=null,server=null,calleridname='ZZXXXXXXXXX',channel='IAX2/mypeer-19706',language=null,exten=null,calleridnum='ZZXXXXXXXXX',context=null,state='Up',callerid='ZZXXXXXXXXX',connectedlinenum='1111',uniqueid='test_ippbx-1532593280.19',timestamp=null,channelstatedesc='Up',systemname=null,connectedlinename='',priority=null,sequencenumber=null,channelstate='6',accountcode=null,systemHashcode=785128601]
2018-07-26 10:21:21,503 command.helpers.CommandsExecutor INFO [Asterisk-Java ManagerConnection-0-Reader-0] - org.asteriskjava.manager.event.VarSetEvent[dateReceived='Thu Jul 26 10:21:21 CEST 2018',privilege='dialplan,all',linkedid=null,server=null,calleridname=null,channel='IAX2/1111-13890',language=null,exten=null,calleridnum=null,context=null,value='ANSWER',connectedlinenum=null,uniqueid='test_ippbx-1532593270.18',timestamp=null,channelstatedesc=null,systemname=null,connectedlinename=null,priority=null,sequencenumber=null,channelstate=null,variable='DIALSTATUS',accountcode=null,systemHashcode=919297227]
2018-07-26 10:21:21,504 command.helpers.CommandsExecutor INFO [Asterisk-Java ManagerConnection-0-Reader-0] - org.asteriskjava.manager.event.VarSetEvent[dateReceived='Thu Jul 26 10:21:21 CEST 2018',privilege='dialplan,all',linkedid=null,server=null,calleridname=null,channel='IAX2/1111-13890',language=null,exten=null,calleridnum=null,context=null,value='IAX2/mypeer-19706',connectedlinenum=null,uniqueid='test_ippbx-1532593270.18',timestamp=null,channelstatedesc=null,systemname=null,connectedlinename=null,priority=null,sequencenumber=null,channelstate=null,variable='DIALEDPEERNAME',accountcode=null,systemHashcode=126124716]
2018-07-26 10:21:21,504 command.helpers.CommandsExecutor INFO [Asterisk-Java ManagerConnection-0-Reader-0] - org.asteriskjava.manager.event.VarSetEvent[dateReceived='Thu Jul 26 10:21:21 CEST 2018',privilege='dialplan,all',linkedid=null,server=null,calleridname=null,channel='IAX2/1111-13890',language=null,exten=null,calleridnum=null,context=null,value='mypeer/ZZXXXXXXXXX',connectedlinenum=null,uniqueid='test_ippbx-1532593270.18',timestamp=null,channelstatedesc=null,systemname=null,connectedlinename=null,priority=null,sequencenumber=null,channelstate=null,variable='DIALEDPEERNUMBER',accountcode=null,systemHashcode=162216333]
2018-07-26 10:21:21,504 command.helpers.CommandsExecutor INFO [Asterisk-Java ManagerConnection-0-Reader-0] - org.asteriskjava.manager.event.VarSetEvent[dateReceived='Thu Jul 26 10:21:21 CEST 2018',privilege='dialplan,all',linkedid=null,server=null,calleridname=null,channel='IAX2/1111-13890',language=null,exten=null,calleridnum=null,context=null,value='IAX2/mypeer-19706',connectedlinenum=null,uniqueid='test_ippbx-1532593270.18',timestamp=null,channelstatedesc=null,systemname=null,connectedlinename=null,priority=null,sequencenumber=null,channelstate=null,variable='BRIDGEPEER',accountcode=null,systemHashcode=1196279029]
2018-07-26 10:21:21,505 command.helpers.CommandsExecutor INFO [Asterisk-Java ManagerConnection-0-Reader-0] - org.asteriskjava.manager.event.VarSetEvent[dateReceived='Thu Jul 26 10:21:21 CEST 2018',privilege='dialplan,all',linkedid=null,server=null,calleridname=null,channel='IAX2/mypeer-19706',language=null,exten=null,calleridnum=null,context=null,value='IAX2/1111-13890',connectedlinenum=null,uniqueid='test_ippbx-1532593280.19',timestamp=null,channelstatedesc=null,systemname=null,connectedlinename=null,priority=null,sequencenumber=null,channelstate=null,variable='BRIDGEPEER',accountcode=null,systemHashcode=722269651]
2018-07-26 10:21:21,505 command.helpers.CommandsExecutor INFO [Asterisk-Java ManagerConnection-0-Reader-0] - org.asteriskjava.manager.event.NewAccountCodeEvent[dateReceived='Thu Jul 26 10:21:21 CEST 2018',privilege='call,all',linkedid=null,server=null,calleridname=null,channel='IAX2/mypeer-19706',language=null,exten=null,calleridnum=null,context=null,connectedlinenum=null,uniqueid='test_ippbx-1532593280.19',timestamp=null,channelstatedesc=null,systemname=null,connectedlinename=null,priority=null,sequencenumber=null,channelstate=null,oldaccountcode='',accountcode='',systemHashcode=146707452]
2018-07-26 10:21:21,506 command.helpers.CommandsExecutor INFO [Asterisk-Java ManagerConnection-0-Reader-0] - org.asteriskjava.manager.event.BridgeEvent[dateReceived='Thu Jul 26 10:21:21 CEST 2018',privilege='call,all',server=null,calleridname=null,link='true',exten=null,calleridnum=null,context=null,connectedlinenum=null,timestamp=null,channelstatedesc=null,bridgestate='Link',systemname=null,bridgetype='core',channel1='IAX2/1111-13890',channel2='IAX2/mypeer-19706',connectedlinename=null,uniqueid2='test_ippbx-1532593280.19',priority=null,sequencenumber=null,channelstate=null,uniqueid1='test_ippbx-1532593270.18',callerid1='1111',unlink='false',callerid2='ZZXXXXXXXXX',systemHashcode=1900718527]
2018-07-26 10:21:21,532 org.apache.http.impl.conn.tsccm.ThreadSafeClientConnManager DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Get connection: {}->http://test-vtiger-sp.local, timeout = 0
2018-07-26 10:21:21,532 org.apache.http.impl.conn.tsccm.ConnPoolByRoute DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - [{}->http://test-vtiger-sp.local] total kept alive: 0, total issued: 0, total allocated: 0 out of 20
2018-07-26 10:21:21,532 org.apache.http.impl.conn.tsccm.ConnPoolByRoute DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - No free connections [{}->http://test-vtiger-sp.local][null]
2018-07-26 10:21:21,532 org.apache.http.impl.conn.tsccm.ConnPoolByRoute DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Available capacity: 2 out of 2 [{}->http://test-vtiger-sp.local][null]
2018-07-26 10:21:21,532 org.apache.http.impl.conn.tsccm.ConnPoolByRoute DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Creating new connection [{}->http://test-vtiger-sp.local]
2018-07-26 10:21:21,532 org.apache.http.impl.conn.DefaultClientConnectionOperator DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Connecting to test-vtiger-sp.local:80
2018-07-26 10:21:21,534 org.apache.http.client.protocol.RequestAddCookies DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - CookieSpec selected: best-match
2018-07-26 10:21:21,534 org.apache.http.client.protocol.RequestAuthCache DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Auth cache not set in the context
2018-07-26 10:21:21,534 org.apache.http.client.protocol.RequestTargetAuthentication DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Target auth state: UNCHALLENGED
2018-07-26 10:21:21,534 org.apache.http.client.protocol.RequestProxyAuthentication DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Proxy auth state: UNCHALLENGED
2018-07-26 10:21:21,534 org.apache.http.impl.client.DefaultHttpClient DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Attempt 1 to execute request
2018-07-26 10:21:21,535 org.apache.http.impl.conn.DefaultClientConnection DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Sending request: POST /modules/PBXManager/callbacks/PBXManager.php HTTP/1.1
2018-07-26 10:21:21,535 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  >> "POST /modules/PBXManager/callbacks/PBXManager.php HTTP/1.1[\r][\n]"
2018-07-26 10:21:21,535 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  >> "Content-Length: 278[\r][\n]"
2018-07-26 10:21:21,535 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  >> "Content-Type: application/x-www-form-urlencoded; charset=UTF-8[\r][\n]"
2018-07-26 10:21:21,535 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  >> "Host: test-vtiger-sp.local[\r][\n]"
2018-07-26 10:21:21,535 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  >> "Connection: Keep-Alive[\r][\n]"
2018-07-26 10:21:21,535 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  >> "[\r][\n]"
2018-07-26 10:21:21,535 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - >> POST /modules/PBXManager/callbacks/PBXManager.php HTTP/1.1
2018-07-26 10:21:21,535 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - >> Content-Length: 278
2018-07-26 10:21:21,535 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - >> Content-Type: application/x-www-form-urlencoded; charset=UTF-8
2018-07-26 10:21:21,535 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - >> Host: test-vtiger-sp.local
2018-07-26 10:21:21,535 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - >> Connection: Keep-Alive
2018-07-26 10:21:21,535 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  >> "vtigersignature=TEST20&pstncallerid=ZZXXXXXXXXX&corpcallerid&connline&totalvar&uniqueid1=test_ippbx-1532593270&uniqueid2=test_ippbx-1532593280&callerid1=1111&callerid2=mypeer&dateReceived=Thu+Jul+26+10%3A21%3A21+CEST+2018&callUUID=990000016&callstatus=DialAnswer"
2018-07-26 10:21:21,585 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  << "HTTP/1.1 200 OK[\r][\n]"
2018-07-26 10:21:21,585 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  << "Date: Thu, 26 Jul 2018 08:21:21 GMT[\r][\n]"
2018-07-26 10:21:21,585 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  << "Server: Apache/2.4.6 () PHP/5.6.31[\r][\n]"
2018-07-26 10:21:21,585 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  << "X-Powered-By: PHP/5.6.31[\r][\n]"
2018-07-26 10:21:21,585 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  << "Content-Length: 0[\r][\n]"
2018-07-26 10:21:21,585 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  << "Keep-Alive: timeout=5, max=100[\r][\n]"
2018-07-26 10:21:21,585 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  << "Connection: Keep-Alive[\r][\n]"
2018-07-26 10:21:21,586 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  << "Content-Type: text/html; charset=UTF-8[\r][\n]"
2018-07-26 10:21:21,586 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  << "[\r][\n]"
2018-07-26 10:21:21,586 org.apache.http.impl.conn.DefaultClientConnection DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Receiving response: HTTP/1.1 200 OK
2018-07-26 10:21:21,586 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - << HTTP/1.1 200 OK
2018-07-26 10:21:21,586 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - << Date: Thu, 26 Jul 2018 08:21:21 GMT
2018-07-26 10:21:21,586 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - << Server: Apache/2.4.6 () PHP/5.6.31
2018-07-26 10:21:21,586 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - << X-Powered-By: PHP/5.6.31
2018-07-26 10:21:21,586 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - << Content-Length: 0
2018-07-26 10:21:21,586 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - << Keep-Alive: timeout=5, max=100
2018-07-26 10:21:21,586 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - << Connection: Keep-Alive
2018-07-26 10:21:21,586 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - << Content-Type: text/html; charset=UTF-8
2018-07-26 10:21:21,586 org.apache.http.impl.client.DefaultHttpClient DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Connection can be kept alive for 5000 MILLISECONDS
2018-07-26 10:21:21,587 command.helpers.CommandsExecutor INFO [Asterisk-Java ManagerConnection-0-Reader-0] - org.asteriskjava.manager.event.VarSetEvent[dateReceived='Thu Jul 26 10:21:21 CEST 2018',privilege='dialplan,all',linkedid=null,server=null,calleridname=null,channel='IAX2/1111-13890',language=null,exten=null,calleridnum=null,context=null,value='IAX2/mypeer-19706',connectedlinenum=null,uniqueid='test_ippbx-1532593270.18',timestamp=null,channelstatedesc=null,systemname=null,connectedlinename=null,priority=null,sequencenumber=null,channelstate=null,variable='BRIDGEPEER',accountcode=null,systemHashcode=434918205]
2018-07-26 10:21:21,589 command.helpers.CommandsExecutor INFO [Asterisk-Java ManagerConnection-0-Reader-0] - org.asteriskjava.manager.event.VarSetEvent[dateReceived='Thu Jul 26 10:21:21 CEST 2018',privilege='dialplan,all',linkedid=null,server=null,calleridname=null,channel='IAX2/mypeer-19706',language=null,exten=null,calleridnum=null,context=null,value='IAX2/1111-13890',connectedlinenum=null,uniqueid='test_ippbx-1532593280.19',timestamp=null,channelstatedesc=null,systemname=null,connectedlinename=null,priority=null,sequencenumber=null,channelstate=null,variable='BRIDGEPEER',accountcode=null,systemHashcode=1703772699]
2018-07-26 10:21:21,589 command.helpers.CommandsExecutor INFO [Asterisk-Java ManagerConnection-0-Reader-0] - org.asteriskjava.manager.event.VarSetEvent[dateReceived='Thu Jul 26 10:21:21 CEST 2018',privilege='dialplan,all',linkedid=null,server=null,calleridname=null,channel='IAX2/1111-13890',language=null,exten=null,calleridnum=null,context=null,value='IAX2/mypeer-19706',connectedlinenum=null,uniqueid='test_ippbx-1532593270.18',timestamp=null,channelstatedesc=null,systemname=null,connectedlinename=null,priority=null,sequencenumber=null,channelstate=null,variable='BRIDGEPEER',accountcode=null,systemHashcode=1731011508]
2018-07-26 10:21:21,589 command.helpers.CommandsExecutor INFO [Asterisk-Java ManagerConnection-0-Reader-0] - org.asteriskjava.manager.event.VarSetEvent[dateReceived='Thu Jul 26 10:21:21 CEST 2018',privilege='dialplan,all',linkedid=null,server=null,calleridname=null,channel='IAX2/mypeer-19706',language=null,exten=null,calleridnum=null,context=null,value='IAX2/1111-13890',connectedlinenum=null,uniqueid='test_ippbx-1532593280.19',timestamp=null,channelstatedesc=null,systemname=null,connectedlinename=null,priority=null,sequencenumber=null,channelstate=null,variable='BRIDGEPEER',accountcode=null,systemHashcode=472113623]
2018-07-26 10:21:21,590 command.helpers.CommandsExecutor INFO [Asterisk-Java ManagerConnection-0-Reader-0] - org.asteriskjava.manager.event.BridgeEvent[dateReceived='Thu Jul 26 10:21:21 CEST 2018',privilege='call,all',server=null,calleridname=null,link='false',exten=null,calleridnum=null,context=null,connectedlinenum=null,timestamp=null,channelstatedesc=null,bridgestate='Unlink',systemname=null,bridgetype='core',channel1='IAX2/1111-13890',channel2='IAX2/mypeer-19706',connectedlinename=null,uniqueid2='test_ippbx-1532593280.19',priority=null,sequencenumber=null,channelstate=null,uniqueid1='test_ippbx-1532593270.18',callerid1='1111',unlink='true',callerid2='ZZXXXXXXXXX',systemHashcode=711670015]
2018-07-26 10:21:21,607 org.apache.http.impl.conn.tsccm.ThreadSafeClientConnManager DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Get connection: {}->http://test-vtiger-sp.local, timeout = 0
2018-07-26 10:21:21,607 org.apache.http.impl.conn.tsccm.ConnPoolByRoute DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - [{}->http://test-vtiger-sp.local] total kept alive: 0, total issued: 0, total allocated: 0 out of 20
2018-07-26 10:21:21,607 org.apache.http.impl.conn.tsccm.ConnPoolByRoute DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - No free connections [{}->http://test-vtiger-sp.local][null]
2018-07-26 10:21:21,607 org.apache.http.impl.conn.tsccm.ConnPoolByRoute DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Available capacity: 2 out of 2 [{}->http://test-vtiger-sp.local][null]
2018-07-26 10:21:21,607 org.apache.http.impl.conn.tsccm.ConnPoolByRoute DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Creating new connection [{}->http://test-vtiger-sp.local]
2018-07-26 10:21:21,607 org.apache.http.impl.conn.DefaultClientConnectionOperator DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Connecting to test-vtiger-sp.local:80
2018-07-26 10:21:21,615 org.apache.http.client.protocol.RequestAddCookies DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - CookieSpec selected: best-match
2018-07-26 10:21:21,616 org.apache.http.client.protocol.RequestAuthCache DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Auth cache not set in the context
2018-07-26 10:21:21,616 org.apache.http.client.protocol.RequestTargetAuthentication DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Target auth state: UNCHALLENGED
2018-07-26 10:21:21,616 org.apache.http.client.protocol.RequestProxyAuthentication DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Proxy auth state: UNCHALLENGED
2018-07-26 10:21:21,616 org.apache.http.impl.client.DefaultHttpClient DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Attempt 1 to execute request
2018-07-26 10:21:21,616 org.apache.http.impl.conn.DefaultClientConnection DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Sending request: POST /modules/PBXManager/callbacks/PBXManager.php HTTP/1.1
2018-07-26 10:21:21,616 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  >> "POST /modules/PBXManager/callbacks/PBXManager.php HTTP/1.1[\r][\n]"
2018-07-26 10:21:21,616 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  >> "Content-Length: 278[\r][\n]"
2018-07-26 10:21:21,616 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  >> "Content-Type: application/x-www-form-urlencoded; charset=UTF-8[\r][\n]"
2018-07-26 10:21:21,616 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  >> "Host: test-vtiger-sp.local[\r][\n]"
2018-07-26 10:21:21,616 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  >> "Connection: Keep-Alive[\r][\n]"
2018-07-26 10:21:21,616 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  >> "[\r][\n]"
2018-07-26 10:21:21,616 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - >> POST /modules/PBXManager/callbacks/PBXManager.php HTTP/1.1
2018-07-26 10:21:21,616 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - >> Content-Length: 278
2018-07-26 10:21:21,616 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - >> Content-Type: application/x-www-form-urlencoded; charset=UTF-8
2018-07-26 10:21:21,616 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - >> Host: test-vtiger-sp.local
2018-07-26 10:21:21,616 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - >> Connection: Keep-Alive
2018-07-26 10:21:21,617 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  >> "vtigersignature=TEST20&pstncallerid=ZZXXXXXXXXX&corpcallerid&connline&totalvar&uniqueid1=test_ippbx-1532593270&uniqueid2=test_ippbx-1532593280&callerid1=1111&callerid2=mypeer&dateReceived=Thu+Jul+26+10%3A21%3A21+CEST+2018&callUUID=990000016&callstatus=DialAnswer"
2018-07-26 10:21:21,670 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  << "HTTP/1.1 200 OK[\r][\n]"
2018-07-26 10:21:21,670 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  << "Date: Thu, 26 Jul 2018 08:21:21 GMT[\r][\n]"
2018-07-26 10:21:21,670 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  << "Server: Apache/2.4.6 () PHP/5.6.31[\r][\n]"
2018-07-26 10:21:21,670 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  << "X-Powered-By: PHP/5.6.31[\r][\n]"
2018-07-26 10:21:21,670 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  << "Content-Length: 0[\r][\n]"
2018-07-26 10:21:21,670 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  << "Keep-Alive: timeout=5, max=100[\r][\n]"
2018-07-26 10:21:21,670 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  << "Connection: Keep-Alive[\r][\n]"
2018-07-26 10:21:21,670 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  << "Content-Type: text/html; charset=UTF-8[\r][\n]"
2018-07-26 10:21:21,670 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  << "[\r][\n]"
2018-07-26 10:21:21,670 org.apache.http.impl.conn.DefaultClientConnection DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Receiving response: HTTP/1.1 200 OK
2018-07-26 10:21:21,670 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - << HTTP/1.1 200 OK
2018-07-26 10:21:21,670 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - << Date: Thu, 26 Jul 2018 08:21:21 GMT
2018-07-26 10:21:21,670 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - << Server: Apache/2.4.6 () PHP/5.6.31
2018-07-26 10:21:21,670 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - << X-Powered-By: PHP/5.6.31
2018-07-26 10:21:21,671 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - << Content-Length: 0
2018-07-26 10:21:21,671 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - << Keep-Alive: timeout=5, max=100
2018-07-26 10:21:21,671 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - << Connection: Keep-Alive
2018-07-26 10:21:21,671 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - << Content-Type: text/html; charset=UTF-8
2018-07-26 10:21:21,671 org.apache.http.impl.client.DefaultHttpClient DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Connection can be kept alive for 5000 MILLISECONDS
2018-07-26 10:21:21,671 command.helpers.CommandsExecutor INFO [Asterisk-Java ManagerConnection-0-Reader-0] - org.asteriskjava.manager.event.BridgeEvent[dateReceived='Thu Jul 26 10:21:21 CEST 2018',privilege='call,all',server=null,calleridname=null,link='true',exten=null,calleridnum=null,context=null,connectedlinenum=null,timestamp=null,channelstatedesc=null,bridgestate='Link',systemname=null,bridgetype='core',channel1='IAX2/1111-13890',channel2='IAX2/mypeer-19706',connectedlinename=null,uniqueid2='test_ippbx-1532593280.19',priority=null,sequencenumber=null,channelstate=null,uniqueid1='test_ippbx-1532593270.18',callerid1='1111',unlink='false',callerid2='ZZXXXXXXXXX',systemHashcode=787426445]
2018-07-26 10:21:21,679 org.apache.http.impl.conn.tsccm.ThreadSafeClientConnManager DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Get connection: {}->http://test-vtiger-sp.local, timeout = 0
2018-07-26 10:21:21,680 org.apache.http.impl.conn.tsccm.ConnPoolByRoute DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - [{}->http://test-vtiger-sp.local] total kept alive: 0, total issued: 0, total allocated: 0 out of 20
2018-07-26 10:21:21,680 org.apache.http.impl.conn.tsccm.ConnPoolByRoute DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - No free connections [{}->http://test-vtiger-sp.local][null]
2018-07-26 10:21:21,680 org.apache.http.impl.conn.tsccm.ConnPoolByRoute DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Available capacity: 2 out of 2 [{}->http://test-vtiger-sp.local][null]
2018-07-26 10:21:21,680 org.apache.http.impl.conn.tsccm.ConnPoolByRoute DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Creating new connection [{}->http://test-vtiger-sp.local]
2018-07-26 10:21:21,680 org.apache.http.impl.conn.DefaultClientConnectionOperator DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Connecting to test-vtiger-sp.local:80
2018-07-26 10:21:21,682 org.apache.http.client.protocol.RequestAddCookies DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - CookieSpec selected: best-match
2018-07-26 10:21:21,682 org.apache.http.client.protocol.RequestAuthCache DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Auth cache not set in the context
2018-07-26 10:21:21,682 org.apache.http.client.protocol.RequestTargetAuthentication DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Target auth state: UNCHALLENGED
2018-07-26 10:21:21,683 org.apache.http.client.protocol.RequestProxyAuthentication DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Proxy auth state: UNCHALLENGED
2018-07-26 10:21:21,683 org.apache.http.impl.client.DefaultHttpClient DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Attempt 1 to execute request
2018-07-26 10:21:21,683 org.apache.http.impl.conn.DefaultClientConnection DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Sending request: POST /modules/PBXManager/callbacks/PBXManager.php HTTP/1.1
2018-07-26 10:21:21,683 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  >> "POST /modules/PBXManager/callbacks/PBXManager.php HTTP/1.1[\r][\n]"
2018-07-26 10:21:21,683 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  >> "Content-Length: 278[\r][\n]"
2018-07-26 10:21:21,683 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  >> "Content-Type: application/x-www-form-urlencoded; charset=UTF-8[\r][\n]"
2018-07-26 10:21:21,683 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  >> "Host: test-vtiger-sp.local[\r][\n]"
2018-07-26 10:21:21,683 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  >> "Connection: Keep-Alive[\r][\n]"
2018-07-26 10:21:21,683 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  >> "[\r][\n]"
2018-07-26 10:21:21,683 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - >> POST /modules/PBXManager/callbacks/PBXManager.php HTTP/1.1
2018-07-26 10:21:21,683 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - >> Content-Length: 278
2018-07-26 10:21:21,683 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - >> Content-Type: application/x-www-form-urlencoded; charset=UTF-8
2018-07-26 10:21:21,683 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - >> Host: test-vtiger-sp.local
2018-07-26 10:21:21,683 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - >> Connection: Keep-Alive
2018-07-26 10:21:21,683 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  >> "vtigersignature=TEST20&pstncallerid=ZZXXXXXXXXX&corpcallerid&connline&totalvar&uniqueid1=test_ippbx-1532593270&uniqueid2=test_ippbx-1532593280&callerid1=1111&callerid2=mypeer&dateReceived=Thu+Jul+26+10%3A21%3A21+CEST+2018&callUUID=990000016&callstatus=DialAnswer"
2018-07-26 10:21:21,738 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  << "HTTP/1.1 200 OK[\r][\n]"
2018-07-26 10:21:21,738 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  << "Date: Thu, 26 Jul 2018 08:21:21 GMT[\r][\n]"
2018-07-26 10:21:21,738 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  << "Server: Apache/2.4.6 () PHP/5.6.31[\r][\n]"
2018-07-26 10:21:21,739 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  << "X-Powered-By: PHP/5.6.31[\r][\n]"
2018-07-26 10:21:21,739 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  << "Content-Length: 0[\r][\n]"
2018-07-26 10:21:21,739 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  << "Keep-Alive: timeout=5, max=100[\r][\n]"
2018-07-26 10:21:21,739 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  << "Connection: Keep-Alive[\r][\n]"
2018-07-26 10:21:21,739 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  << "Content-Type: text/html; charset=UTF-8[\r][\n]"
2018-07-26 10:21:21,739 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  << "[\r][\n]"
2018-07-26 10:21:21,739 org.apache.http.impl.conn.DefaultClientConnection DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Receiving response: HTTP/1.1 200 OK
2018-07-26 10:21:21,739 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - << HTTP/1.1 200 OK
2018-07-26 10:21:21,739 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - << Date: Thu, 26 Jul 2018 08:21:21 GMT
2018-07-26 10:21:21,739 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - << Server: Apache/2.4.6 () PHP/5.6.31
2018-07-26 10:21:21,739 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - << X-Powered-By: PHP/5.6.31
2018-07-26 10:21:21,739 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - << Content-Length: 0
2018-07-26 10:21:21,739 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - << Keep-Alive: timeout=5, max=100
2018-07-26 10:21:21,739 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - << Connection: Keep-Alive
2018-07-26 10:21:21,739 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - << Content-Type: text/html; charset=UTF-8
2018-07-26 10:21:21,740 org.apache.http.impl.client.DefaultHttpClient DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Connection can be kept alive for 5000 MILLISECONDS
2018-07-26 10:21:21,740 command.helpers.CommandsExecutor INFO [Asterisk-Java ManagerConnection-0-Reader-0] - org.asteriskjava.manager.event.VarSetEvent[dateReceived='Thu Jul 26 10:21:21 CEST 2018',privilege='dialplan,all',linkedid=null,server=null,calleridname=null,channel='IAX2/1111-13890',language=null,exten=null,calleridnum=null,context=null,value='IAX2/mypeer-19706',connectedlinenum=null,uniqueid='test_ippbx-1532593270.18',timestamp=null,channelstatedesc=null,systemname=null,connectedlinename=null,priority=null,sequencenumber=null,channelstate=null,variable='BRIDGEPEER',accountcode=null,systemHashcode=642760030]
2018-07-26 10:21:21,740 command.helpers.CommandsExecutor INFO [Asterisk-Java ManagerConnection-0-Reader-0] - org.asteriskjava.manager.event.VarSetEvent[dateReceived='Thu Jul 26 10:21:21 CEST 2018',privilege='dialplan,all',linkedid=null,server=null,calleridname=null,channel='IAX2/mypeer-19706',language=null,exten=null,calleridnum=null,context=null,value='IAX2/1111-13890',connectedlinenum=null,uniqueid='test_ippbx-1532593280.19',timestamp=null,channelstatedesc=null,systemname=null,connectedlinename=null,priority=null,sequencenumber=null,channelstate=null,variable='BRIDGEPEER',accountcode=null,systemHashcode=1897096798]
2018-07-26 10:21:21,741 command.helpers.CommandsExecutor INFO [Asterisk-Java ManagerConnection-0-Reader-0] - org.asteriskjava.manager.event.VarSetEvent[dateReceived='Thu Jul 26 10:21:21 CEST 2018',privilege='dialplan,all',linkedid=null,server=null,calleridname=null,channel='IAX2/1111-13890',language=null,exten=null,calleridnum=null,context=null,value='IAX2/mypeer-19706',connectedlinenum=null,uniqueid='test_ippbx-1532593270.18',timestamp=null,channelstatedesc=null,systemname=null,connectedlinename=null,priority=null,sequencenumber=null,channelstate=null,variable='BRIDGEPEER',accountcode=null,systemHashcode=785866302]
2018-07-26 10:21:21,741 command.helpers.CommandsExecutor INFO [Asterisk-Java ManagerConnection-0-Reader-0] - org.asteriskjava.manager.event.VarSetEvent[dateReceived='Thu Jul 26 10:21:21 CEST 2018',privilege='dialplan,all',linkedid=null,server=null,calleridname=null,channel='IAX2/mypeer-19706',language=null,exten=null,calleridnum=null,context=null,value='IAX2/1111-13890',connectedlinenum=null,uniqueid='test_ippbx-1532593280.19',timestamp=null,channelstatedesc=null,systemname=null,connectedlinename=null,priority=null,sequencenumber=null,channelstate=null,variable='BRIDGEPEER',accountcode=null,systemHashcode=194275832]
2018-07-26 10:21:26,942 command.helpers.CommandsExecutor INFO [Asterisk-Java ManagerConnection-0-Reader-0] - org.asteriskjava.manager.event.HangupRequestEvent[dateReceived='Thu Jul 26 10:21:26 CEST 2018',privilege='call,all',linkedid=null,server=null,calleridname=null,channel='IAX2/mypeer-19706',cause=null,language=null,exten=null,calleridnum=null,context=null,callerid=null,connectedlinenum=null,uniqueid='test_ippbx-1532593280.19',timestamp=null,channelstatedesc=null,systemname=null,connectedlinename=null,priority=null,sequencenumber=null,channelstate=null,accountcode=null,systemHashcode=115397899]
2018-07-26 10:21:26,943 command.helpers.CommandsExecutor INFO [Asterisk-Java ManagerConnection-0-Reader-0] - org.asteriskjava.manager.event.BridgeEvent[dateReceived='Thu Jul 26 10:21:26 CEST 2018',privilege='call,all',server=null,calleridname=null,link='false',exten=null,calleridnum=null,context=null,connectedlinenum=null,timestamp=null,channelstatedesc=null,bridgestate='Unlink',systemname=null,bridgetype='core',channel1='IAX2/1111-13890',channel2='IAX2/mypeer-19706',connectedlinename=null,uniqueid2='test_ippbx-1532593280.19',priority=null,sequencenumber=null,channelstate=null,uniqueid1='test_ippbx-1532593270.18',callerid1='1111',unlink='true',callerid2='ZZXXXXXXXXX',systemHashcode=42660630]
2018-07-26 10:21:26,954 org.apache.http.impl.conn.tsccm.ThreadSafeClientConnManager DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Get connection: {}->http://test-vtiger-sp.local, timeout = 0
2018-07-26 10:21:26,956 org.apache.http.impl.conn.tsccm.ConnPoolByRoute DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - [{}->http://test-vtiger-sp.local] total kept alive: 0, total issued: 0, total allocated: 0 out of 20
2018-07-26 10:21:26,956 org.apache.http.impl.conn.tsccm.ConnPoolByRoute DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - No free connections [{}->http://test-vtiger-sp.local][null]
2018-07-26 10:21:26,956 org.apache.http.impl.conn.tsccm.ConnPoolByRoute DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Available capacity: 2 out of 2 [{}->http://test-vtiger-sp.local][null]
2018-07-26 10:21:26,956 org.apache.http.impl.conn.tsccm.ConnPoolByRoute DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Creating new connection [{}->http://test-vtiger-sp.local]
2018-07-26 10:21:26,957 org.apache.http.impl.conn.DefaultClientConnectionOperator DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Connecting to test-vtiger-sp.local:80
2018-07-26 10:21:26,958 org.apache.http.client.protocol.RequestAddCookies DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - CookieSpec selected: best-match
2018-07-26 10:21:26,958 org.apache.http.client.protocol.RequestAuthCache DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Auth cache not set in the context
2018-07-26 10:21:26,958 org.apache.http.client.protocol.RequestTargetAuthentication DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Target auth state: UNCHALLENGED
2018-07-26 10:21:26,958 org.apache.http.client.protocol.RequestProxyAuthentication DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Proxy auth state: UNCHALLENGED
2018-07-26 10:21:26,958 org.apache.http.impl.client.DefaultHttpClient DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Attempt 1 to execute request
2018-07-26 10:21:26,959 org.apache.http.impl.conn.DefaultClientConnection DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Sending request: POST /modules/PBXManager/callbacks/PBXManager.php HTTP/1.1
2018-07-26 10:21:26,959 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  >> "POST /modules/PBXManager/callbacks/PBXManager.php HTTP/1.1[\r][\n]"
2018-07-26 10:21:26,959 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  >> "Content-Length: 278[\r][\n]"
2018-07-26 10:21:26,959 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  >> "Content-Type: application/x-www-form-urlencoded; charset=UTF-8[\r][\n]"
2018-07-26 10:21:26,959 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  >> "Host: test-vtiger-sp.local[\r][\n]"
2018-07-26 10:21:26,959 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  >> "Connection: Keep-Alive[\r][\n]"
2018-07-26 10:21:26,959 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  >> "[\r][\n]"
2018-07-26 10:21:26,959 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - >> POST /modules/PBXManager/callbacks/PBXManager.php HTTP/1.1
2018-07-26 10:21:26,959 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - >> Content-Length: 278
2018-07-26 10:21:26,959 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - >> Content-Type: application/x-www-form-urlencoded; charset=UTF-8
2018-07-26 10:21:26,959 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - >> Host: test-vtiger-sp.local
2018-07-26 10:21:26,959 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - >> Connection: Keep-Alive
2018-07-26 10:21:26,959 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  >> "vtigersignature=TEST20&pstncallerid=ZZXXXXXXXXX&corpcallerid&connline&totalvar&uniqueid1=test_ippbx-1532593270&uniqueid2=test_ippbx-1532593280&callerid1=1111&callerid2=mypeer&dateReceived=Thu+Jul+26+10%3A21%3A26+CEST+2018&callUUID=990000016&callstatus=DialAnswer"
2018-07-26 10:21:27,037 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  << "HTTP/1.1 200 OK[\r][\n]"
2018-07-26 10:21:27,037 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  << "Date: Thu, 26 Jul 2018 08:21:26 GMT[\r][\n]"
2018-07-26 10:21:27,037 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  << "Server: Apache/2.4.6 () PHP/5.6.31[\r][\n]"
2018-07-26 10:21:27,037 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  << "X-Powered-By: PHP/5.6.31[\r][\n]"
2018-07-26 10:21:27,037 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  << "Content-Length: 0[\r][\n]"
2018-07-26 10:21:27,037 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  << "Keep-Alive: timeout=5, max=100[\r][\n]"
2018-07-26 10:21:27,037 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  << "Connection: Keep-Alive[\r][\n]"
2018-07-26 10:21:27,037 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  << "Content-Type: text/html; charset=UTF-8[\r][\n]"
2018-07-26 10:21:27,037 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  << "[\r][\n]"
2018-07-26 10:21:27,037 org.apache.http.impl.conn.DefaultClientConnection DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Receiving response: HTTP/1.1 200 OK
2018-07-26 10:21:27,037 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - << HTTP/1.1 200 OK
2018-07-26 10:21:27,037 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - << Date: Thu, 26 Jul 2018 08:21:26 GMT
2018-07-26 10:21:27,038 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - << Server: Apache/2.4.6 () PHP/5.6.31
2018-07-26 10:21:27,038 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - << X-Powered-By: PHP/5.6.31
2018-07-26 10:21:27,038 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - << Content-Length: 0
2018-07-26 10:21:27,038 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - << Keep-Alive: timeout=5, max=100
2018-07-26 10:21:27,038 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - << Connection: Keep-Alive
2018-07-26 10:21:27,038 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - << Content-Type: text/html; charset=UTF-8
2018-07-26 10:21:27,038 org.apache.http.impl.client.DefaultHttpClient DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Connection can be kept alive for 5000 MILLISECONDS
2018-07-26 10:21:27,038 command.helpers.CommandsExecutor INFO [Asterisk-Java ManagerConnection-0-Reader-0] - org.asteriskjava.manager.event.VarSetEvent[dateReceived='Thu Jul 26 10:21:27 CEST 2018',privilege='dialplan,all',linkedid=null,server=null,calleridname=null,channel='IAX2/1111-13890',language=null,exten=null,calleridnum=null,context=null,value='5',connectedlinenum=null,uniqueid='test_ippbx-1532593270.18',timestamp=null,channelstatedesc=null,systemname=null,connectedlinename=null,priority=null,sequencenumber=null,channelstate=null,variable='ANSWEREDTIME',accountcode=null,systemHashcode=34526044]
2018-07-26 10:21:27,039 command.helpers.CommandsExecutor INFO [Asterisk-Java ManagerConnection-0-Reader-0] - org.asteriskjava.manager.event.VarSetEvent[dateReceived='Thu Jul 26 10:21:27 CEST 2018',privilege='dialplan,all',linkedid=null,server=null,calleridname=null,channel='IAX2/1111-13890',language=null,exten=null,calleridnum=null,context=null,value='6',connectedlinenum=null,uniqueid='test_ippbx-1532593270.18',timestamp=null,channelstatedesc=null,systemname=null,connectedlinename=null,priority=null,sequencenumber=null,channelstate=null,variable='DIALEDTIME',accountcode=null,systemHashcode=1472827976]
2018-07-26 10:21:27,039 command.helpers.CommandsExecutor INFO [Asterisk-Java ManagerConnection-0-Reader-0] - org.asteriskjava.manager.event.CdrEvent[dateReceived='Thu Jul 26 10:21:27 CEST 2018',privilege='cdr,all',server=null,calleridname=null,starttimeasdate='Thu Jul 26 10:21:20 CEST 2018',channel='IAX2/1111-13890',destination='ZZXXXXXXXXX',lastdata='IAX2/mypeer/ZZXXXXXXXXX,,CI',starttime='2018-07-26 10:21:20',destinationcontext='from_crm',exten=null,duration='6',userfield='',calleridnum=null,context=null,callerid='1111',amaflags='DOCUMENTATION',connectedlinenum=null,uniqueid='test_ippbx-1532593270.18',timestamp=null,channelstatedesc=null,lastapplication='Dial',src='1111',systemname=null,billableseconds='5',endtime='2018-07-26 10:21:26',connectedlinename=null,priority=null,sequencenumber=null,channelstate=null,disposition='ANSWERED',destinationchannel='IAX2/mypeer-19706',answertime='2018-07-26 10:21:21',answertimeasdate='Thu Jul 26 10:21:21 CEST 2018',endtimeasdate='Thu Jul 26 10:21:26 CEST 2018',accountcode='',systemHashcode=1131904896]
2018-07-26 10:21:27,053 org.apache.http.impl.conn.tsccm.ThreadSafeClientConnManager DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Get connection: {}->http://test-vtiger-sp.local, timeout = 0
2018-07-26 10:21:27,053 org.apache.http.impl.conn.tsccm.ConnPoolByRoute DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - [{}->http://test-vtiger-sp.local] total kept alive: 0, total issued: 0, total allocated: 0 out of 20
2018-07-26 10:21:27,053 org.apache.http.impl.conn.tsccm.ConnPoolByRoute DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - No free connections [{}->http://test-vtiger-sp.local][null]
2018-07-26 10:21:27,053 org.apache.http.impl.conn.tsccm.ConnPoolByRoute DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Available capacity: 2 out of 2 [{}->http://test-vtiger-sp.local][null]
2018-07-26 10:21:27,053 org.apache.http.impl.conn.tsccm.ConnPoolByRoute DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Creating new connection [{}->http://test-vtiger-sp.local]
2018-07-26 10:21:27,053 org.apache.http.impl.conn.DefaultClientConnectionOperator DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Connecting to test-vtiger-sp.local:80
2018-07-26 10:21:27,054 org.apache.http.client.protocol.RequestAddCookies DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - CookieSpec selected: best-match
2018-07-26 10:21:27,054 org.apache.http.client.protocol.RequestAuthCache DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Auth cache not set in the context
2018-07-26 10:21:27,055 org.apache.http.client.protocol.RequestTargetAuthentication DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Target auth state: UNCHALLENGED
2018-07-26 10:21:27,055 org.apache.http.client.protocol.RequestProxyAuthentication DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Proxy auth state: UNCHALLENGED
2018-07-26 10:21:27,055 org.apache.http.impl.client.DefaultHttpClient DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Attempt 1 to execute request
2018-07-26 10:21:27,055 org.apache.http.impl.conn.DefaultClientConnection DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Sending request: POST /modules/PBXManager/callbacks/PBXManager.php HTTP/1.1
2018-07-26 10:21:27,055 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  >> "POST /modules/PBXManager/callbacks/PBXManager.php HTTP/1.1[\r][\n]"
2018-07-26 10:21:27,055 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  >> "Content-Length: 239[\r][\n]"
2018-07-26 10:21:27,055 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  >> "Content-Type: application/x-www-form-urlencoded; charset=UTF-8[\r][\n]"
2018-07-26 10:21:27,055 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  >> "Host: test-vtiger-sp.local[\r][\n]"
2018-07-26 10:21:27,055 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  >> "Connection: Keep-Alive[\r][\n]"
2018-07-26 10:21:27,055 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  >> "[\r][\n]"
2018-07-26 10:21:27,055 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - >> POST /modules/PBXManager/callbacks/PBXManager.php HTTP/1.1
2018-07-26 10:21:27,056 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - >> Content-Length: 239
2018-07-26 10:21:27,056 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - >> Content-Type: application/x-www-form-urlencoded; charset=UTF-8
2018-07-26 10:21:27,056 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - >> Host: test-vtiger-sp.local
2018-07-26 10:21:27,056 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - >> Connection: Keep-Alive
2018-07-26 10:21:27,056 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  >> "vtigersignature=TEST20&pstncallerid=ZZXXXXXXXXX&corpcallerid&connline&totalvar&starttime=2018-07-26+10%3A21%3A20&endtime=2018-07-26+10%3A21%3A26&duration=6&billableseconds=5&callerNumber=mypeer&callstatus=EndCall&callUUID=990000016"
2018-07-26 10:21:27,111 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  << "HTTP/1.1 200 OK[\r][\n]"
2018-07-26 10:21:27,111 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  << "Date: Thu, 26 Jul 2018 08:21:27 GMT[\r][\n]"
2018-07-26 10:21:27,111 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  << "Server: Apache/2.4.6 () PHP/5.6.31[\r][\n]"
2018-07-26 10:21:27,112 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  << "X-Powered-By: PHP/5.6.31[\r][\n]"
2018-07-26 10:21:27,112 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  << "Content-Length: 0[\r][\n]"
2018-07-26 10:21:27,112 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  << "Keep-Alive: timeout=5, max=100[\r][\n]"
2018-07-26 10:21:27,112 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  << "Connection: Keep-Alive[\r][\n]"
2018-07-26 10:21:27,112 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  << "Content-Type: text/html; charset=UTF-8[\r][\n]"
2018-07-26 10:21:27,112 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  << "[\r][\n]"
2018-07-26 10:21:27,112 org.apache.http.impl.conn.DefaultClientConnection DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Receiving response: HTTP/1.1 200 OK
2018-07-26 10:21:27,112 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - << HTTP/1.1 200 OK
2018-07-26 10:21:27,112 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - << Date: Thu, 26 Jul 2018 08:21:27 GMT
2018-07-26 10:21:27,112 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - << Server: Apache/2.4.6 () PHP/5.6.31
2018-07-26 10:21:27,112 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - << X-Powered-By: PHP/5.6.31
2018-07-26 10:21:27,112 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - << Content-Length: 0
2018-07-26 10:21:27,112 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - << Keep-Alive: timeout=5, max=100
2018-07-26 10:21:27,112 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - << Connection: Keep-Alive
2018-07-26 10:21:27,112 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - << Content-Type: text/html; charset=UTF-8
2018-07-26 10:21:27,112 org.apache.http.impl.client.DefaultHttpClient DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Connection can be kept alive for 5000 MILLISECONDS
2018-07-26 10:21:27,113 command.helpers.CommandsExecutor INFO [Asterisk-Java ManagerConnection-0-Reader-0] - org.asteriskjava.manager.event.HangupRequestEvent[dateReceived='Thu Jul 26 10:21:27 CEST 2018',privilege='call,all',linkedid=null,server=null,calleridname=null,channel='IAX2/mypeer-19706',cause=null,language=null,exten=null,calleridnum=null,context=null,callerid=null,connectedlinenum=null,uniqueid='test_ippbx-1532593280.19',timestamp=null,channelstatedesc=null,systemname=null,connectedlinename=null,priority=null,sequencenumber=null,channelstate=null,accountcode=null,systemHashcode=1702941012]
2018-07-26 10:21:27,114 command.helpers.CommandsExecutor INFO [Asterisk-Java ManagerConnection-0-Reader-0] - HangupEvent [cause=16, causeTxt=Normal Clearing, language=null, linkedId=null, accountCode=]
2018-07-26 10:21:27,125 org.apache.http.impl.conn.tsccm.ThreadSafeClientConnManager DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Get connection: {}->http://test-vtiger-sp.local, timeout = 0
2018-07-26 10:21:27,125 org.apache.http.impl.conn.tsccm.ConnPoolByRoute DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - [{}->http://test-vtiger-sp.local] total kept alive: 0, total issued: 0, total allocated: 0 out of 20
2018-07-26 10:21:27,125 org.apache.http.impl.conn.tsccm.ConnPoolByRoute DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - No free connections [{}->http://test-vtiger-sp.local][null]
2018-07-26 10:21:27,125 org.apache.http.impl.conn.tsccm.ConnPoolByRoute DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Available capacity: 2 out of 2 [{}->http://test-vtiger-sp.local][null]
2018-07-26 10:21:27,125 org.apache.http.impl.conn.tsccm.ConnPoolByRoute DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Creating new connection [{}->http://test-vtiger-sp.local]
2018-07-26 10:21:27,126 org.apache.http.impl.conn.DefaultClientConnectionOperator DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Connecting to test-vtiger-sp.local:80
2018-07-26 10:21:27,128 org.apache.http.client.protocol.RequestAddCookies DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - CookieSpec selected: best-match
2018-07-26 10:21:27,128 org.apache.http.client.protocol.RequestAuthCache DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Auth cache not set in the context
2018-07-26 10:21:27,128 org.apache.http.client.protocol.RequestTargetAuthentication DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Target auth state: UNCHALLENGED
2018-07-26 10:21:27,128 org.apache.http.client.protocol.RequestProxyAuthentication DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Proxy auth state: UNCHALLENGED
2018-07-26 10:21:27,128 org.apache.http.impl.client.DefaultHttpClient DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Attempt 1 to execute request
2018-07-26 10:21:27,128 org.apache.http.impl.conn.DefaultClientConnection DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Sending request: POST /modules/PBXManager/callbacks/PBXManager.php HTTP/1.1
2018-07-26 10:21:27,128 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  >> "POST /modules/PBXManager/callbacks/PBXManager.php HTTP/1.1[\r][\n]"
2018-07-26 10:21:27,128 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  >> "Content-Length: 167[\r][\n]"
2018-07-26 10:21:27,128 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  >> "Content-Type: application/x-www-form-urlencoded; charset=UTF-8[\r][\n]"
2018-07-26 10:21:27,128 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  >> "Host: test-vtiger-sp.local[\r][\n]"
2018-07-26 10:21:27,128 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  >> "Connection: Keep-Alive[\r][\n]"
2018-07-26 10:21:27,128 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  >> "[\r][\n]"
2018-07-26 10:21:27,129 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - >> POST /modules/PBXManager/callbacks/PBXManager.php HTTP/1.1
2018-07-26 10:21:27,129 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - >> Content-Length: 167
2018-07-26 10:21:27,129 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - >> Content-Type: application/x-www-form-urlencoded; charset=UTF-8
2018-07-26 10:21:27,129 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - >> Host: test-vtiger-sp.local
2018-07-26 10:21:27,129 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - >> Connection: Keep-Alive
2018-07-26 10:21:27,129 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  >> "vtigersignature=TEST20&pstncallerid=ZZXXXXXXXXX&corpcallerid&connline&totalvar&causetxt=Normal+Clearing&callUUID=990000016&callstatus=Hangup&callerIdNum=mypeer"
2018-07-26 10:21:27,201 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  << "HTTP/1.1 200 OK[\r][\n]"
2018-07-26 10:21:27,201 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  << "Date: Thu, 26 Jul 2018 08:21:27 GMT[\r][\n]"
2018-07-26 10:21:27,201 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  << "Server: Apache/2.4.6 () PHP/5.6.31[\r][\n]"
2018-07-26 10:21:27,201 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  << "X-Powered-By: PHP/5.6.31[\r][\n]"
2018-07-26 10:21:27,201 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  << "Content-Length: 0[\r][\n]"
2018-07-26 10:21:27,201 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  << "Keep-Alive: timeout=5, max=100[\r][\n]"
2018-07-26 10:21:27,201 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  << "Connection: Keep-Alive[\r][\n]"
2018-07-26 10:21:27,201 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  << "Content-Type: text/html; charset=UTF-8[\r][\n]"
2018-07-26 10:21:27,201 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  << "[\r][\n]"
2018-07-26 10:21:27,202 org.apache.http.impl.conn.DefaultClientConnection DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Receiving response: HTTP/1.1 200 OK
2018-07-26 10:21:27,202 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - << HTTP/1.1 200 OK
2018-07-26 10:21:27,202 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - << Date: Thu, 26 Jul 2018 08:21:27 GMT
2018-07-26 10:21:27,202 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - << Server: Apache/2.4.6 () PHP/5.6.31
2018-07-26 10:21:27,202 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - << X-Powered-By: PHP/5.6.31
2018-07-26 10:21:27,202 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - << Content-Length: 0
2018-07-26 10:21:27,202 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - << Keep-Alive: timeout=5, max=100
2018-07-26 10:21:27,202 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - << Connection: Keep-Alive
2018-07-26 10:21:27,202 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - << Content-Type: text/html; charset=UTF-8
2018-07-26 10:21:27,202 org.apache.http.impl.client.DefaultHttpClient DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Connection can be kept alive for 5000 MILLISECONDS
2018-07-26 10:21:27,202 command.helpers.CommandsExecutor INFO [Asterisk-Java ManagerConnection-0-Reader-0] - org.asteriskjava.manager.event.VarSetEvent[dateReceived='Thu Jul 26 10:21:27 CEST 2018',privilege='dialplan,all',linkedid=null,server=null,calleridname=null,channel='IAX2/1111-13890',language=null,exten=null,calleridnum=null,context=null,value='ANSWER',connectedlinenum=null,uniqueid='test_ippbx-1532593270.18',timestamp=null,channelstatedesc=null,systemname=null,connectedlinename=null,priority=null,sequencenumber=null,channelstate=null,variable='DIALSTATUS',accountcode=null,systemHashcode=112402060]
2018-07-26 10:21:27,202 command.helpers.CommandsExecutor INFO [Asterisk-Java ManagerConnection-0-Reader-0] - DialEvent [subEvent=End, channel=IAX2/1111-13890, destination=null, callerIdNum=null, callerIdName=null, uniqueId=test_ippbx-1532593270.18, destUniqueId=null, dialString=null, dialStatus=ANSWER, connectedLineNum=null, connectedLineName=null]
2018-07-26 10:21:27,203 command.helpers.CommandsExecutor INFO [Asterisk-Java ManagerConnection-0-Reader-0] - org.asteriskjava.manager.event.SoftHangupRequestEvent[dateReceived='Thu Jul 26 10:21:27 CEST 2018',privilege='call,all',linkedid=null,server=null,calleridname=null,channel='IAX2/1111-13890',cause='16',language=null,exten=null,calleridnum=null,context=null,callerid=null,connectedlinenum=null,uniqueid='test_ippbx-1532593270.18',timestamp=null,channelstatedesc=null,systemname=null,connectedlinename=null,priority=null,sequencenumber=null,channelstate=null,accountcode=null,systemHashcode=2084580333]
2018-07-26 10:21:27,203 command.helpers.CommandsExecutor INFO [Asterisk-Java ManagerConnection-0-Reader-0] - org.asteriskjava.manager.event.HangupRequestEvent[dateReceived='Thu Jul 26 10:21:27 CEST 2018',privilege='call,all',linkedid=null,server=null,calleridname=null,channel='IAX2/1111-13890',cause=null,language=null,exten=null,calleridnum=null,context=null,callerid=null,connectedlinenum=null,uniqueid='test_ippbx-1532593270.18',timestamp=null,channelstatedesc=null,systemname=null,connectedlinename=null,priority=null,sequencenumber=null,channelstate=null,accountcode=null,systemHashcode=644957471]
2018-07-26 10:21:27,203 command.helpers.CommandsExecutor INFO [Asterisk-Java ManagerConnection-0-Reader-0] - HangupEvent [cause=16, causeTxt=Normal Clearing, language=null, linkedId=null, accountCode=]
2018-07-26 10:21:27,213 org.apache.http.impl.conn.tsccm.ThreadSafeClientConnManager DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Get connection: {}->http://test-vtiger-sp.local, timeout = 0
2018-07-26 10:21:27,214 org.apache.http.impl.conn.tsccm.ConnPoolByRoute DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - [{}->http://test-vtiger-sp.local] total kept alive: 0, total issued: 0, total allocated: 0 out of 20
2018-07-26 10:21:27,216 org.apache.http.impl.conn.tsccm.ConnPoolByRoute DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - No free connections [{}->http://test-vtiger-sp.local][null]
2018-07-26 10:21:27,216 org.apache.http.impl.conn.tsccm.ConnPoolByRoute DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Available capacity: 2 out of 2 [{}->http://test-vtiger-sp.local][null]
2018-07-26 10:21:27,216 org.apache.http.impl.conn.tsccm.ConnPoolByRoute DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Creating new connection [{}->http://test-vtiger-sp.local]
2018-07-26 10:21:27,216 org.apache.http.impl.conn.DefaultClientConnectionOperator DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Connecting to test-vtiger-sp.local:80
2018-07-26 10:21:27,217 org.apache.http.client.protocol.RequestAddCookies DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - CookieSpec selected: best-match
2018-07-26 10:21:27,217 org.apache.http.client.protocol.RequestAuthCache DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Auth cache not set in the context
2018-07-26 10:21:27,217 org.apache.http.client.protocol.RequestTargetAuthentication DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Target auth state: UNCHALLENGED
2018-07-26 10:21:27,217 org.apache.http.client.protocol.RequestProxyAuthentication DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Proxy auth state: UNCHALLENGED
2018-07-26 10:21:27,217 org.apache.http.impl.client.DefaultHttpClient DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Attempt 1 to execute request
2018-07-26 10:21:27,217 org.apache.http.impl.conn.DefaultClientConnection DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Sending request: POST /modules/PBXManager/callbacks/PBXManager.php HTTP/1.1
2018-07-26 10:21:27,217 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  >> "POST /modules/PBXManager/callbacks/PBXManager.php HTTP/1.1[\r][\n]"
2018-07-26 10:21:27,217 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  >> "Content-Length: 165[\r][\n]"
2018-07-26 10:21:27,218 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  >> "Content-Type: application/x-www-form-urlencoded; charset=UTF-8[\r][\n]"
2018-07-26 10:21:27,218 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  >> "Host: test-vtiger-sp.local[\r][\n]"
2018-07-26 10:21:27,218 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  >> "Connection: Keep-Alive[\r][\n]"
2018-07-26 10:21:27,218 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  >> "[\r][\n]"
2018-07-26 10:21:27,218 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - >> POST /modules/PBXManager/callbacks/PBXManager.php HTTP/1.1
2018-07-26 10:21:27,218 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - >> Content-Length: 165
2018-07-26 10:21:27,218 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - >> Content-Type: application/x-www-form-urlencoded; charset=UTF-8
2018-07-26 10:21:27,219 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - >> Host: test-vtiger-sp.local
2018-07-26 10:21:27,219 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - >> Connection: Keep-Alive
2018-07-26 10:21:27,219 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  >> "vtigersignature=TEST20&pstncallerid=ZZXXXXXXXXX&corpcallerid&connline&totalvar&causetxt=Normal+Clearing&callUUID=990000016&callstatus=Hangup&callerIdNum=1111"
2018-07-26 10:21:27,288 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  << "HTTP/1.1 200 OK[\r][\n]"
2018-07-26 10:21:27,288 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  << "Date: Thu, 26 Jul 2018 08:21:27 GMT[\r][\n]"
2018-07-26 10:21:27,288 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  << "Server: Apache/2.4.6 () PHP/5.6.31[\r][\n]"
2018-07-26 10:21:27,288 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  << "X-Powered-By: PHP/5.6.31[\r][\n]"
2018-07-26 10:21:27,288 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  << "Content-Length: 0[\r][\n]"
2018-07-26 10:21:27,288 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  << "Keep-Alive: timeout=5, max=100[\r][\n]"
2018-07-26 10:21:27,288 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  << "Connection: Keep-Alive[\r][\n]"
2018-07-26 10:21:27,288 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  << "Content-Type: text/html; charset=UTF-8[\r][\n]"
2018-07-26 10:21:27,288 org.apache.http.wire DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] -  << "[\r][\n]"
2018-07-26 10:21:27,288 org.apache.http.impl.conn.DefaultClientConnection DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Receiving response: HTTP/1.1 200 OK
2018-07-26 10:21:27,288 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - << HTTP/1.1 200 OK
2018-07-26 10:21:27,288 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - << Date: Thu, 26 Jul 2018 08:21:27 GMT
2018-07-26 10:21:27,289 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - << Server: Apache/2.4.6 () PHP/5.6.31
2018-07-26 10:21:27,289 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - << X-Powered-By: PHP/5.6.31
2018-07-26 10:21:27,289 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - << Content-Length: 0
2018-07-26 10:21:27,289 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - << Keep-Alive: timeout=5, max=100
2018-07-26 10:21:27,289 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - << Connection: Keep-Alive
2018-07-26 10:21:27,289 org.apache.http.headers DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - << Content-Type: text/html; charset=UTF-8
2018-07-26 10:21:27,289 org.apache.http.impl.client.DefaultHttpClient DEBUG [Asterisk-Java ManagerConnection-0-Reader-0] - Connection can be kept alive for 5000 MILLISECONDS

SPAsteriskConnector-1.4.2 и LookUpVariablesNames

Free Russian CRM based on Vtiger CRM project.

Group

Searches

Help

#145 SPAsteriskConnector-1.4.2 и LookUpVariablesNames

Discussion