Current Asterisk Version: 15.1.1
FreePBX latest
Visual Dialplan latest
Nothing manually editted in configs.
Current situation:
Running Freepbx in and out is as expected. 2 extensions (sip/700&701, ring group 777 for 700 & 701). Works as expected.
Next step is to create a dialplan with Visual Dial Plan. So far the supplied examples work until we want the fall back to ext-did in
; Generated by Visual Dialplan Professional.
; Creation date: 2017-12-02 14:04:04.121
; Created from: C:\Users\Computer.vdp\samples\00_hello_world_mod.vdp
;This context is used to handle all outbound calls.
[vdp-outbound]
exten => _.,1,Answer()
exten => _.,n,Playback(hello-world)
exten => _.,n,MusicOnHold(radio2nl,20)
exten => _.,n,Goto(outbound-allroutes,${EXTEN},1)
;This context is used to handle all inbound calls.
[vdp-inbound]
exten => _.,1,Answer()
exten => _.,n,Playback(hello-world)
exten => _.,n,Goto(ext-did,${CONTEXT},1)
When Freepbx is dialed, it is answered, hello world is announced and than we have the issue. Whatever I do I can’t go back to the FreePBX regular flow. If I clear extensions_vdp.conf, FreePBX is acting as it should, so my analysis is that there is something my config that creates the hickup in extensions_additional.conf, but I don’t know what.
[ext-did]
include => ext-did-custom
include => ext-did-0001
include => ext-did-0002
exten => foo,1,Noop(bar)
;–== end of [ext-did] ==–;
[ext-did-0001]
include => ext-did-0001-custom
exten => s,1,Set(__DIRECTION=INBOUND)
exten => s,n,Gosub(sub-record-check,s,1(in,${EXTEN},dontcare))
exten => s,n,Gosub(app-blacklist-check,s,1())
exten => s,n,ExecIf($["${FROM_DID}" = “”]?Set(__FROM_DID=${EXTEN}))
exten => s,n,Set(CDR(did)=${FROM_DID})
exten => s,n,ExecIf($[ “${CALLERID(name)}” = “” ] ?Set(CALLERID(name)=${CALLERID(num)}))
exten => s,n,Set(__MOHCLASS=)
exten => s,n,Set(__REVERSAL_REJECT=FALSE)
exten => s,n,GotoIf($["${REVERSAL_REJECT}"!=“TRUE”]?post-reverse-charge)
exten => s,n,GotoIf($["${CHANNEL(reversecharge)}"=“1”]?macro-hangupcall)
exten => s,n(post-reverse-charge),Noop()
exten => s,n,Set(__CALLINGNAMEPRES_SV=${CALLERID(name-pres)})
exten => s,n,Set(__CALLINGNUMPRES_SV=${CALLERID(num-pres)})
exten => s,n,Set(CALLERID(name-pres)=allowed_not_screened)
exten => s,n,Set(CALLERID(num-pres)=allowed_not_screened)
exten => s,n(did-cid-hook),Noop(CallerID Entry Point)
exten => s,n(dest-ext),Goto(ext-group,777,1)
;–== end of [ext-did-0001] ==–;
[ext-did-catchall]
include => ext-did-catchall-custom
exten => _.,1,Noop(Catch-All DID Match - Found ${EXTEN} - You probably want a DID for this.)
exten => _.,n,Log(WARNING,Friendly Scanner from ${CUT(CUT(SIP_HEADER(Via), ,2),:,1)})
exten => _.,n,Set(__FROM_DID=${EXTEN})
exten => _.,n,Goto(ext-did,s,1)
;–== end of [ext-did-catchall] ==–;
Debugged
a=sendrecv... OK.
[2017-12-02 13:40:43] DEBUG[6046][C-0000000a]: chan_sip.c:10793 process_sdp: Processing media-level (audio) SDP a=rtcp:23197... UNSUPPORTED OR FAILED.
[2017-12-02 13:40:43] DEBUG[6046][C-0000000a]: rtp_engine.c:996 ast_rtp_codecs_payloads_xover: Crossover copying tx to rx payload mapping 0 (0x7f24989c9fd0) from 0x7f244cfe11a0 to 0x7f244cfe11a0
[2017-12-02 13:40:43] DEBUG[6046][C-0000000a]: rtp_engine.c:996 ast_rtp_codecs_payloads_xover: Crossover copying tx to rx payload mapping 3 (0x7f24989d5ca0) from 0x7f244cfe11a0 to 0x7f244cfe11a0
[2017-12-02 13:40:43] DEBUG[6046][C-0000000a]: rtp_engine.c:996 ast_rtp_codecs_payloads_xover: Crossover copying tx to rx payload mapping 8 (0x7f2498009f70) from 0x7f244cfe11a0 to 0x7f244cfe11a0
[2017-12-02 13:40:43] DEBUG[6046][C-0000000a]: rtp_engine.c:996 ast_rtp_codecs_payloads_xover: Crossover copying tx to rx payload mapping 18 (0x7f24989d6100) from 0x7f244cfe11a0 to 0x7f244cfe11a0
[2017-12-02 13:40:43] DEBUG[6046][C-0000000a]: rtp_engine.c:996 ast_rtp_codecs_payloads_xover: Crossover copying tx to rx payload mapping 97 (0x7f24989d6620) from 0x7f244cfe11a0 to 0x7f244cfe11a0
[2017-12-02 13:40:43] DEBUG[6046][C-0000000a]: rtp_engine.c:996 ast_rtp_codecs_payloads_xover: Crossover copying tx to rx payload mapping 101 (0x2f38760) from 0x7f244cfe11a0 to 0x7f244cfe11a0
[2017-12-02 13:40:43] DEBUG[6046][C-0000000a]: rtp_engine.c:996 ast_rtp_codecs_payloads_xover: Crossover copying tx to rx payload mapping 112 (0x7f24989d6150) from 0x7f244cfe11a0 to 0x7f244cfe11a0
[2017-12-02 13:40:43] DEBUG[6046][C-0000000a]: acl.c:955 ast_ouraddrfor: For destination '217.10.77.244', our source address is '192.168.1.5'.
[2017-12-02 13:40:43] DEBUG[6046][C-0000000a]: res_rtp_asterisk.c:6255 ast_rtp_remote_address_set: Setting RTCP address on RTP instance '0x7f24989c8328'
[2017-12-02 13:40:43] DEBUG[6046][C-0000000a]: rtp_engine.c:836 rtp_codecs_payloads_copy_rx: Copying rx payload mapping 0 (0x7f24989c9fd0) from 0x7f244cfe11a0 to 0x7f24989c84f0
[2017-12-02 13:40:43] DEBUG[6046][C-0000000a]: rtp_engine.c:836 rtp_codecs_payloads_copy_rx: Copying rx payload mapping 3 (0x7f24989d5ca0) from 0x7f244cfe11a0 to 0x7f24989c84f0
[2017-12-02 13:40:43] DEBUG[6046][C-0000000a]: rtp_engine.c:836 rtp_codecs_payloads_copy_rx: Copying rx payload mapping 8 (0x7f2498009f70) from 0x7f244cfe11a0 to 0x7f24989c84f0
[2017-12-02 13:40:43] DEBUG[6046][C-0000000a]: rtp_engine.c:836 rtp_codecs_payloads_copy_rx: Copying rx payload mapping 18 (0x7f24989d6100) from 0x7f244cfe11a0 to 0x7f24989c84f0
[2017-12-02 13:40:43] DEBUG[6046][C-0000000a]: rtp_engine.c:836 rtp_codecs_payloads_copy_rx: Copying rx payload mapping 97 (0x7f24989d6620) from 0x7f244cfe11a0 to 0x7f24989c84f0
[2017-12-02 13:40:43] DEBUG[6046][C-0000000a]: rtp_engine.c:836 rtp_codecs_payloads_copy_rx: Copying rx payload mapping 101 (0x2f38760) from 0x7f244cfe11a0 to 0x7f24989c84f0
[2017-12-02 13:40:43] DEBUG[6046][C-0000000a]: rtp_engine.c:836 rtp_codecs_payloads_copy_rx: Copying rx payload mapping 112 (0x7f24989d6150) from 0x7f244cfe11a0 to 0x7f24989c84f0
[2017-12-02 13:40:43] DEBUG[6046][C-0000000a]: rtp_engine.c:921 rtp_codecs_payloads_copy_tx: Copying tx payload mapping 0 (0x7f24989c9fd0) from 0x7f244cfe11a0 to 0x7f24989c84f0
[2017-12-02 13:40:43] DEBUG[6046][C-0000000a]: rtp_engine.c:921 rtp_codecs_payloads_copy_tx: Copying tx payload mapping 3 (0x7f24989d5ca0) from 0x7f244cfe11a0 to 0x7f24989c84f0
[2017-12-02 13:40:43] DEBUG[6046][C-0000000a]: rtp_engine.c:921 rtp_codecs_payloads_copy_tx: Copying tx payload mapping 8 (0x7f2498009f70) from 0x7f244cfe11a0 to 0x7f24989c84f0
[2017-12-02 13:40:43] DEBUG[6046][C-0000000a]: rtp_engine.c:921 rtp_codecs_payloads_copy_tx: Copying tx payload mapping 18 (0x7f24989d6100) from 0x7f244cfe11a0 to 0x7f24989c84f0
[2017-12-02 13:40:43] DEBUG[6046][C-0000000a]: rtp_engine.c:921 rtp_codecs_payloads_copy_tx: Copying tx payload mapping 97 (0x7f24989d6620) from 0x7f244cfe11a0 to 0x7f24989c84f0
[2017-12-02 13:40:43] DEBUG[6046][C-0000000a]: rtp_engine.c:921 rtp_codecs_payloads_copy_tx: Copying tx payload mapping 101 (0x2f38760) from 0x7f244cfe11a0 to 0x7f24989c84f0
[2017-12-02 13:40:43] DEBUG[6046][C-0000000a]: rtp_engine.c:921 rtp_codecs_payloads_copy_tx: Copying tx payload mapping 112 (0x7f24989d6150) from 0x7f244cfe11a0 to 0x7f24989c84f0
[2017-12-02 13:40:43] DEBUG[6046][C-0000000a]: res_rtp_asterisk.c:6088 ast_rtp_prop_set: Ignoring duplicate RTCP property on RTP instance '0x7f24989c8328'
[2017-12-02 13:40:43] DEBUG[6046][C-0000000a]: chan_sip.c:11098 process_sdp: We're settling with these formats: (gsm|ulaw|alaw)
[2017-12-02 13:40:43] DEBUG[6046][C-0000000a]: chan_sip.c:26408 handle_request_invite: Checking SIP call limits for device 2455794e0
[2017-12-02 13:40:43] DEBUG[6046][C-0000000a]: chan_sip.c:6765 update_call_counter: Updating call counter for incoming call
[2017-12-02 13:40:43] DEBUG[6046][C-0000000a]: netsock2.c:170 ast_sockaddr_split_hostport: Splitting '213.219.165.4:5060' into...
[2017-12-02 13:40:43] DEBUG[6046][C-0000000a]: netsock2.c:224 ast_sockaddr_split_hostport: ...host '213.219.165.4' and port ''.
[2017-12-02 13:40:43] DEBUG[6046][C-0000000a]: netsock2.c:170 ast_sockaddr_split_hostport: Splitting 'sipgate.co.uk' into...
[2017-12-02 13:40:43] DEBUG[6046][C-0000000a]: netsock2.c:224 ast_sockaddr_split_hostport: ...host 'sipgate.co.uk' and port ''.
[2017-12-02 13:40:43] DEBUG[6046][C-0000000a]: channel.c:1001 __ast_channel_alloc_ap: Channel 0x7f2498a58768 'SIP/0044yyyyyyyyyyyy-0000000d' allocated
[2017-12-02 13:40:43] DEBUG[6046][C-0000000a]: chan_sip.c:8162 sip_new: *** Our native formats are (gsm)
[2017-12-02 13:40:43] DEBUG[6046][C-0000000a]: chan_sip.c:8163 sip_new: *** Joint capabilities are (gsm|ulaw|alaw)
[2017-12-02 13:40:43] DEBUG[6046][C-0000000a]: chan_sip.c:8164 sip_new: *** Our capabilities are (gsm|ulaw|alaw)
[2017-12-02 13:40:43] DEBUG[6046][C-0000000a]: chan_sip.c:8165 sip_new: *** AST_CODEC_CHOOSE formats are gsm
[2017-12-02 13:40:43] DEBUG[6046][C-0000000a]: chan_sip.c:8198 sip_new: This channel will not be able to handle video.
[2017-12-02 13:40:43] DEBUG[6046][C-0000000a]: sip/route.c:103 sip_route_process_header: sip_route_process_header: <sip:217.10.79.23;lr;ftag=as0a19d74c>
[2017-12-02 13:40:43] DEBUG[6046][C-0000000a]: sip/route.c:103 sip_route_process_header: sip_route_process_header: <sip:172.20.40.8;lr>
[2017-12-02 13:40:43] DEBUG[6046][C-0000000a]: sip/route.c:103 sip_route_process_header: sip_route_process_header: <sip:217.10.68.137;lr;ftag=as0a19d74c>
[2017-12-02 13:40:43] DEBUG[6046][C-0000000a]: chan_sip.c:26612 handle_request_invite: SIP/0044yyyyyyyyyyyy-0000000d: New call is still down.... Trying...
[2017-12-02 13:40:43] DEBUG[6046][C-0000000a]: chan_sip.c:3751 __sip_xmit: Trying to put 'SIP/2.0 100' onto UDP socket destined for 217.10.79.23:5060
[2017-12-02 13:40:43] DEBUG[5115]: threadpool.c:517 grow: Increasing threadpool stasis-core's size by 1
[2017-12-02 13:40:43] DEBUG[5128]: devicestate.c:367 _ast_device_state: No provider found, checking channel drivers for SIP - 0044yyyyyyyyyyyy
[2017-12-02 13:40:43] DEBUG[5128]: chan_sip.c:30362 sip_devicestate: Checking device state for peer 0044yyyyyyyyyyyy
[2017-12-02 13:40:43] DEBUG[5128]: devicestate.c:472 do_state_change: Changing state for SIP/0044yyyyyyyyyyyy - state 1 (Not in use)
[2017-12-02 13:40:43] DEBUG[5232]: res_odbc.c:857 _ast_odbc_request_obj2: Reusing ODBC handle 0x7f249400cb58 from class 'asteriskcdrdb'
[2017-12-02 13:40:43] DEBUG[5232]: cel_odbc.c:780 odbc_log: Executing SQL statement: [INSERT INTO cel (eventtype, eventtime, cid_name, cid_num, cid_ani, cid_rdnis, cid_dnid, exten, context, channame, appname, appdata, amaflags, accountcode, uniqueid, linkedid, peer, userdeftype, extra) VALUES ('CHAN_START', {ts '2017-12-02 13:40:43.328509'}, '00zzzzzzzzzz', '00zzzzzzzz', '', '', '', '2455794e0', 'from-trunk', 'SIP/0044yyyyyyyyyyyy-0000000d', '', '', 3, '', '1512222043.13', '1512222043.13', '', '', '')]
[2017-12-02 13:40:43] DEBUG[13525][C-0000000a]: pbx.c:2915 pbx_extension_helper: Launching 'Answer'
-- Executing [2455794e0@from-trunk:1] Answer("SIP/0044yyyyyyyyyyyy-0000000d", "") in new stack
[2017-12-02 13:40:43] DEBUG[13525][C-0000000a]: chan_sip.c:7410 sip_answer: SIP answering channel: SIP/0044yyyyyyyyyyyy-0000000d
[2017-12-02 13:40:43] DEBUG[13525][C-0000000a]: res_rtp_asterisk.c:3638 ast_rtp_update_source: Setting the marker bit due to a source update
[2017-12-02 13:40:43] DEBUG[13525][C-0000000a]: chan_sip.c:13523 add_sdp: ** Our capability: (gsm|ulaw|alaw) Video flag: True Text flag: True
[2017-12-02 13:40:43] DEBUG[13525][C-0000000a]: chan_sip.c:13524 add_sdp: ** Our prefcodec: (nothing)
[2017-12-02 13:40:43] DEBUG[13525][C-0000000a]: chan_sip.c:13695 add_sdp: -- Done with adding codecs to SDP
[2017-12-02 13:40:43] DEBUG[13525][C-0000000a]: chan_sip.c:13720 add_sdp: Setting framing on incoming call: 20
[2017-12-02 13:40:43] DEBUG[13525][C-0000000a]: chan_sip.c:13914 add_sdp: Done building SDP. Settling with this capability: (gsm|ulaw|alaw)
[2017-12-02 13:40:43] DEBUG[13525][C-0000000a]: chan_sip.c:3751 __sip_xmit: Trying to put 'SIP/2.0 200' onto UDP socket destined for 217.10.79.23:5060
[2017-12-02 13:40:43] DEBUG[5128]: devicestate.c:367 _ast_device_state: No provider found, checking channel drivers for SIP - 0044yyyyyyyyyyyy
[2017-12-02 13:40:43] DEBUG[5128]: chan_sip.c:30362 sip_devicestate: Checking device state for peer 0044yyyyyyyyyyyy
[2017-12-02 13:40:43] DEBUG[5128]: devicestate.c:472 do_state_change: Changing state for SIP/0044yyyyyyyyyyyy - state 1 (Not in use)
[2017-12-02 13:40:43] DEBUG[5232]: res_odbc.c:706 ast_odbc_release_obj: Releasing ODBC handle 0x7f249400cb58 into pool
[2017-12-02 13:40:43] DEBUG[5232]: res_odbc.c:857 _ast_odbc_request_obj2: Reusing ODBC handle 0x7f249400cb58 from class 'asteriskcdrdb'
[2017-12-02 13:40:43] DEBUG[5232]: cel_odbc.c:780 odbc_log: Executing SQL statement: [INSERT INTO cel (eventtype, eventtime, cid_name, cid_num, cid_ani, cid_rdnis, cid_dnid, exten, context, channame, appname, appdata, amaflags, accountcode, uniqueid, linkedid, peer, userdeftype, extra) VALUES ('ANSWER', {ts '2017-12-02 13:40:43.373574'},"severalnumbers', '', '2455794e0', '2455794e0', 'from-trunk', 'SIP/0044yyyyyyyyyyyy-0000000d', 'Answer', '', 3, '', '1512222043.13', '1512222043.13', '', '', '')]
[2017-12-02 13:40:43] DEBUG[6046]: chan_sip.c:9416 __find_call: = Looking for Call ID: [email protected] (Checking From) --From tag as0a19d74c --To-tag as273d4c00
[2017-12-02 13:40:43] DEBUG[6046][C-0000000a]: chan_sip.c:28827 handle_incoming: **** Received ACK (6) - Command in SIP ACK
[2017-12-02 13:40:43] DEBUG[6046][C-0000000a]: chan_sip.c:4535 __sip_ack: Stopping retransmission on '[email protected]' of Response 103: Match Found
[2017-12-02 13:40:43] DEBUG[13525][C-0000000a]: chan_sip.c:8616 sip_rtp_read: Oooh, format changed to alaw
[2017-12-02 13:40:43] DEBUG[13525][C-0000000a]: channel.c:5551 set_format: Channel SIP/0044yyyyyyyyyyyy-0000000d setting read format path: alaw -> gsm
[2017-12-02 13:40:43] DEBUG[13525][C-0000000a]: channel.c:5551 set_format: Channel SIP/0044yyyyyyyyyyyy-0000000d setting write format path: gsm -> alaw
[2017-12-02 13:40:43] DEBUG[13525][C-0000000a]: pbx.c:2915 pbx_extension_helper: Launching 'Playback'
-- Executing [2455794e0@from-trunk:2] Playback("SIP/0044yyyyyyyyyyyy-0000000d", "hello-world") in new stack
[2017-12-02 13:40:43] DEBUG[13525][C-0000000a]: media_cache.c:250 ast_media_cache_retrieve: Failed to obtain media at 'hello-world'
[2017-12-02 13:40:43] DEBUG[13525][C-0000000a]: channel.c:5551 set_format: Channel SIP/0044yyyyyyyyyyyy-0000000d setting write format path: g722 -> alaw
[2017-12-02 13:40:43] DEBUG[13525][C-0000000a]: res_rtp_asterisk.c:4291 ast_rtp_write: Ooh, format changed from none to alaw
[2017-12-02 13:40:43] DEBUG[13525][C-0000000a]: channel.c:3192 ast_settimeout_full: Scheduling timer at (50 requested / 50 actual) timer ticks per second
-- <SIP/0044yyyyyyyyyyyy-0000000d> Playing 'hello-world.g722' (language 'nl')
[2017-12-02 13:40:43] DEBUG[5232]: res_odbc.c:706 ast_odbc_release_obj: Releasing ODBC handle 0x7f249400cb58 into pool
[2017-12-02 13:40:44] DEBUG[13525][C-0000000a]: channel.c:3192 ast_settimeout_full: Scheduling timer at (148 requested / 148 actual) timer ticks per second
[2017-12-02 13:40:44] DEBUG[13525][C-0000000a]: channel.c:3192 ast_settimeout_full: Scheduling timer at (0 requested / 0 actual) timer ticks per second
[2017-12-02 13:40:44] DEBUG[13525][C-0000000a]: channel.c:3192 ast_settimeout_full: Scheduling timer at (0 requested / 0 actual) timer ticks per second
[2017-12-02 13:40:44] DEBUG[13525][C-0000000a]: channel.c:3192 ast_settimeout_full: Scheduling timer at (0 requested / 0 actual) timer ticks per second
[2017-12-02 13:40:44] DEBUG[13525][C-0000000a]: channel.c:5551 set_format: Channel SIP/0044yyyyyyyyyyyy-0000000d setting write format path: gsm -> alaw
[2017-12-02 13:40:44] DEBUG[13525][C-0000000a]: pbx_variables.c:379 ast_str_retrieve_variable: Result of 'CONTEXT' is 'from-trunk'
[2017-12-02 13:40:44] DEBUG[13525][C-0000000a]: pbx.c:2915 pbx_extension_helper: Launching 'Goto'
-- Executing [2455794e0@from-trunk:3] Goto("SIP/0044yyyyyyyyyyyy-0000000d", "ext-did,from-trunk,1") in new stack
-- Goto (ext-did,from-trunk,1)
[2017-12-02 13:40:44] WARNING[13525][C-0000000a]: pbx.c:4459 __ast_pbx_run: Channel 'SIP/0044yyyyyyyyyyyy-0000000d' sent to invalid extension but no invalid handler: context,exten,priority=ext-did,from-trunk,1
[2017-12-02 13:40:44] DEBUG[13525][C-0000000a]: channel.c:2496 ast_softhangup_nolock: Soft-Hanging (0x10) up channel 'SIP/0044yyyyyyyyyyyy-0000000d'
[2017-12-02 13:40:44] DEBUG[13525][C-0000000a]: channel.c:2587 ast_hangup: Channel 0x7f2498a58768 'SIP/0044yyyyyyyyyyyy-0000000d' hanging up. Refs: 2
[2017-12-02 13:40:44] DEBUG[13525][C-0000000a]: chan_sip.c:7152 sip_hangup: Hangup call SIP/0044yyyyyyyyyyyy-0000000d, SIP callid [email protected]
[2017-12-02 13:40:44] DEBUG[13525][C-0000000a]: chan_sip.c:3751 __sip_xmit: Trying to put 'BYE sip:003' onto UDP socket destined for 217.10.79.23:5060
[2017-12-02 13:40:44] DEBUG[13525][C-0000000a]: channel.c:2222 ast_channel_destructor: Channel 0x7f2498a58768 'SIP/0044yyyyyyyyyyyy-0000000d' destroying
[2017-12-02 13:40:44] DEBUG[5222]: cdr.c:1289 cdr_object_finalize: Finalized CDR for SIP/0044yyyyyyyyyyyy-0000000d - start 1512222043.328462 answer 1512222043.334069 end 1512222044.749792 dispo ANSWERED
[2017-12-02 13:40:44] DEBUG[5128]: devicestate.c:367 _ast_device_state: No provider found, checking channel drivers for SIP - 0044yyyyyyyyyyyy
[2017-12-02 13:40:44] DEBUG[5128]: chan_sip.c:30362 sip_devicestate: Checking device state for peer 0044yyyyyyyyyyyy
[2017-12-02 13:40:44] DEBUG[5128]: devicestate.c:472 do_state_change: Changing state for SIP/0044yyyyyyyyyyyy - state 1 (Not in use)
[2017-12-02 13:40:44] DEBUG[5222]: res_odbc.c:857 _ast_odbc_request_obj2: Reusing ODBC handle 0x7f249400cb58 from class 'asteriskcdrdb'
[2017-12-02 13:40:44] DEBUG[5222]: cdr_adaptive_odbc.c:756 odbc_log: Executing [INSERT INTO cdr (calldate, clid, src, dst, dcontext, channel, lastapp, lastdata, duration, billsec, disposition, amaflags, uniqueid, linkedid, sequence) VALUES ({ ts '2017-12-02 13:40:43' }, 'several numbers', 'from-trunk', 'ext-did', 'SIP/0044560xxxxx-0000000d', 'Goto', 'ext-did,from-trunk,1', 1, 1, 'ANSWERED', 3, '1512222043.13', '1512222043.13', 16)]
[2017-12-02 13:40:44] DEBUG[5232]: res_odbc.c:919 odbc_obj_connect: Connecting asteriskcdrdb(0x7f24900126c8)
[2017-12-02 13:40:44] DEBUG[5232]: res_odbc.c:957 odbc_obj_connect: res_odbc: Connected to asteriskcdrdb [MySQL-asteriskcdrdb (0x7f24900126c8)]
[2017-12-02 13:40:44] DEBUG[5232]: res_odbc.c:836 _ast_odbc_request_obj2: Created ODBC handle 0x7f24900126c8 on class 'asteriskcdrdb', new count is 2
[2017-12-02 13:40:44] DEBUG[5232]: cel_odbc.c:780 odbc_log: Executing SQL statement: [INSERT INTO cel (eventtype, eventtime, cid_name, cid_num, cid_ani, cid_rdnis, cid_dnid, exten, context, channame, appname, appdata, amaflags, accountcode, uniqueid, linkedid, peer, userdeftype, extra) VALUES ('HANGUP', {ts '2017-12-02 13:40:44.749911'}, "several numbers, 'from-trunk', 'ext-did', 'SIP/0044yyyyyyyyyyyy-0000000d', '', '', 3, '', '1512222043.13', '1512222043.13', '', '', '{"hangupcause":0,"hangupsource":"","dialstatus":""}')]
[2017-12-02 13:40:44] DEBUG[6046]: chan_sip.c:9416 __find_call: = Looking for Call ID: [email protected] (Checking To) --From tag as273d4c00 --To-tag as0a19d74c
[2017-12-02 13:40:44] DEBUG[6046][C-0000000a]: chan_sip.c:4535 __sip_ack: Stopping retransmission on '[email protected]' of Request 102: Match Found
[2017-12-02 13:40:44] DEBUG[6046]: chan_sip.c:6592 sip_pvt_dtor: Destroying SIP dialog [email protected]
[2017-12-02 13:40:44] DEBUG[6046]: rtp_engine.c:414 instance_destructor: Destroyed RTP instance '0x7f24989c8328'
[2017-12-02 13:40:44] DEBUG[5222]: res_odbc.c:706 ast_odbc_release_obj: Releasing ODBC handle 0x7f249400cb58 into pool
[2017-12-02 13:40:44] DEBUG[5232]: res_odbc.c:706 ast_odbc_release_obj: Releasing ODBC handle 0x7f24900126c8 into pool
[2017-12-02 13:40:44] DEBUG[5232]: res_odbc.c:857 _ast_odbc_request_obj2: Reusing ODBC handle 0x7f24900126c8 from class 'asteriskcdrdb'
[2017-12-02 13:40:44] DEBUG[5232]: cel_odbc.c:780 odbc_log: Executing SQL statement: [INSERT INTO cel (eventtype, eventtime, cid_name, cid_num, cid_ani, cid_rdnis, cid_dnid, exten, context, channame, appname, appdata, amaflags, accountcode, uniqueid, linkedid, peer, userdeftype, extra) VALUES ('CHAN_END', {ts '2017-12-02 13:40:44.849599'}, '00xxxxxxxxxx', '00xxxxxxxx', '00xxxxxxxx', '', '2455794e0', 'from-trunk', 'ext-did', 'SIP/0044560307xxxx-0000000d', '', '', 3, '', '1512222043.13', '1512222043.13', '', '', '')]
[2017-12-02 13:40:44] DEBUG[5232]: res_odbc.c:706 ast_odbc_release_obj: Releasing ODBC handle 0x7f24900126c8 into pool
[2017-12-02 13:40:44] DEBUG[5232]: res_odbc.c:857 _ast_odbc_request_obj2: Reusing ODBC handle 0x7f24900126c8 from class 'asteriskcdrdb'
[2017-12-02 13:40:44] DEBUG[5232]: cel_odbc.c:780 odbc_log: Executing SQL statement: [INSERT INTO cel (eventtype, eventtime, cid_name, cid_num, cid_ani, cid_rdnis, cid_dnid, exten, context, channame, appname, appdata, amaflags, accountcode, uniqueid, linkedid, peer, userdeftype, extra) VALUES ('LINKEDID_END', {ts '2017-12-02 13:40:44.977622'},"several numbers"', 'from-trunk', 'ext-did', 'SIP/0044yyyyyyyyyyyy-0000000d', '', '', 3, '', '1512222043.13', '1512222043.13', '', '', '')]
[2017-12-02 13:40:45] DEBUG[5232]: res_odbc.c:706 ast_odbc_release_obj: Releasing ODBC handle 0x7f24900126c8 into pool
[2017-12-02 13:40:53] DEBUG[6079]: res_pjsip_registrar_expire.c:78 check_expiration_thread: Woke up at 1512222053 Interval: 30
[2017-12-02 13:40:53] DEBUG[6079]: res_pjsip_registrar_expire.c:85 check_expiration_thread: Expiring 0 contacts
FREEPBX*CLI>