May 2015 - FreeSWITCH-users - FreeSWITCH Mailing Lists

FreeSWITCH 1.6 Video MP4 recording
by Denis Jakovlev 15 May '15

15 May '15

Hi All Finally I managed to get record MP4. He writes beautifully with the module mod_vlc. But without sound. [00007ff65c027408] core libvlc warning: cannot load module `/usr/lib/vlc/plugins/stream_out/libstream_out_chromaprint_plugin.so' (libvpx.so.1: cannot open shared object file: No such file or directory) [00007ff65c027408] core libvlc warning: cannot load module `/usr/lib/vlc/plugins/access/libavio_plugin.so' (libvpx.so.1: cannot open shared object file: No such file or directory) [00007ff65c027408] core libvlc warning: cannot load module `/usr/lib/vlc/plugins/demux/libavformat_plugin.so' (libvpx.so.1: cannot open shared object file: No such file or directory) [00007ff65c027408] core libvlc warning: cannot load module `/usr/lib/vlc/plugins/codec/libhwdummy_plugin.so' (libvpx.so.1: cannot open shared object file: No such file or directory) [00007ff65c027408] core libvlc warning: cannot load module `/usr/lib/vlc/plugins/codec/libavcodec_plugin.so' (libvpx.so.1: cannot open shared object file: No such file or directory) I checked. Indeed there is a module libvpx.so not in place. What do I need to do to this module come from? Thank you -- S pozdravem, Ing.Denis Jakovlev mob.tel. 775-415-382

4 3

MP4 record in 1.6
by Denis Jakovlev 15 May '15

15 May '15

Hi All, New FreeSWITCH 1.6 Video on Debian 8. I try to record MP4 file in the conference.. Simple dialplan <extension name="nb_conferences"> <condition field="destination_number" expression="^(30\d{2})$"> <action application="answer"/> <action application="set" data="enable_file_write_buffering=false"/> <action application="record" data="/usr/local/freeswitch/recordings/${strftime(%Y-%m-%d-%H-%M-%S)}_${uuid}.mp4"/> <action application="conference" data="$1-${domain_name}@default"/> </condition> </extension> It works. Even something writes. But I can not play this file (The file in the attachment). What am I doing wrong? -- S pozdravem, Ing.Denis Jakovlev mob.tel. 775-415-382

3 3

***NOTICE: FreeSWITCH File Distribution server slight path update.
by Ken Rice 15 May '15

15 May '15

Greetings FreeSWITCHers! Just a quick note, we¹ve done a little spring cleaning on http://files.freeswitch.org/ The root of the web server was getting a bit messy with all the old releases so we¹ve gone through and reorganized a little bit. FreeSWITCH Source Tarballs have been to http://files.freeswitch.org/releases/freeswitch and the sounds tarballs have been moved to http://files.freeswitch.org/releases/sounds/ There is a 301 redirect in place so all your old links to the sources will still work, but you¹ll want to update your scripts to bypass the 301 and look in the new locations. Have a Great Day! K -- Ken http://www.FreeSWITCH.org http://www.ClueCon.com http://www.OSTAG.org irc.freenode.net #freeswitch Twitter: @FreeSWITCH

1 0

Error during the installation of esl luamod
by Aqs Younas 15 May '15

15 May '15

Hi users. During esl luamod installation I see this error. *esl_wrap.cpp:746:17: fatal error: lua.h: No such file or directory #include "lua.h" ^compilation terminated.make[1]: *** [esl_wrap.o] Error 1make[1]: Leaving directory `/usr/src/freeswitch/libs/esl/lua'make: *** [luamod] Error 2* But running '*find lua.h*' I see file is located at ' */usr/include/lua5.2/lua.h*' I guess some of you guys had been gone through this. How did you resolve this? Any pointer would be much appreciated. Thanks.

2 2

FreeSWITCH Friday FreeForAll Reminder!
by Ken Rice 15 May '15

15 May '15

FreeSWITCHers, Do not forget to join us at 2PM CST for the FreeSWITCH Friday FreeFor All Visit http://ift.tt/1n3h0Pf and Click Call 888 with your WebRTC enabled Browser and headset, Call sip:888@conference.freeswitch.org or see http://ift.tt/1prwIZL for access info! -- Ken FreeSWITCH.org ClueCon.com OSTAG.org irc.freenode.net #freeswitch Twitter: @FreeSWITCH @ClueCon

1 0

XML_RPX connection limit
by Leonid Nasedkin 15 May '15

15 May '15

Hi, All! Im trying to use freeswitch for automated outbound calls. Im creating outbound calls via xml_rpc interface with api call. But it seems like somewhere in freeswitch hardcoded connection limit to xml_rpc . I cant create more then 16 concurrent connections. How I can increase this value? Im using: FreeSWITCH version: 1.4.15~64bit ( 64bit) 2.6.32-504.16.2.el6.x86_64 CentOS 6.5 Thanks.

1 0

FreeSWITCH PROXY:0
by Asd 15 May '15

15 May '15

Hi all Freeswitch version: 1.4.18 Debian stable with TLS if i try to call internal: RINGING <<== OKby receive of call <<== NORMAL_CLEARING then KILL with version 1.4.12 worked what am i doing wrong? my log file: tport.c:2773 tport_wakeup() tport_wakeup(0x7fac6803aad0): events IN tport.c:2864 tport_recv_event() tport_recv_event(0x7fac6803aad0) tport_type_tls.c:434 tport_tls_recv() tport_tls_recv(0x7fac6803aad0): tls_read() returned 1143 tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7fac6803aad0) msg 0x7fac6805d660 from (tls/XXX.XXX.XXX.XXX:22035) has 1143 bytes, veclen = 1 tport.c:3023 tport_deliver() tport_deliver(0x7fac6803aad0): msg 0x7fac6805d660 (1143 bytes) from tls/XXX.XXX.XXX.XXX:22035/sips next=(nil) nta.c:2880 agent_recv_request() nta: received INVITE sips:1004@sip.domain.com:9061 SIP/2.0 (CSeq 15796) nta.c:3174 agent_check_request_via() nta: Via check: received=XXX.XXX.XXX.XXX nta.c:3085 agent_recv_request() nta: INVITE (15796) going to a default leg nta.c:1348 set_timeout() nta: timer shortened to 2000 ms nua_server.c:102 nua_stack_process_request() nua: nua_stack_process_request: entering nua_stack.c:899 nh_create() nua: nh_create: entering nua_common.c:108 nh_create_handle() nua: nh_create_handle: entering nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering soa.c:280 soa_clone() soa_clone(static::0x7fac68002100, 0x7fac680015a0, 0x7fac68077650) called soa.c:403 soa_set_params() soa_set_params(static::0x7fac68073910, ...) called nta.c:4417 nta_leg_tcreate() nta_leg_tcreate(0x7fac680711d0) soa.c:1302 soa_init_offer_answer() soa_init_offer_answer(static::0x7fac68073910) called soa.c:1171 soa_set_remote_sdp() soa_set_remote_sdp(static::0x7fac68073910, (nil), 0x7fac68062468, 431) called nua_dialog.c:338 nua_dialog_usage_add() nua(0x7fac68077650): adding session usage tport.c:3257 tport_tsend() tport_tsend(0x7fac6803aad0) tpn = TLS/XXX.XXX.XXX.XXX:22035 tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7fac6803b270 0x7fac6804e0f0 385 (385) tport.c:3492 tport_send_msg() tport_vsend returned 385 tport.c:2296 tport_set_secondary_timer() tport(0x7fac6803aad0): reset timer nta.c:6791 incoming_reply() nta: sent 100 Trying for INVITE (15796) nua_session.c:4139 signal_call_state_change() nua(0x7fac68077650): call state changed: init -> received, received offer soa.c:1098 soa_get_remote_sdp() soa_get_remote_sdp(static::0x7fac68073910, [0x7fac7f7018b8], [0x7fac7f7018c0], [(nil)]) called tport.c:2296 tport_set_secondary_timer() tport(0x7fac6803aad0): reset timer nua_stack.c:359 nua_application_event() nua: nua_application_event: entering nua.c:342 nua_handle_bind() nua: nua_handle_bind: entering 2015-04-26 19:27:42.024708 [NOTICE] switch_channel.c:1055 New Channel sofia/internal/1001(a)sip.domain.com [b847625c-43a8-4ece-9f12-9f7b5e84be32] 2015-04-26 19:27:42.024708 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/1001(a)sip.domain.com [BREAK] nua_stack.c:359 nua_application_event() nua: nua_application_event: entering 2015-04-26 19:27:42.024708 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/1001(a)sip.domain.com [BREAK] 2015-04-26 19:27:42.024708 [DEBUG] switch_core_state_machine.c:472 (sofia/internal/1001(a)sip.domain.com) Running State Change CS_NEW nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering 2015-04-26 19:27:42.024708 [DEBUG] sofia.c:8844 sofia/internal/1001(a)sip.domain.com receiving invite from XXX.XXX.XXX.XXX:22035 version: 1.4.18 -3-1 64bit 2015-04-26 19:27:42.024708 [DEBUG] switch_core_media.c:344 Found audio zrtp-hash; setting r_sdp_audio_zrtp_hash=1.10 b7ef73966e5720fe5736350d2d57cb35460f4add4c6675e8d4221a13c7fc5dbe 2015-04-26 19:27:42.024708 [DEBUG] sofia.c:9011 IP XXX.XXX.XXX.XXX Rejected by acl "domains". Falling back to Digest auth. nua.c:879 nua_respond() nua: nua_respond: entering nua_stack.c:529 nua_signal() nua(0x7fac68077650): sent signal r_respond 2015-04-26 19:27:42.024708 [WARNING] sofia_reg.c:1742 SIP auth challenge (INVITE) on sofia profile 'internal' for [1004(a)sip.domain.com] from ip XXX.XXX.XXX.XXX nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering 2015-04-26 19:27:42.024708 [DEBUG] switch_core_state_machine.c:491 (sofia/internal/1001(a)sip.domain.com) State NEW soa.c:403 soa_set_params() soa_set_params(static::0x7fac68073910, ...) called nua_session.c:2320 nua_invite_server_respond() nua: nua_invite_server_respond: entering soa.c:1214 soa_clear_remote_sdp() soa_clear_remote_sdp(static::0x7fac68073910) called tport.c:3257 tport_tsend() tport_tsend(0x7fac6803aad0) tpn = TLS/XXX.XXX.XXX.XXX:22035 tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7fac6803b270 0x7fac6805a8a0 889 (889) tport.c:3492 tport_send_msg() tport_vsend returned 889 tport.c:2296 tport_set_secondary_timer() tport(0x7fac6803aad0): reset timer nta.c:6791 incoming_reply() nta: sent 407 Proxy Authentication Required for INVITE (15796) nua_dialog.c:397 nua_dialog_usage_remove_at() nua(0x7fac68077650): removing session usage nua_session.c:4139 signal_call_state_change() nua(0x7fac68077650): call state changed: received -> terminated soa.c:356 soa_destroy() soa_destroy(static::0x7fac68073910) called nta.c:4470 nta_leg_destroy() nta_leg_destroy(0x7fac680711d0) nua_stack.c:359 nua_application_event() nua: nua_application_event: entering 2015-04-26 19:27:42.024708 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/1001(a)sip.domain.com [BREAK] nua_stack.c:359 nua_application_event() nua: nua_application_event: entering 2015-04-26 19:27:42.024708 [DEBUG] sofia.c:2065 detaching session b847625c-43a8-4ece-9f12-9f7b5e84be32 nua.c:921 nua_handle_destroy() nua: nua_handle_destroy: entering nua_stack.c:529 nua_signal() nua(0x7fac68077650): sent signal r_destroy nta.c:4470 nta_leg_destroy() nta_leg_destroy((nil)) nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:921 nua_handle_destroy() nua: nua_handle_destroy: entering tport.c:2773 tport_wakeup() tport_wakeup(0x7fac6803aad0): events IN tport.c:2864 tport_recv_event() tport_recv_event(0x7fac6803aad0) tport_type_tls.c:434 tport_tls_recv() tport_tls_recv(0x7fac6803aad0): tls_read() returned 412 tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7fac6803aad0) msg 0x7fac6804e0f0 from (tls/XXX.XXX.XXX.XXX:22035) has 412 bytes, veclen = 1 tport.c:3023 tport_deliver() tport_deliver(0x7fac6803aad0): msg 0x7fac6804e0f0 (412 bytes) from tls/XXX.XXX.XXX.XXX:22035/sips next=(nil) nta.c:2880 agent_recv_request() nta: received ACK sips:1004@sip.domain.com:9061 SIP/2.0 (CSeq 15796) nta.c:3174 agent_check_request_via() nta: Via check: received=XXX.XXX.XXX.XXX nta.c:3019 agent_recv_request() nta: ACK (15796) is going to INVITE (15796) tport.c:2296 tport_set_secondary_timer() tport(0x7fac6803aad0): reset timer tport.c:2773 tport_wakeup() tport_wakeup(0x7fac6803aad0): events IN tport.c:2864 tport_recv_event() tport_recv_event(0x7fac6803aad0) tport_type_tls.c:434 tport_tls_recv() tport_tls_recv(0x7fac6803aad0): tls_read() returned 1419 tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7fac6803aad0) msg 0x7fac6804e0f0 from (tls/XXX.XXX.XXX.XXX:22035) has 1419 bytes, veclen = 1 tport.c:3023 tport_deliver() tport_deliver(0x7fac6803aad0): msg 0x7fac6804e0f0 (1419 bytes) from tls/XXX.XXX.XXX.XXX:22035/sips next=(nil) nta.c:2880 agent_recv_request() nta: received INVITE sips:1004@sip.domain.com:9061 SIP/2.0 (CSeq 15797) nta.c:3174 agent_check_request_via() nta: Via check: received=XXX.XXX.XXX.XXX nta.c:3085 agent_recv_request() nta: INVITE (15797) going to a default leg nua_server.c:102 nua_stack_process_request() nua: nua_stack_process_request: entering nua_stack.c:899 nh_create() nua: nh_create: entering nua_common.c:108 nh_create_handle() nua: nh_create_handle: entering nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering soa.c:280 soa_clone() soa_clone(static::0x7fac68002100, 0x7fac680015a0, 0x7fac680706f0) called soa.c:403 soa_set_params() soa_set_params(static::0x7fac680598d0, ...) called nta.c:4417 nta_leg_tcreate() nta_leg_tcreate(0x7fac68073b20) soa.c:1302 soa_init_offer_answer() soa_init_offer_answer(static::0x7fac680598d0) called soa.c:1171 soa_set_remote_sdp() soa_set_remote_sdp(static::0x7fac680598d0, (nil), 0x7fac6805d1ac, 431) called nua_dialog.c:338 nua_dialog_usage_add() nua(0x7fac680706f0): adding session usage tport.c:3257 tport_tsend() tport_tsend(0x7fac6803aad0) tpn = TLS/XXX.XXX.XXX.XXX:22035 tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7fac6803b270 0x7fac6805b1d0 385 (385) tport.c:3492 tport_send_msg() tport_vsend returned 385 tport.c:2296 tport_set_secondary_timer() tport(0x7fac6803aad0): reset timer nta.c:6791 incoming_reply() nta: sent 100 Trying for INVITE (15797) nua_session.c:4139 signal_call_state_change() nua(0x7fac680706f0): call state changed: init -> received, received offer soa.c:1098 soa_get_remote_sdp() soa_get_remote_sdp(static::0x7fac680598d0, [0x7fac7f7018b8], [0x7fac7f7018c0], [(nil)]) called tport.c:2296 tport_set_secondary_timer() tport(0x7fac6803aad0): reset timer nua_stack.c:359 nua_application_event() nua: nua_application_event: entering nua.c:342 nua_handle_bind() nua: nua_handle_bind: entering 2015-04-26 19:27:42.204725 [DEBUG] sofia.c:2173 Re-attaching to session b847625c-43a8-4ece-9f12-9f7b5e84be32 2015-04-26 19:27:42.204725 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/1001(a)sip.domain.com [BREAK] nua_stack.c:359 nua_application_event() nua: nua_application_event: entering 2015-04-26 19:27:42.204725 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/1001(a)sip.domain.com [BREAK] nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering 2015-04-26 19:27:42.204725 [DEBUG] sofia.c:8844 sofia/internal/1001(a)sip.domain.com receiving invite from XXX.XXX.XXX.XXX:22035 version: 1.4.18 -3-1 64bit 2015-04-26 19:27:42.204725 [DEBUG] switch_core_media.c:344 Found audio zrtp-hash; setting r_sdp_audio_zrtp_hash=1.10 b7ef73966e5720fe5736350d2d57cb35460f4add4c6675e8d4221a13c7fc5dbe 2015-04-26 19:27:42.204725 [DEBUG] sofia.c:9011 IP XXX.XXX.XXX.XXX Rejected by acl "domains". Falling back to Digest auth. nua.c:610 nua_set_hparams() nua: nua_set_hparams: entering nua.c:610 nua_set_hparams() nua: nua_r_set_params with invalid handle (nil) 2015-04-26 19:27:42.204725 [DEBUG] sofia.c:10109 Setting NAT mode based on via received nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering 2015-04-26 19:27:42.204725 [DEBUG] sofia.c:6623 Channel sofia/internal/1001(a)sip.domain.com entering state [received][100] 2015-04-26 19:27:42.204725 [DEBUG] sofia.c:6633 Remote SDP: v=0 o=- 3639058062 3639058062 IN IP4 192.168.51.103 s=pjmedia c=IN IP4 192.168.51.103 t=0 0 m=audio 4002 RTP/AVP 99 0 8 101 c=IN IP4 192.168.51.103 a=rtpmap:99 SILK/24000 a=fmtp:99 useinbandfec=0 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=rtcp:4003 IN IP4 192.168.51.103 a=zrtp-hash:1.10 b7ef73966e5720fe5736350d2d57cb35460f4add4c6675e8d4221a13c7fc5dbe 2015-04-26 19:27:42.204725 [DEBUG] sofia.c:6893 (sofia/internal/1001(a)sip.domain.com) State Change CS_NEW -> CS_INIT 2015-04-26 19:27:42.204725 [DEBUG] switch_core_session.c:1396 Send signal sofia/internal/1001(a)sip.domain.com [BREAK] nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering 2015-04-26 19:27:42.204725 [DEBUG] switch_core_state_machine.c:472 (sofia/internal/1001(a)sip.domain.com) Running State Change CS_INIT 2015-04-26 19:27:42.204725 [DEBUG] switch_core_state_machine.c:512 (sofia/internal/1001(a)sip.domain.com) State INIT 2015-04-26 19:27:42.204725 [DEBUG] mod_sofia.c:87 sofia/internal/1001(a)sip.domain.com SOFIA INIT 2015-04-26 19:27:42.204725 [DEBUG] switch_core_state_machine.c:40 sofia/internal/1001(a)sip.domain.com Standard INIT 2015-04-26 19:27:42.204725 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/1001(a)sip.domain.com) State Change CS_INIT -> CS_ROUTING 2015-04-26 19:27:42.204725 [DEBUG] switch_core_session.c:1396 Send signal sofia/internal/1001(a)sip.domain.com [BREAK] 2015-04-26 19:27:42.204725 [DEBUG] switch_core_state_machine.c:512 (sofia/internal/1001(a)sip.domain.com) State INIT going to sleep 2015-04-26 19:27:42.204725 [DEBUG] switch_core_state_machine.c:472 (sofia/internal/1001(a)sip.domain.com) Running State Change CS_ROUTING 2015-04-26 19:27:42.204725 [DEBUG] switch_channel.c:2184 (sofia/internal/1001(a)sip.domain.com) Callstate Change DOWN -> RINGING 2015-04-26 19:27:42.204725 [DEBUG] switch_core_state_machine.c:528 (sofia/internal/1001(a)sip.domain.com) State ROUTING 2015-04-26 19:27:42.204725 [DEBUG] mod_sofia.c:123 sofia/internal/1001(a)sip.domain.com SOFIA ROUTING 2015-04-26 19:27:42.204725 [DEBUG] switch_core_state_machine.c:166 sofia/internal/1001(a)sip.domain.com Standard ROUTING 2015-04-26 19:27:42.204725 [INFO] mod_dialplan_xml.c:635 Processing 1001 <1001>->1004 in context sip.domain.com Dialplan: sofia/internal/1001(a)sip.domain.com parsing [sip.domain.com->PHONE-FAX_b_1001_49123456789100] continue=false Dialplan: sofia/internal/1001(a)sip.domain.com Regex (PASS) [PHONE-FAX_b_1001_49123456789100] context(sip.domain.com) =~ /sip.domain.com/ break=on-false Dialplan: sofia/internal/1001(a)sip.domain.com Regex (FAIL) [PHONE-FAX_b_1001_49123456789100] destination_number(1004) =~ /^(1234567e0)$/ break=on-false Dialplan: sofia/internal/1001(a)sip.domain.com parsing [sip.domain.com->PHONE-FAX_l_1002_49123456789101] continue=false Dialplan: sofia/internal/1001(a)sip.domain.com Regex (PASS) [PHONE-FAX_l_1002_49123456789101] context(sip.domain.com) =~ /sip.domain.com/ break=on-false Dialplan: sofia/internal/1001(a)sip.domain.com Regex (FAIL) [PHONE-FAX_l_1002_49123456789101] destination_number(1004) =~ /^(1234567e1)$/ break=on-false Dialplan: sofia/internal/1001(a)sip.domain.com parsing [sip.domain.com->PHONE-FAX_m_1003_49123456789101-copy] continue=false Dialplan: sofia/internal/1001(a)sip.domain.com Regex (PASS) [PHONE-FAX_m_1003_49123456789102] context(sip.domain.com) =~ /sip.domain.com/ break=on-false Dialplan: sofia/internal/1001(a)sip.domain.com Regex (FAIL) [PHONE-FAX_m_1003_49123456789102] destination_number(1004) =~ /^(1234567e2)$/ break=on-false Dialplan: sofia/internal/1001(a)sip.domain.com parsing [sip.domain.com->internal-voicemail-com] continue=false Dialplan: sofia/internal/1001(a)sip.domain.com Regex (PASS) [internal-voicemail-com] context(sip.domain.com) =~ /sip.domain.com/ break=on-false Dialplan: sofia/internal/1001(a)sip.domain.com Regex (PASS) [internal-voicemail-com] caller_id_number(1001) =~ /^(((\+|00)49)|1\d{3})$/ break=on-false Dialplan: sofia/internal/1001(a)sip.domain.com Regex (FAIL) [internal-voicemail-com] ${user_data(${destination_number}@${domain} param vm-enabled)}(false) =~ /true/ break=on-false Dialplan: sofia/internal/1001(a)sip.domain.com parsing [sip.domain.com->internal-voicemail-com2] continue=false Dialplan: sofia/internal/1001(a)sip.domain.com Regex (PASS) [internal-voicemail-com2] context(sip.domain.com) =~ /sip.domain.com/ break=on-false Dialplan: sofia/internal/1001(a)sip.domain.com Regex (FAIL) [internal-voicemail-com2] ${user_data(${destination_number}@${domain} param vm-enabled)}(false) =~ /true/ break=on-false Dialplan: sofia/internal/1001(a)sip.domain.com parsing [sip.domain.com->internal] continue=false Dialplan: sofia/internal/1001(a)sip.domain.com Regex (PASS) [internal] context(sip.domain.com) =~ /sip.domain.com/ break=on-false Dialplan: sofia/internal/1001(a)sip.domain.com Regex (PASS) [internal] destination_number(1004) =~ /^(1\d{3})$/ break=on-false Dialplan: sofia/internal/1001(a)sip.domain.com Action set(zrtp_enrollment=true) Dialplan: sofia/internal/1001(a)sip.domain.com Action set(hangup_after_bridge=false) Dialplan: sofia/internal/1001(a)sip.domain.com Action set(continue_on_fail=true) Dialplan: sofia/internal/1001(a)sip.domain.com Action set(intcallid=1004) Dialplan: sofia/internal/1001(a)sip.domain.com Action bridge(sofia/internal/${intcallid}%${domain}) Dialplan: sofia/internal/1001(a)sip.domain.com Action set(eml=${user_data(${intcallid}@${domain} param vm-mailto)}) Dialplan: sofia/internal/1001(a)sip.domain.com Action set(datetime=${strftime(%Y.%m.%d)} | ${strftime(%W)}. HET | ${strftime(%H:%M)}) Dialplan: sofia/internal/1001(a)sip.domain.com Action set(smtp_from=root) Dialplan: sofia/internal/1001(a)sip.domain.com Action lua(NoAns.lua '${originate_disposition}' '${eml}' '${smtp_from}' 'aaa' 'aaa' 'bbb') 2015-04-26 19:27:42.204725 [DEBUG] switch_core_state_machine.c:216 (sofia/internal/1001(a)sip.domain.com) State Change CS_ROUTING -> CS_EXECUTE 2015-04-26 19:27:42.204725 [DEBUG] switch_core_session.c:1396 Send signal sofia/internal/1001(a)sip.domain.com [BREAK] 2015-04-26 19:27:42.204725 [DEBUG] switch_core_state_machine.c:528 (sofia/internal/1001(a)sip.domain.com) State ROUTING going to sleep 2015-04-26 19:27:42.204725 [DEBUG] switch_core_state_machine.c:472 (sofia/internal/1001(a)sip.domain.com) Running State Change CS_EXECUTE 2015-04-26 19:27:42.204725 [DEBUG] switch_core_state_machine.c:535 (sofia/internal/1001(a)sip.domain.com) State EXECUTE 2015-04-26 19:27:42.204725 [DEBUG] mod_sofia.c:178 sofia/internal/1001(a)sip.domain.com SOFIA EXECUTE 2015-04-26 19:27:42.204725 [DEBUG] switch_core_state_machine.c:258 sofia/internal/1001(a)sip.domain.com Standard EXECUTE EXECUTE sofia/internal/1001(a)sip.domain.com set(zrtp_enrollment=true) 2015-04-26 19:27:42.204725 [DEBUG] mod_dptools.c:1445 sofia/internal/1001(a)sip.domain.com SET [zrtp_enrollment]=[true] EXECUTE sofia/internal/1001(a)sip.domain.com set(hangup_after_bridge=false) 2015-04-26 19:27:42.204725 [DEBUG] mod_dptools.c:1445 sofia/internal/1001(a)sip.domain.com SET [hangup_after_bridge]=[false] EXECUTE sofia/internal/1001(a)sip.domain.com set(continue_on_fail=true) 2015-04-26 19:27:42.204725 [DEBUG] mod_dptools.c:1445 sofia/internal/1001(a)sip.domain.com SET [continue_on_fail]=[true] EXECUTE sofia/internal/1001(a)sip.domain.com set(intcallid=1004) 2015-04-26 19:27:42.204725 [DEBUG] mod_dptools.c:1445 sofia/internal/1001(a)sip.domain.com SET [intcallid]=[1004] EXECUTE sofia/internal/1001(a)sip.domain.com bridge(sofia/internal/1004%sip.domain.com) 2015-04-26 19:27:42.204725 [DEBUG] switch_channel.c:1201 sofia/internal/1001(a)sip.domain.com EXPORTING[export_vars] [domain_name]=[sip.domain.com] to event 2015-04-26 19:27:42.204725 [DEBUG] switch_ivr_originate.c:2100 Parsing global variables 2015-04-26 19:27:42.204725 [NOTICE] switch_channel.c:1055 New Channel sofia/internal/1004 [f8a9e60a-a497-4363-bed4-039df448d26d] 2015-04-26 19:27:42.204725 [DEBUG] mod_sofia.c:4701 (sofia/internal/1004) State Change CS_NEW -> CS_INIT 2015-04-26 19:27:42.204725 [DEBUG] switch_core_session.c:1396 Send signal sofia/internal/1004 [BREAK] 2015-04-26 19:27:42.204725 [DEBUG] switch_core_media.c:266 Passing a-leg remote zrtp-hash (audio) to b-leg 2015-04-26 19:27:42.204725 [DEBUG] mod_sofia.c:4771 [zrtp_passthru] Setting a-leg inherit_codec=true 2015-04-26 19:27:42.204725 [DEBUG] mod_sofia.c:4774 [zrtp_passthru] Setting b-leg absolute_codec_string='PCMA@8000h@20i@64000b' 2015-04-26 19:27:42.204725 [DEBUG] switch_core_state_machine.c:472 (sofia/internal/1004) Running State Change CS_INIT 2015-04-26 19:27:42.204725 [DEBUG] switch_core_state_machine.c:512 (sofia/internal/1004) State INIT 2015-04-26 19:27:42.204725 [DEBUG] mod_sofia.c:87 sofia/internal/1004 SOFIA INIT nua_common.c:108 nh_create_handle() nua: nh_create_handle: entering nua.c:342 nua_handle_bind() nua: nua_handle_bind: entering 2015-04-26 19:27:42.224657 [DEBUG] switch_core_media.c:7687 sofia/internal/1004 Patched SDP --- v=0 o=- 3639058062 3639058062 IN IP4 192.168.51.103 s=pjmedia c=IN IP4 192.168.51.103 t=0 0 m=audio 4002 RTP/AVP 99 0 8 101 c=IN IP4 192.168.51.103 a=rtpmap:99 SILK/24000 a=fmtp:99 useinbandfec=0 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=rtcp:4003 IN IP4 192.168.51.103 a=zrtp-hash:1.10 b7ef73966e5720fe5736350d2d57cb35460f4add4c6675e8d4221a13c7fc5dbe +++ v=0 o=FreeSWITCH 1055498831 1055498832 IN IP4 YYY.YYY.YYY.YYY s=FreeSWITCH c=IN IP4 YYY.YYY.YYY.YYY t=0 0 m=audio 20654 RTP/AVP 99 0 8 101 c=IN IP4 YYY.YYY.YYY.YYY a=rtpmap:99 SILK/24000 a=fmtp:99 useinbandfec=0 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=rtcp:4003 IN IP4 192.168.51.103 a=zrtp-hash:1.10 b7ef73966e5720fe5736350d2d57cb35460f4add4c6675e8d4221a13c7fc5dbe 2015-04-26 19:27:42.224657 [DEBUG] sofia_glue.c:1203 sip:1004@XXX.XXX.XXX.XXX:22036;transport=tls;registering_acc=sip_domain_com Setting proxy route to sofia/internal/1004 2015-04-26 19:27:42.224657 [DEBUG] sofia_glue.c:1232 sofia/internal/1004 sending invite version: 1.4.18 -3-1 64bit Local SDP: v=0 o=FreeSWITCH 1055498831 1055498832 IN IP4 YYY.YYY.YYY.YYY s=FreeSWITCH c=IN IP4 YYY.YYY.YYY.YYY t=0 0 m=audio 20654 RTP/AVP 99 0 8 101 c=IN IP4 YYY.YYY.YYY.YYY a=rtpmap:99 SILK/24000 a=fmtp:99 useinbandfec=0 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=rtcp:4003 IN IP4 192.168.51.103 a=zrtp-hash:1.10 b7ef73966e5720fe5736350d2d57cb35460f4add4c6675e8d4221a13c7fc5dbe nua.c:633 nua_invite() nua: nua_invite: entering nua_stack.c:529 nua_signal() nua(0x7fac38005d80): sent signal r_invite 2015-04-26 19:27:42.224657 [DEBUG] switch_core_state_machine.c:40 sofia/internal/1004 Standard INIT 2015-04-26 19:27:42.224657 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/1004) State Change CS_INIT -> CS_ROUTING 2015-04-26 19:27:42.224657 [DEBUG] switch_core_session.c:1396 Send signal sofia/internal/1004 [BREAK] 2015-04-26 19:27:42.224657 [DEBUG] switch_core_state_machine.c:512 (sofia/internal/1004) State INIT going to sleep nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering soa.c:280 soa_clone() soa_clone(static::0x7fac68002100, 0x7fac680015a0, 0x7fac38005d80) called soa.c:403 soa_set_params() soa_set_params(static::0x7fac6805ba70, ...) called soa.c:403 soa_set_params() soa_set_params(static::0x7fac6805ba70, ...) called soa.c:1052 soa_set_user_sdp() soa_set_user_sdp(static::0x7fac6805ba70, (nil), 0x7fac3802d316, -1) called soa.c:890 soa_set_capability_sdp() soa_set_capability_sdp(static::0x7fac6805ba70, (nil), 0x7fac3802d316, -1) called nua_dialog.c:338 nua_dialog_usage_add() nua(0x7fac38005d80): adding session usage nta.c:4417 nta_leg_tcreate() nta_leg_tcreate(0x7fac680596f0) soa.c:1302 soa_init_offer_answer() soa_init_offer_answer(static::0x7fac6805ba70) called soa.c:1426 soa_generate_offer() soa_generate_offer(static::0x7fac6805ba70, 0) called soa_static.c:1146 offer_answer_step() soa_static_offer_answer_action(0x7fac6805ba70, soa_generate_offer): called soa_static.c:1187 offer_answer_step() soa_static(0x7fac6805ba70, soa_generate_offer): generating local description soa_static.c:1215 offer_answer_step() soa_static(0x7fac6805ba70, soa_generate_offer): upgrade with local description soa_static.c:1029 soa_sdp_mode_set() soa_sdp_mode_set(0x7fac7f6ffa70, (nil), ""): called soa_static.c:1444 offer_answer_step() soa_static(0x7fac6805ba70, soa_generate_offer): storing local description soa.c:1270 soa_get_local_sdp() soa_get_local_sdp(static::0x7fac6805ba70, [(nil)], [0x7fac7f701bf8], [0x7fac7f701bf4]) called nta.c:2665 nta_tpn_by_url() nta: selecting scheme sip tport.c:4588 tport_by_name() tport(0x7fac680044d0): found 0x7fac6803c380 by name tls/XXX.XXX.XXX.XXX:22036 tport.c:3257 tport_tsend() tport_tsend(0x7fac6803c380) tpn = tls/XXX.XXX.XXX.XXX:22036 2015-04-26 19:27:42.224657 [DEBUG] switch_core_state_machine.c:472 (sofia/internal/1004) Running State Change CS_ROUTING tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7fac6803c670 0x7fac6807af60 1018 (1018) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7fac6803c670 0x7fac6807a870 90 (90) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7fac6803c670 0x7fac6807bfc0 432 (432) tport.c:3492 tport_send_msg() tport_vsend returned 1540 tport.c:2296 tport_set_secondary_timer() tport(0x7fac6803c380): reset timer nta.c:8304 outgoing_send() nta: sent INVITE (74698567) to tls/XXX.XXX.XXX.XXX:22036 tport.c:4160 tport_pend() tport_pend(0x7fac6803c380): pending 0x7fac68079d20 for tls/XXX.XXX.XXX.XXX:22036 (already 0) nua_session.c:4139 signal_call_state_change() nua(0x7fac38005d80): call state changed: init -> calling, sent offer soa.c:1270 soa_get_local_sdp() soa_get_local_sdp(static::0x7fac6805ba70, [0x7fac7f701bd8], [0x7fac7f701be0], [(nil)]) called nua_stack.c:359 nua_application_event() nua: nua_application_event: entering 2015-04-26 19:27:42.224657 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/1004 [BREAK] nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering 2015-04-26 19:27:42.224657 [DEBUG] sofia.c:6623 Channel sofia/internal/1004 entering state [calling][0] nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering 2015-04-26 19:27:42.224657 [DEBUG] switch_core_state_machine.c:528 (sofia/internal/1004) State ROUTING 2015-04-26 19:27:42.224657 [DEBUG] mod_sofia.c:123 sofia/internal/1004 SOFIA ROUTING 2015-04-26 19:27:42.224657 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/1004) State Change CS_ROUTING -> CS_CONSUME_MEDIA 2015-04-26 19:27:42.224657 [DEBUG] switch_core_session.c:1396 Send signal sofia/internal/1004 [BREAK] 2015-04-26 19:27:42.224657 [DEBUG] switch_core_state_machine.c:528 (sofia/internal/1004) State ROUTING going to sleep 2015-04-26 19:27:42.224657 [DEBUG] switch_core_state_machine.c:472 (sofia/internal/1004) Running State Change CS_CONSUME_MEDIA 2015-04-26 19:27:42.224657 [DEBUG] switch_core_state_machine.c:547 (sofia/internal/1004) State CONSUME_MEDIA 2015-04-26 19:27:42.224657 [DEBUG] switch_core_state_machine.c:547 (sofia/internal/1004) State CONSUME_MEDIA going to sleep tport.c:2773 tport_wakeup() tport_wakeup(0x7fac6803c380): events IN tport.c:2864 tport_recv_event() tport_recv_event(0x7fac6803c380) tport_type_tls.c:434 tport_tls_recv() tport_tls_recv(0x7fac6803c380): tls_read() returned 1 tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7fac6803c380) msg 0x7fac6807cc00 from (tls/XXX.XXX.XXX.XXX:22036) has 1 bytes, veclen = 1 tport.c:2296 tport_set_secondary_timer() tport(0x7fac6803c380): reset timer tport.c:2773 tport_wakeup() tport_wakeup(0x7fac6803c380): events IN tport.c:2864 tport_recv_event() tport_recv_event(0x7fac6803c380) tport_type_tls.c:434 tport_tls_recv() tport_tls_recv(0x7fac6803c380): tls_read() returned 497 tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7fac6803c380) msg 0x7fac6807cc00 from (tls/XXX.XXX.XXX.XXX:22036) has 497 bytes, veclen = 1 tport.c:3023 tport_deliver() tport_deliver(0x7fac6803c380): msg 0x7fac6807cc00 (498 bytes) from tls/XXX.XXX.XXX.XXX:22036/sips next=(nil) nta.c:3299 agent_recv_response() nta: received 180 Ringing for INVITE (74698567) nta.c:3366 agent_recv_response() nta: 180 Ringing is going to a transaction nta.c:9564 outgoing_estimate_delay() nta_outgoing: RTT is 93.106 ms tport.c:4222 tport_release() tport_release(0x7fac6803c380): 0x7fac68079d20 by 0x7fac6807c180 with 0x7fac6807cc00 (preliminary) nua_session.c:4139 signal_call_state_change() nua(0x7fac38005d80): call state changed: calling -> proceeding tport.c:2296 tport_set_secondary_timer() tport(0x7fac6803c380): reset timer nua_stack.c:359 nua_application_event() nua: nua_application_event: entering 2015-04-26 19:27:42.304700 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/1004 [BREAK] nua_stack.c:359 nua_application_event() nua: nua_application_event: entering 2015-04-26 19:27:42.304700 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/1004 [BREAK] nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering 2015-04-26 19:27:42.304700 [DEBUG] sofia.c:6623 Channel sofia/internal/1004 entering state [proceeding][180] 2015-04-26 19:27:42.304700 [NOTICE] sofia.c:6725 Ring-Ready sofia/internal/1004! 2015-04-26 19:27:42.304700 [DEBUG] switch_channel.c:3277 (sofia/internal/1004) Callstate Change DOWN -> RINGING nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:879 nua_respond() nua: nua_respond: entering nua_stack.c:529 nua_signal() nua(0x7fac680706f0): sent signal r_respond 2015-04-26 19:27:42.324677 [NOTICE] mod_sofia.c:2107 Ring-Ready sofia/internal/1001(a)sip.domain.com! nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering soa.c:403 soa_set_params() soa_set_params(static::0x7fac680598d0, ...) called nua_session.c:2320 nua_invite_server_respond() nua: nua_invite_server_respond: entering tport.c:3257 tport_tsend() tport_tsend(0x7fac6803aad0) tpn = TLS/XXX.XXX.XXX.XXX:22035 tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7fac6803b270 0x7fac6807e4e0 799 (799) tport.c:3492 tport_send_msg() tport_vsend returned 799 tport.c:2296 tport_set_secondary_timer() tport(0x7fac6803aad0): reset timer nta.c:6791 incoming_reply() nta: sent 180 Ringing for INVITE (15797) nua_session.c:4139 signal_call_state_change() nua(0x7fac680706f0): call state changed: received -> early nua_stack.c:359 nua_application_event() nua: nua_application_event: entering 2015-04-26 19:27:42.324677 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/1001(a)sip.domain.com [BREAK] nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering 2015-04-26 19:27:42.324677 [DEBUG] sofia.c:6623 Channel sofia/internal/1001(a)sip.domain.com entering state [early][180] nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering 2015-04-26 19:27:42.324677 [DEBUG] switch_core_session.c:912 Send signal sofia/internal/1001(a)sip.domain.com [BREAK] 2015-04-26 19:27:42.324677 [NOTICE] switch_ivr_originate.c:527 Ring Ready sofia/internal/1001(a)sip.domain.com! nta.c:5825 incoming_reclaim_queued() incoming_reclaim_all((nil), (nil), 0x7fac7f701c60) nta.c:7188 _nta_incoming_timer() nta_incoming_timer: 0/0 resent, 0/0 tout, 0/0 term, 1/2 free nta.c:1296 agent_timer() nta: timer set next to 2657 ms nta.c:9101 outgoing_timer_dk() nta: timer D fired, terminate INVITE (74698551) nta.c:8799 outgoing_reclaim_queued() outgoing_reclaim_all((nil), (nil), 0x7fac7f701d40) nta.c:8929 _nta_outgoing_timer() nta_outgoing_timer: 0/0 resent, 0/1 tout, 1/1 term, 1/3 free nta.c:1296 agent_timer() nta: timer set next to 1 ms nta.c:8982 outgoing_timer_bf() nta: timer F fired, terminating ACK (74698551) nta.c:8799 outgoing_reclaim_queued() outgoing_reclaim_all((nil), (nil), 0x7fac7f701d40) nta.c:8929 _nta_outgoing_timer() nta_outgoing_timer: 0/0 resent, 1/1 tout, 0/0 term, 1/2 free nta.c:1296 agent_timer() nta: timer set next to 55631 ms tport.c:2773 tport_wakeup() tport_wakeup(0x7fac6803c380): events IN tport.c:2864 tport_recv_event() tport_recv_event(0x7fac6803c380) tport_type_tls.c:434 tport_tls_recv() tport_tls_recv(0x7fac6803c380): tls_read() returned 1 tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7fac6803c380) msg 0x7fac6805d660 from (tls/XXX.XXX.XXX.XXX:22036) has 1 bytes, veclen = 1 tport.c:2296 tport_set_secondary_timer() tport(0x7fac6803c380): reset timer tport.c:2773 tport_wakeup() tport_wakeup(0x7fac6803c380): events IN tport.c:2864 tport_recv_event() tport_recv_event(0x7fac6803c380) tport_type_tls.c:434 tport_tls_recv() tport_tls_recv(0x7fac6803c380): tls_read() returned 655 tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7fac6803c380) msg 0x7fac6805d660 from (tls/XXX.XXX.XXX.XXX:22036) has 655 bytes, veclen = 1 tport.c:3023 tport_deliver() tport_deliver(0x7fac6803c380): msg 0x7fac6805d660 (656 bytes) from tls/XXX.XXX.XXX.XXX:22036/sips next=(nil) nta.c:3299 agent_recv_response() nta: received 200 OK for INVITE (74698567) nta.c:3366 agent_recv_response() nta: 200 OK is going to a transaction tport.c:4222 tport_release() tport_release(0x7fac6803c380): 0x7fac68079d20 by 0x7fac6807c180 with 0x7fac6805d660 nta.c:1348 set_timeout() nta: timer shortened to 32000 ms soa.c:1171 soa_set_remote_sdp() soa_set_remote_sdp(static::0x7fac6805ba70, (nil), 0x7fac6805aa2e, 130) called soa.c:1595 soa_process_answer() soa_process_answer(static::0x7fac6805ba70) called soa_static.c:1146 offer_answer_step() soa_static_offer_answer_action(0x7fac6805ba70, soa_process_answer): called soa_static.c:1029 soa_sdp_mode_set() soa_sdp_mode_set(0x7fac6807b530, 0x7fac6806f530, ""): called soa_static.c:1302 offer_answer_step() soa_static(0x7fac6805ba70, soa_process_answer): upgrade codecs with remote description soa_static.c:1444 offer_answer_step() soa_static(0x7fac6805ba70, soa_process_answer): storing local description soa.c:1730 soa_activate() soa_activate(static::0x7fac6805ba70, (nil)) called nua_session.c:988 nua_session_client_response() nua(0x7fac38005d80): INVITE: processed SDP answer in 200 OK nua_session.c:4139 signal_call_state_change() nua(0x7fac38005d80): call state changed: proceeding -> completing, received answer soa.c:1098 soa_get_remote_sdp() soa_get_remote_sdp(static::0x7fac6805ba70, [0x7fac7f7015d8], [0x7fac7f7015e0], [(nil)]) called soa.c:616 soa_get_params() soa_get_params(static::0x7fac6805ba70, ...) called tport.c:2296 tport_set_secondary_timer() tport(0x7fac6803c380): reset timer nua_stack.c:359 nua_application_event() nua: nua_application_event: entering 2015-04-26 19:27:54.204709 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/1004 [BREAK] nua_stack.c:359 nua_application_event() nua: nua_application_event: entering 2015-04-26 19:27:54.204709 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/1004 [BREAK] nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering 2015-04-26 19:27:54.204709 [DEBUG] switch_core_media.c:272 Passing b-leg remote zrtp-hash (audio) to a-leg nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering 2015-04-26 19:27:54.204709 [DEBUG] sofia.c:6623 Channel sofia/internal/1004 entering state [completing][200] 2015-04-26 19:27:54.204709 [DEBUG] sofia.c:6633 Remote SDP: v=0 o=1004-jitsi.org 0 0 IN IP4 192.168.51.11 s=- c=IN IP4 192.168.51.11 t=0 0 m=audio 5002 RTP/AVP 8 a=rtpmap:8 PCMA/8000 nua.c:639 nua_ack() nua: nua_ack: entering nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering nua_stack.c:529 nua_signal() nua(0x7fac38005d80): sent signal r_ack soa.c:403 soa_set_params() soa_set_params(static::0x7fac6805ba70, ...) called nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering soa.c:1730 soa_activate() soa_activate(static::0x7fac6805ba70, (nil)) called nta.c:2665 nta_tpn_by_url() nta: selecting scheme sip tport.c:4588 tport_by_name() tport(0x7fac680044d0): found 0x7fac6803c380 by name tls/XXX.XXX.XXX.XXX:22036 tport.c:3257 tport_tsend() tport_tsend(0x7fac6803c380) tpn = tls/XXX.XXX.XXX.XXX:22036 tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7fac6803c670 0x7fac68071360 475 (475) tport.c:3492 tport_send_msg() tport_vsend returned 475 tport.c:2296 tport_set_secondary_timer() tport(0x7fac6803c380): reset timer nta.c:8304 outgoing_send() nta: sent ACK (74698567) to tls/XXX.XXX.XXX.XXX:22036 nua_session.c:4139 signal_call_state_change() nua(0x7fac38005d80): call state changed: completing -> ready nua_stack.c:359 nua_application_event() nua: nua_application_event: entering 2015-04-26 19:27:54.204709 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/1004 [BREAK] nua_stack.c:359 nua_application_event() nua: nua_application_event: entering 2015-04-26 19:27:54.204709 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/1004 [BREAK] nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering 2015-04-26 19:27:54.204709 [DEBUG] sofia.c:6623 Channel sofia/internal/1004 entering state [ready][200] 2015-04-26 19:27:54.204709 [DEBUG] switch_channel.c:3635 Send signal sofia/internal/1001(a)sip.domain.com [BREAK] 2015-04-26 19:27:54.204709 [NOTICE] sofia.c:7446 Channel [sofia/internal/1004] has been answered 2015-04-26 19:27:54.204709 [DEBUG] switch_channel.c:3689 (sofia/internal/1004) Callstate Change RINGING -> ACTIVE 2015-04-26 19:27:54.204709 [DEBUG] switch_core_media.c:2473 Set Codec sofia/internal/1004 PROXY/0 0 ms 160 samples 0 bits 1 channels 2015-04-26 19:27:54.204709 [DEBUG] switch_core_codec.c:111 sofia/internal/1004 Original read codec set to PROXY:0 2015-04-26 19:27:54.224752 [DEBUG] switch_core_media.c:5212 PROXY AUDIO RTP [sofia/internal/1004] 192.168.51.11:5002->192.168.51.11:5002 codec: 0 ms: 20 2015-04-26 19:27:54.224752 [DEBUG] switch_rtp.c:3571 Not using a timer 2015-04-26 19:27:54.224752 [DEBUG] switch_core_media.c:5445 Set 2833 dtmf send payload to 101 2015-04-26 19:27:54.224752 [DEBUG] switch_core_media.c:5451 Set 2833 dtmf receive payload to 101 2015-04-26 19:27:54.224752 [DEBUG] switch_core_media.c:5479 Set comfort noise payload to 13 2015-04-26 19:27:54.224752 [DEBUG] switch_core_session.c:978 Send signal sofia/internal/1001(a)sip.domain.com [BREAK] nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering 2015-04-26 19:27:54.224752 [DEBUG] switch_ivr_originate.c:415 Codec string PROXY@8000h@20i not supported on sofia/internal/1001(a)sip.domain.com, skipping inheritance 2015-04-26 19:27:54.224752 [DEBUG] switch_core_media.c:7687 sofia/internal/1001(a)sip.domain.com Patched SDP --- v=0 o=1004-jitsi.org 0 0 IN IP4 192.168.51.11 s=- c=IN IP4 192.168.51.11 t=0 0 m=audio 5002 RTP/AVP 8 a=rtpmap:8 PCMA/8000 +++ v=0 o=FreeSWITCH 1055880683 1055880684 IN IP4 YYY.YYY.YYY.YYY s=FreeSWITCH c=IN IP4 YYY.YYY.YYY.YYY t=0 0 m=audio 20962 RTP/AVP 8 a=rtpmap:8 PCMA/8000 2015-04-26 19:27:54.224752 [DEBUG] switch_core_media.c:2473 Set Codec sofia/internal/1001(a)sip.domain.com PROXY/0 0 ms 160 samples 0 bits 1 channels 2015-04-26 19:27:54.224752 [DEBUG] switch_core_codec.c:111 sofia/internal/1001(a)sip.domain.com Original read codec set to PROXY:0 2015-04-26 19:27:54.224752 [DEBUG] switch_core_media.c:5212 PROXY AUDIO RTP [sofia/internal/1001(a)sip.domain.com] 192.168.51.103:4002->192.168.51.103:4002 codec: 0 ms: 20 2015-04-26 19:27:54.224752 [DEBUG] switch_rtp.c:3571 Not using a timer 2015-04-26 19:27:54.224752 [DEBUG] switch_core_media.c:5445 Set 2833 dtmf send payload to 101 2015-04-26 19:27:54.224752 [DEBUG] switch_core_media.c:5451 Set 2833 dtmf receive payload to 101 2015-04-26 19:27:54.224752 [DEBUG] switch_core_media.c:5479 Set comfort noise payload to 13 nua.c:879 nua_respond() nua: nua_respond: entering nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering soa.c:403 soa_set_params() soa_set_params(static::0x7fac680598d0, ...) called soa.c:1052 soa_set_user_sdp() soa_set_user_sdp(static::0x7fac680598d0, (nil), 0x7faca000cd90, -1) called nua_stack.c:529 nua_signal() nua(0x7fac680706f0): sent signal r_respond soa.c:890 soa_set_capability_sdp() soa_set_capability_sdp(static::0x7fac680598d0, (nil), 0x7faca000cd90, -1) called 2015-04-26 19:27:54.224752 [DEBUG] switch_core_session.c:912 Send signal sofia/internal/1001(a)sip.domain.com [BREAK] nua_session.c:2320 nua_invite_server_respond() nua: nua_invite_server_respond: entering soa.c:1515 soa_generate_answer() soa_generate_answer(static::0x7fac680598d0) called soa_static.c:1146 offer_answer_step() soa_static_offer_answer_action(0x7fac680598d0, soa_generate_answer): called soa_static.c:1187 offer_answer_step() soa_static(0x7fac680598d0, soa_generate_answer): generating local description soa_static.c:1228 offer_answer_step() soa_static(0x7fac680598d0, soa_generate_answer): upgrade with remote description 2015-04-26 19:27:54.224752 [INFO] switch_channel.c:3321 sofia/internal/1001(a)sip.domain.com ZRTP not negotiated on both sides; disabling ZRTP passthru mode. soa_static.c:1029 soa_sdp_mode_set() soa_sdp_mode_set(0x7fac7f6ffab0, 0x7fac68078200, ""): called soa_static.c:1444 offer_answer_step() soa_static(0x7fac680598d0, soa_generate_answer): storing local description soa.c:1730 soa_activate() soa_activate(static::0x7fac680598d0, (nil)) called soa.c:1270 soa_get_local_sdp() soa_get_local_sdp(static::0x7fac680598d0, [(nil)], [0x7fac7f701c38], [0x7fac7f701c34]) called tport.c:3257 tport_tsend() tport_tsend(0x7fac6803aad0) tpn = TLS/XXX.XXX.XXX.XXX:22035 tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7fac6803b270 0x7fac680621a0 884 (884) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7fac6803b270 0x7fac68072050 156 (156) tport.c:3492 tport_send_msg() tport_vsend returned 1040 tport.c:2296 tport_set_secondary_timer() tport(0x7fac6803aad0): reset timer 2015-04-26 19:27:54.224752 [NOTICE] switch_ivr_originate.c:3519 Channel [sofia/internal/1001(a)sip.domain.com] has been answered nta.c:6791 incoming_reply() nta: sent 200 OK for INVITE (15797) nta.c:1348 set_timeout() nta: timer shortened to 500 ms nua_session.c:4139 signal_call_state_change() nua(0x7fac680706f0): call state changed: early -> completed, sent answer soa.c:1270 soa_get_local_sdp() soa_get_local_sdp(static::0x7fac680598d0, [0x7fac7f701ce8], [0x7fac7f701cf0], [(nil)]) called soa.c:616 soa_get_params() soa_get_params(static::0x7fac680598d0, ...) called nua_stack.c:359 nua_application_event() nua: nua_application_event: entering 2015-04-26 19:27:54.224752 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/1001(a)sip.domain.com [BREAK] 2015-04-26 19:27:54.224752 [DEBUG] switch_channel.c:3689 (sofia/internal/1001(a)sip.domain.com) Callstate Change RINGING -> ACTIVE nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering 2015-04-26 19:27:54.224752 [DEBUG] sofia.c:6623 Channel sofia/internal/1001(a)sip.domain.com entering state [completed][200] nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering 2015-04-26 19:27:54.224752 [DEBUG] switch_ivr_originate.c:3577 Originate Resulted in Success: [sofia/internal/1004] 2015-04-26 19:27:54.224752 [DEBUG] switch_core_session.c:912 Send signal sofia/internal/1004 [BREAK] 2015-04-26 19:27:54.224752 [DEBUG] switch_core_session.c:912 Send signal sofia/internal/1001(a)sip.domain.com [BREAK] 2015-04-26 19:27:54.224752 [DEBUG] switch_ivr_bridge.c:1465 (sofia/internal/1004) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA 2015-04-26 19:27:54.224752 [DEBUG] switch_core_session.c:1396 Send signal sofia/internal/1004 [BREAK] 2015-04-26 19:27:54.224752 [DEBUG] switch_core_state_machine.c:472 (sofia/internal/1004) Running State Change CS_EXCHANGE_MEDIA 2015-04-26 19:27:54.224752 [DEBUG] switch_core_state_machine.c:538 (sofia/internal/1004) State EXCHANGE_MEDIA 2015-04-26 19:27:54.224752 [DEBUG] mod_sofia.c:594 SOFIA EXCHANGE_MEDIA tport.c:2773 tport_wakeup() tport_wakeup(0x7fac6803aad0): events IN tport.c:2864 tport_recv_event() tport_recv_event(0x7fac6803aad0) tport_type_tls.c:434 tport_tls_recv() tport_tls_recv(0x7fac6803aad0): tls_read() returned 415 tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7fac6803aad0) msg 0x7fac68073670 from (tls/XXX.XXX.XXX.XXX:22035) has 415 bytes, veclen = 1 tport.c:3023 tport_deliver() tport_deliver(0x7fac6803aad0): msg 0x7fac68073670 (415 bytes) from tls/XXX.XXX.XXX.XXX:22035/sips next=(nil) nta.c:2880 agent_recv_request() nta: received BYE sip:1004@YYY.YYY.YYY.YYY:9061;transport=tls SIP/2.0 (CSeq 15798) nta.c:3174 agent_check_request_via() nta: Via check: received=XXX.XXX.XXX.XXX nta.c:3060 agent_recv_request() nta: BYE (15798) going to existing leg nua_server.c:102 nua_stack_process_request() nua: nua_stack_process_request: entering tport.c:2296 tport_set_secondary_timer() tport(0x7fac6803aad0): reset timer nua_stack.c:359 nua_application_event() nua: nua_application_event: entering 2015-04-26 19:27:54.384702 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/1001(a)sip.domain.com [BREAK] nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering 2015-04-26 19:27:54.384702 [NOTICE] sofia.c:952 Hangup sofia/internal/1001(a)sip.domain.com [CS_EXECUTE] [NORMAL_CLEARING] 2015-04-26 19:27:54.384702 [DEBUG] switch_channel.c:3222 Send signal sofia/internal/1001(a)sip.domain.com [KILL] 2015-04-26 19:27:54.384702 [DEBUG] switch_core_session.c:1396 Send signal sofia/internal/1001(a)sip.domain.com [BREAK] nua.c:879 nua_respond() nua: nua_respond: entering nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering soa.c:403 soa_set_params() soa_set_params(static::0x7fac680598d0, ...) called tport.c:3257 tport_tsend() tport_tsend(0x7fac6803aad0) tpn = TLS/XXX.XXX.XXX.XXX:22035 nua_stack.c:529 nua_signal() nua(0x7fac680706f0): sent signal r_respond nua.c:342 nua_handle_bind() nua: nua_handle_bind: entering nua.c:921 nua_handle_destroy() nua: nua_handle_destroy: entering nua_stack.c:529 nua_signal() nua(0x7fac680706f0): sent signal r_destroy tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7fac6803b270 0x7fac68074270 540 (540) tport.c:3492 tport_send_msg() tport_vsend returned 540 tport.c:2296 tport_set_secondary_timer() tport(0x7fac6803aad0): reset timer nta.c:6791 incoming_reply() nta: sent 200 OK for BYE (15798) nua_dialog.c:397 nua_dialog_usage_remove_at() nua(0x7fac680706f0): removing session usage nua_session.c:4139 signal_call_state_change() nua(0x7fac680706f0): call state changed: completed -> terminated soa.c:356 soa_destroy() soa_destroy(static::0x7fac680598d0) called nta.c:4470 nta_leg_destroy() nta_leg_destroy(0x7fac68073b20) nta.c:5744 incoming_free() nta: incoming_free(0x7fac6805c910) nta.c:4470 nta_leg_destroy() nta_leg_destroy((nil)) 2015-04-26 19:27:54.384702 [DEBUG] switch_ivr_bridge.c:660 BRIDGE THREAD DONE [sofia/internal/1001(a)sip.domain.com] 2015-04-26 19:27:54.384702 [DEBUG] switch_ivr_bridge.c:690 Send signal sofia/internal/1004 [BREAK] 2015-04-26 19:27:54.384702 [DEBUG] switch_ivr_bridge.c:660 BRIDGE THREAD DONE [sofia/internal/1004] 2015-04-26 19:27:54.384702 [DEBUG] switch_ivr_bridge.c:690 Send signal sofia/internal/1001(a)sip.domain.com [BREAK] 2015-04-26 19:27:54.384702 [NOTICE] switch_ivr_bridge.c:754 Hangup sofia/internal/1004 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING] 2015-04-26 19:27:54.384702 [DEBUG] switch_channel.c:3222 Send signal sofia/internal/1004 [KILL] 2015-04-26 19:27:54.384702 [DEBUG] switch_core_session.c:1396 Send signal sofia/internal/1004 [BREAK] 2015-04-26 19:27:54.384702 [DEBUG] switch_core_state_machine.c:538 (sofia/internal/1004) State EXCHANGE_MEDIA going to sleep 2015-04-26 19:27:54.384702 [DEBUG] switch_core_state_machine.c:472 (sofia/internal/1004) Running State Change CS_HANGUP 2015-04-26 19:27:54.384702 [DEBUG] switch_core_state_machine.c:735 (sofia/internal/1004) Callstate Change ACTIVE -> HANGUP 2015-04-26 19:27:54.384702 [DEBUG] switch_core_state_machine.c:737 (sofia/internal/1004) State HANGUP 2015-04-26 19:27:54.384702 [DEBUG] mod_sofia.c:407 sofia/internal/1004 Overriding SIP cause 480 with 200 from the other leg 2015-04-26 19:27:54.384702 [DEBUG] mod_sofia.c:413 Channel sofia/internal/1004 hanging up, cause: NORMAL_CLEARING 2015-04-26 19:27:54.384702 [DEBUG] switch_ivr_bridge.c:1563 sofia/internal/1004 skip receive message [UNBRIDGE] (channel is comngup already) 2015-04-26 19:27:54.384702 [DEBUG] switch_ivr_bridge.c:1566 sofia/internal/1001(a)sip.domain.com skip receive message [UNBRIDGE] (channel is comngup already) 2015-04-26 19:27:54.384702 [DEBUG] switch_core_session.c:2901 sofia/internal/1001(a)sip.domain.com skip receive message [APPLICATION_EXEC_COMPLETE] (channel is comngup already) 2015-04-26 19:27:54.384702 [DEBUG] switch_core_state_machine.c:535 (sofia/internal/1001(a)sip.domain.com) State EXECUTE going to sleep 2015-04-26 19:27:54.384702 [DEBUG] switch_core_state_machine.c:472 (sofia/internal/1001(a)sip.domain.com) Running State Change CS_HANGUP 2015-04-26 19:27:54.384702 [DEBUG] mod_sofia.c:465 Sending BYE to sofia/internal/1004 nua.c:645 nua_bye() nua: nua_bye: entering nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering soa.c:403 soa_set_params() soa_set_params(static::0x7fac6805ba70, ...) called nua_stack.c:529 nua_signal() nua(0x7fac38005d80): sent signal r_bye soa.c:1784 soa_terminate() soa_terminate(static::0x7fac6805ba70) called soa.c:1302 soa_init_offer_answer() soa_init_offer_answer(static::0x7fac6805ba70) called 2015-04-26 19:27:54.384702 [DEBUG] switch_core_state_machine.c:60 sofia/internal/1004 Standard HANGUP, cause: NORMAL_CLEARING 2015-04-26 19:27:54.384702 [DEBUG] switch_core_state_machine.c:737 (sofia/internal/1004) State HANGUP going to sleep nta.c:2665 nta_tpn_by_url() nta: selecting scheme sip 2015-04-26 19:27:54.384702 [DEBUG] switch_core_state_machine.c:504 (sofia/internal/1004) State Change CS_HANGUP -> CS_REPORTING 2015-04-26 19:27:54.384702 [DEBUG] switch_core_state_machine.c:735 (sofia/internal/1001(a)sip.domain.com) Callstate Change ACTIVE -> HANGUP tport.c:4588 tport_by_name() tport(0x7fac680044d0): found 0x7fac6803c380 by name tls/XXX.XXX.XXX.XXX:22036 2015-04-26 19:27:54.384702 [DEBUG] switch_core_session.c:1396 Send signal sofia/internal/1004 [BREAK] tport.c:3257 tport_tsend() tport_tsend(0x7fac6803c380) tpn = tls/XXX.XXX.XXX.XXX:22036 tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7fac6803c670 0x7fac6805b0f0 657 (657) tport.c:3492 tport_send_msg() tport_vsend returned 657 tport.c:2296 tport_set_secondary_timer() tport(0x7fac6803c380): reset timer nta.c:8304 outgoing_send() nta: sent BYE (74698568) to tls/XXX.XXX.XXX.XXX:22036 tport.c:4160 tport_pend() tport_pend(0x7fac6803c380): pending 0x7fac6807bb60 for tls/XXX.XXX.XXX.XXX:22036 (already 0) 2015-04-26 19:27:54.384702 [DEBUG] switch_core_state_machine.c:737 (sofia/internal/1001(a)sip.domain.com) State HANGUP 2015-04-26 19:27:54.384702 [DEBUG] mod_sofia.c:413 Channel sofia/internal/1001(a)sip.domain.com hanging up, cause: NORMAL_CLEARING 2015-04-26 19:27:54.384702 [DEBUG] switch_core_state_machine.c:472 (sofia/internal/1004) Running State Change CS_REPORTING 2015-04-26 19:27:54.384702 [DEBUG] switch_core_state_machine.c:823 (sofia/internal/1004) State REPORTING 2015-04-26 19:27:54.384702 [DEBUG] switch_core_state_machine.c:60 sofia/internal/1001(a)sip.domain.com Standard HANGUP, cause: NORMAL_CLEARING 2015-04-26 19:27:54.384702 [DEBUG] switch_core_state_machine.c:737 (sofia/internal/1001(a)sip.domain.com) State HANGUP going to sleep 2015-04-26 19:27:54.384702 [DEBUG] switch_core_state_machine.c:504 (sofia/internal/1001(a)sip.domain.com) State Change CS_HANGUP -> CS_REPORTING 2015-04-26 19:27:54.384702 [DEBUG] switch_core_session.c:1396 Send signal sofia/internal/1001(a)sip.domain.com [BREAK] 2015-04-26 19:27:54.384702 [DEBUG] switch_core_state_machine.c:472 (sofia/internal/1001(a)sip.domain.com) Running State Change CS_REPORTING 2015-04-26 19:27:54.384702 [DEBUG] switch_core_state_machine.c:823 (sofia/internal/1001(a)sip.domain.com) State REPORTING 2015-04-26 19:27:54.384702 [DEBUG] switch_core_state_machine.c:104 sofia/internal/1004 Standard REPORTING, cause: NORMAL_CLEARING 2015-04-26 19:27:54.384702 [DEBUG] switch_core_state_machine.c:823 (sofia/internal/1004) State REPORTING going to sleep 2015-04-26 19:27:54.384702 [DEBUG] switch_core_state_machine.c:498 (sofia/internal/1004) State Change CS_REPORTING -> CS_DESTROY 2015-04-26 19:27:54.384702 [DEBUG] switch_core_session.c:1396 Send signal sofia/internal/1004 [BREAK] 2015-04-26 19:27:54.384702 [DEBUG] switch_core_session.c:1623 Session 6 (sofia/internal/1004) Locked, Waiting on external entities 2015-04-26 19:27:54.384702 [NOTICE] switch_core_session.c:1641 Session 6 (sofia/internal/1004) Ended 2015-04-26 19:27:54.384702 [NOTICE] switch_core_session.c:1645 Close Channel sofia/internal/1004 [CS_DESTROY] 2015-04-26 19:27:54.384702 [DEBUG] switch_core_state_machine.c:626 (sofia/internal/1004) Running State Change CS_DESTROY 2015-04-26 19:27:54.384702 [DEBUG] switch_core_state_machine.c:636 (sofia/internal/1004) State DESTROY 2015-04-26 19:27:54.384702 [DEBUG] mod_sofia.c:323 sofia/internal/1004 SOFIA DESTROY 2015-04-26 19:27:54.384702 [DEBUG] switch_core_state_machine.c:111 sofia/internal/1004 Standard DESTROY 2015-04-26 19:27:54.384702 [DEBUG] switch_core_state_machine.c:636 (sofia/internal/1004) State DESTROY going to sleep 2015-04-26 19:27:54.404702 [DEBUG] switch_core_state_machine.c:104 sofia/internal/1001(a)sip.domain.com Standard REPORTING, cause: NORMAL_CLEARING 2015-04-26 19:27:54.404702 [DEBUG] switch_core_state_machine.c:823 (sofia/internal/1001(a)sip.domain.com) State REPORTING going to sleep 2015-04-26 19:27:54.404702 [DEBUG] switch_core_state_machine.c:498 (sofia/internal/1001(a)sip.domain.com) State Change CS_REPORTING -> CS_DESTROY 2015-04-26 19:27:54.404702 [DEBUG] switch_core_session.c:1396 Send signal sofia/internal/1001(a)sip.domain.com [BREAK] 2015-04-26 19:27:54.404702 [DEBUG] switch_core_session.c:1623 Session 5 (sofia/internal/1001(a)sip.domain.com) Locked, Waiting on external entities 2015-04-26 19:27:54.404702 [NOTICE] switch_core_session.c:1641 Session 5 (sofia/internal/1001(a)sip.domain.com) Ended 2015-04-26 19:27:54.404702 [NOTICE] switch_core_session.c:1645 Close Channel sofia/internal/1001(a)sip.domain.com [CS_DESTROY] 2015-04-26 19:27:54.404702 [DEBUG] switch_core_state_machine.c:626 (sofia/internal/1001(a)sip.domain.com) Running State Change CS_DESTROY 2015-04-26 19:27:54.404702 [DEBUG] switch_core_state_machine.c:636 (sofia/internal/1001(a)sip.domain.com) State DESTROY 2015-04-26 19:27:54.404702 [DEBUG] mod_sofia.c:323 sofia/internal/1001(a)sip.domain.com SOFIA DESTROY 2015-04-26 19:27:54.404702 [DEBUG] switch_core_state_machine.c:111 sofia/internal/1001(a)sip.domain.com Standard DESTROY 2015-04-26 19:27:54.404702 [DEBUG] switch_core_state_machine.c:636 (sofia/internal/1001(a)sip.domain.com) State DESTROY going to sleep tport.c:2773 tport_wakeup() tport_wakeup(0x7fac6803c380): events IN tport.c:2864 tport_recv_event() tport_recv_event(0x7fac6803c380) tport_type_tls.c:434 tport_tls_recv() tport_tls_recv(0x7fac6803c380): tls_read() returned 1 tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7fac6803c380) msg 0x7fac680598a0 from (tls/XXX.XXX.XXX.XXX:22036) has 1 bytes, veclen = 1 tport.c:2296 tport_set_secondary_timer() tport(0x7fac6803c380): reset timer tport.c:2773 tport_wakeup() tport_wakeup(0x7fac6803c380): events IN tport.c:2864 tport_recv_event() tport_recv_event(0x7fac6803c380) tport_type_tls.c:434 tport_tls_recv() tport_tls_recv(0x7fac6803c380): tls_read() returned 489 tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7fac6803c380) msg 0x7fac680598a0 from (tls/XXX.XXX.XXX.XXX:22036) has 489 bytes, veclen = 1 tport.c:3023 tport_deliver() tport_deliver(0x7fac6803c380): msg 0x7fac680598a0 (490 bytes) from tls/XXX.XXX.XXX.XXX:22036/sips next=(nil) nta.c:3299 agent_recv_response() nta: received 200 OK for BYE (74698568) nta.c:3366 agent_recv_response() nta: 200 OK is going to a transaction nta.c:9564 outgoing_estimate_delay() nta_outgoing: RTT is 62.433 ms tport.c:4222 tport_release() tport_release(0x7fac6803c380): 0x7fac6807bb60 by 0x7fac6807d640 with 0x7fac680598a0 nua_session.c:4139 signal_call_state_change() nua(0x7fac38005d80): call state changed: terminating -> terminated nua_dialog.c:397 nua_dialog_usage_remove_at() nua(0x7fac38005d80): removing session usage soa.c:356 soa_destroy() soa_destroy(static::0x7fac6805ba70) called nta.c:4470 nta_leg_destroy() nta_leg_destroy(0x7fac680596f0) nua_session.c:351 nua_session_usage_destroy() nua: terminated session 0x7fac38005d80 nta.c:8722 outgoing_free() nta: outgoing_free(0x7fac6807d640) tport.c:2296 tport_set_secondary_timer() tport(0x7fac6803c380): reset timer nua_stack.c:359 nua_application_event() nua: nua_application_event: entering nua_stack.c:359 nua_application_event() nua: nua_application_event: entering nua_stack.c:359 nua_application_event() nua: nua_application_event: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:342 nua_handle_bind() nua: nua_handle_bind: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:921 nua_handle_destroy() nua: nua_handle_destroy: entering nta.c:4470 nta_leg_destroy() nta_leg_destroy((nil)) nua_stack.c:529 nua_signal() nua(0x7fac38005d80): sent signal r_destroy nta.c:6996 _nta_incoming_timer() nta: timer G fired, retransmitting 200 reply tport.c:3257 tport_tsend() tport_tsend(0x7fac6803aad0) tpn = TLS/XXX.XXX.XXX.XXX:22035 tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7fac6803b270 0x7fac680621a0 884 (884) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7fac6803b270 0x7fac68072050 156 (156) tport.c:3492 tport_send_msg() tport_vsend returned 1040 tport.c:2296 tport_set_secondary_timer() tport(0x7fac6803aad0): reset timer nta.c:7188 _nta_incoming_timer() nta_incoming_timer: 1/1 resent, 0/1 tout, 0/0 term, 0/1 free nta.c:1296 agent_timer() nta: timer set next to 1000 ms tport.c:2773 tport_wakeup() tport_wakeup(0x7fac6803aad0): events IN tport.c:2864 tport_recv_event() tport_recv_event(0x7fac6803aad0) tport_type_tls.c:434 tport_tls_recv() tport_tls_recv(0x7fac6803aad0): tls_read() returned 375 tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7fac6803aad0) msg 0x7fac6805b0f0 from (tls/XXX.XXX.XXX.XXX:22035) has 375 bytes, veclen = 1 tport.c:3023 tport_deliver() tport_deliver(0x7fac6803aad0): msg 0x7fac6805b0f0 (375 bytes) from tls/XXX.XXX.XXX.XXX:22035/sips next=(nil) nta.c:2880 agent_recv_request() nta: received ACK sip:1004@YYY.YYY.YYY.YYY:9061;transport=tls SIP/2.0 (CSeq 15797) nta.c:3174 agent_check_request_via() nta: Via check: received=XXX.XXX.XXX.XXX nta.c:3019 agent_recv_request() nta: ACK (15797) is going to INVITE (15797) tport.c:2296 tport_set_secondary_timer() tport(0x7fac6803aad0): reset timer tport.c:2296 tport_set_secondary_timer() tport(0x7fac6803aad0): reset timer nta.c:5825 incoming_reclaim_queued() incoming_reclaim_all((nil), (nil), 0x7fac7f701c60) nta.c:7188 _nta_incoming_timer() nta_incoming_timer: 0/0 resent, 0/0 tout, 0/0 term, 1/1 free nta.c:1296 agent_timer() nta: timer set next to 30478 ms

2 2

Privacy and P-asserted-id header in responses
by Tomáš Boros 15 May '15

15 May '15

Hi, We are having troubles with some cases. Case is the following: [Provider A] --------[FS]-------[user redirects call to number back to operator A]-----| [Provider A] --------[FS]--------------------------------------------------------------| So a there is an incoming call from Provider A, we use Freeswitch for interconnection. The call goes to our network, where client redirects the call back to provider A (to different number then caller). In such a case Diversion header is added with the user's phone number. Provider A (on the second leg..third?!) when accepts the call sends an 200 OK message with P-Asserted-identity and Privacy: ID header. My question is, it is possible to pass these headers back to our network and again back to the Provider A? Provider wants to see on their first leg, that the call was answered in their network using p-asserted-identity header. copy_custom_headers does not solves this issue, as P-Asserted and Privacy headers are not custom headers. Thank you, -- Tomáš Boros

2 1

Cannot collect digits from lua script
by Nicoleta Lazar 15 May '15

15 May '15

Hello all, I have a mod_erlang_event based application and I need to run a lua script within for playing prompt and colecting digits (I use freeswith api and luarun from erlang code for running lua script) The script should collect digits, similar to: freeswitch.consoleLog("notice" , "Before GetDigits\n"); digits = session:getDigits(1, "#", 10000); freeswitch.consoleLog("notice" , "AFTER GetDigits\n"); session:execute('flush_dtmf'); freeswitch.consoleLog("notice" , "flush DTMF 2\n"); freeswitch.consoleLog("notice" , "After Get Digits" .. "\n"); freeswitch.consoleLog("notice" , "digits = " .. digits .. "\n"); However, the digits are not collected (sometimes this scenario works OK but I cannot identify a pattern), as can be seen from the logs below: EXECUTE sofia/test/2001@test flush_dtmf()2015-05-15 07:09:39.694302 [DEBUG] mod_erlang_event.c:169 Ignoring event CHANNEL_EXECUTE for attached session d7e76764-faf2-11e4-8f50- 771905ed12f62015-05-15 07:09:39.694302 [DEBUG] mod_erlang_event.c:169 Ignoring event CHANNEL_EXECUTE_COMPLETE for attached session d7e76764-faf2-11e4-8f50- 771905ed12f62015-05-15 07:09:39.694302 [INFO] switch_cpp.cpp:1291 UUID: d7e76764-faf2-11e4-8f50- 771905ed12f62015-05-15 07:09:39.714301 [NOTICE] switch_cpp.cpp:1291 1234 Before GetDigits2015-05-15 07:09:42.034319 [DEBUG] switch_rtp.c:5788 RTP RECV DTMF 1:11202015-05-15 07:09:42.034319 [DEBUG] switch_channel.c:486 RECV DTMF 1:11202015-05-15 07:09:42.034319 [DEBUG] mod_dptools.c:2138 Digit 12015-05-15 07:09:42.034319 [DEBUG] mod_erlang_event.c:157 Sending event DTMF to attached session d7e76764-faf2-11e4-8f50- 771905ed12f62015-05-15 07:09:49.714345 [DEBUG] switch_cpp.cpp:838 getDigits dtmf_buf: 2015-05-15 07:09:49.714345 [NOTICE] switch_cpp.cpp:1291 1234 AFTER GetDigitsEXECUTE sofia/test/2001@test flush_dtmf()2015-05-15 07:09:49.714345 [DEBUG] mod_erlang_event.c:169 Ignoring event CHANNEL_EXECUTE for attached session d7e76764-faf2-11e4-8f50- 771905ed12f62015-05-15 07:09:49.714345 [NOTICE] switch_cpp.cpp:1291 flush DTMF 22015-05-15 07:09:49.714345 [NOTICE] switch_cpp.cpp:1291 After Get Digits2015-05-15 07:09:49.714345 [NOTICE] switch_cpp.cpp:1291 digits = I also looked in the freeswitch code: https://freeswitch.org/ fisheye/browse/freeswitch/src/ mod/event_handlers/mod_erlang_ event/mod_erlang_event.c?hb= true#to159 and it seems that the DTMF event is properly cloned and added to current session queue. Please advise

1 0

[Bridge/Originate][Hangup call with Single Leg]
by Bilal Abbasi 15 May '15

15 May '15

Hi Users, Currently i am using mod event socket to generate a outbound call, using pyswitch ({execute_on_answer='bridge [DTMF="+DTMF+"]loopback/9665/default/XML'}sofia/gateway/aptcl/XXXXXXXX") Now when call on originate channel is answered it is bridged to extension 9665 in default context. Problem is when originate channel hangups the call,call is not terminated on bridge's channel. I have tried hangup after bridge variable(no luck). Please suggest me some solution. Regards Bilal Abbasi

1 0