[Freeswitch-users] FreeSWITCH PROXY:0

Brian West brian at freeswitch.org
Tue May 12 19:49:25 MSD 2015


Its either you've enabled proxy media mode, or auto proxy due to the
zrtp-hash in the sdp's hard to tell 100% but I suspect thats what is taking
place.

On Tue, May 12, 2015 at 8:03 AM, Asd <asdfgh1234 at freemail.hu> wrote:

> Hi all
>
> Freeswitch version: 1.4.18 Debian stable
>
> with TLS
>
> if i try to call internal:
>
> RINGING <<== OK
> by 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 at 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 at 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 at 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 at sip.domain.com [BREAK]
> 2015-04-26 19:27:42.024708 [DEBUG] switch_core_state_machine.c:472
> (sofia/internal/1001 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at sip.domain.com) State INIT
> 2015-04-26 19:27:42.204725 [DEBUG] mod_sofia.c:87 sofia/internal/
> 1001 at sip.domain.com SOFIA INIT
> 2015-04-26 19:27:42.204725 [DEBUG] switch_core_state_machine.c:40
> sofia/internal/1001 at sip.domain.com Standard INIT
> 2015-04-26 19:27:42.204725 [DEBUG] switch_core_state_machine.c:48
> (sofia/internal/1001 at 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 at sip.domain.com [BREAK]
> 2015-04-26 19:27:42.204725 [DEBUG] switch_core_state_machine.c:512
> (sofia/internal/1001 at 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 at sip.domain.com) Running State Change CS_ROUTING
> 2015-04-26 19:27:42.204725 [DEBUG] switch_channel.c:2184 (sofia/internal/
> 1001 at sip.domain.com) Callstate Change DOWN -> RINGING
> 2015-04-26 19:27:42.204725 [DEBUG] switch_core_state_machine.c:528
> (sofia/internal/1001 at sip.domain.com) State ROUTING
> 2015-04-26 19:27:42.204725 [DEBUG] mod_sofia.c:123 sofia/internal/
> 1001 at sip.domain.com SOFIA ROUTING
> 2015-04-26 19:27:42.204725 [DEBUG] switch_core_state_machine.c:166
> sofia/internal/1001 at 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 at sip.domain.com parsing
> [sip.domain.com->PHONE-FAX_b_1001_49123456789100] continue=false
> Dialplan: sofia/internal/1001 at sip.domain.com Regex (PASS)
> [PHONE-FAX_b_1001_49123456789100] context(sip.domain.com) =~ /
> sip.domain.com/ break=on-false
>
>
> Dialplan: sofia/internal/1001 at sip.domain.com Regex (FAIL)
> [PHONE-FAX_b_1001_49123456789100] destination_number(1004) =~
> /^(1234567e0)$/ break=on-false
>
>
> Dialplan: sofia/internal/1001 at sip.domain.com parsing
> [sip.domain.com->PHONE-FAX_l_1002_49123456789101] continue=false
> Dialplan: sofia/internal/1001 at sip.domain.com Regex (PASS)
> [PHONE-FAX_l_1002_49123456789101] context(sip.domain.com) =~ /
> sip.domain.com/ break=on-false
>
>
> Dialplan: sofia/internal/1001 at sip.domain.com Regex (FAIL)
> [PHONE-FAX_l_1002_49123456789101] destination_number(1004) =~
> /^(1234567e1)$/ break=on-false
>
>
> Dialplan: sofia/internal/1001 at sip.domain.com parsing
> [sip.domain.com->PHONE-FAX_m_1003_49123456789101-copy] continue=false
> Dialplan: sofia/internal/1001 at sip.domain.com Regex (PASS)
> [PHONE-FAX_m_1003_49123456789102] context(sip.domain.com) =~ /
> sip.domain.com/ break=on-false
>
>
> Dialplan: sofia/internal/1001 at sip.domain.com Regex (FAIL)
> [PHONE-FAX_m_1003_49123456789102] destination_number(1004) =~
> /^(1234567e2)$/ break=on-false
>
> Dialplan: sofia/internal/1001 at sip.domain.com parsing
> [sip.domain.com->internal-voicemail-com] continue=false
> Dialplan: sofia/internal/1001 at sip.domain.com Regex (PASS)
> [internal-voicemail-com] context(sip.domain.com) =~ /sip.domain.com/
> break=on-false
> Dialplan: sofia/internal/1001 at sip.domain.com Regex (PASS)
> [internal-voicemail-com] caller_id_number(1001) =~ /^(((\+|00)49)|1\d{3})$/
> break=on-false
>
> Dialplan: sofia/internal/1001 at 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 at sip.domain.com parsing
> [sip.domain.com->internal-voicemail-com2] continue=false
> Dialplan: sofia/internal/1001 at sip.domain.com Regex (PASS)
> [internal-voicemail-com2] context(sip.domain.com) =~ /sip.domain.com/
> break=on-false
> Dialplan: sofia/internal/1001 at 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 at sip.domain.com parsing
> [sip.domain.com->internal] continue=false
> Dialplan: sofia/internal/1001 at sip.domain.com Regex (PASS) [internal]
> context(sip.domain.com) =~ /sip.domain.com/ break=on-false
> Dialplan: sofia/internal/1001 at sip.domain.com Regex (PASS) [internal]
> destination_number(1004) =~ /^(1\d{3})$/ break=on-false
> Dialplan: sofia/internal/1001 at sip.domain.com Action
> set(zrtp_enrollment=true)
> Dialplan: sofia/internal/1001 at sip.domain.com Action
> set(hangup_after_bridge=false)
> Dialplan: sofia/internal/1001 at sip.domain.com Action
> set(continue_on_fail=true)
> Dialplan: sofia/internal/1001 at sip.domain.com Action set(intcallid=1004)
> Dialplan: sofia/internal/1001 at sip.domain.com Action
> bridge(sofia/internal/${intcallid}%${domain})
> Dialplan: sofia/internal/1001 at sip.domain.com Action
> set(eml=${user_data(${intcallid}@${domain} param vm-mailto)})
> Dialplan: sofia/internal/1001 at sip.domain.com Action
> set(datetime=${strftime(%Y.%m.%d)} | ${strftime(%W)}. HET |
> ${strftime(%H:%M)})
> Dialplan: sofia/internal/1001 at sip.domain.com Action set(smtp_from=root)
> Dialplan: sofia/internal/1001 at 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 at 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 at sip.domain.com [BREAK]
> 2015-04-26 19:27:42.204725 [DEBUG] switch_core_state_machine.c:528
> (sofia/internal/1001 at 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 at 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 at sip.domain.com) State EXECUTE
> 2015-04-26 19:27:42.204725 [DEBUG] mod_sofia.c:178 sofia/internal/
> 1001 at sip.domain.com SOFIA EXECUTE
> 2015-04-26 19:27:42.204725 [DEBUG] switch_core_state_machine.c:258
> sofia/internal/1001 at sip.domain.com Standard EXECUTE
> EXECUTE sofia/internal/1001 at sip.domain.com set(zrtp_enrollment=true)
> 2015-04-26 19:27:42.204725 [DEBUG] mod_dptools.c:1445 sofia/internal/
> 1001 at sip.domain.com SET [zrtp_enrollment]=[true]
> EXECUTE sofia/internal/1001 at sip.domain.com set(hangup_after_bridge=false)
> 2015-04-26 19:27:42.204725 [DEBUG] mod_dptools.c:1445 sofia/internal/
> 1001 at sip.domain.com SET [hangup_after_bridge]=[false]
> EXECUTE sofia/internal/1001 at sip.domain.com set(continue_on_fail=true)
> 2015-04-26 19:27:42.204725 [DEBUG] mod_dptools.c:1445 sofia/internal/
> 1001 at sip.domain.com SET [continue_on_fail]=[true]
> EXECUTE sofia/internal/1001 at sip.domain.com set(intcallid=1004)
> 2015-04-26 19:27:42.204725 [DEBUG] mod_dptools.c:1445 sofia/internal/
> 1001 at sip.domain.com SET [intcallid]=[1004]
> EXECUTE sofia/internal/1001 at 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 at 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 at 8000h@20i at 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 at 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 at 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 at 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 at 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 at sip.domain.com [BREAK]
> 2015-04-26 19:27:42.324677 [NOTICE] switch_ivr_originate.c:527 Ring Ready
> sofia/internal/1001 at 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 at 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 at 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 at 8000h@20i not supported on sofia/internal/1001 at sip.domain.com,
> skipping inheritance
>
> 2015-04-26 19:27:54.224752 [DEBUG] switch_core_media.c:7687 sofia/internal/
> 1001 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at sip.domain.com [BREAK]
> 2015-04-26 19:27:54.224752 [DEBUG] switch_channel.c:3689 (sofia/internal/
> 1001 at 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 at 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 at 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 at 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 at 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 at sip.domain.com [CS_EXECUTE] [NORMAL_CLEARING]
> 2015-04-26 19:27:54.384702 [DEBUG] switch_channel.c:3222 Send signal
> sofia/internal/1001 at sip.domain.com [KILL]
> 2015-04-26 19:27:54.384702 [DEBUG] switch_core_session.c:1396 Send signal
> sofia/internal/1001 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at sip.domain.com) State HANGUP
> 2015-04-26 19:27:54.384702 [DEBUG] mod_sofia.c:413 Channel sofia/internal/
> 1001 at 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 at 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 at 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 at 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 at sip.domain.com [BREAK]
> 2015-04-26 19:27:54.384702 [DEBUG] switch_core_state_machine.c:472
> (sofia/internal/1001 at 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 at 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 at 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 at 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 at 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 at sip.domain.com [BREAK]
> 2015-04-26 19:27:54.404702 [DEBUG] switch_core_session.c:1623 Session 5
> (sofia/internal/1001 at 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 at sip.domain.com) Ended
> 2015-04-26 19:27:54.404702 [NOTICE] switch_core_session.c:1645 Close
> Channel sofia/internal/1001 at sip.domain.com [CS_DESTROY]
> 2015-04-26 19:27:54.404702 [DEBUG] switch_core_state_machine.c:626
> (sofia/internal/1001 at 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 at sip.domain.com) State DESTROY
> 2015-04-26 19:27:54.404702 [DEBUG] mod_sofia.c:323 sofia/internal/
> 1001 at sip.domain.com SOFIA DESTROY
> 2015-04-26 19:27:54.404702 [DEBUG] switch_core_state_machine.c:111
> sofia/internal/1001 at sip.domain.com Standard DESTROY
> 2015-04-26 19:27:54.404702 [DEBUG] switch_core_state_machine.c:636
> (sofia/internal/1001 at 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 at 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
>
> _________________________________________________________________________
> Professional FreeSWITCH Consulting Services:
> consulting at freeswitch.org
> http://www.freeswitchsolutions.com
>
> Official FreeSWITCH Sites
> http://www.freeswitch.org
> http://confluence.freeswitch.org
> http://www.cluecon.com
>
> FreeSWITCH-users mailing list
> FreeSWITCH-users at lists.freeswitch.org
> http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
> UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
> http://www.freeswitch.org
>



-- 

*Brian West*
brian at freeswitch.org


*Twitter: @FreeSWITCH , @briankwest*
http://www.freeswitchbook.com
http://www.freeswitchcookbook.com

ClueCon 2015 Call for Speakers <https://www.cluecon.com/call-for-speakers/> |
Register <https://freeswitch.com/cart.php?gid=1> TODAY! | Reddit:
/r/freeswitch <https://www.reddit.com/r/freeswitch>

*T:*+19184209001 | *F:*+19184209002 | *M:*+1918424WEST (9378)
*iNUM:*+883 5100 1420 9001 | *ISN:*410*543 | *Skype:*briankwest
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20150512/8937988b/attachment-0001.html 


Join us at ClueCon 2016 Aug 8-12, 2016
More information about the FreeSWITCH-users mailing list