span style="color: cornflowerblue; font-weight: bold;"> 2017-04-28 08:58:05.101113 [NOTICE] mod_cdr_csv.c:123 Rotated CDR logfile /var/log/freeswitch/cdr-csv/1002.csv
2017-04-28 08:58:05.101113 [NOTICE] mod_logfile.c:192 New log started.
recv 419 bytes from udp/[192.168.1.104]:5060 at 08:59:41.830596:
------------------------------------------------------------------------
INVITE sip:1002@172.17.0.3:5080 SIP/2.0
Via: SIP/2.0/UDP 192.168.1.104:5060;branch=z9hG4bK-1988-1-0;nosdp=true;out-of-dialog=true
From: sipp <sip:sipp@192.168.1.104:5060>;tag=1
To: <sip:1002@172.17.0.3:5080>
Call-ID: 1-1988@192.168.1.104
CSeq: 1 INVITE
Contact: <sip:sipp@192.168.1.104:5060;transport=udp>
Max-Forwards: 70
Subject: Performance Test
Session-Expires: 1800
Min-SE: 900
Content-Length: 0
------------------------------------------------------------------------
send 317 bytes to udp/[192.168.1.104]:5060 at 08:59:41.830888:
------------------------------------------------------------------------
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 192.168.1.104:5060;branch=z9hG4bK-1988-1-0;nosdp=true;out-of-dialog=true
From: sipp <sip:sipp@192.168.1.104:5060>;tag=1
To: <sip:1002@172.17.0.3:5080>
Call-ID: 1-1988@192.168.1.104
CSeq: 1 INVITE
User-Agent: FreeSWITCH-mod_sofia/1.6.17-34-0fc0946~64bit
Content-Length: 0
------------------------------------------------------------------------
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:41.831115 [NOTICE] switch_channel.c:1104 New Channel sofia/external/sipp@192.168.1.104:5060 [c514aafe-c9de-45b1-897d-0ddd5fa3f4b2]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:41.831115 [DEBUG] switch_core_state_machine.c:584 (sofia/external/sipp@192.168.1.104:5060) Running State Change CS_NEW (Cur 1 Tot 9)
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:41.831115 [DEBUG] sofia.c:9834 sofia/external/sipp@192.168.1.104:5060 receiving invite from 192.168.1.104:5060 version: 1.6.17 -34-0fc0946 64bit
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:41.831115 [DEBUG] sofia.c:7048 Channel sofia/external/sipp@192.168.1.104:5060 entering state [received][100]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:41.831115 [DEBUG] sofia.c:7568 (sofia/external/sipp@192.168.1.104:5060) State Change CS_NEW -> CS_INIT
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:41.831115 [DEBUG] switch_core_state_machine.c:603 (sofia/external/sipp@192.168.1.104:5060) State NEW
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:41.831115 [DEBUG] switch_core_state_machine.c:584 (sofia/external/sipp@192.168.1.104:5060) Running State Change CS_INIT (Cur 1 Tot 9)
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:41.831115 [DEBUG] switch_core_state_machine.c:627 (sofia/external/sipp@192.168.1.104:5060) State INIT
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:41.831115 [DEBUG] mod_sofia.c:90 sofia/external/sipp@192.168.1.104:5060 SOFIA INIT
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:41.831115 [DEBUG] switch_core_state_machine.c:40 sofia/external/sipp@192.168.1.104:5060 Standard INIT
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:41.831115 [DEBUG] switch_core_state_machine.c:48 (sofia/external/sipp@192.168.1.104:5060) State Change CS_INIT -> CS_ROUTING
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:41.831115 [DEBUG] switch_core_state_machine.c:627 (sofia/external/sipp@192.168.1.104:5060) State INIT going to sleep
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:41.831115 [DEBUG] switch_core_state_machine.c:584 (sofia/external/sipp@192.168.1.104:5060) Running State Change CS_ROUTING (Cur 1 Tot 9)
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:41.831115 [DEBUG] switch_channel.c:2249 (sofia/external/sipp@192.168.1.104:5060) Callstate Change DOWN -> RINGING
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:41.831115 [DEBUG] switch_core_state_machine.c:643 (sofia/external/sipp@192.168.1.104:5060) State ROUTING
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:41.831115 [DEBUG] mod_sofia.c:143 sofia/external/sipp@192.168.1.104:5060 SOFIA ROUTING
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:41.831115 [DEBUG] switch_core_state_machine.c:236 sofia/external/sipp@192.168.1.104:5060 Standard ROUTING
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:41.831115 [INFO] mod_dialplan_xml.c:637 Processing sipp <sipp>->1002 in context public
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Dialplan: sofia/external/sipp@192.168.1.104:5060 parsing [public->unloop] continue=false
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Dialplan: sofia/external/sipp@192.168.1.104:5060 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Dialplan: sofia/external/sipp@192.168.1.104:5060 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Dialplan: sofia/external/sipp@192.168.1.104:5060 parsing [public->outside_call] continue=true
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Dialplan: sofia/external/sipp@192.168.1.104:5060 Absolute Condition [outside_call]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Dialplan: sofia/external/sipp@192.168.1.104:5060 Action set(outside_call=true)
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Dialplan: sofia/external/sipp@192.168.1.104:5060 Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Dialplan: sofia/external/sipp@192.168.1.104:5060 parsing [public->call_debug] continue=true
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Dialplan: sofia/external/sipp@192.168.1.104:5060 Regex (PASS) [call_debug] ${call_debug}(true) =~ /^true$/ break=never
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Dialplan: sofia/external/sipp@192.168.1.104:5060 Action info()
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Dialplan: sofia/external/sipp@192.168.1.104:5060 parsing [public->public_extensions] continue=false
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Dialplan: sofia/external/sipp@192.168.1.104:5060 Regex (PASS) [public_extensions] destination_number(1002) =~ /^(10[01][0-9])$/ break=on-false
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Dialplan: sofia/external/sipp@192.168.1.104:5060 Action transfer(1002 XML default)
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:41.831115 [DEBUG] switch_core_state_machine.c:286 (sofia/external/sipp@192.168.1.104:5060) State Change CS_ROUTING -> CS_EXECUTE
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:41.831115 [DEBUG] switch_core_state_machine.c:643 (sofia/external/sipp@192.168.1.104:5060) State ROUTING going to sleep
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:41.831115 [DEBUG] switch_core_state_machine.c:584 (sofia/external/sipp@192.168.1.104:5060) Running State Change CS_EXECUTE (Cur 1 Tot 9)
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:41.831115 [DEBUG] switch_core_state_machine.c:650 (sofia/external/sipp@192.168.1.104:5060) State EXECUTE
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:41.831115 [DEBUG] mod_sofia.c:198 sofia/external/sipp@192.168.1.104:5060 SOFIA EXECUTE
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:41.831115 [DEBUG] switch_core_state_machine.c:328 sofia/external/sipp@192.168.1.104:5060 Standard EXECUTE
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 EXECUTE sofia/external/sipp@192.168.1.104:5060 set(outside_call=true)
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:41.831115 [DEBUG] mod_dptools.c:1530 SET sofia/external/sipp@192.168.1.104:5060 [outside_call]=[true]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 EXECUTE sofia/external/sipp@192.168.1.104:5060 export(RFC2822_DATE=Fri, 28 Apr 2017 08:59:41 +0000)
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:41.831115 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [RFC2822_DATE]=[Fri, 28 Apr 2017 08:59:41 +0000]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 EXECUTE sofia/external/sipp@192.168.1.104:5060 info()
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:41.831115 [INFO] mod_dptools.c:1743 CHANNEL_DATA:
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Channel-State: [CS_EXECUTE]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Channel-Call-State: [RINGING]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Channel-State-Number: [4]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Channel-Name: [sofia/external/sipp@192.168.1.104:5060]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Unique-ID: [c514aafe-c9de-45b1-897d-0ddd5fa3f4b2]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Call-Direction: [inbound]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Presence-Call-Direction: [inbound]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Channel-HIT-Dialplan: [true]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Channel-Call-UUID: [c514aafe-c9de-45b1-897d-0ddd5fa3f4b2]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Answer-State: [ringing]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Caller-Direction: [inbound]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Caller-Logical-Direction: [inbound]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Caller-Username: [sipp]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Caller-Dialplan: [XML]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Caller-Caller-ID-Name: [sipp]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Caller-Caller-ID-Number: [sipp]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Caller-Orig-Caller-ID-Name: [sipp]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Caller-Orig-Caller-ID-Number: [sipp]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Caller-Network-Addr: [192.168.1.104]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Caller-ANI: [sipp]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Caller-Destination-Number: [1002]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Caller-Unique-ID: [c514aafe-c9de-45b1-897d-0ddd5fa3f4b2]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Caller-Source: [mod_sofia]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Caller-Context: [public]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Caller-Channel-Name: [sofia/external/sipp@192.168.1.104:5060]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Caller-Profile-Index: [1]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Caller-Profile-Created-Time: [1493369981831115]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Caller-Channel-Created-Time: [1493369981831115]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Caller-Channel-Answered-Time: [0]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Caller-Channel-Progress-Time: [0]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Caller-Channel-Progress-Media-Time: [0]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Caller-Channel-Hangup-Time: [0]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Caller-Channel-Transfer-Time: [0]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Caller-Channel-Resurrect-Time: [0]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Caller-Channel-Bridged-Time: [0]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Caller-Channel-Last-Hold: [0]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Caller-Channel-Hold-Accum: [0]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Caller-Screen-Bit: [true]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Caller-Privacy-Hide-Name: [false]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Caller-Privacy-Hide-Number: [false]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_direction: [inbound]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_uuid: [c514aafe-c9de-45b1-897d-0ddd5fa3f4b2]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_session_id: [9]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_sip_from_user: [sipp]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_sip_from_port: [5060]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_sip_from_uri: [sipp@192.168.1.104:5060]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_sip_from_host: [192.168.1.104]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_video_media_flow: [sendrecv]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_audio_media_flow: [sendrecv]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_channel_name: [sofia/external/sipp@192.168.1.104:5060]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_sip_call_id: [1-1988@192.168.1.104]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_sip_local_network_addr: [172.17.0.3]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_sip_network_ip: [192.168.1.104]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_sip_network_port: [5060]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_sip_received_ip: [192.168.1.104]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_sip_received_port: [5060]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_sip_via_protocol: [udp]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_sip_from_user_stripped: [sipp]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_sip_from_tag: [1]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_sofia_profile_name: [external]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_recovery_profile_name: [external]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_sip_full_via: [SIP/2.0/UDP 192.168.1.104:5060;branch=z9hG4bK-1988-1-0;nosdp=true;out-of-dialog=true]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_sip_from_display: [sipp]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_sip_full_from: [sipp <sip:sipp@192.168.1.104:5060>;tag=1]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_sip_full_to: [<sip:1002@172.17.0.3:5080>]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_sip_req_user: [1002]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_sip_req_port: [5080]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_sip_req_uri: [1002@172.17.0.3:5080]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_sip_req_host: [172.17.0.3]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_sip_to_user: [1002]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_sip_to_port: [5080]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_sip_to_uri: [1002@172.17.0.3:5080]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_sip_to_host: [172.17.0.3]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_sip_contact_params: [transport=udp]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_sip_contact_user: [sipp]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_sip_contact_port: [5060]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_sip_contact_uri: [sipp@192.168.1.104:5060]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_sip_contact_host: [192.168.1.104]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_rtp_use_codec_string: [OPUS,G722,PCMU,PCMA,VP8]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_sip_subject: [Performance Test]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_sip_via_host: [192.168.1.104]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_sip_via_port: [5060]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_max_forwards: [70]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_endpoint_disposition: [RECEIVED_NOSDP]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_DP_MATCH: [ARRAY::1002|:1002]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_call_uuid: [c514aafe-c9de-45b1-897d-0ddd5fa3f4b2]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_outside_call: [true]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_RFC2822_DATE: [Fri, 28 Apr 2017 08:59:41 +0000]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_export_vars: [RFC2822_DATE]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_current_application: [info]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 EXECUTE sofia/external/sipp@192.168.1.104:5060 transfer(1002 XML default)
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:41.831115 [DEBUG] switch_ivr.c:2165 (sofia/external/sipp@192.168.1.104:5060) State Change CS_EXECUTE -> CS_ROUTING
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:41.831115 [NOTICE] switch_ivr.c:2172 Transfer sofia/external/sipp@192.168.1.104:5060 to XML[1002@default]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:41.831115 [DEBUG] switch_core_state_machine.c:650 (sofia/external/sipp@192.168.1.104:5060) State EXECUTE going to sleep
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:41.831115 [DEBUG] switch_core_state_machine.c:584 (sofia/external/sipp@192.168.1.104:5060) Running State Change CS_ROUTING (Cur 1 Tot 9)
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:41.831115 [DEBUG] switch_core_state_machine.c:643 (sofia/external/sipp@192.168.1.104:5060) State ROUTING
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:41.831115 [DEBUG] mod_sofia.c:143 sofia/external/sipp@192.168.1.104:5060 SOFIA ROUTING
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:41.831115 [DEBUG] switch_core_state_machine.c:236 sofia/external/sipp@192.168.1.104:5060 Standard ROUTING
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:41.831115 [INFO] mod_dialplan_xml.c:637 Processing sipp <sipp>->1002 in context default
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Dialplan: sofia/external/sipp@192.168.1.104:5060 parsing [default->unloop] continue=false
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Dialplan: sofia/external/sipp@192.168.1.104:5060 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Dialplan: sofia/external/sipp@192.168.1.104:5060 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Dialplan: sofia/external/sipp@192.168.1.104:5060 parsing [default->tod_example] continue=true
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Dialplan: sofia/external/sipp@192.168.1.104:5060 Date/TimeMatch (FAIL) [tod_example] break=on-false
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Dialplan: sofia/external/sipp@192.168.1.104:5060 parsing [default->holiday_example] continue=true
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Dialplan: sofia/external/sipp@192.168.1.104:5060 Date/TimeMatch (FAIL) [holiday_example] break=on-false
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Dialplan: sofia/external/sipp@192.168.1.104:5060 parsing [default->global-intercept] continue=false
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Dialplan: sofia/external/sipp@192.168.1.104:5060 Regex (FAIL) [global-intercept] destination_number(1002) =~ /^886$/ break=on-false
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Dialplan: sofia/external/sipp@192.168.1.104:5060 parsing [default->group-intercept] continue=false
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Dialplan: sofia/external/sipp@192.168.1.104:5060 Regex (FAIL) [group-intercept] destination_number(1002) =~ /^\*8$/ break=on-false
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Dialplan: sofia/external/sipp@192.168.1.104:5060 parsing [default->intercept-ext] continue=false
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Dialplan: sofia/external/sipp@192.168.1.104:5060 Regex (FAIL) [intercept-ext] destination_number(1002) =~ /^\*\*(\d+)$/ break=on-false
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Dialplan: sofia/external/sipp@192.168.1.104:5060 parsing [default->redial] continue=false
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Dialplan: sofia/external/sipp@192.168.1.104:5060 Regex (FAIL) [redial] destination_number(1002) =~ /^(redial|870)$/ break=on-false
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Dialplan: sofia/external/sipp@192.168.1.104:5060 parsing [default->global] continue=true
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Dialplan: sofia/external/sipp@192.168.1.104:5060 Regex (PASS) [global] ${call_debug}(true) =~ /^true$/ break=never
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Dialplan: sofia/external/sipp@192.168.1.104:5060 Action info()
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Dialplan: sofia/external/sipp@192.168.1.104:5060 Regex (FAIL) [global] ${default_password}(12345) =~ /^1234$/ break=never
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Dialplan: sofia/external/sipp@192.168.1.104:5060 Regex (FAIL) [global] ${rtp_has_crypto}() =~ /^(AEAD_AES_256_GCM_8|AEAD_AES_128_GCM_8|AES_CM_256_HMAC_SHA1_80|AES_CM_192_HMAC_SHA1_80|AES_CM_128_HMAC_SHA1_80|AES_CM_256_HMAC_SHA1_32|AES_CM_192_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_32|AES_CM_128_NULL_AUTH)$/ break=never
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Dialplan: sofia/external/sipp@192.168.1.104:5060 Regex (FAIL) [global] ${endpoint_disposition}(RECEIVED_NOSDP) =~ /^(DELAYED NEGOTIATION)/ break=on-false
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Dialplan: sofia/external/sipp@192.168.1.104:5060 parsing [default->snom-demo-2] continue=false
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Dialplan: sofia/external/sipp@192.168.1.104:5060 Regex (FAIL) [snom-demo-2] destination_number(1002) =~ /^9001$/ break=on-false
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Dialplan: sofia/external/sipp@192.168.1.104:5060 parsing [default->snom-demo-1] continue=false
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Dialplan: sofia/external/sipp@192.168.1.104:5060 Regex (FAIL) [snom-demo-1] destination_number(1002) =~ /^9000$/ break=on-false
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Dialplan: sofia/external/sipp@192.168.1.104:5060 parsing [default->eavesdrop] continue=false
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Dialplan: sofia/external/sipp@192.168.1.104:5060 Regex (FAIL) [eavesdrop] destination_number(1002) =~ /^88(\d{4})$|^\*0(.*)$/ break=on-false
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Dialplan: sofia/external/sipp@192.168.1.104:5060 parsing [default->eavesdrop] continue=false
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Dialplan: sofia/external/sipp@192.168.1.104:5060 Regex (FAIL) [eavesdrop] destination_number(1002) =~ /^779$/ break=on-false
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Dialplan: sofia/external/sipp@192.168.1.104:5060 parsing [default->call_return] continue=false
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Dialplan: sofia/external/sipp@192.168.1.104:5060 Regex (FAIL) [call_return] destination_number(1002) =~ /^\*69$|^869$|^lcr$/ break=on-false
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Dialplan: sofia/external/sipp@192.168.1.104:5060 parsing [default->del-group] continue=false
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Dialplan: sofia/external/sipp@192.168.1.104:5060 Regex (FAIL) [del-group] destination_number(1002) =~ /^80(\d{2})$/ break=on-false
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Dialplan: sofia/external/sipp@192.168.1.104:5060 parsing [default->add-group] continue=false
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Dialplan: sofia/external/sipp@192.168.1.104:5060 Regex (FAIL) [add-group] destination_number(1002) =~ /^81(\d{2})$/ break=on-false
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Dialplan: sofia/external/sipp@192.168.1.104:5060 parsing [default->call-group-simo] continue=false
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Dialplan: sofia/external/sipp@192.168.1.104:5060 Regex (FAIL) [call-group-simo] destination_number(1002) =~ /^82(\d{2})$/ break=on-false
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Dialplan: sofia/external/sipp@192.168.1.104:5060 parsing [default->call-group-order] continue=false
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Dialplan: sofia/external/sipp@192.168.1.104:5060 Regex (FAIL) [call-group-order] destination_number(1002) =~ /^83(\d{2})$/ break=on-false
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Dialplan: sofia/external/sipp@192.168.1.104:5060 parsing [default->extension-intercom] continue=false
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Dialplan: sofia/external/sipp@192.168.1.104:5060 Regex (FAIL) [extension-intercom] destination_number(1002) =~ /^8(10[01][0-9])$/ break=on-false
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Dialplan: sofia/external/sipp@192.168.1.104:5060 parsing [default->Local_Extension] continue=false
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Dialplan: sofia/external/sipp@192.168.1.104:5060 Regex (PASS) [Local_Extension] destination_number(1002) =~ /^(10[01][0-9])$/ break=on-false
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Dialplan: sofia/external/sipp@192.168.1.104:5060 Action export(dialed_extension=1002)
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Dialplan: sofia/external/sipp@192.168.1.104:5060 Action bind_meta_app(1 b s execute_extension::dx XML features)
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Dialplan: sofia/external/sipp@192.168.1.104:5060 Action bind_meta_app(2 b s record_session::/var/lib/freeswitch/recordings/${caller_id_number}.${strftime(%Y-%m-%d-%H-%M-%S)}.wav)
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Dialplan: sofia/external/sipp@192.168.1.104:5060 Action bind_meta_app(3 b s execute_extension::cf XML features)
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Dialplan: sofia/external/sipp@192.168.1.104:5060 Action bind_meta_app(4 b s execute_extension::att_xfer XML features)
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Dialplan: sofia/external/sipp@192.168.1.104:5060 Action set(call_timeout=30)
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Dialplan: sofia/external/sipp@192.168.1.104:5060 Action set(hangup_after_bridge=true)
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Dialplan: sofia/external/sipp@192.168.1.104:5060 Action set(continue_on_fail=true)
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Dialplan: sofia/external/sipp@192.168.1.104:5060 Action hash(insert/${domain_name}-call_return/${dialed_extension}/${caller_id_number})
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Dialplan: sofia/external/sipp@192.168.1.104:5060 Action hash(insert/${domain_name}-last_dial_ext/${dialed_extension}/${uuid})
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Dialplan: sofia/external/sipp@192.168.1.104:5060 Action set(called_party_callgroup=${user_data(${dialed_extension}@${domain_name} var callgroup)})
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Dialplan: sofia/external/sipp@192.168.1.104:5060 Action hash(insert/${domain_name}-last_dial_ext/${called_party_callgroup}/${uuid})
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Dialplan: sofia/external/sipp@192.168.1.104:5060 Action hash(insert/${domain_name}-last_dial_ext/global/${uuid})
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Dialplan: sofia/external/sipp@192.168.1.104:5060 Action hash(insert/${domain_name}-last_dial/${called_party_callgroup}/${uuid})
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Dialplan: sofia/external/sipp@192.168.1.104:5060 Action set(3pcc_always_gen_sdp=true)
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Dialplan: sofia/external/sipp@192.168.1.104:5060 Action bridge(user/${dialed_extension}@${domain_name})
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Dialplan: sofia/external/sipp@192.168.1.104:5060 Action answer()
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Dialplan: sofia/external/sipp@192.168.1.104:5060 Action sleep(1000)
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Dialplan: sofia/external/sipp@192.168.1.104:5060 Action bridge(loopback/app=voicemail:default ${domain_name} ${dialed_extension})
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:41.831115 [DEBUG] switch_core_state_machine.c:286 (sofia/external/sipp@192.168.1.104:5060) State Change CS_ROUTING -> CS_EXECUTE
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:41.831115 [DEBUG] switch_core_state_machine.c:643 (sofia/external/sipp@192.168.1.104:5060) State ROUTING going to sleep
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:41.831115 [DEBUG] switch_core_state_machine.c:584 (sofia/external/sipp@192.168.1.104:5060) Running State Change CS_EXECUTE (Cur 1 Tot 9)
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:41.831115 [DEBUG] switch_core_state_machine.c:650 (sofia/external/sipp@192.168.1.104:5060) State EXECUTE
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:41.831115 [DEBUG] mod_sofia.c:198 sofia/external/sipp@192.168.1.104:5060 SOFIA EXECUTE
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:41.831115 [DEBUG] switch_core_state_machine.c:328 sofia/external/sipp@192.168.1.104:5060 Standard EXECUTE
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 EXECUTE sofia/external/sipp@192.168.1.104:5060 info()
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:41.831115 [INFO] mod_dptools.c:1743 CHANNEL_DATA:
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Channel-State: [CS_EXECUTE]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Channel-Call-State: [RINGING]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Channel-State-Number: [4]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Channel-Name: [sofia/external/sipp@192.168.1.104:5060]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Unique-ID: [c514aafe-c9de-45b1-897d-0ddd5fa3f4b2]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Call-Direction: [inbound]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Presence-Call-Direction: [inbound]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Channel-HIT-Dialplan: [true]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Channel-Call-UUID: [c514aafe-c9de-45b1-897d-0ddd5fa3f4b2]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Answer-State: [ringing]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Caller-Direction: [inbound]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Caller-Logical-Direction: [inbound]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Caller-Username: [sipp]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Caller-Dialplan: [XML]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Caller-Caller-ID-Name: [sipp]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Caller-Caller-ID-Number: [sipp]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Caller-Orig-Caller-ID-Name: [sipp]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Caller-Orig-Caller-ID-Number: [sipp]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Caller-Network-Addr: [192.168.1.104]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Caller-ANI: [sipp]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Caller-Destination-Number: [1002]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Caller-Unique-ID: [c514aafe-c9de-45b1-897d-0ddd5fa3f4b2]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Caller-Source: [mod_sofia]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Caller-Transfer-Source: [1493369981:858cf5c7-117b-4df9-972a-f4afdfecf711:bl_xfer:1002/default/XML]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Caller-Context: [default]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Caller-RDNIS: [1002]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Caller-Channel-Name: [sofia/external/sipp@192.168.1.104:5060]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Caller-Profile-Index: [2]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Caller-Profile-Created-Time: [1493369981831115]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Caller-Channel-Created-Time: [1493369981831115]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Caller-Channel-Answered-Time: [0]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Caller-Channel-Progress-Time: [0]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Caller-Channel-Progress-Media-Time: [0]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Caller-Channel-Hangup-Time: [0]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Caller-Channel-Transfer-Time: [0]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Caller-Channel-Resurrect-Time: [0]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Caller-Channel-Bridged-Time: [0]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Caller-Channel-Last-Hold: [0]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Caller-Channel-Hold-Accum: [0]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Caller-Screen-Bit: [true]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Caller-Privacy-Hide-Name: [false]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 Caller-Privacy-Hide-Number: [false]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_direction: [inbound]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_uuid: [c514aafe-c9de-45b1-897d-0ddd5fa3f4b2]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_session_id: [9]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_sip_from_user: [sipp]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_sip_from_port: [5060]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_sip_from_uri: [sipp@192.168.1.104:5060]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_sip_from_host: [192.168.1.104]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_video_media_flow: [sendrecv]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_audio_media_flow: [sendrecv]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_channel_name: [sofia/external/sipp@192.168.1.104:5060]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_sip_call_id: [1-1988@192.168.1.104]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_sip_local_network_addr: [172.17.0.3]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_sip_network_ip: [192.168.1.104]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_sip_network_port: [5060]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_sip_received_ip: [192.168.1.104]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_sip_received_port: [5060]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_sip_via_protocol: [udp]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_sip_from_user_stripped: [sipp]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_sip_from_tag: [1]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_sofia_profile_name: [external]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_recovery_profile_name: [external]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_sip_full_via: [SIP/2.0/UDP 192.168.1.104:5060;branch=z9hG4bK-1988-1-0;nosdp=true;out-of-dialog=true]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_sip_from_display: [sipp]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_sip_full_from: [sipp <sip:sipp@192.168.1.104:5060>;tag=1]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_sip_full_to: [<sip:1002@172.17.0.3:5080>]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_sip_req_user: [1002]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_sip_req_port: [5080]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_sip_req_uri: [1002@172.17.0.3:5080]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_sip_req_host: [172.17.0.3]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_sip_to_user: [1002]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_sip_to_port: [5080]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_sip_to_uri: [1002@172.17.0.3:5080]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_sip_to_host: [172.17.0.3]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_sip_contact_params: [transport=udp]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_sip_contact_user: [sipp]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_sip_contact_port: [5060]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_sip_contact_uri: [sipp@192.168.1.104:5060]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_sip_contact_host: [192.168.1.104]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_rtp_use_codec_string: [OPUS,G722,PCMU,PCMA,VP8]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_sip_subject: [Performance Test]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_sip_via_host: [192.168.1.104]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_sip_via_port: [5060]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_endpoint_disposition: [RECEIVED_NOSDP]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_outside_call: [true]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_RFC2822_DATE: [Fri, 28 Apr 2017 08:59:41 +0000]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_export_vars: [RFC2822_DATE]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_max_forwards: [69]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_transfer_history: [1493369981:858cf5c7-117b-4df9-972a-f4afdfecf711:bl_xfer:1002/default/XML]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_transfer_source: [1493369981:858cf5c7-117b-4df9-972a-f4afdfecf711:bl_xfer:1002/default/XML]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_DP_MATCH: [ARRAY::1002|:1002]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_call_uuid: [c514aafe-c9de-45b1-897d-0ddd5fa3f4b2]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 variable_current_application: [info]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 EXECUTE sofia/external/sipp@192.168.1.104:5060 export(dialed_extension=1002)
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:41.831115 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [dialed_extension]=[1002]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 EXECUTE sofia/external/sipp@192.168.1.104:5060 bind_meta_app(1 b s execute_extension::dx XML features)
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:41.831115 [INFO] switch_ivr_async.c:4171 Bound B-Leg: *1 execute_extension::dx XML features
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 EXECUTE sofia/external/sipp@192.168.1.104:5060 bind_meta_app(2 b s record_session::/var/lib/freeswitch/recordings/sipp.2017-04-28-08-59-41.wav)
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:41.831115 [INFO] switch_ivr_async.c:4171 Bound B-Leg: *2 record_session::/var/lib/freeswitch/recordings/sipp.2017-04-28-08-59-41.wav
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 EXECUTE sofia/external/sipp@192.168.1.104:5060 bind_meta_app(3 b s execute_extension::cf XML features)
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:41.831115 [INFO] switch_ivr_async.c:4171 Bound B-Leg: *3 execute_extension::cf XML features
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 EXECUTE sofia/external/sipp@192.168.1.104:5060 bind_meta_app(4 b s execute_extension::att_xfer XML features)
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:41.831115 [INFO] switch_ivr_async.c:4171 Bound B-Leg: *4 execute_extension::att_xfer XML features
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 EXECUTE sofia/external/sipp@192.168.1.104:5060 set(call_timeout=30)
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:41.831115 [DEBUG] mod_dptools.c:1530 SET sofia/external/sipp@192.168.1.104:5060 [call_timeout]=[30]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 EXECUTE sofia/external/sipp@192.168.1.104:5060 set(hangup_after_bridge=true)
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:41.831115 [DEBUG] mod_dptools.c:1530 SET sofia/external/sipp@192.168.1.104:5060 [hangup_after_bridge]=[true]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 EXECUTE sofia/external/sipp@192.168.1.104:5060 set(continue_on_fail=true)
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:41.831115 [DEBUG] mod_dptools.c:1530 SET sofia/external/sipp@192.168.1.104:5060 [continue_on_fail]=[true]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 EXECUTE sofia/external/sipp@192.168.1.104:5060 hash(insert/172.17.0.3-call_return/1002/sipp)
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 EXECUTE sofia/external/sipp@192.168.1.104:5060 hash(insert/172.17.0.3-last_dial_ext/1002/c514aafe-c9de-45b1-897d-0ddd5fa3f4b2)
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 EXECUTE sofia/external/sipp@192.168.1.104:5060 set(called_party_callgroup=techsupport)
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:41.841115 [DEBUG] mod_dptools.c:1530 SET sofia/external/sipp@192.168.1.104:5060 [called_party_callgroup]=[techsupport]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 EXECUTE sofia/external/sipp@192.168.1.104:5060 hash(insert/172.17.0.3-last_dial_ext/techsupport/c514aafe-c9de-45b1-897d-0ddd5fa3f4b2)
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 EXECUTE sofia/external/sipp@192.168.1.104:5060 hash(insert/172.17.0.3-last_dial_ext/global/c514aafe-c9de-45b1-897d-0ddd5fa3f4b2)
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 EXECUTE sofia/external/sipp@192.168.1.104:5060 hash(insert/172.17.0.3-last_dial/techsupport/c514aafe-c9de-45b1-897d-0ddd5fa3f4b2)
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 EXECUTE sofia/external/sipp@192.168.1.104:5060 set(3pcc_always_gen_sdp=true)
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:41.841115 [DEBUG] mod_dptools.c:1530 SET sofia/external/sipp@192.168.1.104:5060 [3pcc_always_gen_sdp]=[true]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 EXECUTE sofia/external/sipp@192.168.1.104:5060 bridge(user/1002@172.17.0.3)
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:41.841115 [DEBUG] switch_channel.c:1250 sofia/external/sipp@192.168.1.104:5060 EXPORTING[export_vars] [RFC2822_DATE]=[Fri, 28 Apr 2017 08:59:41 +0000] to event
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:41.841115 [DEBUG] switch_channel.c:1250 sofia/external/sipp@192.168.1.104:5060 EXPORTING[export_vars] [dialed_extension]=[1002] to event
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:41.841115 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:41.841115 [DEBUG] switch_channel.c:1250 sofia/external/sipp@192.168.1.104:5060 EXPORTING[export_vars] [RFC2822_DATE]=[Fri, 28 Apr 2017 08:59:41 +0000] to event
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:41.841115 [DEBUG] switch_channel.c:1250 sofia/external/sipp@192.168.1.104:5060 EXPORTING[export_vars] [dialed_extension]=[1002] to event
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:41.841115 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:41.841115 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/1002@172.17.0.1:15060 [a39555b8-b95f-479f-b480-4601fd615f24]
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:41.841115 [DEBUG] mod_sofia.c:4818 (sofia/internal/1002@172.17.0.1:15060) State Change CS_NEW -> CS_INIT
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:41.841115 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1002@172.17.0.1:15060) Running State Change CS_INIT (Cur 2 Tot 10)
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:41.841115 [NOTICE] switch_ivr_originate.c:2845 Cannot create outgoing channel of type [error] cause: [USER_NOT_REGISTERED]
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:41.841115 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1002@172.17.0.1:15060) State INIT
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:41.841115 [DEBUG] mod_sofia.c:90 sofia/internal/1002@172.17.0.1:15060 SOFIA INIT
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:41.841115 [DEBUG] sofia_glue.c:1295 sofia/internal/1002@172.17.0.1:15060 sending invite version: 1.6.17 -34-0fc0946 64bit
a39555b8-b95f-479f-b480-4601fd615f24 Local SDP:
a39555b8-b95f-479f-b480-4601fd615f24 v=0
a39555b8-b95f-479f-b480-4601fd615f24 o=FreeSWITCH 1493337485 1493337486 IN IP4 172.17.0.3
a39555b8-b95f-479f-b480-4601fd615f24 s=FreeSWITCH
a39555b8-b95f-479f-b480-4601fd615f24 c=IN IP4 172.17.0.3
a39555b8-b95f-479f-b480-4601fd615f24 t=0 0
a39555b8-b95f-479f-b480-4601fd615f24 m=audio 32496 RTP/AVP 102 9 0 8 104 101
a39555b8-b95f-479f-b480-4601fd615f24 a=rtpmap:102 opus/48000/2
a39555b8-b95f-479f-b480-4601fd615f24 a=fmtp:102 useinbandfec=1; maxaveragebitrate=30000; maxplaybackrate=48000; ptime=20; minptime=10; maxptime=40
a39555b8-b95f-479f-b480-4601fd615f24 a=rtpmap:9 G722/8000
a39555b8-b95f-479f-b480-4601fd615f24 a=rtpmap:0 PCMU/8000
a39555b8-b95f-479f-b480-4601fd615f24 a=rtpmap:8 PCMA/8000
a39555b8-b95f-479f-b480-4601fd615f24 a=rtpmap:104 telephone-event/48000
a39555b8-b95f-479f-b480-4601fd615f24 a=fmtp:104 0-16
a39555b8-b95f-479f-b480-4601fd615f24 a=rtpmap:101 telephone-event/8000
a39555b8-b95f-479f-b480-4601fd615f24 a=fmtp:101 0-16
a39555b8-b95f-479f-b480-4601fd615f24 a=ptime:20
a39555b8-b95f-479f-b480-4601fd615f24 a=sendrecv
a39555b8-b95f-479f-b480-4601fd615f24 m=video 18064 RTP/AVP 103
a39555b8-b95f-479f-b480-4601fd615f24 b=AS:1024
a39555b8-b95f-479f-b480-4601fd615f24 a=rtpmap:103 VP8/90000
a39555b8-b95f-479f-b480-4601fd615f24 a=rtcp-fb:103 ccm fir
a39555b8-b95f-479f-b480-4601fd615f24 a=rtcp-fb:103 ccm tmmbr
a39555b8-b95f-479f-b480-4601fd615f24 a=rtcp-fb:103 nack
a39555b8-b95f-479f-b480-4601fd615f24 a=rtcp-fb:103 nack pli
a39555b8-b95f-479f-b480-4601fd615f24
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:41.841115 [DEBUG] switch_core_state_machine.c:40 sofia/internal/1002@172.17.0.1:15060 Standard INIT
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:41.841115 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/1002@172.17.0.1:15060) State Change CS_INIT -> CS_ROUTING
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:41.841115 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1002@172.17.0.1:15060) State INIT going to sleep
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:41.841115 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1002@172.17.0.1:15060) Running State Change CS_ROUTING (Cur 2 Tot 10)
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:41.841115 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1002@172.17.0.1:15060) State ROUTING
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:41.841115 [DEBUG] mod_sofia.c:143 sofia/internal/1002@172.17.0.1:15060 SOFIA ROUTING
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:41.841115 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/1002@172.17.0.1:15060) State Change CS_ROUTING -> CS_CONSUME_MEDIA
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:41.841115 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1002@172.17.0.1:15060) State ROUTING going to sleep
send 1549 bytes to udp/[172.17.0.1]:15060 at 08:59:41.845256:
------------------------------------------------------------------------
INVITE sip:1002@172.17.0.1:15060;transport=udp SIP/2.0
Via: SIP/2.0/UDP 172.17.0.3;rport;branch=z9hG4bKKtB7Dgr6DtZaN
Max-Forwards: 68
From: "sipp" <sip:sipp@172.17.0.3>;tag=Q2gmU46vre09H
To: <sip:1002@172.17.0.1:15060;transport=udp>
Call-ID: dbbbf1c8-a693-1235-0e9b-0242ac110003
CSeq: 106348926 INVITE
Contact: <sip:mod_sofia@172.17.0.3:5060>
User-Agent: FreeSWITCH-mod_sofia/1.6.17-34-0fc0946~64bit
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, path, replaces
Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
Content-Type: application/sdp
Content-Disposition: sessiona39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:41.841115 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1002@172.17.0.1:15060) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 10)
Content-Length: 617
X-FS-Support: update_display,send_info
Remote-Party-ID: "sipp" <sip:sipp@172.17.0.3>;party=calling;screen=yes;privacy=off
v=0
o=FreeSWITCH 1493337485 1493337486 IN IP4 172.17.0.3
s=FreeSWITCH
c=IN IP4 172.17.0.3
t=0 0
m=audio 32496 RTP/AVP 102 9 0 8 104 101
a=rtpmap:102 opus/48000/2
a=fmtp:102 useinbandfec=1; maxaveragebitrate=30000; maxplaybackrate=48000; ptime=20; minptime=10; maxptime=40
a=rtpmap:9 G722/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:104 telephone-event/48000
a=fmtp:104 0-16
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
m=video 18064 RTP/AVP 103
b=AS:1024
a=rtpmap:103 VP8/90000
a=rtcp-fb:103 ccm fir
a=rtcp-fb:103 ccm tmmbr
a=rtcp-fb:103 nack
a=rtcp-fb:103 nack pli
------------------------------------------------------------------------
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:41.841115 [DEBUG] sofia.c:7048 Channel sofia/internal/1002@172.17.0.1:15060 entering state [calling][0]
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:41.841115 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/1002@172.17.0.1:15060) State CONSUME_MEDIA
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:41.841115 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/1002@172.17.0.1:15060) State CONSUME_MEDIA going to sleep
recv 257 bytes from udp/[172.17.0.1]:15060 at 08:59:41.866749:
------------------------------------------------------------------------
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 172.17.0.3;rport;branch=z9hG4bKKtB7Dgr6DtZaN
From: "sipp" <sip:sipp@172.17.0.3>;tag=Q2gmU46vre09H
To: <sip:1002@172.17.0.1:15060;transport=udp>
Call-ID: dbbbf1c8-a693-1235-0e9b-0242ac110003
CSeq: 106348926 INVITE
------------------------------------------------------------------------
recv 348 bytes from udp/[172.17.0.1]:15060 at 08:59:41.883124:
------------------------------------------------------------------------
SIP/2.0 180 Ringing
Via: SIP/2.0/UDP 172.17.0.3;rport;branch=z9hG4bKKtB7Dgr6DtZaN
From: "sipp" <sip:sipp@172.17.0.3>;tag=Q2gmU46vre09H
To: <sip:1002@172.17.0.1:15060;transport=udp>;tag=p4j0hb7
Call-ID: dbbbf1c8-a693-1235-0e9b-0242ac110003
CSeq: 106348926 INVITE
User-Agent: Linphone/3.11.1 (belle-sip/1.6.1)
Supported: replaces, outbound
------------------------------------------------------------------------
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:41.881123 [DEBUG] sofia.c:7048 Channel sofia/internal/1002@172.17.0.1:15060 entering state [proceeding][180]
recv 905 bytes from udp/[172.17.0.1]:15060 at 08:59:50.246067:
------------------------------------------------------------------------
SIP/2.0 200 Ok
Via: SIP/2.0/UDP 172.17.0.3;rport;branch=z9hG4bKKtB7Dgr6DtZaN
From: "sipp" <sip:sipp@172.17.0.3>;tag=Q2gmU46vre09H
To: <sip:1002@172.17.0.1:15060;transport=udp>;tag=p4j0hb7
Call-ID: dbbbf1c8-a693-1235-0e9b-0242ac110003
CSeq: 106348926 INVITE
User-Agent: Linphone/3.11.1 (belle-sip/1.6.1)
Supported: replaces, outbound
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO, UPDATE
Contact: <sip:1002@172.17.0.1:15060;transport=udp>;+sip.instance="<urn:uuid:7762182d-541d-4148-a234-ca1f236a6606>"
Content-Type: application/sdp
Content-Length: 303
v=0
o=1002 701 51 IN IP4 172.17.0.1
s=Talk
c=IN IP4 172.17.0.1
t=0 0
m=audio 7078 RTP/AVP 0 8 101
a=rtpmap:101 telephone-event/8000
m=video 9076 RTP/AVP 103
a=rtpmap:103 VP8/90000
a=rtcp-fb:* trr-int 5000
a=rtcp-fb:* nack
a=rtcp-fb:* ccm tmmbr
a=rtcp-fb:103 nack pli
a=rtcp-fb:103 ccm fir
------------------------------------------------------------------------
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:50.241114 [DEBUG] sofia.c:7048 Channel sofia/internal/1002@172.17.0.1:15060 entering state [completing][200]
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:50.241114 [DEBUG] sofia.c:7058 Remote SDP:
a39555b8-b95f-479f-b480-4601fd615f24 v=0
a39555b8-b95f-479f-b480-4601fd615f24 o=1002 701 51 IN IP4 172.17.0.1
a39555b8-b95f-479f-b480-4601fd615f24 s=Talk
a39555b8-b95f-479f-b480-4601fd615f24 c=IN IP4 172.17.0.1
a39555b8-b95f-479f-b480-4601fd615f24 t=0 0
a39555b8-b95f-479f-b480-4601fd615f24 m=audio 7078 RTP/AVP 0 8 101
a39555b8-b95f-479f-b480-4601fd615f24 a=rtpmap:101 telephone-event/8000
a39555b8-b95f-479f-b480-4601fd615f24 m=video 9076 RTP/AVP 103
a39555b8-b95f-479f-b480-4601fd615f24 a=rtpmap:103 VP8/90000
a39555b8-b95f-479f-b480-4601fd615f24 a=rtcp-fb:* trr-int 5000
a39555b8-b95f-479f-b480-4601fd615f24 a=rtcp-fb:* nack
a39555b8-b95f-479f-b480-4601fd615f24 a=rtcp-fb:* ccm tmmbr
a39555b8-b95f-479f-b480-4601fd615f24 a=rtcp-fb:103 nack pli
a39555b8-b95f-479f-b480-4601fd615f24 a=rtcp-fb:103 ccm fir
a39555b8-b95f-479f-b480-4601fd615f24
send 378 bytes to udp/[172.17.0.1]:15060 at 08:59:50.249818:
------------------------------------------------------------------------
ACK sip:1002@172.17.0.1:15060;transport=udp SIP/2.0
Via: SIP/2.0/UDP 172.17.0.3;rport;branch=z9hG4bKm34ZFB99a3NXg
Max-Forwards: 70
From: "sipp" <sip:sipp@172.17.0.3>;tag=Q2gmU46vre09H
To: <sip:1002@172.17.0.1:15060;transport=udp>;tag=p4j0hb7
Call-ID: dbbbf1c8-a693-1235-0e9b-0242ac110003
CSeq: 106348926 ACK
Contact: <sip:mod_sofia@172.17.0.3:5060>
Content-Length: 0
------------------------------------------------------------------------
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:50.251119 [DEBUG] sofia.c:7048 Channel sofia/internal/1002@172.17.0.1:15060 entering state [ready][200]
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:50.251119 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1]
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:50.251119 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:50.251119 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:50.251119 [DEBUG] switch_core_media.c:4491 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:50.251119 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:50.251119 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[opus:116:48000:20:0:1]
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:50.251119 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:50.251119 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:50.251119 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:50.251119 [DEBUG] switch_core_media.c:4491 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:50.251119 [DEBUG] switch_core_media.c:4352 Set telephone-event payload to 101@8000
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:50.251119 [DEBUG] switch_core_media.c:3056 Set Codec sofia/internal/1002@172.17.0.1:15060 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:50.251119 [DEBUG] switch_core_codec.c:111 sofia/internal/1002@172.17.0.1:15060 Original read codec set to PCMU:0
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:50.251119 [DEBUG] switch_core_media.c:4695 Set telephone-event payload to 101@8000
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:50.251119 [DEBUG] switch_core_media.c:4754 sofia/internal/1002@172.17.0.1:15060 Set 2833 dtmf send payload to 101 recv payload to 101
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:50.251119 [DEBUG] switch_core_media.c:4937 Video Codec Compare [VP8:103]/[VP8:99]
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:50.251119 [DEBUG] switch_core_media.c:4969 Video Codec Compare [VP8:103] +++ is saved as a match
2017-04-28 08:59:50.251119 [DEBUG] switch_vpx.c:627 VPX VER:v1.6.0 VPX_IMAGE_ABI_VERSION:4 VPX_CODEC_ABI_VERSION:7
2017-04-28 08:59:50.251119 [DEBUG] switch_vpx.c:627 VPX VER:v1.6.0 VPX_IMAGE_ABI_VERSION:4 VPX_CODEC_ABI_VERSION:7
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:50.251119 [DEBUG] switch_core_media.c:2866 Set VIDEO Codec sofia/internal/1002@172.17.0.1:15060 VP8/90000 0 ms
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:50.251119 [DEBUG] switch_core_media.c:6865 AUDIO RTP [sofia/internal/1002@172.17.0.1:15060] 172.17.0.3 port 32496 -> 172.17.0.1 port 7078 codec: 0 ms: 20
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:50.251119 [DEBUG] switch_rtp.c:4096 Starting timer [soft] 160 bytes per 20ms
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:50.251119 [DEBUG] switch_core_media.c:7166 sofia/internal/1002@172.17.0.1:15060 Set 2833 dtmf send payload to 101
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:50.251119 [DEBUG] switch_core_media.c:7173 sofia/internal/1002@172.17.0.1:15060 Set 2833 dtmf receive payload to 101
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:50.251119 [DEBUG] switch_core_media.c:7196 sofia/internal/1002@172.17.0.1:15060 Set rtp dtmf delay to 40
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:50.251119 [DEBUG] switch_rtp.c:4107 Starting video timer.
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:50.251119 [DEBUG] switch_core_media.c:7385 VIDEO RTP [sofia/internal/1002@172.17.0.1:15060] 172.17.0.3:18064->172.17.0.1:9076 codec: 103 ms: 0 [SUCCESS]
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:50.251119 [DEBUG] switch_core_media.c:5990 sofia/internal/1002@172.17.0.1:15060 Starting Video thread
2017-04-28 08:59:50.251119 [DEBUG] switch_core_media.c:5856 sofia/internal/1002@172.17.0.1:15060 Video thread started. Echo is off
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:50.251119 [INFO] switch_core_media.c:7465 Activating VIDEO RTCP PORT 9077 interval 1000 mux -1
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:50.251119 [DEBUG] switch_rtp.c:4488 RTCP send rate is: 1000 and packet rate is: 90000 Remote Port: 9077
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:50.251119 [DEBUG] switch_rtp.c:2560 Setting RTCP remote addr to 172.17.0.1:9077 2
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:50.251119 [NOTICE] sofia.c:8182 Channel [sofia/internal/1002@172.17.0.1:15060] has been answered
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:50.251119 [DEBUG] switch_channel.c:3772 (sofia/internal/1002@172.17.0.1:15060) Callstate Change DOWN -> ACTIVE
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:50.263332 [DEBUG] mod_sofia.c:790 3PCC-PROXY, Sent a 200 OK, waiting for ACK
send 1284 bytes to udp/[192.168.1.104]:5060 at 08:59:50.269280:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.1.104:5060;branch=z9hG4bK-1988-1-0;nosdp=true;out-of-dialog=true
From: sipp <sip:sipp@192.168.1.104:5060>;tag=1
To: <sip:1002@172.17.0.3:5080>;tag=ND882pjeBXeQH
Call-ID: 1-1988@192.168.1.104
CSeq: 1 INVITE
Contact: <sip:mod_sofia@172.17.0.3:5080>
User-Agent: FreeSWITCH-mod_sofia/1.6.17-34-0fc0946~64bit
Accept: application/sdp
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
Supported: timer, path, replaces
Allow-Events: talk, hold, conference, refer
Session-Expires: 1800;refresher=uas
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 617
v=0
o=FreeSWITCH 1493349136 1493349137 IN IP4 172.17.0.3
s=FreeSWITCH
c=IN IP4 172.17.0.3
t=0 0
m=audio 20854 RTP/AVP 102 9 0 8 103 101
a=rtpmap:102 opus/48000/2
a=fmtp:102 useinbandfec=1; maxaveragebitrate=30000; maxplaybackrate=48000; ptime=20; minptime=10; maxptime=40
a=rtpmap:9 G722/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:103 telephone-event/48000
a=fmtp:103 0-16
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
m=video 19190 RTP/AVP 103
b=AS:1024
a=rtpmap:103 VP8/90000
a=rtcp-fb:103 ccm fir
a=rtcp-fb:103 ccm tmmbr
a=rtcp-fb:103 nack
a=rtcp-fb:103 nack pli
------------------------------------------------------------------------
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:50.263332 [DEBUG] sofia.c:7048 Channel sofia/external/sipp@192.168.1.104:5060 entering state [completed][200]
recv 572 bytes from udp/[192.168.1.104]:5060 at 08:59:50.274616:
------------------------------------------------------------------------
ACK sip:mod_sofia@172.17.0.3:5080 SIP/2.0
Via: SIP/2.0/UDP 192.168.1.104:5060;branch=z9hG4bK-1988-1-4
From: sipp <sip:sipp@192.168.1.104:5060>;tag=1
To: <sip:1002@172.17.0.3:5080>;tag=ND882pjeBXeQH
Call-ID: 1-1988@192.168.1.104
CSeq: 1 ACK
Contact: <sip:sipp@192.168.1.104:5060;transport=udp>
Max-Forwards: 70
Subject: Performance Test
Content-Type: application/sdp
Content-Length: 171
v=0
o=ipjib 1492600869292 1492600869292 IN IP4 192.168.1.104
s=wms
c=IN IP4 192.168.1.104
t=0 0
m=audio 6000 RTP/AVP 0
a=rtpmap:0 PCMU/8000
a=ptime:20
a=sendrecv
------------------------------------------------------------------------
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:50.271103 [DEBUG] sofia.c:7048 Channel sofia/external/sipp@192.168.1.104:5060 entering state [ready][200]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:50.271103 [DEBUG] sofia.c:7058 Remote SDP:
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 v=0
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 o=ipjib 1492600869292 1492600869292 IN IP4 192.168.1.104
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 s=wms
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 c=IN IP4 192.168.1.104
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 t=0 0
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 m=audio 6000 RTP/AVP 0
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 a=rtpmap:0 PCMU/8000
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 a=ptime:20
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:50.271103 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:50.271103 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:50.271103 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:50.271103 [DEBUG] switch_core_media.c:4491 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:50.271103 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:50.271103 [DEBUG] switch_core_media.c:3056 Set Codec sofia/external/sipp@192.168.1.104:5060 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:50.271103 [DEBUG] switch_core_codec.c:111 sofia/external/sipp@192.168.1.104:5060 Original read codec set to PCMU:0
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:50.271103 [DEBUG] switch_core_media.c:4725 No 2833 in SDP. Liberal DTMF mode adding 101 as telephone-event.
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:50.271103 [DEBUG] switch_core_media.c:4754 sofia/external/sipp@192.168.1.104:5060 Set 2833 dtmf send payload to 101 recv payload to 101
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:50.271103 [DEBUG] switch_core_media.c:6865 AUDIO RTP [sofia/external/sipp@192.168.1.104:5060] 172.17.0.3 port 20854 -> 192.168.1.104 port 6000 codec: 0 ms: 20
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:50.271103 [DEBUG] switch_rtp.c:4096 Starting timer [soft] 160 bytes per 20ms
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:50.271103 [DEBUG] switch_core_media.c:7166 sofia/external/sipp@192.168.1.104:5060 Set 2833 dtmf send payload to 101
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:50.271103 [DEBUG] switch_core_media.c:7173 sofia/external/sipp@192.168.1.104:5060 Set 2833 dtmf receive payload to 101
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:50.271103 [DEBUG] switch_core_media.c:7196 sofia/external/sipp@192.168.1.104:5060 Set rtp dtmf delay to 40
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:50.271103 [NOTICE] sofia.c:8182 Channel [sofia/external/sipp@192.168.1.104:5060] has been answered
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:50.271103 [DEBUG] switch_channel.c:3772 (sofia/external/sipp@192.168.1.104:5060) Callstate Change RINGING -> ACTIVE
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:50.271103 [DEBUG] sofia.c:8191 3PCC-PROXY, Got my ACK
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:50.271103 [DEBUG] mod_sofia.c:808 3PCC-PROXY, Done waiting for ACK
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:50.271103 [DEBUG] switch_ivr_originate.c:3690 Originate Resulted in Success: [sofia/internal/1002@172.17.0.1:15060]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:50.271103 [DEBUG] switch_ivr_originate.c:3690 Originate Resulted in Success: [sofia/internal/1002@172.17.0.1:15060]
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:50.281108 [DEBUG] switch_ivr_bridge.c:1601 (sofia/internal/1002@172.17.0.1:15060) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:50.281108 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1002@172.17.0.1:15060) Running State Change CS_EXCHANGE_MEDIA (Cur 2 Tot 10)
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:50.281108 [DEBUG] switch_core_state_machine.c:653 (sofia/internal/1002@172.17.0.1:15060) State EXCHANGE_MEDIA
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:50.281108 [DEBUG] mod_sofia.c:631 SOFIA EXCHANGE_MEDIA
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:50.331105 [DEBUG] switch_rtp.c:7229 Correct audio ip/port confirmed.
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:50.361105 [DEBUG] switch_rtp.c:6679 Correct video RTCP ip/port confirmed.
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:50.371107 [NOTICE] switch_vpx.c:402 VPX reset encoder picture from 320x240 to 352x288 1024 BW
recv 627 bytes from udp/[192.168.1.104]:5060 at 08:59:50.776894:
------------------------------------------------------------------------
INVITE sip:mod_sofia@172.17.0.3:5080 SIP/2.0
Via: SIP/2.0/UDP 192.168.1.104:5060;branch=z9hG4bK-1988-1-6
From: sipp <sip:sipp@192.168.1.104:5060>;tag=1
To: <sip:1002@172.17.0.3:5080>;tag=ND882pjeBXeQH
Call-ID: 1-1988@192.168.1.104
CSeq: 2 INVITE
Contact: <sip:sipp@192.168.1.104:5060;transport=udp>
Max-Forwards: 70
Subject: Performance Test
Session-Expires: 1800
Min-SE: 900
Content-Length: 215
v=0
o=ipjib 1492600869292 1492600869294 IN IP4 192.168.1.104
s=Basic Session
c=IN IP4 192.168.1.104
t=0 0
m=audio 6000 RTP/AVP 0 8 18 99
a=rtpmap:99 telephone-event/8000
a=fmtp:99 0-15
a=fmtp:18 annexb=yes
------------------------------------------------------------------------
send 911 bytes to udp/[192.168.1.104]:5060 at 08:59:50.777648:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.1.104:5060;branch=z9hG4bK-1988-1-6
From: sipp <sip:sipp@192.168.1.104:5060>;tag=1
To: <sip:1002@172.17.0.3:5080>;tag=ND882pjeBXeQH
Call-ID: 1-1988@192.168.1.104
CSeq: 2 INVITE
Contact: <sip:mod_sofia@172.17.0.3:5080>
User-Agent: FreeSWITCH-mod_sofia/1.6.17-34-0fc0946~64bit
Accept: application/sdp
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
Supported: timer, path, replaces
Session-Expires: 1800;refresher=uas
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 319
v=0
o=FreeSWITCH 1493349136 1493349138 IN IP4 172.17.0.3
s=FreeSWITCH
c=IN IP4 172.17.0.3
t=0 0
m=audio 20854 RTP/AVP 0 8 103 101
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:103 telephone-event/48000
a=fmtp:103 0-16
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
m=video 0 RTP/AVP 19
------------------------------------------------------------------------
recv 406 bytes from udp/[192.168.1.104]:5060 at 08:59:50.778254:
------------------------------------------------------------------------
ACK sip:mod_sofia@172.17.0.3:5080 SIP/2.0
Via: SIP/2.0/UDP 192.168.1.104:5060;branch=z9hG4bK-1988-1-10
From: sipp <sip:sipp@192.168.1.104:5060>;tag=1
To: sut <sip:1002@172.17.0.3:5080>;tag=ND882pjeBXeQH
Call-ID: 1-1988@192.168.1.104
CSeq: 2 ACK
Contact: <sip:sipp@192.168.1.104:5060;transport=udp>
Max-Forwards: 70
Subject: Performance Test
Content-Type: application/sdp
Content-Length: 0
------------------------------------------------------------------------
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:50.791167 [DEBUG] sofia.c:7048 Channel sofia/external/sipp@192.168.1.104:5060 entering state [completed][200]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:50.791167 [DEBUG] sofia.c:7058 Remote SDP:
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 v=0
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 o=ipjib 1492600869292 1492600869294 IN IP4 192.168.1.104
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 s=Basic Session
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 c=IN IP4 192.168.1.104
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 t=0 0
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 m=audio 6000 RTP/AVP 0 8 18 99
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 a=fmtp:18 annexb=yes
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 a=rtpmap:99 telephone-event/8000
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 a=fmtp:99 0-15
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:50.791167 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:50.791167 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:50.791167 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:50.791167 [DEBUG] switch_core_media.c:4491 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:50.791167 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:50.791167 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[opus:116:48000:20:0:1]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:50.791167 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:50.791167 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:50.791167 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:50.791167 [DEBUG] switch_core_media.c:4491 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:50.791167 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G729:18:8000:20:8000:1]/[opus:116:48000:20:0:1]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:50.791167 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G729:18:8000:20:8000:1]/[G722:9:8000:20:64000:1]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:50.791167 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:50.791167 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:50.791167 [DEBUG] switch_core_media.c:4352 Set telephone-event payload to 99@8000
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:50.791167 [DEBUG] switch_core_media.c:4695 Set telephone-event payload to 99@8000
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:50.791167 [DEBUG] switch_core_media.c:4754 sofia/external/sipp@192.168.1.104:5060 Set 2833 dtmf send payload to 99 recv payload to 99
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:50.791167 [DEBUG] switch_core_media.c:6848 Audio params are unchanged for sofia/external/sipp@192.168.1.104:5060.
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:50.791167 [DEBUG] sofia.c:7963 Processing updated SDP
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:50.791167 [DEBUG] sofia.c:7048 Channel sofia/external/sipp@192.168.1.104:5060 entering state [ready][200]
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:51.031123 [DEBUG] switch_rtp.c:1885 rtcp_stats_init: video ssrc[985159765] base_seq[0]
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:51.081126 [DEBUG] switch_rtp.c:7229 Correct video ip/port confirmed.
recv 331 bytes from udp/[172.17.0.1]:15060 at 08:59:56.693337:
------------------------------------------------------------------------
BYE sip:mod_sofia@172.17.0.3:5060 SIP/2.0
Via: SIP/2.0/UDP 172.17.0.1:15060;branch=z9hG4bK.VTfhChwLa;rport
From: <sip:1002@172.17.0.1>;tag=p4j0hb7
To: "sipp" <sip:sipp@172.17.0.3>;tag=Q2gmU46vre09H
CSeq: 111 BYE
Call-ID: dbbbf1c8-a693-1235-0e9b-0242ac110003
Max-Forwards: 70
User-Agent: Linphone/3.11.1 (belle-sip/1.6.1)
------------------------------------------------------------------------
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:56.711226 [NOTICE] sofia.c:1012 Hangup sofia/internal/1002@172.17.0.1:15060 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING]
send 466 bytes to udp/[172.17.0.1]:15060 at 08:59:56.713853:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 172.17.0.1:15060;branch=z9hG4bK.VTfhChwLa;rport=15060
From: <sip:1002@172.17.0.1>;tag=p4j0hb7
To: "sipp" <sip:sipp@172.17.0.3>;tag=Q2gmU46vre09H
Call-ID: dbbbf1c8-a693-1235-0e9b-0242ac110003
CSeq: 111 BYE
User-Agent: FreeSWITCH-mod_sofia/1.6.17-34-0fc0946~64bit
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, path, replaces
Content-Length: 0
------------------------------------------------------------------------
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:56.711226 [DEBUG] switch_ivr_bridge.c:787 BRIDGE THREAD DONE [sofia/internal/1002@172.17.0.1:15060]
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:56.711226 [DEBUG] switch_core_media.c:11605 sofia/internal/1002@172.17.0.1:15060 skip receive message [VIDEO_REFRESH_REQ] (channel is hungup already)
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:56.711226 [DEBUG] switch_core_state_machine.c:653 (sofia/internal/1002@172.17.0.1:15060) State EXCHANGE_MEDIA going to sleep
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:56.711226 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1002@172.17.0.1:15060) Running State Change CS_HANGUP (Cur 2 Tot 10)
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:56.711226 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/1002@172.17.0.1:15060) Callstate Change ACTIVE -> HANGUP
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:56.711226 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1002@172.17.0.1:15060) State HANGUP
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:56.711226 [DEBUG] mod_sofia.c:438 Channel sofia/internal/1002@172.17.0.1:15060 hanging up, cause: NORMAL_CLEARING
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:56.711226 [DEBUG] switch_core_state_machine.c:60 sofia/internal/1002@172.17.0.1:15060 Standard HANGUP, cause: NORMAL_CLEARING
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:56.711226 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1002@172.17.0.1:15060) State HANGUP going to sleep
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:56.711226 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/1002@172.17.0.1:15060) State Change CS_HANGUP -> CS_REPORTING
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:56.711226 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1002@172.17.0.1:15060) Running State Change CS_REPORTING (Cur 2 Tot 10)
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:56.711226 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1002@172.17.0.1:15060) State REPORTING
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:56.711226 [DEBUG] switch_core_state_machine.c:174 sofia/internal/1002@172.17.0.1:15060 Standard REPORTING, cause: NORMAL_CLEARING
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:56.711226 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1002@172.17.0.1:15060) State REPORTING going to sleep
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:56.711226 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/1002@172.17.0.1:15060) State Change CS_REPORTING -> CS_DESTROY
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:56.711226 [DEBUG] switch_core_session.c:1664 Session 10 (sofia/internal/1002@172.17.0.1:15060) Locked, Waiting on external entities
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:56.711226 [DEBUG] switch_ivr_bridge.c:787 BRIDGE THREAD DONE [sofia/external/sipp@192.168.1.104:5060]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:56.711226 [NOTICE] switch_ivr_bridge.c:1751 Hangup sofia/external/sipp@192.168.1.104:5060 [CS_EXECUTE] [NORMAL_CLEARING]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:56.711226 [DEBUG] switch_core_session.c:2814 sofia/external/sipp@192.168.1.104:5060 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:56.711226 [DEBUG] switch_core_state_machine.c:650 (sofia/external/sipp@192.168.1.104:5060) State EXECUTE going to sleep
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:56.711226 [DEBUG] switch_core_state_machine.c:584 (sofia/external/sipp@192.168.1.104:5060) Running State Change CS_HANGUP (Cur 2 Tot 10)
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:56.711226 [DEBUG] switch_core_state_machine.c:850 (sofia/external/sipp@192.168.1.104:5060) Callstate Change ACTIVE -> HANGUP
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:56.711226 [DEBUG] switch_core_state_machine.c:852 (sofia/external/sipp@192.168.1.104:5060) State HANGUP
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:56.711226 [DEBUG] mod_sofia.c:432 sofia/external/sipp@192.168.1.104:5060 Overriding SIP cause 480 with 200 from the other leg
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:56.711226 [DEBUG] mod_sofia.c:438 Channel sofia/external/sipp@192.168.1.104:5060 hanging up, cause: NORMAL_CLEARING
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:56.711226 [DEBUG] mod_sofia.c:491 Sending BYE to sofia/external/sipp@192.168.1.104:5060
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:56.711226 [DEBUG] switch_core_state_machine.c:60 sofia/external/sipp@192.168.1.104:5060 Standard HANGUP, cause: NORMAL_CLEARING
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:56.711226 [DEBUG] switch_core_state_machine.c:852 (sofia/external/sipp@192.168.1.104:5060) State HANGUP going to sleep
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:56.711226 [DEBUG] switch_core_state_machine.c:619 (sofia/external/sipp@192.168.1.104:5060) State Change CS_HANGUP -> CS_REPORTING
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:56.711226 [DEBUG] switch_core_state_machine.c:584 (sofia/external/sipp@192.168.1.104:5060) Running State Change CS_REPORTING (Cur 2 Tot 10)
send 541 bytes to udp/[192.168.1.104]:5060 at 08:59:56.718214:
------------------------------------------------------------------------
BYE sip:sipp@192.168.1.104:5060;transport=udp SIP/2.0
Via: SIP/2.0/UDP 172.17.0.3:5080;rport;branch=z9hG4bKN5XtmKjQrrS3p
Max-Forwards: 70
From: <sip:1002@172.17.0.3:5080>;tag=ND882pjeBXeQH
To: sipp <sip:sipp@192.168.1.104:5060>;tag=1
Call-ID: 1-1988@192.168.1.104
CSeq: 106348934 BYE
User-Agent: FreeSWITCH-mod_sofia/1.6.17-34-0fc0946~64bit
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFYc514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:56.711226 [DEBUG] switch_core_state_machine.c:938 (sofia/external/sipp@192.168.1.104:5060) State REPORTING
Supported: timer, path, replaces
Reason: Q.850;cause=16;text="NORMAL_CLEARING"
Content-Length: 0
------------------------------------------------------------------------
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:56.711226 [DEBUG] switch_core_state_machine.c:174 sofia/external/sipp@192.168.1.104:5060 Standard REPORTING, cause: NORMAL_CLEARING
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:56.711226 [DEBUG] switch_core_state_machine.c:938 (sofia/external/sipp@192.168.1.104:5060) State REPORTING going to sleep
recv 255 bytes from udp/[192.168.1.104]:5060 at 08:59:56.718368:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 172.17.0.3:5080;rport;branch=z9hG4bKN5XtmKjQrrS3p
From: <sip:1002@172.17.0.3:5080>;tag=ND882pjeBXeQH
To: sipp <sip:sipp@192.168.1.104:5060>;tag=1
Call-ID: 1-1988@192.168.1.104
CSeq: 106348934 BYE
Content-Length: 0
------------------------------------------------------------------------
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:56.711226 [DEBUG] switch_core_state_machine.c:610 (sofia/external/sipp@192.168.1.104:5060) State Change CS_REPORTING -> CS_DESTROY
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:56.711226 [DEBUG] switch_core_session.c:1664 Session 9 (sofia/external/sipp@192.168.1.104:5060) Locked, Waiting on external entities
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:56.711226 [NOTICE] switch_core_session.c:1682 Session 9 (sofia/external/sipp@192.168.1.104:5060) Ended
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:56.711226 [NOTICE] switch_core_session.c:1686 Close Channel sofia/external/sipp@192.168.1.104:5060 [CS_DESTROY]
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:56.711226 [DEBUG] switch_core_state_machine.c:741 (sofia/external/sipp@192.168.1.104:5060) Running State Change CS_DESTROY (Cur 1 Tot 10)
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:56.711226 [DEBUG] switch_core_state_machine.c:751 (sofia/external/sipp@192.168.1.104:5060) State DESTROY
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:56.711226 [DEBUG] mod_sofia.c:343 sofia/external/sipp@192.168.1.104:5060 SOFIA DESTROY
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:56.711226 [DEBUG] switch_core_state_machine.c:181 sofia/external/sipp@192.168.1.104:5060 Standard DESTROY
c514aafe-c9de-45b1-897d-0ddd5fa3f4b2 2017-04-28 08:59:56.711226 [DEBUG] switch_core_state_machine.c:751 (sofia/external/sipp@192.168.1.104:5060) State DESTROY going to sleep
2017-04-28 08:59:56.711226 [DEBUG] switch_core_media.c:5957 sofia/internal/1002@172.17.0.1:15060 Video thread ended
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:56.711226 [NOTICE] switch_core_session.c:1682 Session 10 (sofia/internal/1002@172.17.0.1:15060) Ended
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:56.711226 [NOTICE] switch_core_session.c:1686 Close Channel sofia/internal/1002@172.17.0.1:15060 [CS_DESTROY]
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:56.711226 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/1002@172.17.0.1:15060) Running State Change CS_DESTROY (Cur 0 Tot 10)
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:56.711226 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1002@172.17.0.1:15060) State DESTROY
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:56.711226 [DEBUG] mod_sofia.c:343 sofia/internal/1002@172.17.0.1:15060 SOFIA DESTROY
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:56.711226 [DEBUG] switch_core_state_machine.c:181 sofia/internal/1002@172.17.0.1:15060 Standard DESTROY
a39555b8-b95f-479f-b480-4601fd615f24 2017-04-28 08:59:56.711226 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1002@172.17.0.1:15060) State DESTROY going to sleep
2017-04-28 09:00:04.351110 [NOTICE] mod_cdr_csv.c:123 Rotated CDR logfile /var/log/freeswitch/cdr-csv/Master.csv